Log4j calls are slow in getStackTrace calls
Issue
- Our application is facing slowness in logging calls and thread dumps show log4j lock contention with lock owners frequently in getStackTrace calls like below:
"default task-857" #2137 prio=5 os_prio=0 tid=0x0000000019b91000 nid=0x3c51b2 runnable [0x00007fe092996000]
java.lang.Thread.State: RUNNABLE
at java.lang.Throwable.getStackTraceElement(Native Method)
at java.lang.Throwable.getOurStackTrace(Throwable.java:827)
- locked <0x00000007883ec1b0> (a java.lang.Throwable)
at java.lang.Throwable.getStackTrace(Throwable.java:816)
at org.jboss.logmanager.JDKSpecific.calculateCaller(JDKSpecific.java:86)
at org.jboss.logmanager.ExtLogRecord.calculateCaller(ExtLogRecord.java:335)
at org.jboss.logmanager.ExtLogRecord.getSourceFileName(ExtLogRecord.java:383)
at org.apache.log4j.spi.LoggingEvent.getLocationInformation(LoggingEvent.java:175)
at org.apache.log4j.helpers.PatternParser$LocationPatternConverter.convert(PatternParser.java:464)
at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:65)
at org.apache.log4j.PatternLayout.format(PatternLayout.java:506)
at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310)
at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileAppender.java:369)
at org.apache.log4j.WriterAppender.append(WriterAppender.java:162)
at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
- locked <0x0000000713b2e058> (a org.apache.log4j.DailyRollingFileAppender)
at org.apache.log4j.JBossAppenderHandler.doPublish(JBossAppenderHandler.java:34)
at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:77)
at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:333)
at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:341)
at org.jboss.logmanager.Logger.logRaw(Logger.java:852)
at org.jboss.logmanager.Logger.log(Logger.java:598)
at org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)
"default task-18810" #566701 prio=5 os_prio=0 tid=0x0000557ab9d09800 nid=0x5f9d runnable [0x00007f747e449000]
java.lang.Thread.State: RUNNABLE
at java.lang.Throwable.getStackTraceElement(Native Method)
at java.lang.Throwable.getOurStackTrace(Throwable.java:828)
- locked <0x00007f76b8167a08> (a java.lang.Exception)
at java.lang.Throwable.getStackTrace(Throwable.java:817)
at java.lang.Thread.getStackTrace(Thread.java:1559)
at org.apache.logging.log4j.core.impl.Log4jLogEvent.calcLocation(Log4jLogEvent.java:386)
at org.apache.logging.log4j.core.impl.Log4jLogEvent.getSource(Log4jLogEvent.java:378)
at org.apache.logging.log4j.core.pattern.FileLocationPatternConverter.format(FileLocationPatternConverter.java:57)
at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:36)
at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:197)
at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:55)
at org.apache.logging.log4j.core.layout.AbstractStringLayout.toByteArray(AbstractStringLayout.java:67)
at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:108)
at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:99)
at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:430)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:409)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:367)
at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:112)
at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:727)
at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:716)
at org.apache.logging.log4j.spi.AbstractLogger.debug(AbstractLogger.java:232)
Environment
- Log4j
- JBoss Enterprise Application Platform (EAP)
Subscriber exclusive content
A Red Hat subscription provides unlimited access to our knowledgebase, tools, and much more.