You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by ma...@apache.org on 2014/04/06 04:21:21 UTC
svn commit: r1585228 -
/logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml
Author: mattsicker
Date: Sun Apr 6 02:21:21 2014
New Revision: 1585228
URL: http://svn.apache.org/r1585228
Log:
Add XSD information and fix markup.
Modified:
logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml?rev=1585228&r1=1585227&r2=1585228&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml Sun Apr 6 02:21:21 2014
@@ -1,15 +1,17 @@
<?xml version="1.0"?>
-<!-- Licensed to the Apache Software Foundation (ASF) under one or more contributor
- license agreements. See the NOTICE file distributed with this work for additional
- information regarding copyright ownership. The ASF licenses this file to
- You under the Apache License, Version 2.0 (the "License"); you may not use
- this file except in compliance with the License. You may obtain a copy of
- the License at http://www.apache.org/licenses/LICENSE-2.0 Unless required
- by applicable law or agreed to in writing, software distributed under the
- License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS
- OF ANY KIND, either express or implied. See the License for the specific
+<!-- Licensed to the Apache Software Foundation (ASF) under one or more contributor
+ license agreements. See the NOTICE file distributed with this work for additional
+ information regarding copyright ownership. The ASF licenses this file to
+ You under the Apache License, Version 2.0 (the "License"); you may not use
+ this file except in compliance with the License. You may obtain a copy of
+ the License at http://www.apache.org/licenses/LICENSE-2.0 Unless required
+ by applicable law or agreed to in writing, software distributed under the
+ License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS
+ OF ANY KIND, either express or implied. See the License for the specific
language governing permissions and limitations under the License. -->
-<document>
+<document xmlns="http://maven.apache.org/XDOC/2.0"
+ xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
+ xsi:schemaLocation="http://maven.apache.org/XDOC/2.0 http://maven.apache.org/xsd/xdoc-2.0.xsd">
<properties>
<title>Log4j 2 Asynchronous Loggers for Low-Latency Logging</title>
<author email="rpopma@apache.org">Remko Popma</author>
@@ -17,7 +19,7 @@
<body>
<section name="Asynchronous Loggers for Low-Latency Logging">
<p>
- Asynchronous logging can improve your application's
+ Asynchronous logging can improve your application's
performance by executing the I/O operations
in a separate thread.
Log4j 2 makes a number of improvements in this area.
@@ -46,10 +48,10 @@
already existed in Log4j 1.x, but have
been enhanced to flush to disk
at the end of a batch (when the queue is empty).
- This produces the same result as configuring
+ This produces the same result as configuring
"immediateFlush=true", that is, all
received log events are always available on disk,
- but is more efficient because it does not need to
+ but is more efficient because it does not need to
touch the disk on each and every log event.
(Async Appenders use ArrayBlockingQueue internally and
do not need the disruptor jar on the classpath.)
@@ -58,7 +60,7 @@
<b>Random Access File Appenders</b>
are an alternative to Buffered File
Appenders. Under the hood, these
- new appenders use a ByteBuffer + RandomAccessFile instead
+ new appenders use a ByteBuffer + RandomAccessFile instead
of a BufferedOutputStream. In our testing
this was about 20-200% faster.
These appenders can also be used
@@ -71,7 +73,7 @@
<subsection name="Trade-offs">
<p>
Although asynchronous logging can give significant performance
- benefits, there are situations where you may want to
+ benefits, there are situations where you may want to
choose synchronous logging.
This section describes some of the trade-offs of
asynchronous logging.
@@ -80,13 +82,13 @@
<b>Benefits</b>
</p>
<ul>
- <li>Higher <a href="#Performance">throughput</a>.
+ <li>Higher <a href="#Performance">throughput</a>.
With an asynchronous logger
- your application can log messages at 6 - 68 times
+ your application can log messages at 6 - 68 times
the rate of a synchronous logger.
</li>
<li>
- Lower logging <a href="#Latency">latency</a>.
+ Lower logging <a href="#Latency">latency</a>.
Latency is the time it takes for a call to Logger.log to return.
Asynchronous Loggers have consistently lower latency
than synchronous loggers or even queue-based asynchronous appenders.
@@ -99,7 +101,7 @@
<li>Prevent or dampen latency spikes during bursts of events.
If the queue size is configured large enough to handle
spikes, asynchronous logging will help prevent your
- application from falling behind (as much) during
+ application from falling behind (as much) during
sudden bursts of activity.
</li>
</ul>
@@ -109,7 +111,7 @@
process and an exception is thrown, it is less easy for an
asynchronous logger or appender to signal this problem to the
application. This can partly be alleviated by configuring an
- <tt>ExceptionHandler</tt>, but this may
+ <tt>ExceptionHandler</tt>, but this may
still not cover all cases. For this
reason, if logging is part of your business logic,
for example if
@@ -117,7 +119,7 @@
we would
recommend to synchronously log those audit messages.
(Note that you
- can still <a href="#MixedSync-Async">combine</a> them
+ can still <a href="#MixedSync-Async">combine</a> them
and use asynchronous logging for debug/trace
logging in addition to synchronous
logging for the audit trail.)
@@ -140,14 +142,15 @@
asynchronous loggers. If one of your layouts or custom
filters needs location information, you need to set
"includeLocation=true"
- in the configuration of all relevant loggers,
+ in the configuration of all relevant loggers,
including the root logger.
</p>
<p>
A configuration that does not require location might look like:
+ </p>
<pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
-<!-- Don't forget to set system property
+<!-- Don't forget to set system property
-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
to make all loggers asynchronous. -->
@@ -166,7 +169,6 @@
</Root>
</Loggers>
</Configuration>]]></pre>
- </p>
<p>
When
<tt>AsyncLoggerContextSelector</tt> is used to make
@@ -180,7 +182,7 @@
<tt><asyncRoot></tt> or
<tt><asyncLogger></tt>.
The latter elements are intended for mixing async with sync
- loggers. If you use both mechanisms together you will end
+ loggers. If you use both mechanisms together you will end
up with two
background threads, where your application passes the log
message to
@@ -193,18 +195,21 @@
<p>
There are a few system properties
- you can use to control
+ you can use to control
aspects of the asynchronous logging subsystem.
Some of these can be used to
tune logging performance.
</p>
<table>
- <tr>
+ <caption align="top">System Properties to configure all
+ asynchronous loggers
+ </caption>
+ <tr>
<th>System Property</th>
<th>Default Value</th>
<th>Description</th>
</tr>
- <tr>
+ <tr>
<td>AsyncLogger.ExceptionHandler</td>
<td>
<tt>null</tt>
@@ -220,10 +225,9 @@
logging the messages.
</td>
</tr>
- <tr>
+ <tr>
<td>AsyncLogger.RingBufferSize</td>
- <td>256 * 1024
- </td>
+ <td>256 * 1024</td>
<td>
Size (number of slots) in the RingBuffer used by the
asynchronous logging subsystem.
@@ -236,7 +240,7 @@
or shrink during the life of the system.
</td>
</tr>
- <tr>
+ <tr>
<td>AsyncLogger.WaitStrategy</td>
<td>
<tt>Sleep</tt>
@@ -260,9 +264,9 @@
minimum number of nanos the OS and JVM will allow
while the I/O thread is waiting for log events.
Sleep is a good compromise between performance
- and CPU resource.
- This strategy has very low impact on the
- application thread, in exchange for some additional
+ and CPU resource.
+ This strategy has very low impact on the
+ application thread, in exchange for some additional
latency for actually getting the message logged.
<br />
<tt>Yield</tt>
@@ -273,7 +277,7 @@
in order to get the message logged to disk sooner.
</td>
</tr>
- <tr>
+ <tr>
<td>AsyncLogger.ThreadNameStrategy</td>
<td>
<tt>CACHED</tt>
@@ -282,13 +286,13 @@
Valid values: CACHED, UNCACHED.
<br />
By default, AsyncLogger caches the thread name
- in a threadlocal variable to improve performance.
+ in a ThreadLocal variable to improve performance.
Specify the <tt>UNCACHED</tt> option if your application
modifies the thread name at runtime (with <tt>Thread.currentThread().setName()</tt>)
and you want to see the new thread name reflected in the log.
</td>
</tr>
- <tr>
+ <tr>
<td>log4j.Clock</td>
<td>
<tt>SystemClock</tt>
@@ -296,7 +300,7 @@
<td>
Implementation of the
<tt>org.apache.logging.log4j.core.helpers.Clock</tt>
- interface that is used for timestamping the log
+ interface that is used for timestamping the log
events when all loggers are asynchronous.
<br />
By default, <tt>System.currentTimeMillis</tt>
@@ -320,9 +324,6 @@
interface.
</td>
</tr>
- <caption align="top">System Properties to configure all
- asynchronous loggers
- </caption>
</table>
</subsection>
<a name="MixedSync-Async" />
@@ -352,20 +353,21 @@
asynchronous loggers. If one of your layouts or custom
filters needs location information, you need to set
"includeLocation=true"
- in the configuration of all relevant loggers,
+ in the configuration of all relevant loggers,
including the root logger.
</p>
<p>
A configuration that mixes asynchronous loggers might look like:
+ </p>
<pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
-<!-- No need to set system property "Log4jContextSelector" to any value
+<!-- No need to set system property "Log4jContextSelector" to any value
when using <asyncLogger> or <asyncRoot>. -->
<Configuration status="WARN">
<Appenders>
<!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
- <RandomAccessFile name="RandomAccessFile" fileName="asyncWithLocation.log"
+ <RandomAccessFile name="RandomAccessFile" fileName="asyncWithLocation.log"
immediateFlush="false" append="false">
<PatternLayout>
<Pattern>%d %p %class{1.} [%t] %location %m %ex%n</Pattern>
@@ -382,21 +384,23 @@
</Root>
</Loggers>
</Configuration>]]></pre>
- </p>
<p>
There are a few system properties
- you can use to control
+ you can use to control
aspects of the asynchronous logging subsystem.
Some of these can be used to
tune logging performance.
</p>
<table>
- <tr>
+ <caption align="top">System Properties to configure mixed
+ asynchronous and normal loggers
+ </caption>
+ <tr>
<th>System Property</th>
<th>Default Value</th>
<th>Description</th>
</tr>
- <tr>
+ <tr>
<td>AsyncLoggerConfig.ExceptionHandler</td>
<td>
<tt>null</tt>
@@ -412,9 +416,9 @@
logging the messages.
</td>
</tr>
- <tr>
+ <tr>
<td>AsyncLoggerConfig.RingBufferSize</td>
- <td>256 * 1024
+ <td>256 * 1024
</td>
<td>
Size (number of slots) in the RingBuffer used by the
@@ -427,7 +431,7 @@
or shrink during the life of the system.
</td>
</tr>
- <tr>
+ <tr>
<td>AsyncLoggerConfig.WaitStrategy</td>
<td>
<tt>Sleep</tt>
@@ -451,9 +455,9 @@
minimum number of nanos the OS and JVM will allow
while the I/O thread is waiting for log events.
Sleep is a good compromise between performance
- and CPU resource.
- This strategy has very low impact on the
- application thread, in exchange for some additional
+ and CPU resource.
+ This strategy has very low impact on the
+ application thread, in exchange for some additional
latency for actually getting the message logged.
<br />
<tt>Yield</tt>
@@ -464,18 +468,15 @@
in order to get the message logged to disk sooner.
</td>
</tr>
- <caption align="top">System Properties to configure mixed
- asynchronous and normal loggers
- </caption>
</table>
</subsection>
<a name="Location" />
<subsection name="Location, location, location...">
<p>
If one of the layouts is
- configured with a location-related attribute like
+ configured with a location-related attribute like
HTML <a href="layouts.html#HtmlLocationInfo">locationInfo</a>,
- or one of the patterns
+ or one of the patterns
<a href="layouts.html#PatternClass">%C or $class</a>,
<a href="layouts.html#PatternFile">%F or %file</a>,
<a href="layouts.html#PatternLocation">%l or %location</a>,
@@ -488,7 +489,7 @@
This is an expensive operation: 1.3 - 5 times slower for
synchronous loggers. Synchronous loggers wait as
long as possible before they take this stack snapshot. If no
- location is required, the snapshot will never be taken.
+ location is required, the snapshot will never be taken.
</p><p>
However,
asynchronous loggers need to make this decision before passing the
@@ -500,8 +501,8 @@
For this reason, asynchronous loggers and asynchronous
appenders do not include location information by default.
</p><p>
- You can override the default behaviour in your logger
- or asynchronous appender configuration
+ You can override the default behaviour in your logger
+ or asynchronous appender configuration
by specifying
<tt>includeLocation="true"</tt>.
</p>
@@ -511,10 +512,10 @@
<a name="Performance" />
<subsection name="Asynchronous Logging Performance">
<p>
- The performance results below were all derived from running the
- PerfTest, MTPerfTest and PerfTestDriver classes which can be found
+ The performance results below were all derived from running the
+ PerfTest, MTPerfTest and PerfTestDriver classes which can be found
in the Log4j 2 unit test source directory.
- All tests were done using the
+ All tests were done using the
default settings (SystemClock and SleepingWaitStrategy).
The methodology used was the same for all tests:
</p>
@@ -522,8 +523,8 @@
<li>First, warm up the JVM by logging 200,000 log messages of 500
characters.</li>
<li>Repeat the warm-up 10 times, then wait 10 seconds for the I/O thread to catch up and buffers to drain.</li>
- <li>Latency test: at less than saturation, measure how
- long a call to Logger.log takes.
+ <li>Latency test: at less than saturation, measure how
+ long a call to Logger.log takes.
Pause for 10 microseconds * threadCount between measurements.
Repeat this 5 million times, and measure average latency,
latency of 99% of observations and 99.99% of observations.</li>
@@ -538,37 +539,38 @@
<p>
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
+ 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.
</p>
<p>
Asynchronous loggers' throughput increases with the number of threads,
- whereas both synchronous loggers and asynchronous appenders
+ whereas both synchronous loggers and asynchronous appenders
have more or less constant throughput regardless of the number of
threads that are doing the logging.
</p>
- <p><img src="../images/async-vs-sync-throughput.png" /></p>
-
+ <p><img src="../images/async-vs-sync-throughput.png" alt="Async loggers have much higher throughput than sync loggers." /></p>
+
<h4>Asynchronous Throughput Comparison with Other Logging Packages</h4>
<p>
We also compared 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
+ 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.
</p>
<p>
- <img src="../images/async-throughput-comparison.png" />
+ <img src="../images/async-throughput-comparison.png" alt="Async loggers have the highest throughput." />
</p>
<p>On Solaris 10 (64bit) with JDK1.7.0_06, 4-core Xeon X5570 dual CPU
@2.93Ghz with hyperthreading switched on (16 virtual cores):</p>
<table>
- <tr>
+ <caption align="top">Throughput per thread in messages/second</caption>
+ <tr>
<th>Logger</th>
<th>1 thread</th>
<th>2 threads</th>
@@ -578,7 +580,7 @@
<th>32 threads</th>
<th>64 threads</th>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Loggers all asynchronous</td>
<td align="right">2,652,412</td>
<td align="right">909,119</td>
@@ -588,7 +590,7 @@
<td align="right">253,791</td>
<td align="right">288,997</td>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Loggers mixed sync/async</td>
<td align="right">2,454,358</td>
<td align="right">839,394</td>
@@ -598,7 +600,7 @@
<td align="right">216,863</td>
<td align="right">218,937</td>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Async Appender</td>
<td align="right">1,713,429</td>
<td align="right">603,019</td>
@@ -618,7 +620,7 @@
<td align="right">31,706</td>
<td align="right">14,072</td>
</tr>
- <tr>
+ <tr>
<td>Logback: Async Appender</td>
<td align="right">2,206,907</td>
<td align="right">624,082</td>
@@ -628,7 +630,7 @@
<td align="right">43,422</td>
<td align="right">21,303</td>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Synchronous</td>
<td align="right">273,536</td>
<td align="right">136,523</td>
@@ -638,7 +640,7 @@
<td align="right">7,903</td>
<td align="right">4,253</td>
</tr>
- <tr>
+ <tr>
<td>Log4j1: Synchronous</td>
<td align="right">326,894</td>
<td align="right">105,591</td>
@@ -648,7 +650,7 @@
<td align="right">7,094</td>
<td align="right">3,509</td>
</tr>
- <tr>
+ <tr>
<td>Logback: Synchronous</td>
<td align="right">178,063</td>
<td align="right">65,000</td>
@@ -658,14 +660,13 @@
<td align="right">3,985</td>
<td align="right">1,967</td>
</tr>
- <caption align="top">Throughput per thread in messages/second
- </caption>
</table>
- <p></p>
+ <p/>
<p>On Windows 7 (64bit) with JDK1.7.0_11, 2-core Intel i5-3317u CPU
@1.70Ghz with hyperthreading switched on (4 virtual cores):</p>
<table>
- <tr>
+ <caption align="top">Throughput per thread in messages/second</caption>
+ <tr>
<th>Logger</th>
<th>1 thread</th>
<th>2 threads</th>
@@ -674,7 +675,7 @@
<th>16 threads</th>
<th>32 threads</th>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Loggers all asynchronous</td>
<td align="right">1,715,344</td>
<td align="right">928,951</td>
@@ -683,7 +684,7 @@
<td align="right">1,708,989</td>
<td align="right">773,565</td>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Loggers mixed sync/async</td>
<td align="right">571,099</td>
<td align="right">1,204,774</td>
@@ -692,7 +693,7 @@
<td align="right">462,093</td>
<td align="right">908,529</td>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Async Appender</td>
<td align="right">1,236,548</td>
<td align="right">1,006,287</td>
@@ -701,7 +702,7 @@
<td align="right">160,094</td>
<td align="right">60,152</td>
</tr>
- <tr>
+ <tr>
<td>Log4j1: Async Appender</td>
<td align="right">1,373,195</td>
<td align="right">911,657</td>
@@ -710,7 +711,7 @@
<td align="right">202,777</td>
<td align="right">162,964</td>
</tr>
- <tr>
+ <tr>
<td>Logback: Async Appender</td>
<td align="right">1,979,515</td>
<td align="right">783,722</td>
@@ -719,7 +720,7 @@
<td align="right">172,463</td>
<td align="right">133,435</td>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Synchronous</td>
<td align="right">281,250</td>
<td align="right">225,731</td>
@@ -728,7 +729,7 @@
<td align="right">34,401</td>
<td align="right">17,347</td>
</tr>
- <tr>
+ <tr>
<td>Log4j1: Synchronous</td>
<td align="right">147,824</td>
<td align="right">72,383</td>
@@ -737,7 +738,7 @@
<td align="right">8,937</td>
<td align="right">4,440</td>
</tr>
- <tr>
+ <tr>
<td>Logback: Synchronous</td>
<td align="right">149,811</td>
<td align="right">66,301</td>
@@ -746,56 +747,53 @@
<td align="right">8,431</td>
<td align="right">3,610</td>
</tr>
- <caption align="top">Throughput per thread in messages/second
- </caption>
</table>
<h4>Throughput of Logging With Location (includeLocation="true")</h4>
<p>On Solaris 10 (64bit) with JDK1.7.0_06, 4-core Xeon X5570 dual CPU
@2.93Ghz with hyperthreading switched off (8 virtual cores):</p>
<table>
- <tr>
+ <caption align="top">Throughput in log messages/second per thread</caption>
+ <tr>
<th>Logger (Log4j 2)</th>
<th>1 thread</th>
<th>2 threads</th>
<th>4 threads</th>
<th>8 threads</th>
</tr>
- <tr>
+ <tr>
<td>Loggers all asynchronous</td>
<td align="right">75,862</td>
<td align="right">88,775</td>
<td align="right">80,240</td>
<td align="right">68,077</td>
</tr>
- <tr>
+ <tr>
<td>Loggers mixed sync/async</td>
<td align="right">61,993</td>
<td align="right">66,164</td>
<td align="right">55,735</td>
<td align="right">52,843</td>
</tr>
- <tr>
+ <tr>
<td>Async Appender</td>
<td align="right">47,033</td>
<td align="right">52,426</td>
<td align="right">50,882</td>
<td align="right">36,905</td>
</tr>
- <tr>
+ <tr>
<td>Synchronous</td>
<td align="right">31,054</td>
<td align="right">33,175</td>
<td align="right">29,791</td>
<td align="right">23,628</td>
</tr>
- <caption align="top">Throughput in log messages/second
- per thread</caption>
</table>
<p>As expected, logging location information
- has a large performance impact. Asynchronous loggers are 4 - 20
+ has a large performance impact. Asynchronous loggers are 4 - 20
times slower, while synchronous loggers are 1.3 - 5 times slower.
- However, if you do need location information,
+ However, if you do need location information,
asynchronous logging will still be faster than synchronous logging.</p>
<a name="Latency" />
@@ -803,31 +801,32 @@
<p>Latency tests are done by logging at
less than saturation, measuring how long a call to Logger.log
takes to return. After each call to Logger.log, the test waits
- for 10 microseconds * threadCount before continuing.
+ for 10 microseconds * threadCount before continuing.
Each thread logs 5 million messages.
</p>
<p>All the latency measurements below are results of tests run
on Solaris 10 (64bit) with JDK1.7.0_06, 4-core Xeon X5570 dual CPU
@2.93Ghz with hyperthreading switched on (16 virtual cores).</p>
- <p><img src="../images/async-latency-histogram-64-threads.png" /></p>
- <p>Note that this is log-scale, not linear.
- The above graph compares the latency distributions of
+ <p><img src="../images/async-latency-histogram-64-threads.png" alt="Histogram of async latency" /></p>
+ <p>Note that this is log-scale, not linear.
+ The above graph compares the latency distributions of
an asynchronous logger and a Log4j 1.2.17 Async Appender.
This shows the latency of one thread
during a test where 64 threads are logging in parallel.
The test was run once for the async logger and once for the
async appender.</p>
<table>
- <tr>
- <th></th>
+ <caption align="top">Latency of a call to Logger.log() in nanoseconds</caption>
+ <tr>
+ <th/>
<th colspan="2" >Average latency</th>
<th colspan="2">99% observations
less than</th>
<th colspan="2">99.99%
observations less than</th>
</tr>
- <tr>
- <th></th>
+ <tr>
+ <th/>
<th>1 thread</th>
<th>64 threads</th>
<th>1 thread</th>
@@ -835,7 +834,7 @@
<th>1 thread</th>
<th>64 threads</th>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Loggers all async</td>
<td align="right">677</td>
<td align="right">4,135</td>
@@ -844,7 +843,7 @@
<td align="right">8,192</td>
<td align="right">16,128</td>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Loggers mixed
sync/async</td>
<td align="right">648</td>
@@ -854,7 +853,7 @@
<td align="right">8,192</td>
<td align="right">16,384</td>
</tr>
- <tr>
+ <tr>
<td>Log4j 2: Async Appender</td>
<td align="right">2,423</td>
<td align="right">2,117,722</td>
@@ -863,7 +862,7 @@
<td align="right">16,384</td>
<td align="right">268,435,456</td>
</tr>
- <tr>
+ <tr>
<td>Log4j1: Async Appender</td>
<td align="right">1,562</td>
<td align="right">1,781,404</td>
@@ -872,7 +871,7 @@
<td align="right">16,384</td>
<td align="right">268,435,456</td>
</tr>
- <tr>
+ <tr>
<td>Logback: Async Appender</td>
<td align="right">2,123</td>
<td align="right">2,079,020</td>
@@ -881,11 +880,10 @@
<td align="right">14,745</td>
<td align="right">268,435,456</td>
</tr>
- <caption align="top">Latency of a call to Logger.log() in nanoseconds</caption>
</table>
<p>
- The latency comparison graph below is also log-scale,
- and shows the average latency of asynchronous loggers and
+ The latency comparison graph below is also log-scale,
+ and shows the average latency of asynchronous loggers and
ArrayBlockingQueue-based asynchronous appenders
in scenarios with more and more threads running in parallel.
Up to 8 threads asynchronous appenders have comparable
@@ -894,22 +892,22 @@
asynchronous appenders is orders of magnitude larger than
asynchronous loggers.
</p>
- <p><img src="../images/async-average-latency.png" /></p>
+ <p><img src="../images/async-average-latency.png" alt="Average async logger latency" /></p>
<p>
- Applications interested in low latency often care not only about
- average latency, but also about worst-case latency.
- The graph below shows that asynchronous loggers also do
- better when comparing the maximum latency of 99.99% of
+ Applications interested in low latency often care not only about
+ average latency, but also about worst-case latency.
+ The graph below shows that asynchronous loggers also do
+ better when comparing the maximum latency of 99.99% of
observations with other logging methods.
When increasing the number of threads
- the vast majority of latency measurements for asynchronous
+ the vast majority of latency measurements for asynchronous
loggers stay in the 10-20 microseconds range
where Asynchronous Appenders start experiencing many
latency spikes in the 100 millisecond range, a difference of
four orders of magnitude.
</p>
<p>
- <img src="../images/async-max-latency-99.99pct.png" />
+ <img src="../images/async-max-latency-99.99pct.png" alt="Maximum async logger latency" />
</p>
<a name="RandomAccessFileAppenderPerformance" />
@@ -919,92 +917,90 @@
<p>On Windows 7 (64bit) with JDK1.7.0_11, 2-core Intel i5-3317u CPU
@1.70Ghz with hyperthreading switched on (4 virtual cores):</p>
<table>
- <tr>
+ <caption align="top">Throughput per thread in messages/second</caption>
+ <tr>
<th>Appender</th>
<th>1 thread</th>
<th>2 threads</th>
<th>4 threads</th>
<th>8 threads</th>
</tr>
- <tr>
+ <tr>
<td>RandomAccessFileAppender</td>
<td align="right">250,438</td>
<td align="right">169,939</td>
<td align="right">109,074</td>
<td align="right">58,845</td>
</tr>
- <tr>
+ <tr>
<td>FileAppender</td>
<td align="right">186,695</td>
<td align="right">118,587</td>
<td align="right">57,012</td>
<td align="right">28,846</td>
</tr>
- <tr>
+ <tr>
<td>RollingRandomAccessFileAppender</td>
<td align="right">278,369</td>
<td align="right">213,176</td>
<td align="right">125,300</td>
<td align="right">63,103</td>
</tr>
- <tr>
+ <tr>
<td>RollingFileAppender</td>
<td align="right">182,518</td>
<td align="right">114,690</td>
<td align="right">55,147</td>
<td align="right">28,153</td>
</tr>
- <caption align="top">Throughput per thread in messages/second
- </caption>
</table>
- <p>On Solaris 10 (64bit) with JDK1.7.0_06, 4-core dual Xeon X5570 CPU
+ <p>On Solaris 10 (64bit) with JDK1.7.0_06, 4-core dual Xeon X5570 CPU
@2.93GHz with hyperthreading switched off (8 virtual cores):</p>
<table>
- <tr>
+ <caption align="top">Throughput per thread in messages/second</caption>
+ <tr>
<th>Appender</th>
<th>1 thread</th>
<th>2 threads</th>
<th>4 threads</th>
<th>8 threads</th>
</tr>
- <tr>
+ <tr>
<td>RandomAccessFileAppender</td>
<td align="right">240,760</td>
<td align="right">128,713</td>
<td align="right">66,555</td>
<td align="right">30,544</td>
</tr>
- <tr>
+ <tr>
<td>FileAppender</td>
<td align="right">172,517</td>
<td align="right">106,587</td>
<td align="right">55,885</td>
<td align="right">25,675</td>
</tr>
- <tr>
+ <tr>
<td>RollingRandomAccessFileAppender</td>
<td align="right">228,491</td>
<td align="right">135,355</td>
<td align="right">69,277</td>
<td align="right">32,484</td>
</tr>
- <tr>
+ <tr>
<td>RollingFileAppender</td>
<td align="right">186,422</td>
<td align="right">97,737</td>
<td align="right">55,766</td>
<td align="right">25,097</td>
</tr>
- <caption align="top">Throughput per thread in messages/second
- </caption>
</table>
</subsection>
- <!--
+ <!--
<a name="PerformanceTuning" />
<subsection name="Async Logger Performance Tuning">
<p>While the default settings should give good results out
of the box, you may want to change settings to improve
- your logging throughput and/or latency.
+ your logging throughput and/or latency.
We suggest the following steps for tuning your logging performance:</p>
<ol>
<li>Create a base line by running the performance tests in your environment.</li>
@@ -1023,18 +1019,19 @@
[<b>RingBufferSize</b>] is an optional system property with an integer value of at least 128.
Details are documented under "System Properties to configure ... loggers".
<br />
- [<b>path-to-java</b>] is an optional parameter that is the full
- path to the "java" executable. Specify this if just running
+ [<b>path-to-java</b>] is an optional parameter that is the full
+ path to the "java" executable. Specify this if just running
"java" in the current directory does not specify the version of
java that you want to test with.
<br />
[<b>repeats</b>] is an optional parameter that specifies how often
each test is repeated. The default is 5.
</blockquote>
-
+
<p>For reference, below are some of the numbers we used to
determine the default settings. (Solaris 10 (64bit), 2.93GHz Xeon X5570 with JDK1.7.0_06):</p>
<table>
+ <caption align="top">Throughput in log messages/second per thread</caption>
<tr>
<th>Logger</th>
<th>WaitStrategy</th>
@@ -1109,7 +1106,6 @@
<td align="right">389,609</td>
<td align="right">391,969</td>
</tr>
- <caption align="top">Throughput in log messages/second per thread</caption>
</table>
</subsection>
-->
@@ -1126,14 +1122,14 @@
introducing latency, so we
focused on optimising this area.
The Disruptor is the result of our research and
- testing. We found that cache misses at the
+ testing. We found that cache misses at the
CPU-level, and locks requiring kernel
arbitration are both extremely costly, so we created a
- framework which has "mechanical sympathy" for
+ framework which has "mechanical sympathy" for
the hardware it's running on, and that's lock-free.
</p>
</blockquote>
-
+
<p>
LMAX Disruptor internal performance comparisons with
<tt>java.util.concurrent.ArrayBlockingQueue</tt>