Dan,
On 7/2/25 10:22 AM, Daniel Sheridan wrote:
Hi folks,
We're using Tomcat 10.1.40, but also seeing this issue with multiple Tomcat 9
versions, running on Windows Server 2019 and Server 2022 machines. We're
hosting a web app with a REST API, and encounter delays on requests when they
hit our REST API of 9-12 seconds. Easiest way to reproduce it is leaving the
web page (which utilizes the REST API) idle for 10+ minutes and then initiating
a request, but have seen it happen rarely with shorter idle periods as well.
Have done extensive investigation into this, narrowed it down to a
classloading/jar scanning issue. Here's an excerpt from the Catalina logs with
loader logging set to ALL:
25-Jun-2025 15:00:10.475 FINER [https-openssl-nio-443-exec-10]
org.apache.catalina.loader.WebappClassLoaderBase.loadClass
loadClass(org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver$EmptyBodyCheckingHttpInputMessage,
false)
25-Jun-2025 15:00:10.477 FINER [https-openssl-nio-443-exec-10]
org.apache.catalina.loader.WebappClassLoaderBase.loadClass Searching local
repositories
25-Jun-2025 15:00:10.478 FINER [https-openssl-nio-443-exec-10]
org.apache.catalina.loader.WebappClassLoaderBase.findClass
findClass(org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver$EmptyBodyCheckingHttpInputMessage)
25-Jun-2025 15:00:10.478 FINER [https-openssl-nio-443-exec-10]
org.apache.catalina.loader.WebappClassLoaderBase.findClass
findClassInternal(org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver$EmptyBodyCheckingHttpInputMessage)
25-Jun-2025 15:00:19.682 FINER [https-openssl-nio-443-exec-10]
org.apache.catalina.loader.WebappClassLoaderBase.findClass Returning
class class
org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver$EmptyBodyCheckingHttpInputMessage
25-Jun-2025 15:00:19.682 FINER [https-openssl-nio-443-exec-10]
org.apache.catalina.loader.WebappClassLoaderBase.findClass Loaded by
ParallelWebappClassLoader
context: ROOT
delegate: false
----------> Parent Classloader:
mailto:java.net.URLClassLoader@3b94d659
25-Jun-2025 15:00:19.683 FINER [https-openssl-nio-443-exec-10]
org.apache.catalina.loader.WebappClassLoaderBase.loadClass Loading class from
local repository
As you can see, the majority of the delay is during the findClassInternal call.
I inspected the Tomcat process behaviour with ProcMon, and I can see that the
delay happens during the jar scan for the
AbstractMessageConverterMethodArgumentResolver class; we have 140+ dependency
jars and it's reading through most of them until it find the class; the
scanning takes much longer than regular jar scans for some reason. Mostly, the
delay is between QueryEAFile and QueryStandardInformationFile operations, of
which there are 1 each per jar scanned (though the operations themselves have a
reasonable duration, there is a delay there with no file operations occurring).
AbstractMessageConverterMethodArgumentResolver IS loaded in when the
application is started, so it isn't the first time it's been loaded in. Note
that AbstractMessageConverterMethodArgumentResolver is not the only class I've
seen this happen with, it doesn't appear to be related to specific
classes/jars, I've seen the class that the jar scan is initiated for be
different depending on the endpoint the request is sent to.
JVM classloading/unloading and GC logging doesn't reveal any cleanup/unloading
happening that might necessitate the new classloading. I am not having this
issue occur when I run our web app on a non-Tomcat web server, which makes me
think the issue is Tomcat related.
My main question is, what inside Tomcat would force the classloading if there
isn't any sign of the classes being unloaded beforehand? Is there some kind of
periodic refresh of idle/'cold' classes I'm missing?
Also, would there be any suggestions about why the jar scan in this case takes
so long compared to the other regular jar scans Tomcat does? I understand this
might have other causes (like on the I/O side), but maybe there's something
relevant here on the Tomcat side.
Is there any chance you could produce a Java + native flame graph of
this behavior? It will help hone in on exactly where the problem is.
It could be some poorly-performing locks in Tomcat or the JVM. Or it
could be poorly-sized caches that need to be refilled with an expensive
process. Or it could be a failing disk. A flame graph will likely
pinpoint that.
-chris
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
