java - 为什么在 Tomcat 8.5 上调用 Java findClass() 可能需要 7 分钟？
问题描述
我正在尝试调查使用独立 Tomcat 8.5 实例部署的 Java 应用程序的性能问题。应用程序偶尔会冻结 5-10 分钟，并且对用户查询没有响应，大约每 24 小时一次。该应用程序被打包为一个 war 文件，但在部署过程中被解包。
通过在日志记录中启用卡住线程检测，我们发现线程在加载类时遇到了卡住：
27-Mar-2021 19:21:46.045 WARNING [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.valves.StuckThreadDetectionValve.notifyStuckThreadDetected Thread [http-nio-8080-exec-8] (id=[70]) has been active for [308,580] milliseconds (since [3/27/21 7:16 PM]) to serve the same request for [http://gms-beta.beta.euw2.vi.basespace.illumina.com/hadean-api/user/login-urls] and may be stuck (configured threshold for this StuckThreadDetectionValve is [300] seconds). There is/are [1] thread(s) in total that are monitored by this Valve and may be stuck.
java.lang.Throwable
at java.util.zip.ZipFile.open(Native Method)
at java.util.zip.ZipFile.<init>(ZipFile.java:225)
at java.util.zip.ZipFile.<init>(ZipFile.java:155)
at java.util.jar.JarFile.<init>(JarFile.java:166)
at java.util.jar.JarFile.<init>(JarFile.java:130)
at org.apache.tomcat.util.compat.JreCompat.jarFileNewInstance(JreCompat.java:202)
at org.apache.tomcat.util.compat.JreCompat.jarFileNewInstance(JreCompat.java:187)
at org.apache.catalina.webresources.AbstractArchiveResourceSet.openJarFile(AbstractArchiveResourceSet.java:308)
at org.apache.catalina.webresources.AbstractSingleArchiveResourceSet.getArchiveEntry(AbstractSingleArchiveResourceSet.java:96)
at org.apache.catalina.webresources.AbstractArchiveResourceSet.getResource(AbstractArchiveResourceSet.java:257)
at org.apache.catalina.webresources.StandardRoot.getResourceInternal(StandardRoot.java:280)
at org.apache.catalina.webresources.Cache.getResource(Cache.java:62)
at org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot.java:215)
at org.apache.catalina.webresources.StandardRoot.getClassLoaderResource(StandardRoot.java:224)
at org.apache.catalina.loader.WebappClassLoaderBase.findClassInternal(WebappClassLoaderBase.java:2278)
at org.apache.catalina.loader.WebappClassLoaderBase.findClass(WebappClassLoaderBase.java:855)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1327)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1180)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:264)
at groovy.lang.MetaClassRegistry$MetaClassCreationHandle.createWithCustomLookup(MetaClassRegistry.java:149)
at groovy.lang.MetaClassRegistry$MetaClassCreationHandle.create(MetaClassRegistry.java:144)
at org.codehaus.groovy.reflection.ClassInfo.getMetaClassUnderLock(ClassInfo.java:270)
at org.codehaus.groovy.reflection.ClassInfo.getMetaClass(ClassInfo.java:313)
at org.codehaus.groovy.reflection.ClassInfo.getMetaClass(ClassInfo.java:323)
at org.codehaus.groovy.runtime.metaclass.MetaClassRegistryImpl.getMetaClass(MetaClassRegistryImpl.java:262)
at org.codehaus.groovy.runtime.InvokerHelper.getMetaClass(InvokerHelper.java:879)
at org.codehaus.groovy.runtime.callsite.CallSiteArray.createPojoSite(CallSiteArray.java:125)
at org.codehaus.groovy.runtime.callsite.CallSiteArray.createCallSite(CallSiteArray.java:166)
at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113)
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:117)
at com.ilmn.hadean.controller.UserController.getAppConfig(UserController.groovy:217)
at com.ilmn.hadean.controller.UserController$$FastClassBySpringCGLIB$$7cdc282f.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:752)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:180)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
at com.ilmn.hadean.controller.UserController$$EnhancerBySpringCGLIB$$3259232e.getAppConfig(<generated>)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:892)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:626)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.ilmn.hadean.filter.XssFilter.doFilterInternal(XssFilter.java:26)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:209)
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:178)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.thetransactioncompany.cors.CORSFilter.doFilter(CORSFilter.java:209)
at com.thetransactioncompany.cors.CORSFilter.doFilter(CORSFilter.java:244)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:543)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.valves.StuckThreadDetectionValve.invoke(StuckThreadDetectionValve.java:206)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:615)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:818)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1626)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
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)
在类加载器上启用日志记录，我可以看到 findClass() 调用花费了非常长的时间——大多数时候加载一个类需要几毫秒，但是有用的卡住线程检测会找到许多线程，这一步类加载需要整整几分钟。在这种情况下，findClass() 方法在 09:25 被调用，并且直到 09:32 才返回！
30-Mar-2021 09:25:20.191 FINE [http-nio-8080-exec-46] org.apache.catalina.loader.WebappClassLoaderBase.loadClass loadClass(org.springframework.web.multipart.support.MultipartResolutionDelegate, false)
30-Mar-2021 09:25:20.191 FINE [http-nio-8080-exec-46] org.apache.catalina.loader.WebappClassLoaderBase.loadClass loadClass(org.springframework.web.multipart.support.MultipartResolutionDelegate, false)
30-Mar-2021 09:25:20.191 FINE [http-nio-8080-exec-46] org.apache.catalina.loader.WebappClassLoaderBase.findClass findClass(org.springframework.web.multipart.support.MultipartResolutionDelegate)
30-Mar-2021 09:32:26.342 FINE [http-nio-8080-exec-46] org.apache.catalina.loader.WebappClassLoaderBase.findClass Returning class class org.springframework.web.multipart.support.MultipartResolutionDelegate
非常感谢您对这里发生的事情的任何见解！我可以使用哪些工具来缩小这种延迟的来源，我可以调整哪些配置来消除它？
从四处阅读，这听起来像是一种首先停止卸载类的方法可以解决问题，但首先要理解为什么这个操作需要这么长时间并修复它是理想的。
一些额外的上下文：
- 我们在不同的源 jar 文件提供的不同类中看到了这种行为。
- 我们已经在同一 Tomcat/Spring Boot 2 应用程序的不同版本中看到它
- 我们在几个不同的环境中偶尔会出现这个问题 - 但在其他环境中根本没有。
- 这些环境的利用率非常低（因此卸载类是有意义的），但即使在 24 小时以上空闲的开发人员环境中，我们也无法重现该问题。
- 我们在首次启动时相当一致地看到类似的性能问题 - 但后来在环境闲置后也出现了！
由于后一个原因，我们推测类被 Tomcat 动态卸载是这里的一个因素。
我们看到此问题的环境的一个共同点是限制了出站互联网访问。我很好奇Tomcat类加载器是否有任何方式可能依赖出站互联网访问 - 据我了解，findClass()方法将在类路径中的本地存储库中查找 - 在这种情况下是默认类路径的一部分${CATALINA_HOME}/WEB-INF/lib/*.jar- 不在互联网上的任何地方。
参考：
用于收集此信息的配置，以防对其他人有用：
要启用 Stuck Thread Detection 值，请将以下内容添加到${CATALINA_BASE}/conf/server.xml元素内：
<Server port="8005" shutdown="SHUTDOWN">
<Service name="Catalina">
<Connector port="8080"/>
<Connector port="8009" protocol="AJP/1.3"/>
<Engine name="Catalina" defaultHost="localhost">
<Host name="localhost" appBase="webapps"/>
...
...
<Valve className="org.apache.catalina.valves.StuckThreadDetectionValve" threshold="300" />
</Engine>
</Service>
</Server>
将该threshold值设置为在将线程分类为卡住之前等待的秒数 - 在这种情况下，它设置为 300 秒（5 分钟）。
要捕获详细的类加载信息，请将以下内容添加到${CATALINA_BASE}/conf/logging.properties. 请注意它非常冗长：
org.apache.catalina.loader.WebappClassLoaderBase.level=ALL
解决方案
推荐阅读
- javascript - 不会使用 API 和 Javascript 显示正面或反面的结果
- stripe-payments - 可以在客户端创建 Stripe Payment Intent 吗？
- android - 通过桥反应原生的 AFS 广告
- python - 基于另一个矩阵的数字化形式对一个矩阵的条目进行混洗
- django - 如果当前登录的用户不是帖子的作者，则拒绝编辑/删除帖子的访问权限。Django REST + simpleJWT
- yaml - 我可以在 yaml azure 构建管道脚本中的模板文件之前运行脚本吗？
- linux - 没有处理程序的孩子处理 SIGQUIT？
- kubernetes - K8S 端口转发到安全集群中的服务
- fullcalendar - fullcalendar-vue 视图属性没有反应
- firebase - 我可以使用 yarn 作为包管理器来安装 firebase CLI 吗？