I am using these because the reporter provided them. I will convert them to John at some point.
Log4J 3.0 is the master branch. Since it uses java 8 some things are easier to do than on release-2.x. The withLocation test uses the new builder I add to the api. The witHLocation method doesn’t have to walk the stack so it is pretty fast. Ralph > On Jul 2, 2019, at 3:47 PM, Remko Popma <[email protected]> wrote: > > If memory serves correctly, the `includeLocation` was introduced because it > was necessary for async loggers (and it seemed not feasible to get this > information from the layout pattern). > > Async loggers need to know upfront whether they need to pass location > information to the consumer thread. > > If obtaining location information becomes so cheap that it’s essentially > free, it is fine to ignore the `includeLocation` directive and include > location information anyway. > > About the performance results: what’s the difference between “Log4j 3.0 with > class and method” and “Log4j 3.0 withLocation()”? > > Also I am generally cautious of custom benchmarks; any reason not to use JMH? > > Overall impressive results, congratulations! > > Remko. > > (Shameless plug) Every java main() method deserves http://picocli.info > >> On Jul 3, 2019, at 7:26, Ralph Goers <[email protected]> wrote: >> >> But what do you think about includeLocation. Should it override the result >> of requiresLocation or should the fact that we determined location >> information is required override the includeLocation setting? >> >> Ralph >> >>> On Jul 2, 2019, at 2:34 PM, Matt Sicker <[email protected]> wrote: >>> >>> These benchmarks are impressive! Moving the point of call site calculation >>> is a great idea. >>> >>> On Tue, 2 Jul 2019 at 16:22, Ralph Goers <[email protected] >>> <mailto:[email protected]>> wrote: >>> I have made changes to the code the master branch to measure and improve >>> performance. I have committed some of the changes but not the last set. I >>> have not made the latest changes to release-2.x because they will have to >>> be implemented a bit differently to avoid compatibility issues. The table >>> below summarizes what I am seeing, at least on my MacBook Pro. This test >>> just basically writes 1.5 million log statements in a loop using an >>> equivalent format for each logging framework. Note that JUL is faster with >>> location information than without primarily because a custom Handler had to >>> be created to format the log record and it performs better than the one >>> used to log without location information. >>> >>> >>> >>> There are several things I should note about this: >>> • The first step, which is in the PR, has StackLocator.calcLocation >>> modified to use a faster algorithm. Streams are not particularly fast. This >>> resulted in some gains not shown here but can be seen in >>> https://issues.apache.org/jira/browse/LOG4J2-2644 >>> <https://issues.apache.org/jira/browse/LOG4J2-2644> >>> • Performance is proportional to the number of stack traces that need to >>> be traversed. JUL only had 11 whereas Log4j had 35 before it called >>> calcLocation. Our stack is very deep because AbstractLogger and >>> LoggerConfig have been overly refactored along with having to go though >>> several intermediate objects. >>> • I introduced a requiredLocation() method throughout the stack. Any >>> component that requires location information sets this value to true. Based >>> on this, the call to calcLocation can be made significantly higher up the >>> stack just before the log event is created but only when a configured >>> component will use it - with a few exceptions. This code is not yet checked >>> in. >>> • If for some reason the location information isn’t calculated when the >>> event is constructed it can still be lazily populated later using the >>> current, slower mechanism. >>> >>> As you can see these changes result in a pretty dramatic improvement, >>> almost to the point that the cost of obtaining location information doesn’t >>> really matter - especially in Java 11. The results in Java 11 amount to 5us >>> per logging call with no location vs 7.5us per logging call with location >>> info. These results could probably be improved even more if AbstractLogger >>> was “flattened” a bit. >>> >>> I should point out that the logic isn’t perfect. I cannot determine whether >>> location information is required or not for the RoutingAppender since it >>> dynamically creates Appenders at run time. Instead, I added a >>> “requiresLocation” attribute that can be set to indicate that. >>> >>> However, in testing I have encountered a unit test failure in >>> RandomAccessFileAppenderTest. It is failing because the location >>> information is being included even though includeLocation is set to false. >>> I am wondering if that setting needs to be respected since the pattern >>> specifies including it. It seems odd to me to not include it in that case. >>> >>> Thoughts? >>> >>> Ralph >>> >>> >>> -- >>> Matt Sicker <[email protected] <mailto:[email protected]>> >> >
