[jira] [Updated] (LOG4J2-2940) High CPU at Java 11 due to the use of StackWalker from StackLocator.getCallerClass

["Peter H (Jira)" <ji...@apache.org>]

     [ https://issues.apache.org/jira/browse/LOG4J2-2940?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Peter H updated LOG4J2-2940:
----------------------------
    Component/s:     (was: Core)
                 API

> High CPU at Java 11 due to the use of StackWalker from StackLocator.getCallerClass
> ----------------------------------------------------------------------------------
>
>                 Key: LOG4J2-2940
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-2940
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: API
>    Affects Versions: 2.13.3
>            Reporter: Peter H
>            Priority: Major
>
> We're encountering an issue similar to [LOG4J2-2792] and [LOG4J2-2880] but it isn't because of the use of Location, but because of the use of dynamically created loggers that we then refer to via {{org.slf4j.LoggerFactory.getLogger(method.getDeclaringClass())}}. This attempts to get the caller class and ends up walking the whole stack as in the stack trace example below. This is known to be rather problematic (from the performance perspective) and even becomes worse with the time (until the JVM restart, or full GC) - https://bugs.openjdk.java.net/browse/JDK-8222942 for example.
> However I believe that to get to the required class it isn't be actually necessary to perform such expensive and problematic operation, but rather use an approach similar to what jboss-logging library developers used when working on the following issue:
> https://bugzilla.redhat.com/show_bug.cgi?id=1813436
> https://issues.redhat.com/browse/LOGMGR-263
> The related commit: https://github.com/jboss-logging/jboss-logmanager/commit/fc1fc3b509df9797ff06a423878a5b113f6281f8
> {noformat}at java.lang.StackStreamFactory$AbstractStackWalker.fetchStackFrames(java.base@11.0.8/Native Method)
> at java.lang.StackStreamFactory$AbstractStackWalker.fetchStackFrames(java.base@11.0.8/StackStreamFactory.java:386)
> at java.lang.StackStreamFactory$AbstractStackWalker.getNextBatch(java.base@11.0.8/StackStreamFactory.java:322)
> at java.lang.StackStreamFactory$AbstractStackWalker.peekFrame(java.base@11.0.8/StackStreamFactory.java:263)
> at java.lang.StackStreamFactory$AbstractStackWalker.hasNext(java.base@11.0.8/StackStreamFactory.java:351)
> at java.lang.StackStreamFactory$StackFrameTraverser.tryAdvance(java.base@11.0.8/StackStreamFactory.java:593)
> at java.util.stream.ReferencePipeline.forEachWithCancel(java.base@11.0.8/ReferencePipeline.java:127)
> at java.util.stream.AbstractPipeline.copyIntoWithCancel(java.base@11.0.8/AbstractPipeline.java:502)
> at java.util.stream.AbstractPipeline.copyInto(java.base@11.0.8/AbstractPipeline.java:488)
> at java.util.stream.AbstractPipeline.wrapAndCopyInto(java.base@11.0.8/AbstractPipeline.java:474)
> at java.util.stream.FindOps$FindOp.evaluateSequential(java.base@11.0.8/FindOps.java:150)
> at java.util.stream.AbstractPipeline.evaluate(java.base@11.0.8/AbstractPipeline.java:234)
> at java.util.stream.ReferencePipeline.findFirst(java.base@11.0.8/ReferencePipeline.java:543)
> at org.apache.logging.log4j.util.StackLocator.lambda$getCallerClass$6(StackLocator.java:58)
> at org.apache.logging.log4j.util.StackLocator$$Lambda$1226/0x00000008414fec40.apply(Unknown Source)
> at java.lang.StackStreamFactory$StackFrameTraverser.consumeFrames(java.base@11.0.8/StackStreamFactory.java:534)
> at java.lang.StackStreamFactory$AbstractStackWalker.doStackWalk(java.base@11.0.8/StackStreamFactory.java:306)
> at java.lang.StackStreamFactory$AbstractStackWalker.callStackWalk(java.base@11.0.8/Native Method)
> at java.lang.StackStreamFactory$AbstractStackWalker.beginStackWalk(java.base@11.0.8/StackStreamFactory.java:370)
> at java.lang.StackStreamFactory$AbstractStackWalker.walk(java.base@11.0.8/StackStreamFactory.java:243)
> at java.lang.StackWalker.walk(java.base@11.0.8/StackWalker.java:498)
> at org.apache.logging.log4j.util.StackLocator.getCallerClass(StackLocator.java:57)
> at org.apache.logging.log4j.util.StackLocatorUtil.getCallerClass(StackLocatorUtil.java:67)
> at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:45)
> at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:48)
> at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:30)
> at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:363)
> at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:388)
> at LoggerAspect.isLogLevelEnabled(LoggerAspect.java:91)
> ...{noformat}



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