为什么spring boot嵌入式tomcat会延迟api响应?

igsr9ssn  于 2021-10-10  发布在  Java
关注(0)|答案(0)|浏览(293)

我们已经使用微服务体系结构很长时间了。这些服务是使用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)`

暂无答案!

目前还没有任何答案,快来回答吧!

相关问题