我们已经使用微服务体系结构很长时间了。这些服务是使用spring boot开发的。这些服务很早以前就使用spring boot 1.3.5.release开发,该版本在内部使用以下tomcat依赖项:
<dependency>
<groupId>org.apache.tomcat.embed</groupId>
<artifactId>tomcat-embed-core</artifactId>
<version>8.0.33</version>
</dependency>
<dependency>
<groupId>org.apache.tomcat.embed</groupId>
<artifactId>tomcat-embed-el</artifactId>
<version>8.0.33</version>
</dependency>
<dependency>
<groupId>org.apache.tomcat.embed</groupId>
<artifactId>tomcat-embed-jasper</artifactId>
<version>8.0.33</version>
</dependency>
<dependency>
<groupId>org.apache.tomcat.embed</groupId>
<artifactId>tomcat-embed-logging-juli</artifactId>
<version>8.0.33</version>
</dependency>
<dependency>
<groupId>org.apache.tomcat.embed</groupId>
<artifactId>tomcat-embed-websocket</artifactId>
<version>8.0.33</version>
</dependency>
为了找出api响应缓慢的原因,我们启用了日志级别在test env上进行调试,发现是tomcat将响应延迟了近6-7秒,请查看以下日志:
2021-05-28 13:04:37 [http-nio-9112-exec-1] DEBUG o.apache.tomcat.util.http.Parameters-[DirectJDKLog.java:180]-Set query string encoding to UTF-8
2021-05-28 13:04:37 [http-nio-9112-exec-1] DEBUG o.a.catalina.connector.CoyoteAdapter-[DirectJDKLog.java:180]-The variable [uriBC] has value [<Path_Param>]
2021-05-28 13:04:37 [http-nio-9112-exec-1] DEBUG o.a.catalina.connector.CoyoteAdapter-[DirectJDKLog.java:180]-The variable [semicolon] has value [-1]
2021-05-28 13:04:37 [http-nio-9112-exec-1] DEBUG o.a.catalina.connector.CoyoteAdapter-[DirectJDKLog.java:180]-The variable [enc] has value [utf-8]
2021-05-28 13:04:45 [http-nio-9112-exec-1] DEBUG o.a.c.a.AuthenticatorBase-[DirectJDKLog.java:180]-Security checking request GET <Path_Param>
2021-05-28 13:04:45 [http-nio-9112-exec-1] DEBUG org.apache.catalina.realm.RealmBase-[DirectJDKLog.java:180]- No applicable constraints defined
2021-05-28 13:04:45 [http-nio-9112-exec-1] DEBUG o.a.c.a.AuthenticatorBase-[DirectJDKLog.java:180]- Not subject to any constraint
2021-05-28 13:04:45 [http-nio-9112-exec-1] INFO o.a.c.c.C.[Tomcat].[localhost].[/]-[DirectJDKLog.java:180]-Initializing Spring FrameworkServlet 'dispatcherServlet'
当从coyoteadapter调用authenticatorbase时,如果查看上面的日志,它会被卡住6-7秒(查看日志计时的差异),并且每个api调用都会发生这种情况。
奇怪的是,其他使用同一版本tomcat的服务没有这个问题。有人能帮我们找出这个问题的根本原因吗?
ps:我知道升级到最新的spring版本可能会解决这个问题,但是这个选项现在不在考虑范围之内。
添加线程等待时执行的线程转储:
`"http-nio-9112-exec-1" #64 daemon prio=5 os_prio=0 tid=0x00007fe2c800d800 nid=0x519c runnable [0x00007fe3156e6000]
java.lang.Thread.State: RUNNABLE
at java.util.zip.Inflater.inflateBytes(Native Method)
at java.util.zip.Inflater.inflate(Inflater.java:259)
- locked <0x00000000f814e928> (a java.util.zip.ZStreamRef)
at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:152)
at java.util.zip.ZipInputStream.read(ZipInputStream.java:194)
at java.util.jar.JarInputStream.read(JarInputStream.java:207)
at java.util.zip.ZipInputStream.closeEntry(ZipInputStream.java:140)
at java.util.zip.ZipInputStream.getNextEntry(ZipInputStream.java:118)
at java.util.jar.JarInputStream.getNextEntry(JarInputStream.java:142)
at java.util.jar.JarInputStream.getNextJarEntry(JarInputStream.java:179)
at org.apache.catalina.webresources.JarWarResourceSet.getArchiveEntries(JarWarResourceSet.java:112)
- locked <0x00000000e35168e0> (a java.lang.Object)
at org.apache.catalina.webresources.AbstractArchiveResourceSet.getResource(AbstractArchiveResourceSet.java:256)
at org.apache.catalina.webresources.StandardRoot.getResourceInternal(StandardRoot.java:281)
at org.apache.catalina.webresources.CachedResource.validateResource(CachedResource.java:95)
at org.apache.catalina.webresources.Cache.getResource(Cache.java:70)
at org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot.java:216)
at org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot.java:206)
at org.apache.catalina.mapper.Mapper.internalMapWrapper(Mapper.java:1006)
at org.apache.catalina.mapper.Mapper.internalMap(Mapper.java:822)
at org.apache.catalina.mapper.Mapper.map(Mapper.java:687)
at org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:886)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:517)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1095)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:672)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1502)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1458)
- locked <0x00000000e80faeb8> (a org.apache.tomcat.util.net.NioChannel)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)`
暂无答案!
目前还没有任何答案,快来回答吧!