Remko Popma created LOG4J2-1382:
-----------------------------------
Summary: 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
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
