[jira] [Created] (LOG4J2-2644) Logging with location information is considerably slower than logging with location information in java.util.logging

["Marco Herrn (JIRA)" <ji...@apache.org>]

Marco Herrn created LOG4J2-2644:
-----------------------------------

             Summary: Logging with location information is considerably slower than logging with location information in java.util.logging
                 Key: LOG4J2-2644
                 URL: https://issues.apache.org/jira/browse/LOG4J2-2644
             Project: Log4j 2
          Issue Type: Improvement
    Affects Versions: 2.11.2
            Reporter: Marco Herrn


according to https://logging.apache.org/log4j/2.x/performance.html logging
with location information should be roughly the same performance for JUL
and Log4j2.

However I made a few comparisons between Log4j2 and JUL and in this case
Log4j2 is much faster than JUL when omitting location information, but is
considerably slower when logging with location information.

Those are the results:

JUL without location information   : 32.162s
JUL with location information      : 21.682s
Log4j2 without location information:  4.168s
Log4j2 with location information   : 59.000s

In each case I logged 1500000 simple log statements (only a fixed string)
and compared the timestamp of the first and the last generated log
statement. Above you see the time spent between the first and the last log
statement.
I did these tests several times and the results are equal each time.

In all cases I logged to a RollingFileAppender (or JULs equivalent).
I assume that JUL with location information is faster than JUL without
location information is because for JUL with location information I used a
custom Formatter that doesn't support any configuration whereas I was
using a SimpleFormatter with a specified formatstring for JUL without log
information.

It should be noted that I didn't use the Log4j2 API, but instead used the
JUL logging API and used the log4j-jul-bridge to actually use Log4j2
instead of the JUL implementation!

I want to pay special attention to the difference when logging with
location information, since I am puzzled that Log4j2 is that much slower
than JUL in that case.

The example code used for testing and the corresponding logging configurations can be found at [my example github project|http://github.com/hupfdule/LoggingPerformanceTest].

I don't think there is anything special. Since when logging without
location information Log4j2 is much faster than JUL there must be a
difference between getting the location information. My above mentioned
custom formatter uses the methods java.util.LogRecord#getSourceClassName()
and java.util.LogRecord#getSourceMethodName() for obtaining that
information. I haven't looked into how Log4j2 does it, but it seems to be
much less efficient.

I have done the tests with Java 8, but it seems that running it under Java 11 shows the same behaviour.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)