Repository: logging-log4j2 Updated Branches: refs/heads/master 873beebf4 -> a79425884
LOG4J2-1297 updated garbagefree.xml page, added JFR screenshots Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/a7942588 Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/a7942588 Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/a7942588 Branch: refs/heads/master Commit: a7942588421b53f6eee5691013906222ff7d26e8 Parents: 873beeb Author: rpopma <[email protected]> Authored: Sun Apr 3 01:56:52 2016 +0900 Committer: rpopma <[email protected]> Committed: Sun Apr 3 01:56:52 2016 +0900 ---------------------------------------------------------------------- .../images/log4j-2.5-FlightRecording.png | Bin 0 -> 68628 bytes .../images/log4j-2.6-FlightRecording.png | Bin 0 -> 50481 bytes src/site/xdoc/manual/garbagefree.xml | 43 +++++++++++++++++-- 3 files changed, 39 insertions(+), 4 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/a7942588/src/site/resources/images/log4j-2.5-FlightRecording.png ---------------------------------------------------------------------- diff --git a/src/site/resources/images/log4j-2.5-FlightRecording.png b/src/site/resources/images/log4j-2.5-FlightRecording.png new file mode 100644 index 0000000..bd69464 Binary files /dev/null and b/src/site/resources/images/log4j-2.5-FlightRecording.png differ http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/a7942588/src/site/resources/images/log4j-2.6-FlightRecording.png ---------------------------------------------------------------------- diff --git a/src/site/resources/images/log4j-2.6-FlightRecording.png b/src/site/resources/images/log4j-2.6-FlightRecording.png new file mode 100644 index 0000000..e42b1de Binary files /dev/null and b/src/site/resources/images/log4j-2.6-FlightRecording.png differ http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/a7942588/src/site/xdoc/manual/garbagefree.xml ---------------------------------------------------------------------- diff --git a/src/site/xdoc/manual/garbagefree.xml b/src/site/xdoc/manual/garbagefree.xml index f42955c..a3f9fbd 100644 --- a/src/site/xdoc/manual/garbagefree.xml +++ b/src/site/xdoc/manual/garbagefree.xml @@ -19,18 +19,20 @@ <section name="Garbage-free Steady State Logging"> <p> Different applications have different performance requirements. - Some applications only need to worry about throughput, but for many applications + Some only need to worry about throughput, but for many the most important performance consideration is latency (response time). Users of such applications would consider it a big problem if the system becomes unresponsive for more than a few seconds, or even milliseconds in some cases. In financial trading for example predictable low latency is so important that it is often considered - worthwhile to trade off some throughput in return for consistent latency. - + worthwhile to trade off some throughput in return for consistent response time. + </p> + <p> Garbage collection pauses are a common cause of latency spikes and for many systems significant effort is spent on controlling these pauses. </p> <p> - Traditionally, logging libraries allocate many temporary objects like log event objects, Strings, and more during steady state logging. + Traditionally, logging libraries allocate many temporary objects like log event objects, Strings, byte arrays + and more during steady state logging. This contributes to pressure on the garbage collector and increases the frequency with which GC pauses occur. From version 2.6, Log4j can be run in a "garbage free" mode where objects and buffers are reused and temporary object allocation is avoided as much as possible. @@ -38,6 +40,39 @@ <p> </p> + <a name="jfr" /> + <subsection name="A Contrived Example"> + <p> + To highlight the difference, we used Java Flight Recorder to measure a simple application that + does nothing but logging a simple string for about 12 seconds. + </p> + <p> + The application is configured to use Async Loggers, a RandomAccessFile appender and a + "%d %p %c{1.} [%t] %X{aKey} %m %ex%n" pattern layout). + It logged about 8.5 million messages and generated a ~600MB log file. + </p> + <p> + Mission Control shows that with Log4j 2.5 this application allocated memory at a rate of about 809 MB/sec, + resulting in 141 minor collections, with an average pause time of 7 ms. + Log4j 2.6 does not allocate temporary objects in this configuration, and as a result + the same application with Log4j 2.6 had an allocation rate of 1.6 MB/sec and 0 (zero) garbage collections. + </p> + <table> + <tr> + <td> + <a href="../images/log4j-2.5-FlightRecording.png"><img + src="../images/log4j-2.5-FlightRecording.png" + alt="log4j-2.5: allocation rate 809 MB/sec, 141 minor GCs, each pausing 7 ms on avg" /></a> + </td> + <td> + <a href="../images/log4j-2.6-FlightRecording.png"><img + src="../images/log4j-2.6-FlightRecording.png" + alt="log4j-2.6: allocation rate 1.6 MB/sec, 0 minor or major GCs" /></a> + </td> + </tr> + </table> + </subsection> + <a name="Enabling" /> <subsection name="Enabling Garbage-free Logging"> <p>
