Details
-
Bug
-
Status: Open
-
Major
-
Resolution: Unresolved
-
2.11.2
-
None
-
None
Description
Extended stack traces invoke class loading, including for classes such as "jdk/internal/reflect/GeneratedMethodAccessor183.class".
When running e.g. springboot+Tomcat with a fat-jar, this class loading is delegated to TomcatEmbeddedWebappClassLoader, which will unzip JAR files in an attempt to find the class. This causes performance issues, as JAR files are unzipped every time an exception with one of these classes in the stack is logged.
In the case of TomcatEmbeddedWebappClassLoader, there is a caching mechanism in place but this particular code path bypasses the cache, due to the filename pattern being searched for (starts-with "/WEB-INF/classes", ends-with ".class").
Others have also noticed performance issues here, due to locking in Jetty's classloader: https://stackoverflow.com/questions/53627883/how-to-stop-log4j2-load-class-in-exception-stack
Example stack trace:
java.lang.Thread.State: RUNNABLE at java.util.zip.Inflater.inflateBytesBytes(java.base@11.0.3/Native Method) at java.util.zip.Inflater.inflate(java.base@11.0.3/Inflater.java:385) - locked <0x00000000c337ca78> (a java.util.zip.Inflater$InflaterZStreamRef) at java.util.zip.InflaterInputStream.read(java.base@11.0.3/InflaterInputStream.java:153) at java.util.zip.ZipInputStream.read(java.base@11.0.3/ZipInputStream.java:195) at java.util.jar.JarInputStream.read(java.base@11.0.3/JarInputStream.java:207) at java.util.zip.ZipInputStream.closeEntry(java.base@11.0.3/ZipInputStream.java:141) at java.util.zip.ZipInputStream.getNextEntry(java.base@11.0.3/ZipInputStream.java:119) at java.util.jar.JarInputStream.getNextEntry(java.base@11.0.3/JarInputStream.java:142) at java.util.jar.JarInputStream.getNextJarEntry(java.base@11.0.3/JarInputStream.java:179) at org.apache.catalina.webresources.JarWarResourceSet.getArchiveEntries(JarWarResourceSet.java:117) - locked <0x00000000d6fc7d00> (a java.lang.Object) at org.apache.catalina.webresources.AbstractArchiveResourceSet.getResource(AbstractArchiveResourceSet.java:253) at org.apache.catalina.webresources.StandardRoot.getResourceInternal(StandardRoot.java:282) at org.apache.catalina.webresources.Cache.getResource(Cache.java:62) at org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot.java:217) at org.apache.catalina.webresources.StandardRoot.getClassLoaderResource(StandardRoot.java:226) at org.apache.catalina.loader.WebappClassLoaderBase.findClassInternal(WebappClassLoaderBase.java:2303) at org.apache.catalina.loader.WebappClassLoaderBase.findClass(WebappClassLoaderBase.java:865) at org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader.findClassIgnoringNotFound(TomcatEmbeddedWebappClassLoader.java:119) at org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader.doLoadClass(TomcatEmbeddedWebappClassLoader.java:84) at org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader.loadClass(TomcatEmbeddedWebappClassLoader.java:66) - locked <0x00000000d9741ce8> (a java.lang.Object) at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1188) at org.apache.logging.log4j.util.LoaderUtil.loadClass(LoaderUtil.java:166) at org.apache.logging.log4j.core.impl.ThrowableProxyHelper.loadClass(ThrowableProxyHelper.java:218) at org.apache.logging.log4j.core.impl.ThrowableProxyHelper.toExtendedStackTrace(ThrowableProxyHelper.java:114) at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:109) at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:93) at org.apache.logging.log4j.core.impl.Log4jLogEvent.getThrownProxy(Log4jLogEvent.java:605) at org.apache.logging.log4j.core.impl.Log4jLogEvent.serialize(Log4jLogEvent.java:718) at org.apache.logging.log4j.core.impl.Log4jLogEvent.createMemento(Log4jLogEvent.java:772) at org.apache.logging.log4j.core.appender.AsyncAppender.append(AsyncAppender.java:162) at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156) at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129) at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120) at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84) at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:464) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:448) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:431) at org.apache.logging.log4j.core.config.LoggerConfig.logParent(LoggerConfig.java:455) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:450) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:431) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:406) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63) at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146) at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2170) at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2125) at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2108) at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2002) at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1974) at org.apache.logging.slf4j.Log4jLogger.error(Log4jLogger.java:319)