Affects: 5.1.7.RELEASE spring boot:2.1.5.RELEASE


When using StreamingResponseBody and Spring Security together, Error occurs when there are many requests.

Cause

In the processing of main thread and sub thread, the variables of HttpHeader are overwritten and an error occurs.


@RestController
public class SampleController {

  @GetMapping("/stream"}
  public ResponseEntity<StreamingResponseBody> stream(@PathVariable("str") String str) {
        return ResponseEntity.ok().contentType(MediaType.APPLICATION_JSON_UTF8).body(outputStream -> {
              // outputStream.write()
              outputStream.flush();
        });
  }
}

java.lang.NullPointerException: null
        at org.apache.tomcat.util.http.MimeHeaders.getValue(MimeHeaders.java:341) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.tomcat.util.http.MimeHeaders.getHeader(MimeHeaders.java:373) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.connector.Response.getHeader(Response.java:863) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.connector.ResponseFacade.getHeader(ResponseFacade.java:633) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at javax.servlet.http.HttpServletResponseWrapper.getHeader(HttpServletResponseWrapper.java:241) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at javax.servlet.http.HttpServletResponseWrapper.getHeader(HttpServletResponseWrapper.java:241) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at javax.servlet.http.HttpServletResponseWrapper.getHeader(HttpServletResponseWrapper.java:241) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at sun.reflect.GeneratedMethodAccessor34.invoke(Unknown Source) ~[na:na]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_212]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_212]
        at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) ~[spring-core-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.springframework.security.web.header.writers.CacheControlHeadersWriter.hasHeader(CacheControlHeadersWriter.java:73) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.security.web.header.writers.CacheControlHeadersWriter.writeHeaders(CacheControlHeadersWriter.java:62) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.security.web.header.HeaderWriterFilter$HeaderWriterResponse.writeHeaders(HeaderWriterFilter.java:109) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:77) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:215) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:178) ~[spring-security-web-5.1.5.RELEASE.jar:5.1.5.RELEASE]
        at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:357) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:270) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:92) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.zalando.logbook.servlet.SecurityStrategy.doFilter(SecurityStrategy.java:33) ~[logbook-servlet-1.13.0.jar:na]
        at org.zalando.logbook.servlet.LogbookFilter.doFilter(LogbookFilter.java:39) ~[logbook-servlet-1.13.0.jar:na]
        at org.zalando.logbook.servlet.HttpFilter.doFilter(HttpFilter.java:31) ~[logbook-servlet-1.13.0.jar:na]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:109) ~[spring-web-5.1.8.RELEASE.jar:5.1.8.RELEASE]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:490) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:853) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1587) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_212]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_212]
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.21.jar:9.0.21]
        at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212]

https://github.com/spring-projects/spring-framework/blob/79cf6b43534a88f58b058294b976cf8f56423104/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/StreamingResponseBodyReturnValueHandler.java#L94

If you fix it like this, no error will occur.

        WebAsyncUtils.getAsyncManager(webRequest).startCallableProcessing(callable, mavContainer);
        countDownLatch.await();
    private static class StreamingResponseBodyTask implements Callable<Void> {

        private final OutputStream outputStream;

        private final StreamingResponseBodystreamingBody;

        private final CountDownLatch countDownLatch;


        StreamingResponseBodyTask(OutputStream outputStream, StreamingResponseBody streamingBody,
                CountDownLatch countDownLatch) {
            this.outputStream = outputStream;
            this.streamingBody = streamingBody;
            this.countDownLatch = countDownLatch;
        }

        @Override
        public Void call() throws Exception {
            try {
                this.streamingBody.writeTo(this.outputStream);
                this.outputStream.flush();
            } finally {
                countDownLatch.countDown();
            }
            return null;
        }
    }

Comment From: rstoyanchev

@ykawano-class are you able to provide a sample to reproduce the issue? That would help to figure out what's going on.

Comment From: ykawano-class

sample https://github.com/ykawano-class/stream

When you run a number of times it is output error log. But the test itself does not result in an error.

Comment From: rstoyanchev

Thanks for the sample project. I think this issue is similar to spring-projects/spring-security#9175 in the sense that Spring Security's HeaderWriterFilter tries to update the headers while the main Servlet container thread is exiting, and runs into an issue because the response is updated concurrently. In this case the StreamResponseBody probably completes very quickly and closes the response before Spring Security has been able to update the headers. Again I think some kind of solution has to be on the Spring Security side in the HeadersWriterFilter that needs to be better protected for async request scenarios and early termination.

Note that we can't use a CountDownLatch as suggested since that would block the main Servlet container thread on which the request is processed until the async response is complete. That defeats the purpose of doing it asynchronously.

Comment From: ykawano-class

Thank you. It's the same problem as #9175, so I'll close it.