You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by rp...@apache.org on 2014/09/14 16:03:32 UTC
[1/2] format improvements (no content changes)
Repository: logging-log4j2
Updated Branches:
refs/heads/master 73a29ed0e -> c66269021
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/c6626902/src/site/xdoc/manual/async.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/manual/async.xml b/src/site/xdoc/manual/async.xml
index 4f089b2..7b6ee9c 100644
--- a/src/site/xdoc/manual/async.xml
+++ b/src/site/xdoc/manual/async.xml
@@ -1,174 +1,144 @@
<?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
- language governing permissions and limitations under the License. -->
-<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>
- </properties>
- <body>
- <section name="Asynchronous Loggers for Low-Latency Logging">
- <p>
- 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.
- </p>
- <ul>
- <li>
- <b>Asynchronous Loggers</b>
- are a new addition to Log4j 2.
- Their aim is to return from the call
- to Logger.log to the application as
- soon as possible. You can choose
- between making all Loggers asynchronous
- or using a mixture of synchronous
- and asynchronous Loggers. Making all
- Loggers asynchronous will give
- the best performance, while mixing
- gives you more flexibility.
- </li>
- <li><b>LMAX Disruptor technology</b>. Asynchronous Loggers
- internally use the <a href="#UnderTheHood">Disruptor</a>,
- a lock-free inter-thread
- communication library, instead of queues, resulting in higher
- throughput and lower latency.</li>
- <li>
- <b>Asynchronous Appenders</b>
- 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
- "immediateFlush=true", that is, all
- received log events are always available on disk,
- 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.)
- </li>
- <li>(For synchronous and asynchronous use)
- <b>Random Access File Appenders</b>
- are an alternative to Buffered File
- Appenders. Under the hood, these
- 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
- with synchronous loggers
- and will give the same performance benefits.
- Random Access File Appenders do not need the disruptor jar on the classpath.
- </li>
- </ul>
- <a name="Trade-offs" />
- <subsection name="Trade-offs">
- <p>
- Although asynchronous logging can give significant performance
- benefits, there are situations where you may want to
- choose synchronous logging.
- This section describes some of the trade-offs of
- asynchronous logging.
- </p>
- <p>
- <b>Benefits</b>
- </p>
- <ul>
- <li>Higher <a href="#Performance">throughput</a>.
- With an asynchronous logger
- your application can log messages at 6 - 68 times
- the rate of a synchronous logger.
- </li>
- <li>
- 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.
- Applications interested in low latency often care
- not only about average latency, but also about worst-case latency.
- Our performance comparison shows that Asynchronous
- Loggers also do better when comparing the maximum latency
- of 99% or even 99.99% of observations with other logging methods.
- </li>
- <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
- sudden bursts of activity.
- </li>
- </ul>
- <b>Drawbacks</b>
- <ul>
- <li>Error handling. If a problem happens during the logging
- 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
- still not cover all cases. For this
- reason, if logging is part of your business logic,
- for example if
- you are using Log4j as an audit logging framework,
- we would
- recommend to synchronously log those audit messages.
- (Note that you
- 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.)
- </li>
- <li>In some rare cases, care must be taken with mutable messages.
- Most of the time you don't need to worry about this. Log4 will ensure that log messages like
- <code>logger.debug("My object is {}", myObject)</code> will use the state of the
- <code>myObject</code> parameter at the time of the call to <code>logger.debug()</code>.
- The log message will not change even if <code>myObject</code> is modified later.
- It is safe to asynchronously log mutable objects because most
- <a href="../log4j-api/apidocs/org/apache/logging/log4j/message/Message.html">Message</a>
- implementations built-in to Log4j take a snapshot of the parameters.
- There are some exceptions however:
- <a href="../log4j-api/apidocs/org/apache/logging/log4j/message/MapMessage.html">MapMessage</a>
- and
- <a href="../log4j-api/apidocs/org/apache/logging/log4j/message/StructuredDataMessage.html">StructuredDataMessage</a>
- are mutable by design: fields can be added to these messages after the message object was created.
- These messages should not be modified after they are logged with asynchronous loggers or
- asynchronous appenders; you may or may not see the modifications in the resulting log output.
- Similarly, custom
- <a href="../log4j-api/apidocs/org/apache/logging/log4j/message/Message.html">Message</a>
- implementations should be designed with asynchronous use in mind, and either take a snapshot
- of their parameters at construction time, or document their thread-safety characteristics.
- </li>
- </ul>
- </subsection>
- <a name="AllAsync" />
- <subsection name="Making All Loggers Asynchronous">
- <p><i>Requires disruptor-3.0.0.jar or higher on the classpath.</i></p>
- <p>
- This is simplest to configure and gives the best performance.
- To make all loggers asynchronous,
- add the disruptor jar to the classpath
- and set the system property <tt>Log4jContextSelector</tt>
- to
- <tt>org.apache.logging.log4j.core.async.AsyncLoggerContextSelector</tt>.
- </p>
- <p>
- By default, <a href="#Location">location</a> is not passed to the I/O thread by
- 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,
- including the root logger.
- </p>
- <p>
- A configuration that does not require location might look like:
+<!-- 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 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>
+ </properties>
+ <body>
+ <section name="Asynchronous Loggers for Low-Latency Logging">
+ <p>
+ 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.
+ </p>
+ <ul>
+ <li>
+ <b>Asynchronous Loggers</b> are a new addition to Log4j 2.
+ Their aim is to return from the call to Logger.log to the application as
+ soon as possible. You can choose between making all Loggers asynchronous
+ or using a mixture of synchronous and asynchronous Loggers. Making all
+ Loggers asynchronous will give the best performance, while mixing
+ gives you more flexibility.
+ </li>
+ <li>
+ <b>LMAX Disruptor technology</b>. Asynchronous Loggers internally use the
+ <a href="#UnderTheHood">Disruptor</a>, a lock-free inter-thread
+ communication library, instead of queues, resulting in higher throughput and lower latency.
+ </li>
+ <li>
+ <b>Asynchronous Appenders</b> 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 "immediateFlush=true", that is, all
+ received log events are always available on disk, 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.)
+ </li>
+ <li>(For synchronous and asynchronous use) <b>Random Access File Appenders</b>
+ are an alternative to Buffered File Appenders. Under the hood, these
+ 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
+ with synchronous loggers and will give the same performance benefits.
+ Random Access File Appenders do not need the disruptor jar on the classpath.
+ </li>
+ </ul>
+ <a name="Trade-offs" />
+ <subsection name="Trade-offs">
+ <p>
+ Although asynchronous logging can give significant performance benefits,
+ there are situations where you may want to choose synchronous logging.
+ This section describes some of the trade-offs of asynchronous logging.
+ </p>
+ <p>
+ <b>Benefits</b>
+ </p>
+ <ul>
+ <li>
+ Higher <a href="#Performance">throughput</a>. With an asynchronous logger
+ your application can log messages at 6 - 68 times the rate of a synchronous logger.
+ </li>
+ <li>
+ 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. Applications interested in low latency often care
+ not only about average latency, but also about worst-case latency.
+ Our performance comparison shows that Asynchronous Loggers also do better when comparing the
+ maximum latency of 99% or even 99.99% of observations with other logging methods.
+ </li>
+ <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 sudden bursts of activity.
+ </li>
+ </ul>
+ <b>Drawbacks</b>
+ <ul>
+ <li>
+ Error handling. If a problem happens during the logging 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 still not cover all cases. For this reason, if logging is part of your business logic,
+ for example if you are using Log4j as an audit logging framework, we would
+ recommend to synchronously log those audit messages.
+ (Note that you 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.)
+ </li>
+ <li>
+ In some rare cases, care must be taken with mutable messages.
+ Most of the time you don't need to worry about this. Log4 will ensure that log messages like
+ <code>logger.debug("My object is {}", myObject)</code> will use the state of the
+ <code>myObject</code> parameter at the time of the call to <code>logger.debug()</code>.
+ The log message will not change even if <code>myObject</code> is modified later.
+ It is safe to asynchronously log mutable objects because most
+ <a href="../log4j-api/apidocs/org/apache/logging/log4j/message/Message.html">Message</a>
+ implementations built-in to Log4j take a snapshot of the parameters.
+ There are some exceptions however:
+ <a
+ href="../log4j-api/apidocs/org/apache/logging/log4j/message/MapMessage.html">MapMessage</a>
+ and
+ <a
+ href="../log4j-api/apidocs/org/apache/logging/log4j/message/StructuredDataMessage.html">StructuredDataMessage</a>
+ are mutable by design: fields can be added to these messages after the message object was created.
+ These messages should not be modified after they are logged with asynchronous loggers or
+ asynchronous appenders; you may or may not see the modifications in the resulting log output.
+ Similarly, custom
+ <a
+ href="../log4j-api/apidocs/org/apache/logging/log4j/message/Message.html">Message</a>
+ implementations should be designed with asynchronous use in mind, and either take a snapshot
+ of their parameters at construction time, or document their thread-safety characteristics.
+ </li>
+ </ul>
+ </subsection>
+ <a name="AllAsync" />
+ <subsection name="Making All Loggers Asynchronous">
+ <p>
+ <i>Requires disruptor-3.0.0.jar or higher on the classpath.
+ </i>
+ </p>
+ <p>
+ This is simplest to configure and gives the best performance. To make all loggers asynchronous,
+ add the disruptor jar to the classpath and set the system property <tt>Log4jContextSelector</tt>
+ to <tt>org.apache.logging.log4j.core.async.AsyncLoggerContextSelector</tt>.
</p>
- <pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
+ <p>
+ By default, <a href="#Location">location</a> is not passed to the I/O thread by
+ 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, 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
-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
@@ -189,202 +159,140 @@
</Root>
</Loggers>
</Configuration>]]></pre>
- <p>
- When
- <tt>AsyncLoggerContextSelector</tt> is used to make
- all loggers asynchronous, make sure to use normal
- <tt><root></tt> and
- <tt><logger></tt> elements
- in the configuration. The
- AsyncLoggerContextSelector
- will ensure that all loggers are asynchronous, using a mechanism
- that is different from what happens when you configure
- <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
- up with two
- background threads, where your application passes the log
- message to
- thread A, which passes the message to thread B,
- which then finally
- logs the message to disk. This works, but
- there will be an unnecessary
- step in the middle.
- </p>
-
- <p>
- There are a few system properties
- you can use to control
- aspects of the asynchronous logging subsystem.
- Some of these can be used to
- tune logging performance.
- </p>
- <a name="SysPropsAllAsync" />
- <table>
- <caption align="top">System Properties to configure all
- asynchronous loggers
+ <p>
+ When <tt>AsyncLoggerContextSelector</tt> is used to make all loggers asynchronous, make sure to use normal
+ <tt><root></tt> and <tt><logger></tt> elements in the configuration. The
+ AsyncLoggerContextSelector will ensure that all loggers are asynchronous, using a mechanism
+ that is different from what happens when you configure <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 up with two background threads, where your application passes the log
+ message to thread A, which passes the message to thread B, which then finally
+ logs the message to disk. This works, but there will be an unnecessary step in the middle.
+ </p>
+ <p>
+ There are a few system properties you can use to control aspects of the asynchronous logging subsystem.
+ Some of these can be used to tune logging performance.
+ </p>
+ <a name="SysPropsAllAsync" />
+ <table>
+ <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>
- <td>AsyncLogger.ExceptionHandler</td>
- <td>
- <tt>null</tt>
- </td>
- <td>
- Fully qualified name of a class that implements the
- <tt>com.lmax.disruptor.ExceptionHandler</tt>
- interface. The class needs to have a public
- zero-argument
- constructor. If specified, this class
- will be notified when an
- exception occurs while
- logging the messages.
- </td>
- </tr>
- <tr>
- <td>AsyncLogger.RingBufferSize</td>
- <td>256 * 1024</td>
- <td>
- Size (number of slots) in the RingBuffer used by the
- asynchronous logging subsystem.
- Make this value large enough to
- deal with bursts
- of activity. The minimum size is 128.
- The
- RingBuffer will
- be pre-allocated at first use and will never grow
- or shrink during the life of the system.
- </td>
- </tr>
- <tr>
- <td>AsyncLogger.WaitStrategy</td>
- <td>
- <tt>Sleep</tt>
- </td>
- <td>
- Valid values: Block, Sleep, Yield.
- <br />
- <tt>Block</tt>
- is a strategy that uses a lock and
- condition
- variable for the I/O thread waiting for log events.
- Block can be used when
- throughput and low-latency
- are not as important as CPU resource.
- Recommended for resource constrained/virtualised environments.
- <br />
- <tt>Sleep</tt>
- is a strategy that initially spins, then
- uses a Thread.yield(), and
- eventually parks for the
- 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
- latency for actually getting the message logged.
- <br />
- <tt>Yield</tt>
- is a strategy that uses a Thread.yield() for
- waiting for log events after an initially spinning.
- Yield is a good compromise between performance
- and CPU resource, but may use more CPU than Sleep
- in order to get the message logged to disk sooner.
- </td>
- </tr>
- <tr>
- <td>AsyncLogger.ThreadNameStrategy</td>
- <td>
- <tt>CACHED</tt>
- </td>
- <td>
- Valid values: CACHED, UNCACHED.
- <br />
- By default, AsyncLogger caches the thread name
- 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>
- <td>log4j.Clock</td>
- <td>
- <tt>SystemClock</tt>
- </td>
- <td>
- <p>Implementation of the
- <tt>org.apache.logging.log4j.core.helpers.Clock</tt>
- interface that is used for timestamping the log
- events when all loggers are asynchronous.
- <br />
- By default, <tt>System.currentTimeMillis</tt>
- is called on every log event.
- </p>
- <p>
- <tt>CachedClock</tt>
- is an optimization intended for low-latency applications where
- time stamps are generated from a clock that
- updates its internal time in a background thread once
- every millisecond, or every 1024 log events,
- whichever comes first. This
- reduces logging latency a little, at the cost of
- some precision in the logged time stamps.
- Unless you are logging many
- events, you may see "jumps"
- of 10-16 milliseconds between log time stamps.
- WEB APPLICATION WARNING: The use of a background thread may cause issues
- for web applications and OSGi applications
- so CachedClock is not recommended for this kind
- of applications.
- </p><p>
- You can also specify a fully qualified class name
- of a custom class that implements the
- <tt>Clock</tt> interface.</p>
- </td>
- </tr>
- </table>
- </subsection>
- <a name="MixedSync-Async" />
- <subsection name="Mixing Synchronous and Asynchronous Loggers">
- <p><i>Requires disruptor-3.0.0.jar or higher on the classpath.
- There is no need to set system property "Log4jContextSelector" to any value.</i></p>
- <p>
- Synchronous and asynchronous loggers can be combined in
- configuration. This gives you more flexibility at the cost
- of a
- slight loss in performance (compared to making
- all loggers asynchronous). Use the
- <tt><asyncRoot></tt>
- or
- <tt><asyncLogger></tt>
- configuration elements to specify the loggers that need to
- be
- asynchronous. The same configuration file can also
- contain
- <tt><root></tt>
- and
- <tt><logger></tt>
- elements for the synchronous loggers.
- </p>
- <p>
- By default, <a href="#Location">location</a> is not passed to the I/O thread by
- 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,
- including the root logger.
- </p>
- <p>
- A configuration that mixes asynchronous loggers might look like:
+ <th>System Property</th>
+ <th>Default Value</th>
+ <th>Description</th>
+ </tr>
+ <tr>
+ <td>AsyncLogger.ExceptionHandler</td>
+ <td>
+ <tt>null</tt>
+ </td>
+ <td>
+ Fully qualified name of a class that implements the <tt>com.lmax.disruptor.ExceptionHandler</tt>
+ interface. The class needs to have a public zero-argument constructor.
+ If specified, this class will be notified when an exception occurs while logging the messages.
+ </td>
+ </tr>
+ <tr>
+ <td>AsyncLogger.RingBufferSize</td>
+ <td>256 * 1024</td>
+ <td>
+ Size (number of slots) in the RingBuffer used by the asynchronous logging subsystem.
+ Make this value large enough to deal with bursts of activity. The minimum size is 128.
+ The RingBuffer will be pre-allocated at first use and will never grow or shrink
+ during the life of the system.
+ </td>
+ </tr>
+ <tr>
+ <td>AsyncLogger.WaitStrategy</td>
+ <td>
+ <tt>Sleep</tt>
+ </td>
+ <td>
+ Valid values: Block, Sleep, Yield.
+ <br />
+ <tt>Block</tt> is a strategy that uses a lock and condition variable for the I/O thread waiting for log events.
+ Block can be used when throughput and low-latency are not as important as CPU resource.
+ Recommended for resource constrained/virtualised environments.
+ <br />
+ <tt>Sleep</tt> is a strategy that initially spins, then uses a Thread.yield(), and
+ eventually parks for the 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
+ latency for actually getting the message logged.
+ <br />
+ <tt>Yield</tt> is a strategy that uses a Thread.yield() for waiting for log events after an initially spinning.
+ Yield is a good compromise between performance and CPU resource, but may use more CPU than Sleep
+ in order to get the message logged to disk sooner.
+ </td>
+ </tr>
+ <tr>
+ <td>AsyncLogger.ThreadNameStrategy</td>
+ <td>
+ <tt>CACHED</tt>
+ </td>
+ <td>
+ Valid values: CACHED, UNCACHED.
+ <br />
+ By default, AsyncLogger caches the thread name 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>
+ <td>log4j.Clock</td>
+ <td>
+ <tt>SystemClock</tt>
+ </td>
+ <td>
+ <p>
+ Implementation of the <tt>org.apache.logging.log4j.core.helpers.Clock</tt>
+ interface that is used for timestamping the log events when all loggers are asynchronous.
+ <br />
+ By default, <tt>System.currentTimeMillis</tt> is called on every log event.
+ </p>
+ <p>
+ <tt>CachedClock</tt> is an optimization intended for low-latency applications where
+ time stamps are generated from a clock that updates its internal time in a background thread once
+ every millisecond, or every 1024 log events, whichever comes first.
+ This reduces logging latency a little, at the cost of some precision in the logged time stamps.
+ Unless you are logging many events, you may see "jumps" of 10-16 milliseconds between log time stamps.
+ WEB APPLICATION WARNING: The use of a background thread may cause issues
+ for web applications and OSGi applications so CachedClock is not recommended for this kind
+ of applications.
+ </p>
+ <p>
+ You can also specify a fully qualified class name of a custom class that implements the
+ <tt>Clock</tt> interface.
+ </p>
+ </td>
+ </tr>
+ </table>
+ </subsection>
+ <a name="MixedSync-Async" />
+ <subsection name="Mixing Synchronous and Asynchronous Loggers">
+ <p><i>Requires disruptor-3.0.0.jar or higher on the classpath. There is no need to set system property
+ "Log4jContextSelector" to any value.</i></p>
+ <p>
+ Synchronous and asynchronous loggers can be combined in configuration.
+ This gives you more flexibility at the cost of a slight loss in performance (compared to making
+ all loggers asynchronous). Use the <tt><asyncRoot></tt> or <tt><asyncLogger></tt>
+ configuration elements to specify the loggers that need to be asynchronous.
+ The same configuration file can also contain <tt><root></tt> and
+ <tt><logger></tt> elements for the synchronous loggers.
+ </p>
+ <p>
+ By default, <a href="#Location">location</a> is not passed to the I/O thread by 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, including the root logger.
</p>
- <pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
+ <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
when using <asyncLogger> or <asyncRoot>. -->
@@ -409,762 +317,642 @@
</Root>
</Loggers>
</Configuration>]]></pre>
- <p>
- There are a few system properties
- you can use to control
- aspects of the asynchronous logging subsystem.
- Some of these can be used to
- tune logging performance.
- </p>
- <a name="SysPropsMixedSync-Async" />
- <table>
- <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>
- <td>AsyncLoggerConfig.ExceptionHandler</td>
- <td>
- <tt>null</tt>
- </td>
- <td>
- Fully qualified name of a class that implements the
- <tt>com.lmax.disruptor.ExceptionHandler</tt>
- interface. The class needs to have a public
- zero-argument
- constructor. If specified, this class
- will be notified when an
- exception occurs while
- logging the messages.
- </td>
- </tr>
- <tr>
- <td>AsyncLoggerConfig.RingBufferSize</td>
- <td>256 * 1024
- </td>
- <td>
- Size (number of slots) in the RingBuffer used by the
- asynchronous logging subsystem.
- Make this value large enough to
- deal with bursts
- of activity. The minimum size is 128.
- The RingBuffer will
- be pre-allocated at first use and will never grow
- or shrink during the life of the system.
- </td>
- </tr>
- <tr>
- <td>AsyncLoggerConfig.WaitStrategy</td>
- <td>
- <tt>Sleep</tt>
- </td>
- <td>
- Valid values: Block, Sleep, Yield.
- <br />
- <tt>Block</tt>
- is a strategy that uses a lock and
- condition
- variable for the I/O thread waiting for log events.
- Block can be used when
- throughput and low-latency
- are not as important as CPU resource.
- Recommended for resource constrained/virtualised environments.
- <br />
- <tt>Sleep</tt>
- is a strategy that initially spins, then
- uses a Thread.yield(), and
- eventually parks for the
- 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
- latency for actually getting the message logged.
- <br />
- <tt>Yield</tt>
- is a strategy that uses a Thread.yield() for
- waiting for log events after an initially spinning.
- Yield is a good compromise between performance
- and CPU resource, but may use more CPU than Sleep
- in order to get the message logged to disk sooner.
- </td>
- </tr>
- </table>
- </subsection>
- <a name="Location" />
- <subsection name="Location, location, location...">
<p>
- If one of the layouts is
- configured with a location-related attribute like
- HTML <a href="layouts.html#HtmlLocationInfo">locationInfo</a>,
- 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>,
- <a href="layouts.html#PatternLine">%L or %line</a>,
- <a href="layouts.html#PatternMethod">%M or %method</a>,
- Log4j will take a snapshot of the
- stack, and walk the stack trace to find the location information.
- </p>
- <p>
- 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.
- </p><p>
- However,
- asynchronous loggers need to make this decision before passing the
- log message to another thread; the location information will be
- lost after that point.
- The performance impact of taking a stack trace snapshot is even
- higher for asynchronous loggers: logging with location is
- 4 - 20 times slower than without location.
- 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
- by specifying
- <tt>includeLocation="true"</tt>.
- </p>
- <p>
- </p>
- </subsection>
- <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
- in the Log4j 2 unit test source directory.
- All tests were done using the
- default settings (SystemClock and SleepingWaitStrategy).
- The methodology used was the same for all tests:
- </p>
- <ul>
- <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.
- 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>
- <li>Throughput test: measure how long it takes to execute 256 *
- 1024 / threadCount calls to Logger.log and express the
- result in messages per second.</li>
- <li>Repeat the test 5 times and average the results.</li>
- </ul>
- <p>The results below were obtained with log4j-2.0-beta5, disruptor-3.0.0.beta3,
- log4j-1.2.17 and logback-1.0.10.</p>
- <h4>Logging Throughput</h4>
- <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
- synchronous loggers.
- </p>
- <p>
- 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.
- </p>
- <p><img src="../images/async-vs-sync-throughput.png" alt="Async loggers have much higher throughput than sync loggers." /></p>
+ There are a few system properties you can use to control aspects of the asynchronous logging subsystem.
+ Some of these can be used to tune logging performance.
+ </p>
+ <a name="SysPropsMixedSync-Async" />
+ <table>
+ <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>
+ <td>AsyncLoggerConfig.ExceptionHandler</td>
+ <td>
+ <tt>null</tt>
+ </td>
+ <td>
+ Fully qualified name of a class that implements the <tt>com.lmax.disruptor.ExceptionHandler</tt>
+ interface. The class needs to have a public zero-argument constructor.
+ If specified, this class will be notified when an exception occurs while logging the messages.
+ </td>
+ </tr>
+ <tr>
+ <td>AsyncLoggerConfig.RingBufferSize</td>
+ <td>256 * 1024</td>
+ <td>
+ Size (number of slots) in the RingBuffer used by the asynchronous logging subsystem.
+ Make this value large enough to deal with bursts of activity. The minimum size is 128.
+ The RingBuffer will be pre-allocated at first use and will never grow
+ or shrink during the life of the system.
+ </td>
+ </tr>
+ <tr>
+ <td>AsyncLoggerConfig.WaitStrategy</td>
+ <td>
+ <tt>Sleep</tt>
+ </td>
+ <td>
+ Valid values: Block, Sleep, Yield.
+ <br />
+ <tt>Block</tt> is a strategy that uses a lock and condition variable for the I/O thread waiting for log events.
+ Block can be used when throughput and low-latency are not as important as CPU resource.
+ Recommended for resource constrained/virtualised environments.
+ <br />
+ <tt>Sleep</tt> is a strategy that initially spins, then uses a Thread.yield(), and
+ eventually parks for the 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
+ latency for actually getting the message logged.
+ <br />
+ <tt>Yield</tt> is a strategy that uses a Thread.yield() for waiting for log events after an initially spinning.
+ Yield is a good compromise between performance and CPU resource, but may use more CPU than Sleep
+ in order to get the message logged to disk sooner.
+ </td>
+ </tr>
+ </table>
+ </subsection>
+ <a name="Location" />
+ <subsection name="Location, location, location...">
+ <p>
+ If one of the layouts is configured with a location-related attribute like HTML
+ <a href="layouts.html#HtmlLocationInfo">locationInfo</a>,
+ 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>,
+ <a href="layouts.html#PatternLine">%L or %line</a>,
+ <a href="layouts.html#PatternMethod">%M or %method</a>,
+ Log4j will take a snapshot of the stack, and walk the stack trace to find the location information.
+ </p>
+ <p>
+ 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.
+ </p>
+ <p>
+ However, asynchronous loggers need to make this decision before passing the
+ log message to another thread; the location information will be lost after that point.
+ The performance impact of taking a stack trace snapshot is even higher for asynchronous loggers:
+ logging with location is 4 - 20 times slower than without location.
+ 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
+ by specifying <tt>includeLocation="true"</tt>.
+ </p>
+ <p>
+ </p>
+ </subsection>
+ <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 in the Log4j 2 unit test source directory.
+ All tests were done using the default settings (SystemClock and SleepingWaitStrategy).
+ The methodology used was the same for all tests:
+ </p>
+ <ul>
+ <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.
+ 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>
+ <li>Throughput test: measure how long it takes to execute 256 * 1024 / threadCount calls to Logger.log
+ and express the result in messages per second.
+ </li>
+ <li>Repeat the test 5 times and average the results.</li>
+ </ul>
+ <p>The results below were obtained with log4j-2.0-beta5, disruptor-3.0.0.beta3,
+ log4j-1.2.17 and logback-1.0.10.
+ </p>
+ <h4>Logging Throughput</h4>
+ <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
+ synchronous loggers.
+ </p>
+ <p>
+ 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.
+ </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
- 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" 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>
- <caption align="top">Throughput per thread in messages/second</caption>
- <tr>
- <th>Logger</th>
- <th>1 thread</th>
- <th>2 threads</th>
- <th>4 threads</th>
- <th>8 threads</th>
- <th>16 threads</th>
- <th>32 threads</th>
- <th>64 threads</th>
- </tr>
- <tr>
- <td>Log4j 2: Loggers all asynchronous</td>
- <td align="right">2,652,412</td>
- <td align="right">909,119</td>
- <td align="right">776,993</td>
- <td align="right">516,365</td>
- <td align="right">239,246</td>
- <td align="right">253,791</td>
- <td align="right">288,997</td>
- </tr>
- <tr>
- <td>Log4j 2: Loggers mixed sync/async</td>
- <td align="right">2,454,358</td>
- <td align="right">839,394</td>
- <td align="right">854,578</td>
- <td align="right">597,913</td>
- <td align="right">261,003</td>
- <td align="right">216,863</td>
- <td align="right">218,937</td>
- </tr>
- <tr>
- <td>Log4j 2: Async Appender</td>
- <td align="right">1,713,429</td>
- <td align="right">603,019</td>
- <td align="right">331,506</td>
- <td align="right">149,408</td>
- <td align="right">86,107</td>
- <td align="right">45,529</td>
- <td align="right">23,980</td>
- </tr>
- <tr>
- <td>Log4j1: Async Appender</td>
- <td align="right">2,239,664</td>
- <td align="right">494,470</td>
- <td align="right">221,402</td>
- <td align="right">109,314</td>
- <td align="right">60,580</td>
- <td align="right">31,706</td>
- <td align="right">14,072</td>
- </tr>
- <tr>
- <td>Logback: Async Appender</td>
- <td align="right">2,206,907</td>
- <td align="right">624,082</td>
- <td align="right">307,500</td>
- <td align="right">160,096</td>
- <td align="right">85,701</td>
- <td align="right">43,422</td>
- <td align="right">21,303</td>
- </tr>
- <tr>
- <td>Log4j 2: Synchronous</td>
- <td align="right">273,536</td>
- <td align="right">136,523</td>
- <td align="right">67,609</td>
- <td align="right">34,404</td>
- <td align="right">15,373</td>
- <td align="right">7,903</td>
- <td align="right">4,253</td>
- </tr>
- <tr>
- <td>Log4j1: Synchronous</td>
- <td align="right">326,894</td>
- <td align="right">105,591</td>
- <td align="right">57,036</td>
- <td align="right">30,511</td>
- <td align="right">13,900</td>
- <td align="right">7,094</td>
- <td align="right">3,509</td>
- </tr>
- <tr>
- <td>Logback: Synchronous</td>
- <td align="right">178,063</td>
- <td align="right">65,000</td>
- <td align="right">34,372</td>
- <td align="right">16,903</td>
- <td align="right">8,334</td>
- <td align="right">3,985</td>
- <td align="right">1,967</td>
- </tr>
- </table>
- <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>
- <caption align="top">Throughput per thread in messages/second</caption>
- <tr>
- <th>Logger</th>
- <th>1 thread</th>
- <th>2 threads</th>
- <th>4 threads</th>
- <th>8 threads</th>
- <th>16 threads</th>
- <th>32 threads</th>
- </tr>
- <tr>
- <td>Log4j 2: Loggers all asynchronous</td>
- <td align="right">1,715,344</td>
- <td align="right">928,951</td>
- <td align="right">1,045,265</td>
- <td align="right">1,509,109</td>
- <td align="right">1,708,989</td>
- <td align="right">773,565</td>
- </tr>
- <tr>
- <td>Log4j 2: Loggers mixed sync/async</td>
- <td align="right">571,099</td>
- <td align="right">1,204,774</td>
- <td align="right">1,632,204</td>
- <td align="right">1,368,041</td>
- <td align="right">462,093</td>
- <td align="right">908,529</td>
- </tr>
- <tr>
- <td>Log4j 2: Async Appender</td>
- <td align="right">1,236,548</td>
- <td align="right">1,006,287</td>
- <td align="right">511,571</td>
- <td align="right">302,230</td>
- <td align="right">160,094</td>
- <td align="right">60,152</td>
- </tr>
- <tr>
- <td>Log4j1: Async Appender</td>
- <td align="right">1,373,195</td>
- <td align="right">911,657</td>
- <td align="right">636,899</td>
- <td align="right">406,405</td>
- <td align="right">202,777</td>
- <td align="right">162,964</td>
- </tr>
- <tr>
- <td>Logback: Async Appender</td>
- <td align="right">1,979,515</td>
- <td align="right">783,722</td>
- <td align="right">582,935</td>
- <td align="right">289,905</td>
- <td align="right">172,463</td>
- <td align="right">133,435</td>
- </tr>
- <tr>
- <td>Log4j 2: Synchronous</td>
- <td align="right">281,250</td>
- <td align="right">225,731</td>
- <td align="right">129,015</td>
- <td align="right">66,590</td>
- <td align="right">34,401</td>
- <td align="right">17,347</td>
- </tr>
- <tr>
- <td>Log4j1: Synchronous</td>
- <td align="right">147,824</td>
- <td align="right">72,383</td>
- <td align="right">32,865</td>
- <td align="right">18,025</td>
- <td align="right">8,937</td>
- <td align="right">4,440</td>
- </tr>
- <tr>
- <td>Logback: Synchronous</td>
- <td align="right">149,811</td>
- <td align="right">66,301</td>
- <td align="right">32,341</td>
- <td align="right">16,962</td>
- <td align="right">8,431</td>
- <td align="right">3,610</td>
- </tr>
- </table>
+ <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
+ 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" 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>
+ <caption align="top">Throughput per thread in
+ messages/second</caption>
+ <tr>
+ <th>Logger</th>
+ <th>1 thread</th>
+ <th>2 threads</th>
+ <th>4 threads</th>
+ <th>8 threads</th>
+ <th>16 threads</th>
+ <th>32 threads</th>
+ <th>64 threads</th>
+ </tr>
+ <tr>
+ <td>Log4j 2: Loggers all asynchronous</td>
+ <td align="right">2,652,412</td>
+ <td align="right">909,119</td>
+ <td align="right">776,993</td>
+ <td align="right">516,365</td>
+ <td align="right">239,246</td>
+ <td align="right">253,791</td>
+ <td align="right">288,997</td>
+ </tr>
+ <tr>
+ <td>Log4j 2: Loggers mixed sync/async</td>
+ <td align="right">2,454,358</td>
+ <td align="right">839,394</td>
+ <td align="right">854,578</td>
+ <td align="right">597,913</td>
+ <td align="right">261,003</td>
+ <td align="right">216,863</td>
+ <td align="right">218,937</td>
+ </tr>
+ <tr>
+ <td>Log4j 2: Async Appender</td>
+ <td align="right">1,713,429</td>
+ <td align="right">603,019</td>
+ <td align="right">331,506</td>
+ <td align="right">149,408</td>
+ <td align="right">86,107</td>
+ <td align="right">45,529</td>
+ <td align="right">23,980</td>
+ </tr>
+ <tr>
+ <td>Log4j1: Async Appender</td>
+ <td align="right">2,239,664</td>
+ <td align="right">494,470</td>
+ <td align="right">221,402</td>
+ <td align="right">109,314</td>
+ <td align="right">60,580</td>
+ <td align="right">31,706</td>
+ <td align="right">14,072</td>
+ </tr>
+ <tr>
+ <td>Logback: Async Appender</td>
+ <td align="right">2,206,907</td>
+ <td align="right">624,082</td>
+ <td align="right">307,500</td>
+ <td align="right">160,096</td>
+ <td align="right">85,701</td>
+ <td align="right">43,422</td>
+ <td align="right">21,303</td>
+ </tr>
+ <tr>
+ <td>Log4j 2: Synchronous</td>
+ <td align="right">273,536</td>
+ <td align="right">136,523</td>
+ <td align="right">67,609</td>
+ <td align="right">34,404</td>
+ <td align="right">15,373</td>
+ <td align="right">7,903</td>
+ <td align="right">4,253</td>
+ </tr>
+ <tr>
+ <td>Log4j1: Synchronous</td>
+ <td align="right">326,894</td>
+ <td align="right">105,591</td>
+ <td align="right">57,036</td>
+ <td align="right">30,511</td>
+ <td align="right">13,900</td>
+ <td align="right">7,094</td>
+ <td align="right">3,509</td>
+ </tr>
+ <tr>
+ <td>Logback: Synchronous</td>
+ <td align="right">178,063</td>
+ <td align="right">65,000</td>
+ <td align="right">34,372</td>
+ <td align="right">16,903</td>
+ <td align="right">8,334</td>
+ <td align="right">3,985</td>
+ <td align="right">1,967</td>
+ </tr>
+ </table>
+ <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>
+ <caption align="top">Throughput per thread in
+ messages/second</caption>
+ <tr>
+ <th>Logger</th>
+ <th>1 thread</th>
+ <th>2 threads</th>
+ <th>4 threads</th>
+ <th>8 threads</th>
+ <th>16 threads</th>
+ <th>32 threads</th>
+ </tr>
+ <tr>
+ <td>Log4j 2: Loggers all asynchronous</td>
+ <td align="right">1,715,344</td>
+ <td align="right">928,951</td>
+ <td align="right">1,045,265</td>
+ <td align="right">1,509,109</td>
+ <td align="right">1,708,989</td>
+ <td align="right">773,565</td>
+ </tr>
+ <tr>
+ <td>Log4j 2: Loggers mixed sync/async</td>
+ <td align="right">571,099</td>
+ <td align="right">1,204,774</td>
+ <td align="right">1,632,204</td>
+ <td align="right">1,368,041</td>
+ <td align="right">462,093</td>
+ <td align="right">908,529</td>
+ </tr>
+ <tr>
+ <td>Log4j 2: Async Appender</td>
+ <td align="right">1,236,548</td>
+ <td align="right">1,006,287</td>
+ <td align="right">511,571</td>
+ <td align="right">302,230</td>
+ <td align="right">160,094</td>
+ <td align="right">60,152</td>
+ </tr>
+ <tr>
+ <td>Log4j1: Async Appender</td>
+ <td align="right">1,373,195</td>
+ <td align="right">911,657</td>
+ <td align="right">636,899</td>
+ <td align="right">406,405</td>
+ <td align="right">202,777</td>
+ <td align="right">162,964</td>
+ </tr>
+ <tr>
+ <td>Logback: Async Appender</td>
+ <td align="right">1,979,515</td>
+ <td align="right">783,722</td>
+ <td align="right">582,935</td>
+ <td align="right">289,905</td>
+ <td align="right">172,463</td>
+ <td align="right">133,435</td>
+ </tr>
+ <tr>
+ <td>Log4j 2: Synchronous</td>
+ <td align="right">281,250</td>
+ <td align="right">225,731</td>
+ <td align="right">129,015</td>
+ <td align="right">66,590</td>
+ <td align="right">34,401</td>
+ <td align="right">17,347</td>
+ </tr>
+ <tr>
+ <td>Log4j1: Synchronous</td>
+ <td align="right">147,824</td>
+ <td align="right">72,383</td>
+ <td align="right">32,865</td>
+ <td align="right">18,025</td>
+ <td align="right">8,937</td>
+ <td align="right">4,440</td>
+ </tr>
+ <tr>
+ <td>Logback: Synchronous</td>
+ <td align="right">149,811</td>
+ <td align="right">66,301</td>
+ <td align="right">32,341</td>
+ <td align="right">16,962</td>
+ <td align="right">8,431</td>
+ <td align="right">3,610</td>
+ </tr>
+ </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>
+ <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>
<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>
- <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>
- <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>
- <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>
- <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>
- </table>
- <p>As expected, logging location information
- 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,
- asynchronous logging will still be faster than synchronous logging.</p>
+ <th>Logger (Log4j 2)</th>
+ <th>1 thread</th>
+ <th>2 threads</th>
+ <th>4 threads</th>
+ <th>8 threads</th>
+ </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>
+ <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>
+ <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>
+ <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>
+ </table>
+ <p>As expected, logging location information 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, asynchronous logging will still be faster than synchronous logging.
+ </p>
- <a name="Latency" />
- <h4>Latency</h4>
- <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.
- 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" 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>
- <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>1 thread</th>
- <th>64 threads</th>
- <th>1 thread</th>
- <th>64 threads</th>
- <th>1 thread</th>
- <th>64 threads</th>
- </tr>
- <tr>
- <td>Log4j 2: Loggers all async</td>
- <td align="right">677</td>
- <td align="right">4,135</td>
- <td align="right">1,638</td>
- <td align="right">4,096</td>
- <td align="right">8,192</td>
- <td align="right">16,128</td>
- </tr>
- <tr>
- <td>Log4j 2: Loggers mixed
- sync/async</td>
- <td align="right">648</td>
- <td align="right">4,873</td>
- <td align="right">1,228</td>
- <td align="right">4,096</td>
- <td align="right">8,192</td>
- <td align="right">16,384</td>
- </tr>
- <tr>
- <td>Log4j 2: Async Appender</td>
- <td align="right">2,423</td>
- <td align="right">2,117,722</td>
- <td align="right">4,096</td>
- <td align="right">67,108,864</td>
- <td align="right">16,384</td>
- <td align="right">268,435,456</td>
- </tr>
- <tr>
- <td>Log4j1: Async Appender</td>
- <td align="right">1,562</td>
- <td align="right">1,781,404</td>
- <td align="right">4,096</td>
- <td align="right">109,051,904</td>
- <td align="right">16,384</td>
- <td align="right">268,435,456</td>
- </tr>
- <tr>
- <td>Logback: Async Appender</td>
- <td align="right">2,123</td>
- <td align="right">2,079,020</td>
- <td align="right">3,276</td>
- <td align="right">67,108,864</td>
- <td align="right">14,745</td>
- <td align="right">268,435,456</td>
- </tr>
- </table>
- <p>
- 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
- average latency, two or three times that of asynchronous loggers.
- With more threads, the average latency of
- asynchronous appenders is orders of magnitude larger than
- asynchronous loggers.
- </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
- observations with other logging methods.
- When increasing the number of threads
- 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" alt="Maximum async logger latency" />
- </p>
+ <a name="Latency" />
+ <h4>Latency</h4>
+ <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.
+ 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"
+ 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>
+ <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>1 thread</th>
+ <th>64 threads</th>
+ <th>1 thread</th>
+ <th>64 threads</th>
+ <th>1 thread</th>
+ <th>64 threads</th>
+ </tr>
+ <tr>
+ <td>Log4j 2: Loggers all async</td>
+ <td align="right">677</td>
+ <td align="right">4,135</td>
+ <td align="right">1,638</td>
+ <td align="right">4,096</td>
+ <td align="right">8,192</td>
+ <td align="right">16,128</td>
+ </tr>
+ <tr>
+ <td>Log4j 2: Loggers mixed sync/async</td>
+ <td align="right">648</td>
+ <td align="right">4,873</td>
+ <td align="right">1,228</td>
+ <td align="right">4,096</td>
+ <td align="right">8,192</td>
+ <td align="right">16,384</td>
+ </tr>
+ <tr>
+ <td>Log4j 2: Async Appender</td>
+ <td align="right">2,423</td>
+ <td align="right">2,117,722</td>
+ <td align="right">4,096</td>
+ <td align="right">67,108,864</td>
+ <td align="right">16,384</td>
+ <td align="right">268,435,456</td>
+ </tr>
+ <tr>
+ <td>Log4j1: Async Appender</td>
+ <td align="right">1,562</td>
+ <td align="right">1,781,404</td>
+ <td align="right">4,096</td>
+ <td align="right">109,051,904</td>
+ <td align="right">16,384</td>
+ <td align="right">268,435,456</td>
+ </tr>
+ <tr>
+ <td>Logback: Async Appender</td>
+ <td align="right">2,123</td>
+ <td align="right">2,079,020</td>
+ <td align="right">3,276</td>
+ <td align="right">67,108,864</td>
+ <td align="right">14,745</td>
+ <td align="right">268,435,456</td>
+ </tr>
+ </table>
+ <p>
+ 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 average latency, two or three times that of asynchronous loggers.
+ With more threads, the average latency of asynchronous appenders is orders of magnitude larger than
+ asynchronous loggers.
+ </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
+ observations with other logging methods.
+ When increasing the number of threads 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" alt="Maximum async logger latency" />
+ </p>
- <a name="RandomAccessFileAppenderPerformance" />
- <h4>FileAppender vs. RandomAccessFileAppender</h4>
- <p>The appender comparison below was done with <em>synchronous loggers</em>.
- </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>
+ <a name="RandomAccessFileAppenderPerformance" />
+ <h4>FileAppender vs. RandomAccessFileAppender</h4>
+ <p>
+ The appender comparison below was done with <em>synchronous loggers</em>.
+ </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>
<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>
- <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>
- <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>
- <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>
- <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>
- </table>
- <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>
+ <th>Appender</th>
+ <th>1 thread</th>
+ <th>2 threads</th>
+ <th>4 threads</th>
+ <th>8 threads</th>
+ </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>
+ <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>
+ <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>
+ <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>
+ </table>
+ <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>
<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>
- <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>
- <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>
- <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>
- <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>
- </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.
- 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>
- <li>Change a parameter (e.g. WaitStrategy or RingBufferSize) and
- run the tests again. Check performance results.</li>
- <li>Repeat (2) until you find a parameter combination that gives acceptable performance.</li>
- </ol>
- <p>Use the following command to run the performance tests:</p>
- <blockquote>
- <tt>java -cp log4j-async-2.0-tests.jar:log4j-async-2.0.jar:disruptor-3.0.0.jar:log4j-api-2.0.jar:log4j-core-2.0.jar \<br />
- [-DWaitStrategy=Sleep] [-DRingBufferSize=262144] org.apache.logging.log4j.async.perftest.PerfTestDriver [path-to-java] [repeats]</tt>
- <br /><br />
- [<b>WaitStrategy</b>] is an optional system property with valid values "Block", "Sleep", or "Yield".
- Details are documented under "System Properties to configure ... loggers".
- <br />
- [<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
- "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>
- <th>1 thread</th>
- <th>2 threads</th>
- <th>4 threads</th>
- <th>8 threads</th>
- </tr>
- <tr>
- <td rowspan="3" valign="top">All Async System Clock</td>
- <td align="center">Block</td>
- <td align="right">1,717,261</td>
- <td align="right">727,075</td>
- <td align="right">263,760</td>
- <td align="right">150,533</td>
- </tr>
- <tr>
- <td align="center">Sleep</td>
- <td align="right">1,568,623</td>
- <td align="right">948,653</td>
- <td align="right">629,951</td>
- <td align="right">651,340</td>
- </tr>
- <tr>
- <td align="center">Yield</td>
- <td align="right">1,618,103</td>
- <td align="right">884,314</td>
- <td align="right">628,008</td>
- <td align="right">675,879</td>
- </tr>
- <tr>
- <td rowspan="3" valign="top">All Async Cached Clock</td>
- <td align="center">Block</td>
- <td align="right">2,771,734</td>
- <td align="right">642,899</td>
- <td align="right">331,003</td>
- <td align="right">172,877</td>
- </tr>
- <tr>
- <td align="center">Sleep</td>
- <td align="right">2,393,901</td>
- <td align="right">1,211,425</td>
- <td align="right">770,416</td>
- <td align="right">632,361</td>
- </tr>
- <tr>
- <td align="center">Yield</td>
- <td align="right">2,331,763</td>
- <td align="right">1,132,529</td>
- <td align="right">684,109</td>
- <td align="right">671,957</td>
- </tr>
- <tr>
- <td rowspan="3" valign="top">Mixed Async</td>
- <td align="center">Block</td>
- <td align="right">1,347,853</td>
- <td align="right">443,652</td>
- <td align="right">251,433</td>
- <td align="right">136,152</td>
- </tr>
- <tr>
- <td align="center">Sleep</td>
- <td align="right">1,371,511</td>
- <td align="right">567,829</td>
- <td align="right">407,676</td>
- <td align="right">408,071</td>
- </tr>
- <tr>
- <td align="center">Yield</td>
- <td align="right">1,360,267</td>
- <td align="right">675,570</td>
- <td align="right">389,609</td>
- <td align="right">391,969</td>
- </tr>
- </table>
- </subsection>
- -->
- <a name="UnderTheHood" />
- <subsection name="Under The Hood">
- <p>
- Asynchronous Loggers are implemented using the
- <a href="http://lmax-exchange.github.com/disruptor/">LMAX Disruptor</a>
- inter-thread messaging library. From the LMAX web site:
- </p>
- <blockquote>
- <p>... using queues to pass
- data between stages of the system was
- 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
- CPU-level, and locks requiring kernel
- arbitration are both extremely costly, so we created a
- framework which has "mechanical sympathy" for
- the hardware it's running on, and that's lock-free.
- </p>
- </blockquote>
+ <th>Appender</th>
+ <th>1 thread</th>
+ <th>2 threads</th>
+ <th>4 threads</th>
+ <th>8 threads</th>
+ </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>
+ <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>
+ <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>
+ <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>
+ </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. 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>
+ <li>Change a parameter (e.g. WaitStrategy or RingBufferSize) and run the
+ tests again. Check performance results.</li> <li>Repeat (2) until you find
+ a parameter combination that gives acceptable performance.</li> </ol> <p>Use
+ the following command to run the performance tests:</p> <blockquote> <tt>java
+ -cp log4j-async-2.0-tests.jar:log4j-async-2.0.jar:disruptor-3.0.0.jar:log4j-api-2.0.jar:log4j-core-2.0.jar
+ \<br /> [-DWaitStrategy=Sleep] [-DRingBufferSize=262144] org.apache.logging.log4j.async.perftest.PerfTestDriver
+ [path-to-java] [repeats]</tt> <br /><br /> [<b>WaitStrategy</b>] is an optional
+ system property with valid values "Block", "Sleep", or "Yield". Details are
+ documented under "System Properties to configure ... loggers". <br /> [<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 "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>
+ <th>1 thread</th> <th>2 threads</th> <th>4 threads</th> <th>8 threads</th>
+ </tr> <tr> <td rowspan="3" valign="top">All Async System Clock</td> <td align="center">Block</td>
+ <td align="right">1,717,261</td> <td align="right">727,075</td> <td align="right">263,760</td>
+ <td align="right">150,533</td> </tr> <tr> <td align="center">Sleep</td> <td
+ align="right">1,568,623</td> <td align="right">948,653</td> <td align="right">629,951</td>
+ <td align="right">651,340</td> </tr> <tr> <td align="center">Yield</td> <td
+ align="right">1,618,103</td> <td align="right">884,314</td> <td align="right">628,008</td>
+ <td align="right">675,879</td> </tr> <tr> <td rowspan="3" valign="top">All
+ Async Cached Clock</td> <td align="center">Block</td> <td align="right">2,771,734</td>
+ <td align="right">642,899</td> <td align="right">331,003</td> <td align="right">172,877</td>
+ </tr> <tr> <td align="center">Sleep</td> <td align="right">2,393,901</td>
+ <td align="right">1,211,425</td> <td align="right">770,416</td> <td align="right">632,361</td>
+ </tr> <tr> <td align="center">Yield</td> <td align="right">2,331,763</td>
+ <td align="right">1,132,529</td> <td align="right">684,109</td> <td align="right">671,957</td>
+ </tr> <tr> <td rowspan="3" valign="top">Mixed Async</td> <td align="center">Block</td>
+ <td align="right">1,347,853</td> <td align="right">443,652</td> <td align="right">251,433</td>
+ <td align="right">136,152</td> </tr> <tr> <td align="center">Sleep</td> <td
+ align="right">1,371,511</td> <td align="right">567,829</td> <td align="right">407,676</td>
+ <td align="right">408,071</td> </tr> <tr> <td align="center">Yield</td> <td
+ align="right">1,360,267</td> <td align="right">675,570</td> <td align="right">389,609</td>
+ <td align="right">391,969</td> </tr> </table> </subsection> -->
+ <a name="UnderTheHood" />
+ <subsection name="Under The Hood">
+ <p>
+ Asynchronous Loggers are implemented using the
+ <a href="http://lmax-exchange.github.com/disruptor/">LMAX Disruptor</a>
+ inter-thread messaging library. From the LMAX web site:
+ </p>
+ <blockquote>
+ <p>... using queues to pass data between stages of the system was 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 CPU-level, and locks requiring kernel arbitration are both
+ extremely costly, so we created a 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>
- can be found
- <a
- href="https://github.com/LMAX-Exchange/disruptor/wiki/Performance-Results">
- here</a>.
- </p>
- </subsection>
- </section>
- </body>
+ <p>
+ LMAX Disruptor internal perfor
<TRUNCATED>
[2/2] git commit: format improvements (no content changes)
Posted by rp...@apache.org.
format improvements (no content changes)
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/c6626902
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/c6626902
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/c6626902
Branch: refs/heads/master
Commit: c66269021126045f9f5f20b94f117c23b11a05be
Parents: 73a29ed
Author: rpopma <rp...@apache.org>
Authored: Sun Sep 14 23:03:33 2014 +0900
Committer: rpopma <rp...@apache.org>
Committed: Sun Sep 14 23:03:33 2014 +0900
----------------------------------------------------------------------
src/site/xdoc/manual/async.xml | 2004 ++++++++++++++++-------------------
1 file changed, 896 insertions(+), 1108 deletions(-)
----------------------------------------------------------------------