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 Mon, 19 Jan 2015 09:23:35 GMT

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

Remko Popma commented on LOG4J2-940:
------------------------------------

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