为什么 Spring Boot Embedded tomcat 会延迟 API 响应？

问题描述

我们一直在使用微服务架构。这些服务是使用 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)`

解决方法

暂无找到可以解决该程序问题的有效方法，小编努力寻找整理中！

如果你已经找到好的解决方法，欢迎将解决方案带上本链接一起发送给小编。

小编邮箱:dio#foxmail.com (将#修改为@）