Skip to content

Add logging to CsrfTokenRequestHandler implementations #16994

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 2 commits into
base: main
Choose a base branch
from

Conversation

yybmion
Copy link

@yybmion yybmion commented Apr 24, 2025

Issue

This PR adds trace-level logging to CSRF token handlers to improve debugging capabilities.

Changes

  • Add logging to show token source (header or parameter) in resolveCsrfTokenValue
  • Add logging to show request attribute names used in handle methods
  • Add logging in XorCsrfTokenRequestAttributeHandler when token processing fails (as specifically requested in the issue)
  • Apply similar logging improvements to XorServerCsrfTokenRequestAttributeHandler for consistency

Fixes #13626

Add trace-level logging to show the logical path of CSRF token processing
- Log token source (header or parameter) in resolveCsrfTokenValue
- Log request attribute names in handle methods
- Log failures in XorCsrfTokenRequestAttributeHandler (especially Base64 decoding)
- Add similar logging to XorServerCsrfTokenRequestAttributeHandler

Improves debugging capabilities without changing functionality.

Signed-off-by: yybmion <[email protected]>
@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Apr 24, 2025
Copy link
Contributor

@jzheaux jzheaux left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi, @yybmion, thanks for the PR! I've left some feedback inline for the servlet code. Will you please apply the same to the reactive code?

Also, I don't see changes to ServerCsrfTokenRequestHandler. Can you add logging changes equivalent to CsrfTokenRequestHandler?

@@ -60,6 +66,9 @@ public void handle(HttpServletRequest request, HttpServletResponse response,
String csrfAttrName = (this.csrfRequestAttributeName != null) ? this.csrfRequestAttributeName
: csrfToken.getParameterName();
request.setAttribute(csrfAttrName, csrfToken);

logger.trace(LogMessage.format("CSRF token written to request attributes: %s, %s", CsrfToken.class.getName(),
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's please rephrase to match the following grammar:

Wrote a CSRF token to the following request attributes: [%s, %s]

The motive for this is it allows the logs to read more like a sentence:

2025-01-03T02:20:45Z [CsrfTokenRequestAttributeHandler] Wrote a CSRF token to the following request attributes ...

The reason for the brackets is that the CsrfToken class name will be log in the logs and it will make it easier visually to find the end of the list.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

@@ -51,6 +55,13 @@ default String resolveCsrfTokenValue(HttpServletRequest request, CsrfToken csrfT
String actualToken = request.getHeader(csrfToken.getHeaderName());
if (actualToken == null) {
actualToken = request.getParameter(csrfToken.getParameterName());
if (actualToken != null) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we refactor this logic a bit to reduce nesting? For example (starting at line 56):

if (actualToken != null) {
    return actualToken;
}
logger.trace(LogMessage.format("Did not find a CSRF token in the [%s] request header", csrfToken.getHeaderName()));
actualToken = request.getParameter(csrfToken.getParameterName());
if (actualToken != null) {
    return actualToken;
} 
logger.trace(LogMessage.format("Did not find a CSRF token in the [%s] request parameter", csrfToken.getParameterName()));
return null;

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

* @since 5.8
* @see CsrfTokenRequestAttributeHandler
*/
@FunctionalInterface
public interface CsrfTokenRequestHandler extends CsrfTokenRequestResolver {

Log logger = LogFactory.getLog(CsrfTokenRequestHandler.class);
Copy link
Contributor

@jzheaux jzheaux Apr 29, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We don't want to expose our logger as a public member. Instead, please create a package-private class (maybe called CsrfTokenRequestHandlerLoggerHolder) that has a package-private Log member. The default method can reference it.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Created a package-private CsrfTokenRequestHandlerLoggerHolder class to encapsulate the logger as requested.

@@ -55,6 +59,7 @@ public void handle(HttpServletRequest request, HttpServletResponse response,
Assert.notNull(response, "response cannot be null");
Assert.notNull(deferredCsrfToken, "deferredCsrfToken cannot be null");
Supplier<CsrfToken> updatedCsrfToken = deferCsrfTokenUpdate(deferredCsrfToken);
logger.trace(LogMessage.format("XOR CSRF token created and will be written to request attributes"));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Will you please remove this log? It is implied by the CsrfTokenRequestAttributeHandler log message. Also, we don't typically want to make future promises in logs since future logic in CsrfTokenRequestAttributeHandler might contradict this statement.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

@@ -70,7 +75,18 @@ private Supplier<CsrfToken> deferCsrfTokenUpdate(Supplier<CsrfToken> csrfTokenSu
@Override
public String resolveCsrfTokenValue(HttpServletRequest request, CsrfToken csrfToken) {
String actualToken = super.resolveCsrfTokenValue(request, csrfToken);
return getTokenValue(actualToken, csrfToken.getToken());
if (actualToken == null) {
logger.trace(LogMessage.format("No CSRF token value found in request"));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Will you please remove this log? It is taken care of by the suggested changes to CsrfTokenRequestHandler.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

}
String tokenValue = getTokenValue(actualToken, csrfToken.getToken());
if (tokenValue == null) {
logger.trace(LogMessage.format("CSRF token validation failed"));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Will you please remove this log? It's taken care of in getTokenValue

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

logger.trace(LogMessage.format("CSRF token validation failed"));
}
else {
logger.trace(LogMessage.format("CSRF token successfully validated"));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please remove this log message since we don't know if the value is valid yet. Instead, let's add a log to CsrfFilter that says

Found a CSRF token in the request

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added the requested log message to CsrfFilter as follows:

CsrfToken csrfToken = deferredCsrfToken.get();
String actualToken = this.requestHandler.resolveCsrfTokenValue(request, csrfToken);
if (actualToken != null && this.logger.isTraceEnabled()) {
   this.logger.trace(LogMessage.format("Found a CSRF token in the request"));
}

@@ -60,6 +66,9 @@ public void handle(HttpServletRequest request, HttpServletResponse response,
String csrfAttrName = (this.csrfRequestAttributeName != null) ? this.csrfRequestAttributeName
: csrfToken.getParameterName();
request.setAttribute(csrfAttrName, csrfToken);

logger.trace(LogMessage.format("CSRF token written to request attributes: %s, %s", CsrfToken.class.getName(),
csrfAttrName));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please switch the two attribute names to show the shorter one first.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

@@ -79,12 +95,14 @@ private static String getTokenValue(String actualToken, String token) {
actualBytes = Base64.getUrlDecoder().decode(actualToken);
}
catch (Exception ex) {
logger.trace(LogMessage.format("Failed to find CSRF token since Base64 decoding failed"), ex);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please change this to:

Not returning the CSRF token since it's not Base64-encoded

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

return null;
}

byte[] tokenBytes = Utf8.encode(token);
int tokenSize = tokenBytes.length;
if (actualBytes.length != tokenSize * 2) {
logger.trace(LogMessage.format("Failed to validate CSRF token since token length is invalid"));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please change this to:

"Not returning the CSRF token since its Base64-decoded length (%d) is not equal to (%d)",  actualBytes.length, tokenSize * 2

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

Improve CSRF logging: consistent formatting, reduced nesting, proper encapsulation, and removal of redundant messages

Signed-off-by: yybmion <[email protected]>
@yybmion
Copy link
Author

yybmion commented Apr 30, 2025

Thank you @jzheaux for thorough review and detailed guidance!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status: waiting-for-triage An issue we've not yet triaged
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Add logging to CsrfTokenRequestHandler implementations
3 participants