SpringBoot接口频繁超时,长时间找不到原因,我用 Arthas 定位到了( 四 )

从stack日志上可以很直观的看出DispatchServlet的调用栈,那么这么长的路径,该trace哪个类呢(这里跳过spring mvc中的过滤器的trace过程,实际排查的时候也trace了一遍,但这诡异的时间消耗不是由这里过滤器产生的)?
有一定经验的老司机从名字上大概也能猜出来从哪里下手比较好,那就是org.apache.coyote.http11.Http11Processor.service,从名字上看,http1.1处理器,这可能是一个比较好的切入点 。下面来trace一下:
[arthas@24851]$ trace org.apache.coyote.http11.Http11Processor servicePress Q or Ctrl+C to abort.Affect(class-cnt:1 , method-cnt:1) cost in 269 ms.`---ts=2019-09-14 21:22:51;thread_name=http-nio-7744-exec-8;id=17;is_daemon=true;priority=5;TCCL=org.springframework.boot.loader.LaunchedURLClassLoader@20ad9418`---[131.650285ms] org.apache.coyote.http11.Http11Processor:service+---[0.036851ms] org.apache.coyote.Request:getRequestProcessor#667+---[0.009986ms] org.apache.coyote.RequestInfo:setStage#668+---[0.008928ms] org.apache.coyote.http11.Http11Processor:setSocketWrapper#671+---[0.013236ms] org.apache.coyote.http11.Http11InputBuffer:init#672+---[0.00981ms] org.apache.coyote.http11.Http11OutputBuffer:init#673+---[min=0.00213ms,max=0.007317ms,total=0.009447ms,count=2] org.apache.coyote.http11.Http11Processor:getErrorState#683+---[min=0.002098ms,max=0.008888ms,total=0.010986ms,count=2] org.apache.coyote.ErrorState:isError#683+---[min=0.002448ms,max=0.007149ms,total=0.009597ms,count=2] org.apache.coyote.http11.Http11Processor:isAsync#683+---[min=0.002399ms,max=0.00852ms,total=0.010919ms,count=2] org.apache.tomcat.util.net.AbstractEndpoint:isPaused#683+---[min=0.033587ms,max=0.11832ms,total=0.151907ms,count=2] org.apache.coyote.http11.Http11InputBuffer:parseRequestLine#687+---[0.005384ms] org.apache.tomcat.util.net.AbstractEndpoint:isPaused#695+---[0.007924ms] org.apache.coyote.Request:getMimeHeaders#702+---[0.006744ms] org.apache.tomcat.util.net.AbstractEndpoint:getMaxHeaderCount#702+---[0.012574ms] org.apache.tomcat.util.http.MimeHeaders:setLimit#702+---[0.14319ms] org.apache.coyote.http11.Http11InputBuffer:parseHeaders#703+---[0.003997ms] org.apache.coyote.Request:getMimeHeaders#743+---[0.026561ms] org.apache.tomcat.util.http.MimeHeaders:values#743+---[min=0.002869ms,max=0.01203ms,total=0.014899ms,count=2] java.util.Enumeration:hasMoreElements#745+---[0.070114ms] java.util.Enumeration:nextElement#746+---[0.010921ms] java.lang.String:toLowerCase#746+---[0.008453ms] java.lang.String:contains#746+---[0.002698ms] org.apache.coyote.http11.Http11Processor:getErrorState#775+---[0.00307ms] org.apache.coyote.ErrorState:isError#775+---[0.002708ms] org.apache.coyote.RequestInfo:setStage#777+---[0.171139ms] org.apache.coyote.http11.Http11Processor:prepareRequest#779+---[0.009349ms] org.apache.tomcat.util.net.SocketWrapperBase:decrementKeepAlive#794+---[0.002574ms] org.apache.coyote.http11.Http11Processor:getErrorState#800+---[0.002696ms] org.apache.coyote.ErrorState:isError#800+---[0.002499ms] org.apache.coyote.RequestInfo:setStage#802+---[0.005641ms] org.apache.coyote.http11.Http11Processor:getAdapter#803+---[129.868916ms] org.apache.coyote.Adapter:service#803+---[0.003859ms] org.apache.coyote.http11.Http11Processor:getErrorState#809+---[0.002365ms] org.apache.coyote.ErrorState:isError#809+---[0.003844ms] org.apache.coyote.http11.Http11Processor:isAsync#809+---[0.002382ms] org.apache.coyote.Response:getStatus#809+---[0.002476ms] org.apache.coyote.http11.Http11Processor:statusDropsConnection#809+---[0.002284ms] org.apache.coyote.RequestInfo:setStage#838+---[0.00222ms] org.apache.coyote.http11.Http11Processor:isAsync#839+---[0.037873ms] org.apache.coyote.http11.Http11Processor:endRequest#843+---[0.002188ms] org.apache.coyote.RequestInfo:setStage#845+---[0.002112ms] org.apache.coyote.http11.Http11Processor:getErrorState#849+---[0.002063ms] org.apache.coyote.ErrorState:isError#849+---[0.002504ms] org.apache.coyote.http11.Http11Processor:isAsync#853+---[0.009808ms] org.apache.coyote.Request:updateCounters#854+---[0.002008ms] org.apache.coyote.http11.Http11Processor:getErrorState#855+---[0.002192ms] org.apache.coyote.ErrorState:isIoAllowed#855+---[0.01968ms] org.apache.coyote.http11.Http11InputBuffer:nextRequest#856+---[0.010065ms] org.apache.coyote.http11.Http11OutputBuffer:nextRequest#857+---[0.002576ms] org.apache.coyote.RequestInfo:setStage#870+---[0.016599ms] org.apache.coyote.http11.Http11Processor:processSendfile#872+---[0.008182ms] org.apache.coyote.http11.Http11InputBuffer:getParsingRequestLinePhase#688+---[0.0075ms] org.apache.coyote.http11.Http11Processor:handleIncompleteRequestLineRead#690+---[0.001979ms] org.apache.coyote.RequestInfo:setStage#875+---[0.001981ms] org.apache.coyote.http11.Http11Processor:getErrorState#877+---[0.001934ms] org.apache.coyote.ErrorState:isError#877+---[0.001995ms] org.apache.tomcat.util.net.AbstractEndpoint:isPaused#877+---[0.002403ms] org.apache.coyote.http11.Http11Processor:isAsync#879`---[0.006176ms] org.apache.coyote.http11.Http11Processor:isUpgrade#881


推荐阅读