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

["ASF GitHub Bot (JIRA)" <ji...@apache.org>]

     [ https://issues.apache.org/jira/browse/LOG4J2-2644?focusedWorklogId=270184&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-270184 ]

ASF GitHub Bot logged work on LOG4J2-2644:
------------------------------------------

                Author: ASF GitHub Bot
            Created on: 01/Jul/19 13:39
            Start Date: 01/Jul/19 13:39
    Worklog Time Spent: 10m 
      Work Description: carterkozak commented on pull request #289: LOG4J2-2644 - Improve performance of getting location info
URL: https://github.com/apache/logging-log4j2/pull/289#discussion_r299047174
 
 

 ##########
 File path: log4j-api-java9/src/main/java/org/apache/logging/log4j/util/StackLocator.java
 ##########
 @@ -31,6 +33,7 @@
 
     private final static StackLocator INSTANCE = new StackLocator();
 
+    private final static ThreadLocal<FqcnCallerLocator> LOCATOR = ThreadLocal.withInitial(FqcnCallerLocator::new);
 
 Review comment:
   Should we check if threadlocals are enabled before using this since it's not a standard type like StringBuilder?
 
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Issue Time Tracking
-------------------

    Worklog Id:     (was: 270184)
    Time Spent: 1h 20m  (was: 1h 10m)

> 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
>            Priority: Minor
>          Time Spent: 1h 20m
>  Remaining Estimate: 0h
>
> 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)