Skip to content

Since upgrade to 2.0.1: IllegalStateException: InputStream has already been read #12939

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

Closed
mixcloud-downloader opened this issue Apr 21, 2018 · 6 comments
Labels
for: stackoverflow A question that's better suited to stackoverflow.com

Comments

@mixcloud-downloader
Copy link

I upgraded a web application from Spring-boot-1.5.10 to 2.0.1. Since then I notice these frequent errors:

Apr 22 01:40:00 ru downloader.jar[7010]: 2018-04-22 01:40:00.083 ERROR 7030 --- [p-nio-80-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.IllegalStateException: InputStream has already been read - do not use InputStreamResource if a stream needs to be read multiple times] with root cause
Apr 22 01:40:00 ru downloader.jar[7010]: java.lang.IllegalStateException: InputStream has already been read - do not use InputStreamResource if a stream needs to be read multiple times
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.core.io.InputStreamResource.getInputStream(InputStreamResource.java:97)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.http.converter.ResourceHttpMessageConverter.writeContent(ResourceHttpMessageConverter.java:130)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.http.converter.ResourceHttpMessageConverter.writeInternal(ResourceHttpMessageConverter.java:124)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.http.converter.ResourceHttpMessageConverter.writeInternal(ResourceHttpMessageConverter.java:45)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.http.converter.AbstractHttpMessageConverter.write(AbstractHttpMessageConverter.java:224)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodProcessor.writeWithMessageConverters(AbstractMessageConverterMethodProcessor.java:274)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.mvc.method.annotation.HttpEntityMethodProcessor.handleReturnValue(HttpEntityMethodProcessor.java:224)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.method.support.HandlerMethodReturnValueHandlerComposite.handleReturnValue(HandlerMethodReturnValueHandlerComposite.java:82)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:119)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:877)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:783)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:974)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:866)
Apr 22 01:40:00 ru downloader.jar[7010]:         at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:851)
Apr 22 01:40:00 ru downloader.jar[7010]:         at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.servlet.resource.ResourceUrlEncodingFilter.doFilter(ResourceUrlEncodingFilter.java:60)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:158)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:126)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:111)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:84)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:496)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:803)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:790)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
Apr 22 01:40:00 ru downloader.jar[7010]:         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
Apr 22 01:40:00 ru downloader.jar[7010]:         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
Apr 22 01:40:00 ru downloader.jar[7010]:         at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
Apr 22 01:40:00 ru downloader.jar[7010]:         at java.lang.Thread.run(Thread.java:748)

The particular controller returns a ResponseEntity to download an InputStream. Also it seems only a fraction fails. Many download succeed. I know this report is not very helpful, but unfortunately I also don't know where to look further to get more details. Maybe this InputStreamResource sounds familiar to someone and can point me to a recent change with Spring-5.

@mixcloud-downloader
Copy link
Author

The particular controller returns a ResponseEntity

Markdown ate ResponseEntity<InputStreamResource>

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Apr 21, 2018
@snicoll
Copy link
Member

snicoll commented Apr 22, 2018

point me to a recent change with Spring-5.

I think you can turn this into something very useful by extracting that controller in a sample app we can run ourselves and open an issue in the Spring Framework issue tracker. This discussion shouldn't really happen here given the stacktrace you've shared.

@snicoll snicoll closed this as completed Apr 22, 2018
@snicoll snicoll added for: stackoverflow A question that's better suited to stackoverflow.com and removed status: waiting-for-triage An issue we've not yet triaged labels Apr 22, 2018
@mixcloud-downloader
Copy link
Author

extracting that controller in a sample app we can run ourselves

Here's the thing:

Also it seems only a fraction fails. Many download succeed.

That sample app will not be of much a help, as it probably won't reproduce the issue. I't really nothing too exoctically. It's a Controller returing just said ResponseEntity<InputStreamResource> and most of the times it just works. I tried some edge cases locally, but without reproducing the issue. I can only observe it frequently with production traffic. Also the stacktrace is completely out of my application, so do you really thing such a sample application would be so helpful?

@snicoll
Copy link
Member

snicoll commented Apr 22, 2018

Looking at what the controller does and the stacktrace might help the Spring Framework team to figure out what might cause this in Spring Framework 5 and not in Spring Framework 4.

@mixcloud-downloader
Copy link
Author

True, I'll do that. I just hoped to avoid the hassle around submitting to your Jira.

@mixcloud-downloader
Copy link
Author

For reference: https://jira.spring.io/browse/SPR-16754

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
for: stackoverflow A question that's better suited to stackoverflow.com
Projects
None yet
Development

No branches or pull requests

3 participants