一、背景
基於SpringBoot 構建了一個http文件下載服務，檢查tomcat access 發現偶爾出現500 狀態碼的請求，檢查拋出的異常堆棧
2019-03-20 10:03:14,273 ERROR [http-bio-8080-exec-3] o.s.b.w.s.s.ErrorPageFilter - Forwarding to error page from request [/demo.xls] due to exception [org.springframewo
rk.web.util.NestedServletException: 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]
javax.servlet.ServletException: org.springframework.web.util.NestedServletException: 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
at com.vdian.vtrace.VtraceFilter.doFilter(VtraceFilter.java:65)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.springframework.boot.web.servlet.support.ErrorPageFilter.doFilter(ErrorPageFilter.java:115)
at org.springframework.boot.web.servlet.support.ErrorPageFilter.access$000(ErrorPageFilter.java:59)
at org.springframework.boot.web.servlet.support.ErrorPageFilter$1.doFilterInternal(ErrorPageFilter.java:90)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.springframework.boot.web.servlet.support.ErrorPageFilter.doFilter(ErrorPageFilter.java:108)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:436)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1078)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.springframework.web.util.NestedServletException: 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
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:986)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:870)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:624)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:855)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at com.vdian.vtrace.VtraceFilter.doFilter(VtraceFilter.java:50)
... 40 common frames omitted
Caused by: java.lang.IllegalStateException: InputStream has already been read - do not use InputStreamResource if a stream needs to be read multiple times
at org.springframework.core.io.InputStreamResource.getInputStream(InputStreamResource.java:97)
at org.springframework.http.converter.ResourceHttpMessageConverter.writeContent(ResourceHttpMessageConverter.java:130)
at org.springframework.http.converter.ResourceHttpMessageConverter.writeInternal(ResourceHttpMessageConverter.java:124)
at org.springframework.http.converter.ResourceHttpMessageConverter.writeInternal(ResourceHttpMessageConverter.java:45)
at org.springframework.http.converter.AbstractHttpMessageConverter.write(AbstractHttpMessageConverter.java:230)
at org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodProcessor.writeWithMessageConverters(AbstractMessageConverterMethodProcessor.java:274)
at org.springframework.web.servlet.mvc.method.annotation.HttpEntityMethodProcessor.handleReturnValue(HttpEntityMethodProcessor.java:218)
at org.springframework.web.method.support.HandlerMethodReturnValueHandlerComposite.handleReturnValue(HandlerMethodReturnValueHandlerComposite.java:82)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:119)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:870)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:776)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:978)
... 50 common frames omitted
二、問題排查
從exception message 看，是
java.lang.IllegalStateException: InputStream has already been read - do not use InputStreamResource if a stream needs to be read multiple times
StackOverflow 查一下發現有解決方案，就是把Resonse body 由InputStreamResource 類型改為ByteArrayResource即可，
但想八一八什么原因
（一）初步嘗試
取異常請求的 URL，在chrome 瀏覽器上重試，並沒有復現問題
（二）抓包查看
發現 500的請求中有Range Header
（三）問題復現
curl -v -o test.amr -H "Range:bytes=0-" "http://aud.idcheihei.com/se1-sellerexpt-31e9000001698f06b9370a216239.amr"
使用curl 命令帶上Range header 請求后端，請求返回500，復現問題
（四）根據堆棧查看代碼
org.springframework.core.io.InputStreamResource#getInputStream
inputstream 只能讀取一次內容，所以這里有一個read 成員變量，控制resource 的讀取
當resource 被讀取一次后，第二次讀取就會拋異常
那為什么會讀取兩次呢？
（五）本地debug
根據堆棧，打斷點，org.springframework.core.io.InputStreamResource#getInputStream
逐步調試發現發起第一次getInputStream 調用的地方是：
org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodProcessor#writeWithMessageConverters(T, org.springframework.core.MethodParameter, org.springframework.http.server.ServletServerHttpRequest, org.springframework.http.server.ServletServerHttpResponse)
由 outputValue = HttpRange.toResourceRegions(httpRanges, resource);拋異常，進入catch 邏輯
org.springframework.http.HttpRange#toResourceRegion 實現體
public ResourceRegion toResourceRegion(Resource resource) {
Assert.isTrue(resource.getClass() != InputStreamResource.class, "Cannot convert an InputStreamResource to a ResourceRegion");
try {
long contentLength = resource.contentLength();
Assert.isTrue(contentLength > 0L, "Resource content length should be > 0");
long start = this.getRangeStart(contentLength);
long end = this.getRangeEnd(contentLength);
return new ResourceRegion(resource, start, end - start + 1L);
} catch (IOException var8) {
throw new IllegalArgumentException("Failed to convert Resource to ResourceRegion", var8);
}
}
org.springframework.core.io.AbstractResource#contentLength的實現體：
public long contentLength() throws IOException {
InputStream is = this.getInputStream();
try {
long size = 0L;
int read;
for(byte[] buf = new byte[255]; (read = is.read(buf)) != -1; size += (long)read) {
}
long var6 = size;
return var6;
} finally {
try {
is.close();
} catch (IOException var14) {
}
}
}
第二次getInputStream 調用的地方是輸出內容的地方，/org/springframework/web/servlet/mvc/method/annotation/AbstractMessageConverterMethodProcessor.class:214
debug 到這里，已定位問題
（六）結論
1、文件下載 http 請求使用range header 時，response 需要設置一個Content-Range header，設置這個header 需要獲取response body 的contentlength，對於InputStreamResource這種resource，需要讀取整個inputstream的內容后才能得到body 的長度
2、resonse 填充文件內容的時候，由於 inputstream 讀取完成后不能再次讀取，所以拋出了InputStream has already been read - do not use InputStreamResource if a stream needs to be read multiple times 異常
本文作者：Blyde
原文鏈接：https://www.cnblogs.com/gliu/p/10570687.html
版權歸作者所有，轉載請注明出處