>On 7/11/25 17:42, Christopher Schultz wrote: >Daniel, > >On 7/11/25 11:57 AM, Daniel Sheridan wrote: > > > > [snip] > > >> Correct, almost the entire delay is during the JAR scanning when the >> files are being accessed. >> >> We are using expanded-WAR deployment. > >Good. That fixes at least one known performance issue (scanning WAR files is >inefficient regardless of environment). > >> We have no JAR files in WEB-INF/classes, just class files for our >> proprietary code. We have 160 jar files in WEB-INF/lib, mostly >> consisting of 3rd party dependencies; it's this directory that's being >> scanned through during the delay. > >Understood and expected. I did mean WEB-INF/lib and not /classes, thanks for >answering the question I was trying to ask, rather than the question I >actually asked :) > >> The size of the JAR files varies quite a bit, as big as 11MB to as >> small as >> 3 KB. Around 140 out of the 164 JARs are under 1MB in size, around 70 >> of those 140 are under 150KB. > >160 JARs isn't insane, but it's also not nothing, especially if some of them >are large (in terms of number of entries). Reading the ZIP directory is all >that needs to happen unless one of the file names matches what's being >searched for. > >> I've been running the web app on virtual machines, which I would >> assume use network-attached storage. > >+1 > >>> The flame graph points to either a slow disk or an unusually huge >>> number of file-opens > >> From my previous ProcMon investigating, during the JAR scanning around 140 >> files are opened, in the case of loading the >> EmptyBodyCheckingHttpInputMessage class. The delay happens once after >> the idle period, then doesn't happen afterwards even if further JAR >> scanning of a similar amount of JARs is done when a different class is being >> loaded. > >.... until another idle period, right? If that's the case, my guess is that >you are being saved by the OS's disk cache when things are going quickly. I >*am* curious what is causing those JAR-scans to take place periodically. >Theoretically, once the application is "up and running" >then it should not be scanning JARs much if at all. > >> We haven't changed any Tomcat defaults around anything that would be >> related; I did mess around with some resource caching settings to see >> if it'd make any difference, but it did not. >> >> We're not running in development mode. > >Just to double-check, have a look at your <Context> element in >META-INF/context.xml or in >$CATALINA_BASE/conf/[engine]/[host]/[application].xml. If you have set >reloadable="true" then I call this "development mode" where Tomcat scans your >files to see if anything changed. But typically it's looking at file-changes >and not actually diving into the files to see if the classes changed inside >the files, without the file timestamps or sizes changing for some reason. > >> If I idle the virtual machine and do other file related tasks, I don't >> notice a long delay like we see here, which makes me think it isn't an >> issue with the disk being slow after an idle; however, maybe I'm >> missing something there, and that is the case. >> >> The other side of it is, why is Tomcat doing the classload when the >> classes don't seem to be unloaded at any point? I don't understand why >> the classload is needed at all at this point. > >You mentioned AbstractMessageConverterMethodArgumentResolver in your original >message, but the flame graph you showed indicates that it's >AbstractMessageConverterMethodArgumentResolver that is causing the class >loading to take place. The >AbstractMessageConverterMethodArgumentResolver.readWithMessage method is >running, which means that the class has already been loaded and it's >triggering the load of another class. > >Does this application (or some component you are using) have any kind of >custom class-loading capabilities or anything that might try to do some >class-resolution itself -- rather than relying on the JVM triggering such >things? The flame graph points to the JVM just trying to load a class that >AbstractMessageConverterMethodArgumentResolver apparently needs, but once that >class has been loaded, it should really just already exist. Maybe it's loading >one class at a time, incrementally, over time? > >I'm grasping at straws. > >If you enable TRACE-level logging for >org.apache.catalina.loader.WebappClassLoaderBase it will tell you what is >being loaded (or attempted) after those idles. Maybe that will point to what >the underlying cause is. > >-chris > > >--------------------------------------------------------------------- >To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org >For additional commands, e-mail: users-h...@tomcat.apache.org
Chris, >.... until another idle period, right? Exactly, after another idle period the issue occurs again. >If that's the case, my guess is that you are being saved by the OS's disk >cache when things are going quickly. Well, if we're assuming that what makes the loading take so long after the delay is the disk being 'cold' and taking a while to get going, I'm surprised there isn't one long delay for the initial operations of the JAR scan, instead of what's actually happening where the delay is spread between all JARs being scanned. But I'm not sure on this. >If you have set reloadable="true" then I call this "development mode" where >Tomcat scans your files to see if anything changed. Checked this and can confirm we're not running in development mode. >You mentioned AbstractMessageConverterMethodArgumentResolver in your original >message, but the flame graph you showed indicates that it's >AbstractMessageConverterMethodArgumentResolver that is causing the class >loading to take place. The >AbstractMessageConverterMethodArgumentResolver.readWithMessage method is >running, which means that the class has already been loaded and it's >triggering the load of another class. I should be more precise, in this case the class being loaded isn't AbstractMessageConverterMethodArgumentResolver, it's an inner class of AbstractMessageConverterMethodArgumentResolver called EmptyBodyCheckingHttpInputMessage. I can see this in the class loading logs, and in the ProcMon capture. So it's the loading of the inner class that has the delay, in this case. >Does this application (or some component you are using) have any kind of >custom class-loading capabilities or anything that might try to do some >class-resolution itself -- rather than relying on the JVM triggering such >things? The flame graph points to the JVM just trying to load a class that >AbstractMessageConverterMethodArgumentResolver apparently needs, but once that >class has been loaded, it should really just already exist. Maybe it's loading >one class at a time, incrementally, over time? I don't believe we have any custom class loading logic in the app; I wouldn't even say there could be something in Spring doing some custom class loading, because I see the delay for other classes as well. A followup question on this, the Tomcat logs show it is Tomcat's WebappClassLoaderBase doing the class loading during the delay, if there was custom class loading wouldn't it be another class doing the class loading in the logs, or the Tomcat logs wouldn't show the loading in that case at all right? It's definitely Tomcat doing the class loading in this case, and we don't use any Tomcat dependencies in our code, it's just used as a web server. >If you enable TRACE-level logging for >org.apache.catalina.loader.WebappClassLoaderBase it will tell you what is >being loaded (or attempted) after those idles. Maybe that will point to what >the underlying cause is. Have been running this with org.apache.catalina.loader.level = ALL, so I think that's already covered; no sign of class unloading there. - Dan --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
