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-1382) Performance regression in RewriteAppender
Date Mon, 09 May 2016 11:41:12 GMT

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

Remko Popma commented on LOG4J2-1382:

Note that MutableLogEvent.createMemento() also calls getSource() but this is on purpose (and
works this way for Log4jLogEvent as well). So this is not a problem and should not be changed.

> Performance regression in RewriteAppender
> -----------------------------------------
>                 Key: LOG4J2-1382
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1382
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 2.6
>            Reporter: Remko Popma
>            Assignee: Remko Popma
>             Fix For: 2.6
> While working on LOG4J2-1179, I ran into these benchmark results:
> {code}
> Benchmark                                                         Mode  Samples     
     Score            Error  Units
> o.a.l.l.p.j.Log4j2AppenderComparisonBenchmark.appenderRewrite    thrpt        5    44263670.008
±   17389305.070  ops/s
> o.a.l.l.p.j.Log4j2AppenderComparisonBenchmark.end2endRewrite     thrpt        5     
 37254.554 ±      16440.919  ops/s
> {code}
> In plain English: directly calling RewriteAppender.append(LogEvent) can do 44 million
ops/sec, but when calling rewriteLogger.debug(msg) to invoke a logger that calls this appender,
all of a sudden throughput drops to 37 _thousand_ ops/sec. That's 1000x slower. Fishy...
> Turns out that when rewriting the event we are now including caller location information
(taking a snapshot of the stack and walking it). Ouch.
> This is a regression caused by the garbage-free stuff. Rewriting the event makes a copy
of the event and avoids calling LogEvent.getSource() only if the event is an instance of Log4jLogEvent,
but now we are passing in MutableLogEvent. 
> The fix is to update Log4jLogEvent.Builder to also avoid calling getSource when copying
from a MutableLogEvent.

This message was sent by Atlassian JIRA

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

View raw message