[
https://issues.apache.org/jira/browse/LOG4J2-2880?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Hash Jang updated LOG4J2-2880:
------------------------------
Description:
While using OpenJDK 11, there are possibility cause severe CPU consumption
because of JDK bug in using StackWalker.
[Application on JDK11 consume 100% CPU after a few hours of
uptime|[https://bugs.openjdk.java.net/browse/JDK-8222942]]
And it happened serveral times on our production environment.
!image-2020-06-28-02-42-12-987.png!
Stack trace Is:
"reactor-http-epoll-1" #75 daemon prio=5 os_prio=0 cpu=25100145.64ms
elapsed=306507.26s tid=0x0000556eddcbd000 nid=0x61 runnable
[0x00007f8605443000]"reactor-http-epoll-2" #75 daemon prio=5 os_prio=0
cpu=25100145.64ms elapsed=306507.26s tid=0x0000556eddcbd000 nid=0x61 runnable
[0x00007f8605443000] java.lang.Thread.State: RUNNABLE at
java.lang.StackStreamFactory$AbstractStackWalker.callStackWalk([email protected]/Native
Method) at
java.lang.StackStreamFactory$AbstractStackWalker.beginStackWalk([email protected]/StackStreamFactory.java:370)
at
java.lang.StackStreamFactory$AbstractStackWalker.walk([email protected]/StackStreamFactory.java:243)
at java.lang.StackWalker.walk([email protected]/StackWalker.java:498) at
org.apache.logging.log4j.util.StackLocator.calcLocation(StackLocator.java:81)
at
org.apache.logging.log4j.util.StackLocatorUtil.calcLocation(StackLocatorUtil.java:76)
at
org.apache.logging.log4j.spi.AbstractLogger.getLocation(AbstractLogger.java:2201)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2144)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2127)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2020)
at
org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1891)
at org.apache.logging.log4j.spi.AbstractLogger.info(AbstractLogger.java:1436)
was:
While using OpenJDK 11, there are possibility cause severe CPU consumption
because of JDK bug in using StackWalker.
[Application on JDK11 consume 100% CPU after a few hours of
uptime|[https://bugs.openjdk.java.net/browse/JDK-8222942]]
And it happened serveral times on our production environment.
!image-2020-06-28-02-42-12-987.png!
Stack trace Is:
"reactor-http-epoll-1" #69 daemon prio=5 os_prio=0 cpu=25789335.11ms
elapsed=306523.88s tid=0x00007f8713f99800 nid=0x5d runnable
[0x00007f8605645000]"reactor-http-epoll-1" #69 daemon prio=5 os_prio=0
cpu=25789335.11ms elapsed=306523.88s tid=0x00007f8713f99800 nid=0x5d runnable
[0x00007f8605645000] java.lang.Thread.State: RUNNABLE at
java.lang.StackStreamFactory$AbstractStackWalker.fetchStackFrames([email protected]/Native
Method) at
java.lang.StackStreamFactory$AbstractStackWalker.fetchStackFrames([email protected]/StackStreamFactory.java:386)
at
java.lang.StackStreamFactory$AbstractStackWalker.getNextBatch([email protected]/StackStreamFactory.java:322)
at
java.lang.StackStreamFactory$AbstractStackWalker.peekFrame([email protected]/StackStreamFactory.java:263)
at
java.lang.StackStreamFactory$AbstractStackWalker.hasNext([email protected]/StackStreamFactory.java:351)
at
java.lang.StackStreamFactory$StackFrameTraverser.nextStackFrame([email protected]/StackStreamFactory.java:520)
at
java.lang.StackStreamFactory$StackFrameTraverser.forEachRemaining([email protected]/StackStreamFactory.java:581)
at
java.util.stream.AbstractPipeline.copyInto([email protected]/AbstractPipeline.java:484)
at
java.util.stream.AbstractPipeline.wrapAndCopyInto([email protected]/AbstractPipeline.java:474)
at
java.util.stream.AbstractPipeline.evaluate([email protected]/AbstractPipeline.java:550)
at
java.util.stream.AbstractPipeline.evaluateToArrayNode([email protected]/AbstractPipeline.java:260)
at
java.util.stream.ReferencePipeline.toArray([email protected]/ReferencePipeline.java:517)
at
java.util.stream.ReferencePipeline.toArray([email protected]/ReferencePipeline.java:523)
at
org.apache.logging.log4j.util.StackLocator$FqcnCallerLocator.apply(StackLocator.java:96)
at
org.apache.logging.log4j.util.StackLocator$FqcnCallerLocator.apply(StackLocator.java:90)
at
java.lang.StackStreamFactory$StackFrameTraverser.consumeFrames([email protected]/StackStreamFactory.java:534)
at
java.lang.StackStreamFactory$AbstractStackWalker.doStackWalk([email protected]/StackStreamFactory.java:306)
at
java.lang.StackStreamFactory$AbstractStackWalker.callStackWalk([email protected]/Native
Method) at
java.lang.StackStreamFactory$AbstractStackWalker.beginStackWalk([email protected]/StackStreamFactory.java:370)
at
java.lang.StackStreamFactory$AbstractStackWalker.walk([email protected]/StackStreamFactory.java:243)
at java.lang.StackWalker.walk([email protected]/StackWalker.java:498) at
org.apache.logging.log4j.util.StackLocator.calcLocation(StackLocator.java:81)
at
org.apache.logging.log4j.util.StackLocatorUtil.calcLocation(StackLocatorUtil.java:76)
at
org.apache.logging.log4j.spi.AbstractLogger.getLocation(AbstractLogger.java:2201)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2144)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2127)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2026)
at
org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1899)
at org.apache.logging.log4j.spi.AbstractLogger.info(AbstractLogger.java:1441)
> High CPU consumption using StackWalker
> --------------------------------------
>
> Key: LOG4J2-2880
> URL: https://issues.apache.org/jira/browse/LOG4J2-2880
> Project: Log4j 2
> Issue Type: Bug
> Components: Core
> Affects Versions: 2.11.1, 2.11.2, 2.12.0, 2.12.1, 2.13.0, 2.13.1, 2.13.2,
> 2.13.3
> Environment: log4j version: 2.12.1
> JDK version: OpenJDK 11.0.6
> Reporter: Hash Jang
> Priority: Major
> Attachments: image-2020-06-28-02-42-12-987.png
>
>
> While using OpenJDK 11, there are possibility cause severe CPU consumption
> because of JDK bug in using StackWalker.
>
> [Application on JDK11 consume 100% CPU after a few hours of
> uptime|[https://bugs.openjdk.java.net/browse/JDK-8222942]]
>
> And it happened serveral times on our production environment.
>
> !image-2020-06-28-02-42-12-987.png!
>
> Stack trace Is:
> "reactor-http-epoll-1" #75 daemon prio=5 os_prio=0 cpu=25100145.64ms
> elapsed=306507.26s tid=0x0000556eddcbd000 nid=0x61 runnable
> [0x00007f8605443000]"reactor-http-epoll-2" #75 daemon prio=5 os_prio=0
> cpu=25100145.64ms elapsed=306507.26s tid=0x0000556eddcbd000 nid=0x61 runnable
> [0x00007f8605443000] java.lang.Thread.State: RUNNABLE at
> java.lang.StackStreamFactory$AbstractStackWalker.callStackWalk([email protected]/Native
> Method) at
> java.lang.StackStreamFactory$AbstractStackWalker.beginStackWalk([email protected]/StackStreamFactory.java:370)
> at
> java.lang.StackStreamFactory$AbstractStackWalker.walk([email protected]/StackStreamFactory.java:243)
> at java.lang.StackWalker.walk([email protected]/StackWalker.java:498) at
> org.apache.logging.log4j.util.StackLocator.calcLocation(StackLocator.java:81)
> at
> org.apache.logging.log4j.util.StackLocatorUtil.calcLocation(StackLocatorUtil.java:76)
> at
> org.apache.logging.log4j.spi.AbstractLogger.getLocation(AbstractLogger.java:2201)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2144)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2127)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2020)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1891)
> at org.apache.logging.log4j.spi.AbstractLogger.info(AbstractLogger.java:1436)
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
