InputStream consumed by DispatcherServlet logRequest

[martinvw]

Affects: 5.2.1

---

A few weeks ago I enabled debug logging for my application, today I had forgotten about but noticed that my injected InputStream was empty. After a debugging session (first assuming it again was related to the HiddenHttpMethodFilter) I ended up at

spring-framework/spring-webmvc/src/main/java/org/springframework/web/servlet/DispatcherServlet.java

Lines 955 to 965 in 8d84650

	private void logRequest(HttpServletRequest request) {
	LogFormatUtils.traceDebug(logger, traceOn -> {
	String params;
	if (isEnableLoggingRequestDetails()) {
	params = request.getParameterMap().entrySet().stream()
	.map(entry -> entry.getKey() + ":" + Arrays.toString(entry.getValue()))
	.collect(Collectors.joining(", "));
	}
	else {
	params = (request.getParameterMap().isEmpty() ? "" : "masked");
	}

So every time I enable debug logging I cannot use my injected InputStream:

@PostMapping
public ResponseEntity<String> doPost(InputStream input, HttpServletRequest request) {
    ...

I do now get this logging:

2019-12-10T10:27:46,305 [http-nio-8082-exec-7] DEBUG org.springframework.web.servlet.DispatcherServlet - POST "/communication", parameters={masked}

But maybe it would make sense to auto-wrap the request in DEBUG when that logging is active or give a warning when injecting the consumed InputStream later and even report who did it 😄

Thanks!

Related to (but not covered by): #22985

[martinvw]

Or maybe its completely related it seems to be a application/x-www-form-urlencoded request as well here, so kind of by design

[rstoyanchev]

Yes this is expected, and besides the logging of request details, any other code could cause a similar issue by accessing a request parameter.

Note that you can inject the content reliably as @RequestBody String or @RequestBody ByteArrayResource because we reconstruct the body from request parameters in ServletServerHttpRequest#getBody.

[martinvw]

Great, I will do some tests with the @RequestBody

[martinvw]

A major drawback is that even the ByteArrayResource contains an interpreted value (in this case url-encoded which make sense but brakes our code), I will have to convince my callers to pass the proper content-type headers :-)

[rstoyanchev]

The InputStream should also give you encoded form data. Perhaps you can provide some sample input to explain? Also can you clarify what you mean by the proper content-type header?

[carlsagan21]

So may I interpret this thread as follows?: Receiving stream via HTTP request body is not what Spring is designed to support..? Because by any reason, reading stream can happen before the request body reaches to controller.

[rstoyanchev]

This issue concerns the use of one of the getParameter methods on HttpServletRequest which indirectly consume the body of the request body. That's related to form data only, not streaming, and it is how the Servlet API works, with or without Spring.

[brecht-yperman-tb]

This does cause the CommonsMultipartResolver to no longer work (if logging on DispatcherServlet is enabled), resulting in an error MissingServletRequestPartException: Required request part 'file' is not present

Should we no longer use CommonsMultipartResolver?

[rstoyanchev]

Yes, just use the standard multipart support in the Servlet container.