logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Remko Popma (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (LOG4J2-940) Large number of RUNNABLE threads at "AsyncLoggerConfig.callAppenders" causing High CPU
Date Sat, 17 Jan 2015 04:36:34 GMT

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

Remko Popma commented on LOG4J2-940:

This is not a known issue of rc2 as far as I can see. That said, I agree with Gary that it
is better to use the latest stable version.

The stacktrace you posted is in TIMED_WAITING state, and it seems that the logger is blocked
waiting for a slot in the RingBuffer to become available. (Reminds me of LOG4J2-485, but that
was fixed in rc1.)

This could be caused by the application doing more logging than the underlying appender can
keep up with. The RingBuffer can isolate the application from bursts, but if the sustained
logging rate is higher than the appender can keep up with, eventually the RingBuffer will
fill up and loggers will block until the appender catches up.

I realize this does not explain the high CPU rate, but this is all I can tell you from the
information you provided...

What appender(s) are you using? Can you provide your full log4j2 configuration?
Next time you experience excessive CPU usage, can you attach VisualVM to determine the exact
thread(s) that is/are busy?

> Large number of RUNNABLE threads at "AsyncLoggerConfig.callAppenders" causing High CPU
> --------------------------------------------------------------------------------------
>                 Key: LOG4J2-940
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-940
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 2.0-rc2
>         Environment: RHEL 6.2
> Apache Tomcat 7
> Java 7
>            Reporter: Siva B
> 336 threads are in RUNNING state with below stack trace causing the JVM to consume more
> "ajp-bio-15024-exec-138" daemon prio=10 tid=0x00007f5870046000 nid=0x52d7 runnable [0x00007f5921f56000]
>    java.lang.Thread.State: TIMED_WAITING (parking)
> 	at sun.misc.Unsafe.park(Native Method)
> 	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:349)
> 	at com.lmax.disruptor.MultiProducerSequencer.next(MultiProducerSequencer.java:133)
> 	at com.lmax.disruptor.MultiProducerSequencer.next(MultiProducerSequencer.java:102)
> 	at com.lmax.disruptor.RingBuffer.publishEvent(RingBuffer.java:466)
> 	at org.apache.logging.log4j.core.async.AsyncLoggerConfigHelper.callAppendersFromAnotherThread(AsyncLoggerConfigHelper.java:342)
> 	at org.apache.logging.log4j.core.async.AsyncLoggerConfig.callAppenders(AsyncLoggerConfig.java:111)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:407)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:365)
> 	at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:103)
> 	at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1336)
> 	at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1325)
> 	at org.apache.logging.log4j.spi.AbstractLogger.log(AbstractLogger.java:1237)

This message was sent by Atlassian JIRA

To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org

View raw message