Uploaded image for project: 'Log4j 2'
  1. Log4j 2
  2. LOG4J2-2644

Logging with location information is considerably slower than logging with location information in java.util.logging

    XMLWordPrintableJSON

    Details

    • Type: Improvement
    • Status: Closed
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 2.11.2
    • Fix Version/s: 2.12.1
    • Component/s: None
    • Labels:
      None

      Description

      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.

      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.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                hupfdule Marco Herrn
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 3h
                  3h