This is an automated email from the ASF dual-hosted git repository. vy pushed a commit to branch doc/perf-main in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
The following commit(s) were added to refs/heads/doc/perf-main by this push: new b0ed60b604 Remove asynchronous logging benchmark figures b0ed60b604 is described below commit b0ed60b604eddc3af024112614cecd25cf205079 Author: Volkan Yazıcı <vol...@yazi.ci> AuthorDate: Thu May 16 09:45:04 2024 +0200 Remove asynchronous logging benchmark figures --- .../antora/modules/ROOT/pages/manual/async.adoc | 176 --------------------- 1 file changed, 176 deletions(-) diff --git a/src/site/antora/modules/ROOT/pages/manual/async.adoc b/src/site/antora/modules/ROOT/pages/manual/async.adoc index 11018b8485..73e87fa0db 100644 --- a/src/site/antora/modules/ROOT/pages/manual/async.adoc +++ b/src/site/antora/modules/ROOT/pages/manual/async.adoc @@ -495,182 +495,6 @@ include location information by default. You can override the default behaviour in your logger or asynchronous appender configuration by specifying `includeLocation="true"`. -[#Performance] -== Asynchronous Logging Performance - -The throughput performance results below were derived from running the -PerfTest, MTPerfTest and PerfTestDriver classes which can be found in -the Log4j 2 unit test source directory. For throughput tests, the -methodology used was: - -* First, warm up the JVM by logging 200,000 log messages of 500 -characters. -* Repeat the warm-up 10 times, then wait 10 seconds for the I/O thread -to catch up and buffers to drain. -* Measure how long it takes to execute 256 * 1024 / threadCount calls to -Logger.log and express the result in messages per second. -* Repeat the test 5 times and average the results. - -The results below were obtained with log4j-2.0-beta5, -disruptor-3.0.0.beta3, log4j-1.2.17 and logback-1.0.10. - -=== Logging Peak Throughput - -The graph below compares the throughput of synchronous loggers, -asynchronous appenders and asynchronous loggers. This is the total -throughput of all threads together. In the test with 64 threads, -asynchronous loggers are 12 times faster than asynchronous appenders, -and 68 times faster than synchronous loggers. - -Asynchronous loggers' throughput increases with the number of threads, -whereas both synchronous loggers and asynchronous appenders have more or -less constant throughput regardless of the number of threads that are -doing the logging. - -image:async-vs-sync-throughput.png[Async loggers have much -higher throughput than sync loggers.] - -=== Asynchronous Throughput Comparison with Other Logging Packages - -We also compared peak throughput of asynchronous loggers to the -synchronous loggers and asynchronous appenders available in other -logging packages, specifically log4j-1.2.17 and logback-1.0.10, with -similar results. For asynchronous appenders, total logging throughput of -all threads together remains roughly constant when adding more threads. -Asynchronous loggers make more effective use of the multiple cores -available on the machine in multi-threaded scenarios. - -image:async-throughput-comparison.png[Async loggers have the -highest throughput.] - -On Solaris 10 (64bit) with JDK1.7.0_06, 4-core Xeon X5570 dual CPU -@2.93Ghz with hyperthreading switched on (16 virtual cores): - -.Throughput per thread in messages/second -[cols="h,>,>,>,>,>,>,>",options="header",] -|======================================================================= -|Logger |1 thread |2 threads |4 threads |8 threads |16 threads |32 -threads |64 threads -|Log4j 2: Loggers all asynchronous |2,652,412 |909,119 |776,993 |516,365 -|239,246 |253,791 |288,997 - -|Log4j 2: Loggers mixed sync/async |2,454,358 |839,394 |854,578 |597,913 -|261,003 |216,863 |218,937 - -|Log4j 2: Async Appender |1,713,429 |603,019 |331,506 |149,408 |86,107 -|45,529 |23,980 - -|Log4j1: Async Appender |2,239,664 |494,470 |221,402 |109,314 |60,580 -|31,706 |14,072 - -|Logback: Async Appender |2,206,907 |624,082 |307,500 |160,096 |85,701 -|43,422 |21,303 - -|Log4j 2: Synchronous |273,536 |136,523 |67,609 |34,404 |15,373 |7,903 -|4,253 - -|Log4j1: Synchronous |326,894 |105,591 |57,036 |30,511 |13,900 |7,094 -|3,509 - -|Logback: Synchronous |178,063 |65,000 |34,372 |16,903 |8,334 |3,985 -|1,967 -|======================================================================= - -On Windows 7 (64bit) with JDK1.7.0_11, 2-core Intel i5-3317u CPU -@1.70Ghz with hyperthreading switched on (4 virtual cores): - -.Throughput per thread in messages/second -[cols="h,>,>,>,>,>,>",options="header",] -|======================================================================= -|Logger |1 thread |2 threads |4 threads |8 threads |16 threads |32 -threads -|Log4j 2: Loggers all asynchronous |1,715,344 |928,951 |1,045,265 -|1,509,109 |1,708,989 |773,565 - -|Log4j 2: Loggers mixed sync/async |571,099 |1,204,774 |1,632,204 -|1,368,041 |462,093 |908,529 - -|Log4j 2: Async Appender |1,236,548 |1,006,287 |511,571 |302,230 -|160,094 |60,152 - -|Log4j1: Async Appender |1,373,195 |911,657 |636,899 |406,405 |202,777 -|162,964 - -|Logback: Async Appender |1,979,515 |783,722 |582,935 |289,905 |172,463 -|133,435 - -|Log4j 2: Synchronous |281,250 |225,731 |129,015 |66,590 |34,401 |17,347 - -|Log4j1: Synchronous |147,824 |72,383 |32,865 |18,025 |8,937 |4,440 - -|Logback: Synchronous |149,811 |66,301 |32,341 |16,962 |8,431 |3,610 -|======================================================================= - -[#Latency] -=== Response Time Latency - -This section has been rewritten with the Log4j 2.6 release. The -previous version only reported _service time_ instead of _response -time_. See the xref:manual/performance.adoc#responseTime[response time] side -bar on the performance page on why this is too optimistic. Furthermore -the previous version reported average latency, which does not make sense -since latency is not a normal distribution. Finally, the previous -version of this section only reported the maximum latency of up to -99.99% of the measurements, which does not tell you how bad the worst -0.01% were. This is unfortunate because often the "outliers" are all -that matter when it comes to response time. From this release we will -try to do better and report response time latency across the full range -of percentages, including all the outliers. Our thanks to Gil Tene for -his http://www.infoq.com/presentations/latency-response-time[How NOT to -measure latency] presentation. (Now we know why this is also known as -the "Oh s#@t!" presentation.) - -xref:manual/performance.adoc#responseTime[Response time] is how long it -takes to log a message under a certain load. What is often reported as -latency is actually _service time_: how long it took to perform the -operation. This hides the fact that a single spike in service time adds -queueing delay for many of the subsequent operations. Service time is -easy to measure (and often looks good on paper) but is irrelevant for -users since it omits the time spent waiting for service. For this reason -we report response time: service time plus wait time. - -The response time test results below were all derived from running the -ResponseTimeTest class which can be found in the Log4j 2 unit test -source directory. If you want to run these tests yourself, here are the -command line options we used: - -* -Xms1G -Xmx1G (prevent heap resizing during the test) -* -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector --DAsyncLogger.WaitStrategy=busyspin (to use Async Loggers. The BusySpin -wait strategy reduces some jitter.) -* *classic mode:* -Dlog4j2.enable.direct.encoders=false + -*garbage-free mode:* -Dlog4j2.enable.direct.encoders=true -* -XX:CompileCommand=dontinline,org.apache.logging.log4j.core.async.perftest.NoOpIdleStrategy::idle -* -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps --XX:+PrintTenuringDistribution -XX:+PrintGCApplicationConcurrentTime --XX:+PrintGCApplicationStoppedTime (to eyeball GC and safepoint pauses) - -The graph below compares response time latency of the -ArrayBlockingQueue-based asynchronous appenders in Logback 1.1.7, Log4j -1.2.17 to the various options for asynchronous logging that Log4j 2.6 -offers. Under a workload of 128,000 messages per second, using 16 -threads (each logging at a rate of 8,000 messages per second), we see -that Logback 1.1.7, Log4j 1.2.17 experience latency spikes that are -orders of magnitude larger than Log4j 2. - -image:ResponseTimeAsyncLogging16Threads_8kEach.png[When 16 -threads generate a total workload of 128,000 msg/sec, Logback 1.1.7 and -Log4j 1.2.17 experience latency spikes that are orders of magnitude -larger than Log4j 2] - -The graph below zooms in on the Log4j 2 results for the same test. We -see that the worst-case response time is highest for the -ArrayBlockingQueue-based Async Appender. -xref:manual/garbagefree.adoc[Garbage-free] async loggers have the best response -time behaviour. - -image:ResponseTimeAsyncLogging16Threads_8kEachLog4j2Only-labeled.png[image] - [#UnderTheHood] == Under The Hood