Affects: 5.2.2 (SpringBoot: 2.2.2)
Logging request/response payload should be a pretty standard and straightforward thing to configure in such a powerful and customisable web framework as Spring is. Yet there are a number of different alternatives and confusing implementation details which resulted in all sorts of advices on the internet. Take a look at this StackOverflow question for example: https://stackoverflow.com/questions/33744875/spring-boot-how-to-log-all-requests-and-responses-with-exceptions-in-single-pl I couldn't find a good standard example in the official docs, sorry if I missed it and please just point me at it then.
There are several problems that I'm facing when it comes to logging in Spring.
1. CommonsRequestLoggingFilter
doesn't log request payload in Before request
where it's expected to be logged.
1. Default AbstractRequestLoggingFilter
also doesn't log payload in Before request
. But here you can fix it if you override getMessagePayload
method and include wrapper.getParameterMap()
call before calling wrapper.getContentAsByteArray()
where wrapper
is a ContentCachingRequestWrapper
object.
1. Even if you call getParameterMap()
before getContentAsByteArray()
, ContentCachingRequestWrapper
implementation won't allow you to log anything else but POST requests with application/x-www-form-urlencoded
content type. It's not clear to me why is this limitation.
There is some confusion here if you see.
My main question I guess is about limitations in ContentCachingRequestWrapper
, what's the reason for them and could they be removed to allow any text-based payload to be logged?
Comment From: rstoyanchev
@bigunyak we went back and forth on this under #24533. I think I see now where the confusion comes from.
ContentCachingRequestWrapper
does not eagerly consume the body which can cause side effects in some cases and prevent the request from being processed if input data exceeds the cache size. Instead it waits for the application to consume the request body and only then it buffers up to allowed cache size.
When you call request.getParameterMap()
that causes the Servlet container to parse the request body but but it does so only for form data on a POST in order to return the request parameters.
I don't see why logging "before" rather than "after" is important. The trade off is the side effect of consuming the request body early potentially causing side effects. If you really want it you can follow my advice under https://github.com/spring-projects/spring-framework/pull/24533#issuecomment-589188646.
Comment From: bigunyak
@rstoyanchev thanks for your response. Not sure why you qualified my report as invalid and closed it when I think you also see there is clearly some confusion here in how request logging works in Spring.
The way things work, as you described them, I had to learn hard way, debugging and trying to figure out why things don't work they logically should. This is also the reason there are dozens of different "solutions" for requests logging on the internet which I mentioned in the original report.
Logging "before" is quite important in building a natural sequential stream of logging events where I want to see events in the order they happen. Seeing log messages about request handling before seeing request data log is not logical and not cool.
You're justifying this strange logic implemented in ContentCachingRequestWrapper
by potential side effects, but what are those? If you're suggesting a simple solution from your comment, why can't that solution be implemented in Spring and provide a standard and logical way to log request data?
I think there is definitely a room for improvement here, it's a pity you don't agree.
Comment From: bigunyak
@rstoyanchev your advice does work and is exactly what I need to implement desired logging logic in a custom Filter class. Thanks! I just wish there was something standard like that available in Spring, also side-effects free. :)
Comment From: zjunothing
mark
Comment From: Susuper2019
https://github.com/spring-projects/spring-framework/issues/25046#issuecomment-632727561 I have reviewed the relevant information about this issue, and I would like to add a supplement regarding "before." In my scenario, I need to perform anti-tampering validation on parameters at the filter layer. (The HTTP request typically contains an encrypted value in the header. I need to parse the parameters, re-encrypt them, and check whether the encrypted value matches the one in the header.) it can help me whether to terminate the request early before the @RequestBody is parsed.