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] [Comment Edited] (LOG4J2-940) Large number of RUNNABLE threads at "AsyncLoggerConfig.callAppenders" causing High CPU
Date Mon, 19 Jan 2015 09:28:34 GMT

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

Remko Popma edited comment on LOG4J2-940 at 1/19/15 9:28 AM:
-------------------------------------------------------------

It's not as easy as I thought... If we send all events for 10 loggers to a shared AsyncAppender,
then we need some way to separate out to the target FileAppender again. This may require a
custom filter class.

Below is an idea of how this could be done. You'll need to experiment...

Note that this is getting pretty complex. Makes me wonder why one would need so many files...

{code}
<Configuration status="WARN" package="my.plugin.package">
<Appenders>
  <File name="FileGroup1Member1" immediateFlush="false" fileName="/logs/app/ABCLogFile.log">
    <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss,SSS}|%X{1}:%X{2}|%X{3}| %p [ %C %M ]
  %m%n " />
    <LoggerFilter acceptedName="ABCLogFile" onMatch="ACCEPT" />
  </File>
  <File name="FileGroup1Member2" ...>
    <LoggerFilter acceptedName="BCDLogFile" onMatch="ACCEPT" />
  </File>
  <File name="FileGroup1Member3" ...
  ... (repeat for 10 file appenders in group 1)
  
  <File name="FileGroup2Member1" ...
  <File name="FileGroup2Member2" ...
  ... (repeat for 10 file appenders in group 2)
  
  <File name="FileGroup3Member1" ...
  <File name="FileGroup3Member2" ...
  ... (repeat for 10 file appenders in group 3)
  
  ... (repeat for 14 groups)
 
  <Async name="AsyncGroup1">
    <AppenderRef ref="FileGroup1Member1"/>
    <AppenderRef ref="FileGroup1Member2"/>
    <AppenderRef ref="FileGroup1Member3"/>
    ... (repeat for 10 file appenders in group 1)
  </Async>
  <Async name="AsyncGroup2">
    <AppenderRef ref="FileGroup2Member1"/>
    <AppenderRef ref="FileGroup2Member2"/>
    <AppenderRef ref="FileGroup2Member3"/>
    ... (repeat for 10 file appenders in group 2)
  </Async>
  ... (repeat for 14 async appenders)
  
</Appenders>

<Loggers>
  <AsyncLogger name="ABCLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  <AsyncLogger name="BCDLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  <AsyncLogger name="DEFLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  ... (10 loggers go to group 1)
  
  <AsyncLogger name="ABCXLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  <AsyncLogger name="BCDXLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  <AsyncLogger name="DEFXLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  ... (10 loggers go to group 2)
  
  ... repeat for all 14 groups
{code}

{{LoggerFilter}} is not a built-in filter class, you will need to create it yourself. Below
is some example code:

{code}
package my.plugin.package;

import org.apache.logging.log4j.*;
import org.apache.logging.log4j.core.*;
import org.apache.logging.log4j.core.config.Node;
import org.apache.logging.log4j.core.config.plugins.*;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.core.filter.*;

@Plugin(name = "LoggerFilter", category = Node.CATEGORY, elementType = Filter.ELEMENT_TYPE,
printObject = true)
public final class LoggerFilter extends AbstractFilter {

    private final String acceptedName;

    private LoggerFilter(final String acceptedName, final Result onMatch, final Result onMismatch)
{
        super(onMatch, onMismatch);
        this.acceptedName = acceptedName;
    }

    @Override
    public Result filter(final Logger logger, final Level level, final Marker marker, final
String msg, final Object... params) {
        return filter(logger.getName());
    }

    @Override
    public Result filter(final Logger logger, final Level level, final Marker marker, final
Object msg, final Throwable t) {
        return filter(logger.getName());
    }

    @Override
    public Result filter(final Logger logger, final Level level, final Marker marker, final
Message msg, final Throwable t) {
        return filter(logger.getName());
    }

    @Override
    public Result filter(final LogEvent event) {
        return filter(event.getLoggerName());
    }

    private Result filter(final String loggerName) {
        return acceptedName.equals(loggerName) ? onMatch : onMismatch;
    }

    @Override
    public String toString() {
        return acceptedName;
    }

    /**
     * Create a LoggerFilter.
     * @param acceptedName The accepted logger name.
     * @param match The action to take on a match.
     * @param mismatch The action to take on a mismatch.
     * @return The created ThresholdFilter.
     */
    @PluginFactory
    public static LoggerFilter createFilter(
            @PluginAttribute("acceptedName") final String acceptedName,
            @PluginAttribute("onMatch") final Result match,
            @PluginAttribute("onMismatch") final Result mismatch) {
        if (acceptedName == null) {
        	throw new NullPointerException("acceptedName is null");
        }
        final Result onMatch = match == null ? Result.NEUTRAL : match;
        final Result onMismatch = mismatch == null ? Result.DENY : mismatch;
        return new LoggerFilter(acceptedName, onMatch, onMismatch);
    }
}
{code}


