logging-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From rgo...@apache.org
Subject svn commit: r1463078 [4/4] - in /logging/log4j/log4j2/trunk: ./ core/src/main/java/org/apache/logging/log4j/core/ core/src/main/java/org/apache/logging/log4j/core/appender/ core/src/main/java/org/apache/logging/log4j/core/config/ core/src/main/java/org...
Date Mon, 01 Apr 2013 03:51:23 GMT
Added: 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=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml (added)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml Mon Apr  1 03:51:21 2013
@@ -0,0 +1,1377 @@
+<?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>
+	<properties>
+		<title>Log4j2 Asynchronous Logging</title>
+		<author email="remkop@yahoo.com">Remko Popma</author>
+	</properties>
+	<body>
+		<section name="Asynchronous Logging">
+			<p>
+				Asynchronous logging can improve your application's 
+				performance by executing the I/O operations
+				in a separate thread.
+				Log4j2 makes a number of improvements in this area.
+			</p>
+			<ul>
+				<li>
+					<b>Asynchronous Loggers</b>
+					are a new addition to Log4j2.
+					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>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.
+				</li>
+				<li>
+					<b>Fast 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 10-30% faster.
+					These appenders can also be used
+					with synchronous loggers
+					and will give the same performance benefits.
+				</li>
+				<li><b>LMAX Disruptor technology</b>. The Asynchronous Loggers
+				internally
+				use the <a href="#UnderTheHood">Disruptor</a> inter-thread
+				communication library instead of queues, resulting in higher
+				throughput and lower latency.</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>
+				</ul>
+			</subsection>
+			<a name="AllAsync" />
+			<subsection name="Making All Loggers Asynchronous">
+				<p>
+					This is simplest to configure and gives the best performance.
+					To make all loggers asynchronous, add log4j-async.jar 
+					and disruptor-3.0.0.jar to the classpath
+					and set the system property <tt>Log4jContextSelector</tt>
+					to
+					<tt>org.apache.logging.log4j.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:
+					<pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+  <appenders>
+    <FastFile name="FastFile" fileName="async.log" immediateFlush="false" append="false">
+      <PatternLayout>
+        <pattern>%d %p %c{1.} [%t] %m %ex%n</pattern>
+      </PatternLayout>
+    </FastFile>
+  </appenders>
+  <loggers>
+    <root level="info" includeLocation="false">
+      <appender-ref ref="FastFile"/>
+    </root>
+  </loggers>
+</configuration>]]></pre>
+				</p>
+				<p>
+					When
+					<tt>AsyncLoggerContextSelector</tt> is used to make
+					all loggers asynchronous, make sure to use normal
+					<tt>&lt;root&gt;</tt> and
+					<tt>&lt;logger&gt;</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>&lt;asyncRoot&gt;</tt> or
+					<tt>&lt;asyncLogger&gt;</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>
+				<table>
+					<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&nbsp;*&nbsp;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.Clock</td>
+						<td>
+							<tt>SystemClock</tt>
+						</td>
+						<td>
+							Implementation of the
+							<tt>org.apache.logging.log4j.async.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.
+							<br />
+							<tt>CachedClock</tt>
+							is an optimization 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.
+							<br />
+							You can also specify a fully qualified class name
+							of a custom class that implements the
+							<tt>Clock</tt>
+							interface.
+						</td>
+					</tr>
+					<caption align="top">System Properties to configure all
+						asynchronous loggers
+					</caption>
+				</table>
+			</subsection>
+			<a name="MixedSync-Async" />
+			<subsection name="Mixing Synchronous and Asynchronous Loggers">
+				<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>&lt;asyncRoot&gt;</tt>
+					or
+					<tt>&lt;asyncLogger&gt;</tt>
+					configuration elements to specify the loggers that need to
+					be
+					asynchronous. The same configuration file can also
+					contain
+					<tt>&lt;root&gt;</tt>
+					and
+					<tt>&lt;logger&gt;</tt>
+					elements for the synchronous loggers.
+				</p>
+				<p>
+					There is no need to set the system property
+					"Log4jContextSelector" to any value.
+				</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:
+					<pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+  <appenders>
+    <FastFile name="FastFile" fileName="asyncWithLocation.log" 
+              immediateFlush="false" append="false">
+      <PatternLayout>
+        <pattern>%d %p %class{1.} [%t] %location %m %ex%n</pattern>
+      </PatternLayout>
+    </FastFile>
+  </appenders>
+  <loggers>
+    <asyncLogger name="com.foo.Bar" level="trace" includeLocation="true"><!-- pattern actually uses location, so need to include it -->
+      <appender-ref ref="FastFile"/>
+    </asyncLogger>
+    <root level="info" includeLocation="true">
+      <appender-ref ref="FastFile"/>
+    </root>
+  </loggers>
+</configuration>]]></pre>
+				</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>
+				<table>
+					<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&nbsp;*&nbsp;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>
+					<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 %line,
+			%location, %class or %method, Log4j will take a snapshot of the
+			stack, and walk the stack trace to find the location information.
+			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. 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.
+			</p><p>
+			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.
+			
+			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="FastFileAppender" />
+			<subsection name="FastFileAppender">
+				<p>
+					The FastFileAppender is similar to the standard
+					<a href="appenders.html#FileAppender">FileAppender</a>
+					except it is always buffered (this cannot be switched off)
+					and internally it uses a
+					<tt>ByteBuffer + RandomAccessFile</tt>
+					instead of a
+					<tt>BufferedOutputStream</tt>.
+					We saw a 10-30% performance improvement compared to
+					FileAppender with "bufferedIO=true" in our 
+					<a href="#FastFileAppenderPerformance">measurements</a>.
+					Similar to the FileAppender,
+					FastFileAppender uses a FastFileManager to actually perform the
+					file I/O. While FastFileAppender
+					from different Configurations
+					cannot be shared, the FastFileManagers can be if the Manager is
+					accessible. For example, two webapps in a
+					servlet container can have
+					their own configuration and safely
+					write to the same file if Log4j
+					is in a ClassLoader that is common to
+					both of them.
+				</p>
+				<table>
+					<tr>
+						<th>Parameter Name</th>
+						<th>Type</th>
+						<th>Description</th>
+					</tr>
+					<tr>
+						<td>append</td>
+						<td>boolean</td>
+						<td>When true - the default, records will be appended to the end
+							of the file. When set to false,
+							the file will be cleared before
+							new records are written.
+						</td>
+					</tr>
+					<tr>
+						<td>fileName</td>
+						<td>String</td>
+						<td>The name of the file to write to. If the file, or any of its
+							parent directories, do not exist,
+							they will be created.
+						</td>
+					</tr>
+					<tr>
+						<td>filters</td>
+						<td>Filter</td>
+						<td>A Filter to determine if the event should be handled by this
+							Appender. More than one Filter
+							may be used by using a CompositeFilter.
+						</td>
+					</tr>
+					<tr>
+						<td>immediateFlush</td>
+						<td>boolean</td>
+						<td>When set to true, each write will be followed by a flush.
+							This will guarantee the data is written
+							to disk but could impact performance.
+							This option is only necessary when using this
+							appender with synchronous loggers. Asynchronous loggers will
+							automatically flush at the end of a batch, which also guarantees
+							the data is written to disk but is more efficient.
+						</td>
+					</tr>
+					<tr>
+						<td>layout</td>
+						<td>Layout</td>
+						<td>The Layout to use to format the LogEvent</td>
+					</tr>
+					<tr>
+						<td>name</td>
+						<td>String</td>
+						<td>The name of the Appender.</td>
+					</tr>
+					<tr>
+						<td>suppressExceptions</td>
+						<td>boolean</td>
+						<td>The default is true, causing exceptions to be internally
+							logged and then ignored. When set to
+							false exceptions will be
+							percolated to the caller.
+						</td>
+					</tr>
+					<caption align="top">FastFileAppender Parameters</caption>
+				</table>
+				<p>
+					Here is a sample FastFile configuration:
+
+					<pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="warn" name="MyApp" packages="">
+  <appenders>
+    <FastFile name="MyFile" fileName="logs/app.log">
+      <PatternLayout>
+        <pattern>%d %p %c{1.} [%t] %m%n</pattern>
+      </PatternLayout>
+    </FastFile>
+  </appenders>
+  <loggers>
+    <root level="error">
+      <appender-ref ref="MyFile"/>
+    </root>
+  </loggers>
+</configuration>]]></pre>
+				</p>
+			</subsection>
+			<a name="FastRollingFileAppender" />
+			<subsection name="FastRollingFileAppender">
+				<p>
+					The FastRollingFileAppender is similar to the standard
+					<a href="appenders.html#RollingFileAppender">RollingFileAppender</a>
+					except it is always buffered (this cannot be switched off)
+					and
+					internally it uses a
+					<tt>ByteBuffer + RandomAccessFile</tt>
+					instead of a
+					<tt>BufferedOutputStream</tt>.
+					<!-- 
+					We saw a 10-30% performance improvement compared to
+					RollingFileAppender with "bufferedIO=true"
+					in our 
+					<a href="#FastFileAppenderPerformance">measurements</a>.
+					-->
+					The FastRollingFileAppender writes
+					to the File named in the
+					fileName parameter
+					and rolls the file over according the
+					TriggeringPolicy
+					and the RolloverPolicy.
+
+					Similar to the RollingFileAppender,
+					FastRollingFileAppender uses a FastRollingFileManager 
+					to actually perform the
+					file I/O and perform the rollover. While FastRollingFileAppender
+					from different Configurations cannot be
+					shared, the FastRollingFileManagers can be
+					if the Manager is accessible.
+					For example, two webapps in a servlet
+					container can have their own configuration and safely write to the
+					same file if Log4j is in a ClassLoader that is common to both of them.
+				</p>
+				<p>
+					A FastRollingFileAppender requires a
+					<a href="#TriggeringPolicies">TriggeringPolicy</a>
+					and a
+					<a href="#RolloverStrategies">RolloverStrategy</a>.
+					The triggering policy determines if a rollover should
+					be performed
+					while the RolloverStrategy defines how the rollover
+					should be done.
+					If no RolloverStrategy
+					is configured, FastRollingFileAppender will
+					use the
+					<a href="appenders.html#DefaultRolloverStrategy">DefaultRolloverStrategy</a>.
+				</p>
+				<p>
+					File locking is not supported by the FastRollingFileAppender.
+				</p>
+				<table>
+					<tr>
+						<th>Parameter Name</th>
+						<th>Type</th>
+						<th>Description</th>
+					</tr>
+					<tr>
+						<td>append</td>
+						<td>boolean</td>
+						<td>When true - the default, records will be appended to the end
+							of the file. When set to false,
+							the file will be cleared before
+							new records are written.
+						</td>
+					</tr>
+					<tr>
+						<td>filter</td>
+						<td>Filter</td>
+						<td>A Filter to determine if the event should be handled by this
+							Appender. More than one Filter
+							may be used by using a
+							CompositeFilter.
+						</td>
+					</tr>
+					<tr>
+						<td>fileName</td>
+						<td>String</td>
+						<td>The name of the file to write to. If the file, or any of its
+							parent directories, do not exist,
+							they will be created.
+						</td>
+					</tr>
+					<tr>
+						<td>filePattern</td>
+						<td>String</td>
+						<td>
+							The pattern of the file name of the archived log file. The format
+							of the pattern should is
+							dependent on the RolloverPolicy that is
+							used. The DefaultRolloverPolicy
+							will accept both
+							a date/time
+							pattern compatible with
+							<a
+								href="http://download.oracle.com/javase/6/docs/api/java/text/SimpleDateFormat.html">
+								SimpleDateFormat</a>
+							
+							and/or a %i which represents an integer counter. The pattern
+							also supports interpolation at
+							runtime so any of the Lookups (such
+							as the
+							<a href="./lookups.html#DateLookup">DateLookup</a>
+							can
+							be included in the pattern.
+						</td>
+					</tr>
+					<tr>
+						<td>immediateFlush</td>
+						<td>boolean</td>
+						<td>When set to true, each write will be followed by a flush. This
+							will guarantee the data is written
+							to disk but could impact
+							performance.
+							This option is only necessary when using this
+							appender with
+							synchronous loggers. Asynchronous loggers will
+							automatically
+							flush at the end of a batch, which also guarantees
+							the data
+							is written to disk but is more efficient.
+						</td>
+					</tr>
+					<tr>
+						<td>layout</td>
+						<td>Layout</td>
+						<td>The Layout to use to format the LogEvent</td>
+					</tr>
+
+					<tr>
+						<td>name</td>
+						<td>String</td>
+						<td>The name of the Appender.</td>
+					</tr>
+					<tr>
+						<td>policy</td>
+						<td>TriggeringPolicy</td>
+						<td>The policy to use to determine if a rollover should occur.
+						</td>
+					</tr>
+					<tr>
+						<td>strategy</td>
+						<td>RolloverStrategy</td>
+						<td>The strategy to use to determine the name and location of the
+							archive file.
+						</td>
+					</tr>
+					<tr>
+						<td>suppressExceptions</td>
+						<td>boolean</td>
+						<td>The default is true, causing exceptions to be internally
+							logged and then ignored. When set to
+							false exceptions will be
+							percolated to the caller.
+						</td>
+					</tr>
+					<caption align="top">FastRollingFileAppender Parameters</caption>
+				</table>
+				<a name="TriggeringPolicies" />
+				<h4>Triggering Policies</h4>
+				<p>
+					See
+					<a href="appenders.html#TriggeringPolicies">RollingFileAppender Triggering Policies</a>.
+				</p>
+				<a name="RolloverStrategies" />
+				<h4>Rollover Strategies</h4>
+				<p>
+					See
+					<a href="appenders.html#RolloverStrategies">RollingFileAppender Rollover Strategies</a>.
+				</p>
+
+				<p>
+					Below is a sample configuration that uses a FastRollingFileAppender
+					with both the time and size based
+					triggering policies, will create
+					up to 7 archives on the same day (1-7) that
+					are stored in a
+					directory
+					based on the current year and month, and will compress
+					each
+					archive using gzip:
+
+					<pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="warn" name="MyApp" packages="">
+  <appenders>
+    <FastRollingFile name="FastRollingFile" fileName="logs/app.log"
+                 filePattern="logs/$${date:yyyy-MM}/app-%d{MM-dd-yyyy}-%i.log.gz">
+      <PatternLayout>
+        <pattern>%d %p %c{1.} [%t] %m%n</pattern>
+      </PatternLayout>
+      <Policies>
+        <TimeBasedTriggeringPolicy />
+        <SizeBasedTriggeringPolicy size="250 MB"/>
+      </Policies>
+    </FastRollingFile>
+  </appenders>
+  <loggers>
+    <root level="error">
+      <appender-ref ref="FastRollingFile"/>
+    </root>
+  </loggers>
+</configuration>]]></pre>
+				</p>
+				<p>
+					This second example shows a rollover strategy that will keep up to
+					20 files before removing them.
+					<pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="warn" name="MyApp" packages="">
+  <appenders>
+    <FastRollingFile name="FastRollingFile" fileName="logs/app.log"
+                 filePattern="logs/$${date:yyyy-MM}/app-%d{MM-dd-yyyy}-%i.log.gz">
+      <PatternLayout>
+        <pattern>%d %p %c{1.} [%t] %m%n</pattern>
+      </PatternLayout>
+      <Policies>
+        <TimeBasedTriggeringPolicy />
+        <SizeBasedTriggeringPolicy size="250 MB"/>
+      </Policies>
+      <DefaultRolloverStrategy max="20"/>
+    </FastRollingFile>
+  </appenders>
+  <loggers>
+    <root level="error">
+      <appender-ref ref="FastRollingFile"/>
+    </root>
+  </loggers>
+</configuration>]]></pre>
+				</p>
+				<p>
+					Below is a sample configuration that uses a FastRollingFileAppender
+					with both the time and size based
+					triggering policies, will create
+					up to 7 archives on the same day (1-7) that
+					are stored in a
+					directory
+					based on the current year and month, and will compress
+					each
+					archive using gzip and will roll every 6 hours when the hour is
+					divisible
+					by 6:
+
+					<pre class="prettyprint linenums"><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="warn" name="MyApp" packages="">
+  <appenders>
+    <FastRollingFile name="FastRollingFile" fileName="logs/app.log"
+                 filePattern="logs/$${date:yyyy-MM}/app-%d{yyyy-MM-dd-HH}-%i.log.gz">
+      <PatternLayout>
+        <pattern>%d %p %c{1.} [%t] %m%n</pattern>
+      </PatternLayout>
+      <Policies>
+        <TimeBasedTriggeringPolicy interval="6" modulate="true"/>
+        <SizeBasedTriggeringPolicy size="250 MB"/>
+      </Policies>
+    </FastRollingFile>
+  </appenders>
+  <loggers>
+    <root level="error">
+      <appender-ref ref="FastRollingFile"/>
+    </root>
+  </loggers>
+</configuration>]]></pre>
+				</p>
+			</subsection>
+			<a name="Performance" />
+			<subsection name="Performance Measurements">
+				<p>
+					This section shows the results of our performance tests.
+					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 log 256 *
+						1024 / threadCount messages of 500 characters.</li>
+				</ul>
+				<h4>Logging Throughput</h4>
+				<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>
+				  <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>Log4j2: Loggers all asynchronous</td>
+				  <td align="right">1,655,952</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>Log4j2: Loggers mixed sync/async</td>
+				  <td align="right">534,592</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>Log4j2: Async Appender</td>
+				  <td align="right">1,091,563</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,336,667</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">2,231,044</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>Log4j2: 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>
+					<caption align="top">Throughput per thread in messages/second
+					</caption>
+				</table>
+				<p></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>
+				  <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>Log4j2: 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>Log4j2: 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>Log4j2: 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>Log4j2: 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>
+					<caption align="top">Throughput per thread in messages/second
+					</caption>
+				</table>
+				<p>
+				In the above two environments, with the 
+				default settings (SystemClock and SleepingWaitStrategy),
+				asynchronous logging 
+				processes 6 - 68 times the number of log events in the same time
+				as synchronous logging. These numbers may also give you an
+				idea of the performance trade-off when choosing between
+				<a href="#AllAsync">All Async</a> and the more flexible 
+				<a href="#MixedSync-Async">Mixed Async</a> logging.
+				</p>
+				<p>Note that the numbers above are throughput <i>per thread</i>.
+				The graph below shows the total throughput of all threads together.
+				<img src="../images/async-throughput-comparison.png" /></p>
+
+				<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>
+						<th>Logger</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>
+					<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 
+				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>The latency comparison below is 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>
+				<img src="../images/async-average-latency.png" />
+				</p>
+				<p>
+				The scale of the latency comparison graphs is logarithmic, not linear.
+				That makes it a bit difficult to see, but the average latency of
+				asynchronous loggers is half to one third of the latency of
+				ArrayBlockingQueue-based asynchronous appenders in scenarios
+				up to 8 threads. With more threads, the average latency of
+				asynchronous appenders is orders of magnitude larger than
+				asynchronous loggers.
+				</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.
+				The worst case latency of asynchronous loggers remains more or
+				less the same (around 10-20 microseconds) in multi-threaded scenarios where
+				ArrayBlockingQueue-based asynchronous appenders have more outliers
+				with latencies of over 100 milliseconds per call to Logger.log.
+				</p>
+				<p>
+				<img src="../images/async-max-latency-99.99pct.png" />				
+				</p>
+
+				<a name="FastFileAppenderPerformance" />
+				<h4>FileAppender vs. FastFileAppender</h4>
+				<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>
+						<th>Appender</th>
+						<th>1 thread</th>
+						<th>2 threads</th>
+						<th>4 threads</th>
+						<th>8 threads</th>
+					</tr>
+					<tr>
+						<td>FastFileAppender</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>RollingFastFileAppender</td>
+						<td align="right">104,254</td>
+						<td align="right">39,345</td>
+						<td align="right">16,971</td>
+						<td align="right">9,465</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>
+					<caption align="top">Throughput per thread in operations/second
+					</caption>
+				</table>
+				<p>On Solaris 10 (64bit) with JDK1.7.0_06, 4-core Xeon X5570 CPU 
+				@2.93GHz with hyperthreading switched on (8 virtual cores):</p>
+				<table>
+					<tr>
+						<th>Appender</th>
+						<th>1 thread</th>
+						<th>2 threads</th>
+						<th>4 threads</th>
+						<th>8 threads</th>
+					</tr>
+					<tr>
+						<td>FastFileAppender</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>RollingFastFileAppender</td>
+						<td align="right">78,715</td>
+						<td align="right">31,426</td>
+						<td align="right">17,881</td>
+						<td align="right">8,727</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>
+					<caption align="top">Throughput per thread in operations/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. 
+				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>
+					<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>
+					<caption align="top">Throughput in log messages/second per thread</caption>
+				</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>
+</document>
\ No newline at end of file



Mime
View raw message