You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "wei wang (Jira)" <ji...@apache.org> on 2021/07/21 06:02:00 UTC

[jira] [Commented] (LOG4J2-2696) Class loading for extended stack traces causes performance issues

    [ https://issues.apache.org/jira/browse/LOG4J2-2696?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17384671#comment-17384671 ] 

wei wang commented on LOG4J2-2696:
----------------------------------

+1,are there any plans to solve this bug?

> Class loading for extended stack traces causes performance issues
> -----------------------------------------------------------------
>
>                 Key: LOG4J2-2696
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-2696
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.11.2
>            Reporter: Joe Jordan
>            Priority: Major
>
> 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:
> {noformat}
>    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){noformat}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)