A simpler and more effective approach may be to just have fewer log files.


was (Author: remkop@yahoo.com):
It's not as easy as I thought... If we send all events for 10 loggers to a shared AsyncAppender,
then we need some way to separate out to the target FileAppender again. This may require a
custom filter class.

Below is an idea of how this could be done. You'll need to experiment...

{code}
<Configuration status="WARN" package="my.plugin.package">
<Appenders>
  <File name="FileGroup1Member1" immediateFlush="false" fileName="/logs/app/ABCLogFile.log">
    <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss,SSS}|%X{1}:%X{2}|%X{3}| %p [ %C %M ]
  %m%n " />
    <LoggerFilter acceptedName="ABCLogFile" onMatch="ACCEPT" />
  </File>
  <File name="FileGroup1Member2" ...>
    <LoggerFilter acceptedName="BCDLogFile" onMatch="ACCEPT" />
  </File>
  <File name="FileGroup1Member3" ...
  ... (repeat for 10 file appenders in group 1)
  
  <File name="FileGroup2Member1" ...
  <File name="FileGroup2Member2" ...
  ... (repeat for 10 file appenders in group 2)
  
  <File name="FileGroup3Member1" ...
  <File name="FileGroup3Member2" ...
  ... (repeat for 10 file appenders in group 3)
  
  ... (repeat for 14 groups)
 
  <Async name="AsyncGroup1">
    <AppenderRef ref="FileGroup1Member1"/>
    <AppenderRef ref="FileGroup1Member2"/>
    <AppenderRef ref="FileGroup1Member3"/>
    ... (repeat for 10 file appenders in group 1)
  </Async>
  <Async name="AsyncGroup2">
    <AppenderRef ref="FileGroup2Member1"/>
    <AppenderRef ref="FileGroup2Member2"/>
    <AppenderRef ref="FileGroup2Member3"/>
    ... (repeat for 10 file appenders in group 2)
  </Async>
  ... (repeat for 14 async appenders)
  
</Appenders>

<Loggers>
  <AsyncLogger name="ABCLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  <AsyncLogger name="BCDLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  <AsyncLogger name="DEFLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  ... (10 loggers go to group 1)
  
  <AsyncLogger name="ABCXLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  <AsyncLogger name="BCDXLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  <AsyncLogger name="DEFXLogFile" level="DEBUG" additivity="false">
    <AppenderRef ref="AsyncGroup1" /></AsyncLogger>
  ... (10 loggers go to group 2)
  
  ... repeat for all 14 groups
{code}

{{LoggerFilter}} is not a built-in filter class, you will need to create it yourself. Below
is some example code:

{code}
package my.plugin.package;

@Plugin(name = "LoggerFilter", category = Node.CATEGORY, elementType = Filter.ELEMENT_TYPE,
printObject = true)
public final class LoggerFilter extends AbstractFilter {

    private final String acceptedName;

    private LoggerFilter(final String acceptedName, final Result onMatch, final Result onMismatch)
{
        super(onMatch, onMismatch);
        this.acceptedName = acceptedName;
    }

    @Override
    public Result filter(final Logger logger, final Level level, final Marker marker, final
String msg, final Object... params) {
        return filter(logger.getName());
    }

    @Override
    public Result filter(final Logger logger, final Level level, final Marker marker, final
Object msg, final Throwable t) {
        return filter(logger.getName());
    }

    @Override
    public Result filter(final Logger logger, final Level level, final Marker marker, final
Message msg, final Throwable t) {
        return filter(logger.getName());
    }

    @Override
    public Result filter(final LogEvent event) {
        return filter(event.getLoggerName());
    }

    private Result filter(final String loggerName) {
        return acceptedName.equals(loggerName) ? onMatch : onMismatch;
    }

    @Override
    public String toString() {
        return acceptedName;
    }

    /**
     * Create a LoggerFilter.
     * @param acceptedName The accepted logger name.
     * @param match The action to take on a match.
     * @param mismatch The action to take on a mismatch.
     * @return The created ThresholdFilter.
     */
    @PluginFactory
    public static LoggerFilter createFilter(
            @PluginAttribute("acceptedName") final String acceptedName,
            @PluginAttribute("onMatch") final Result match,
            @PluginAttribute("onMismatch") final Result mismatch) {
        if (acceptedName == null) {
        	throw new NullPointerException("acceptedName is null");
        }
        final Result onMatch = match == null ? Result.NEUTRAL : match;
        final Result onMismatch = mismatch == null ? Result.DENY : mismatch;
        return new LoggerFilter(acceptedName, onMatch, onMismatch);
    }
}
{code}


A simpler and more effective approach may be to just have fewer log files.

> 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
CPU.
> "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
(v6.3.4#6332)

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


Mime
View raw message