While working on
LOG4J2-1179, I ran into these benchmark results:
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.