Qfyilyi

I need to log heavily for further analisys so when file is rolled the whole flow stuck for a while doing something like this:

"org.springframework.kafka.KafkaListenerEndpointContainer#1-1-C-1" - Thread t@56

   java.lang.Thread.State: BLOCKED

    at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.checkRollover(RollingFileManager.java:174)

    - waiting to lock <2afdff68> (a org.apache.logging.log4j.core.appender.rolling.RollingFileManager) owned by "SrpResultsProcessor-8" t@90

    at org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:280)

    at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)

    at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)

    at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)

    at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)

    at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:447)

    at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:432)

    at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:416)

    at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:402)

    at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)

    at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)

    at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2091)

    at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2005)

    at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1876)

    at org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:124)

...    

Here is my yaml config:

Configuration:

name: default



Appenders:



  RollingFile:

    - name: stdout

      fileName: ../logs/${component.name}.log

      filePattern: "../logs/archive/${component.name}_%d{yyyy-MM-dd}_%i.log.zip"

      PatternLayout:

        pattern: "%d{ISO8601} %-5level [%t] %logger{36} - %msg%n"

      Policies:

        SizeBasedTriggeringPolicy:

          size: 300 MB

      DefaultRollOverStrategy:

        max: 20

        Delete:

          basePath: ../logs

          maxDepth: 2

          IfFileName:

            glob: "*/${component.name}_*.log.zip"

            IfAccumulatedFileCount:

              exceeds: 50



    - name: stderr

      fileName: ../logs/${component.name}.err

      filePattern: "../logs/archive/${component.name}_%d{yyyy-MM-dd}_%i.err.zip"

      PatternLayout:

        pattern: "%d{ISO8601} %-5level [%t] %logger{36} - %msg%n"

      Policies:

        SizeBasedTriggeringPolicy:

          size: 300 MB

      DefaultRollOverStrategy:

        max: 5

        Delete:

          basePath: ../logs

          maxDepth: 2

          IfFileName:

            glob: "*/${component.name}_*.err.zip"

            IfAccumulatedFileCount:

              exceeds: 10

...

Any ideas to improve performance of the 'rolling'?

-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

source

This is a problem with high concurrency, and it works as designed. The file system (I/O) doesn't have the enough performance as required.

The synchronized makes BLOCKED some Java monitor when trying to acquire the resource.

/**

 * Determines if a rollover should occur.

 * @param event The LogEvent.

 */

public synchronized void checkRollover(final LogEvent event) {

    if (triggeringPolicy.isTriggeringEvent(event)) {

        rollover();

    }

}

The solution as mentioned above is to move to Async logging.

https://logging.apache.org/log4j/2.x/manual/async.html