You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "Ralph Goers (Jira)" <ji...@apache.org> on 2022/07/24 07:16:00 UTC
[jira] [Comment Edited] (LOG4J2-3549) The printed thread blocked
[ https://issues.apache.org/jira/browse/LOG4J2-3549?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17570422#comment-17570422 ]
Ralph Goers edited comment on LOG4J2-3549 at 7/24/22 7:15 AM:
--------------------------------------------------------------
Whether it helps or not is dependent on choices you make.
When logging asynchronously the logs are written to a ring buffer and control is returned to the application. Another thread then reads from the buffer and writes the to disk. If writing is slower than logs are being written eventually the buffer will fill up. The default behavior is for the thread to block until an entry in the buffer is available, so basically you will be back in the same situation. However, you can also chose a strategy that discards the log events when the buffer is full. Thus your application won't slow down but it will lose log events, which you might find unacceptable.
There is one other scenario where async logging could help.
You have not provided your configuration but from the code it looks like you have immediateFlush set to true (the default). Performing a flush for every log event is pretty slow and if your application is logging a lot it would be recommended to set it to false. The area where async logging could help is that it automatically forces immediateFlush to false since it makes no sense if you are logging asynchronously.
To be honest, I would first set immediateFlush to false and see how that impacts the application. Based on that you can decide if you also want to use async logging.
was (Author: ralph.goers@dslextreme.com):
Whether it helps or not is dependent on choices you make.
When logging asynchronously the logs are written to a ring buffer and control is returned to the application. Another thread then reads from the buffer and writes the to disk. If writing is slower than logs are being written eventually the buffer will fill up. The default behavior is for the thread to block until an entry in the buffer is available, so basically you will be back in the same situation. However, you can also chose a strategy that discards the log events when the buffer is full. Thus your application won't slow down but it will lose log events, which you might find unacceptable.
There is one other scenario where async logging could help.
You have not provided your configuration but from the code it looks like you have immediateFlush set to true (the default). Performing a flush for every log event is pretty slow and if your application is logging a lot it would be recommended to set it to false. The area where async logging could help is that it automatically forces immediateFlush to false since it makes no sense if you are logging asynchronously.
> The printed thread blocked
> --------------------------
>
> Key: LOG4J2-3549
> URL: https://issues.apache.org/jira/browse/LOG4J2-3549
> Project: Log4j 2
> Issue Type: Bug
> Components: Log4j 1.2 bridge
> Affects Versions: 2.17.2
> Reporter: yimiluo
> Priority: Minor
> Attachments: image-2022-07-08-20-20-11-818.png
>
>
> When we were printing the log, the printed thread was blocked, causing the service to go down. The following is the exception information:
> !image-2022-07-08-20-20-11-818.png|width=895,height=537!
> {code:java}
> [arthas@1]$ thread -b
> "http-nio-8080-exec-5" Id=97 RUNNABLE (in native)
> at java.base@11.0.8-ga/java.io.FileOutputStream.writeBytes(Native Method)
> at java.base@11.0.8-ga/java.io.FileOutputStream.write(FileOutputStream.java:354)
> at java.base@11.0.8-ga/java.io.BufferedOutputStream.write(BufferedOutputStream.java:123)
> - locked java.io.BufferedOutputStream@ea9396a
> at java.base@11.0.8-ga/java.io.PrintStream.write(PrintStream.java:559)
> - locked java.io.PrintStream@3ff1e46c
> at org.apache.logging.log4j.core.util.CloseShieldOutputStream.write(CloseShieldOutputStream.java:53)
> at org.apache.logging.log4j.core.appender.OutputStreamManager.writeToDestination(OutputStreamManager.java:250)
> at org.apache.logging.log4j.core.appender.OutputStreamManager.flushBuffer(OutputStreamManager.java:283)
> - locked org.apache.logging.log4j.core.appender.OutputStreamManager@7ba4158c <---- but blocks 236 other threads!
> at org.apache.logging.log4j.core.appender.OutputStreamManager.flush(OutputStreamManager.java:294)
> - locked org.apache.logging.log4j.core.appender.OutputStreamManager@7ba4158c <---- but blocks 236 other threads!
> at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:199)
> at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190)
> at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:181)
> at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161)
> at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:134)
> at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125)
> at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89)
> at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:542)
> at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:500)
> at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:483)
> at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:417)
> at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82)
> at org.apache.logging.log4j.core.Logger.log(Logger.java:161)
> at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2205)
> at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2159)
> at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2142)
> at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2028)
> at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1891)
> at org.apache.logging.slf4j.Log4jLogger.info(Log4jLogger.java:194) {code}
>
> I don't know what the solution is now. I would be very grateful if you could reply.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)