[
https://issues.apache.org/jira/browse/LOG4J2-2031?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16153768#comment-16153768
]
Remko Popma edited comment on LOG4J2-2031 at 9/5/17 3:27 PM:
-------------------------------------------------------------
I haven't looked in great detail, but some initial observations:
* the PatternLayout uses location ( {{%L}} ). This is implemented by walking
the stack trace for every log event. This is [known to be very
slow|https://logging.apache.org/log4j/2.x/performance.html#asyncLoggingWithLocation].
* rollover is configured in the test to be size-based after 20MB, and I suspect
that the test spends a lot of its time doing rollovers. What is measured in
this test is likely very different from the actual logging performance in
your real-life application.
* you can get another small performance boost by using one of the predefined
date formats like {{%d\{DEFAULT\}}}. (These use a highly optimized custom
formatter.)
* the tests also include initialization time in their measurement. Log4j2 is
slower to initialize than Log4j-1.2. We're aware of that but don't have plans
to optimize that area. Not sure how important startup time is for your
applications, but may I suggest adding a separate loop (with the same number of
iterations) that is not measured, before starting to measure? That will also
allow the JVM to warm up and should give more realistic results.
* The tests are single threaded. A lot of the [performance
improvements|https://logging.apache.org/log4j/2.x/performance.html#fileLoggingComparison]
in Log4j2 (even for synchronous file logging) have to do with concurrent
logging from multiple threads. J2EE applications tend to be heavily
multi-threaded so they should benefit from Log4j2's fine grained locking and
use of lock-free data structures. However, these benefits won't show up in the
current tests. May I suggest looking at JMH for performance testing? This takes
care of things like warmup and allows you to easily verify multi threaded
performance.
I need to run your example to see what's causing the reordering.
was (Author: [email protected]):
I haven't looked in great detail, but some initial observations:
* the PatternLayout uses location ( {{%L}} ). This is implemented by walking
the stack trace for every log event. This is [known to be very
slow|https://logging.apache.org/log4j/2.x/performance.html#asyncLoggingWithLocation].
* rollover is configured in the test to be size-based after 20MB, and I suspect
that the test spends a lot of its time doing rollovers. What is measured in
this test is likely very different from the actual logging performance in
your real-life application.
* you can get another small performance boost by using one of the predefined
date formats like {{%d\{DEFAULT\}}}. (These use a highly optimized custom
formatter.)
* the tests also include initialization time in their measurement. Log4j2 is
slower to initialize than Log4j-1.2. We're aware of that but don't have plans
to optimize that area. Not sure how important startup time is for your
applications, but may I suggest adding a separate loop (with the same number of
iterations) that is not measured, before starting to measure? That will also
allow the JVM to warm up and should give more realistic results.
I need to run your example to see what's causing the reordering.
> Log4j2 log file not reflecting application log function calls
> -------------------------------------------------------------
>
> Key: LOG4J2-2031
> URL: https://issues.apache.org/jira/browse/LOG4J2-2031
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.8.2, 2.9.0
> Environment: Windows, Sun Java 8.
> Reporter: Colin McDowell
> Fix For: 2.9.1
>
> Attachments: CapacityTest.java, log4j2.xml, pom2.xml
>
> Original Estimate: 672h
> Remaining Estimate: 672h
>
> Was hoping to move our numerous J2EE projects from Log4j to Log4j2 for the
> performance improvements. I put together a small test case that writes a
> string pattern to a Rolling File. There is a 6 digit sequence number at the
> start of the log message. This allows me to quickly see if all the log
> requests are making it into the log file. I attach the test case and
> log4j2.xml. The log4j2.xml uses an asynchronous appender.
> What I observe in the output log file is that after a short interval (120 or
> so entries) the logged are appearing in the wrong order, and entries can be
> missing. The missing entries issues especially shows up when rolling to the
> next log file.
> Perhaps there is a deliberate decision to not to guarantee log file
> accurately for speed. However we need the logs to accurately reflect what
> the application is logging. I have also noticed the performance is 25% worse
> in Log4j2 than Log4j when not using the asynchronous appender. So that
> rather kills us using Log4j2 at the moment.
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
