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 2013/04/28 21:48:03 UTC
svn commit: r1476820 - in /logging/log4j/log4j2/trunk/src/site: ./
xdoc/manual/
Author: rpopma
Date: Sun Apr 28 19:48:03 2013
New Revision: 1476820
URL: http://svn.apache.org/r1476820
Log:
LOG4J2-225 Improve documentation on use of location in pattern layouts, prefer non-location patterns in samples
Modified:
logging/log4j/log4j2/trunk/src/site/site.xml
logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml
logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml
logging/log4j/log4j2/trunk/src/site/xdoc/manual/configuration.xml.vm
logging/log4j/log4j2/trunk/src/site/xdoc/manual/filters.xml
logging/log4j/log4j2/trunk/src/site/xdoc/manual/flowtracing.xml
logging/log4j/log4j2/trunk/src/site/xdoc/manual/layouts.xml.vm
logging/log4j/log4j2/trunk/src/site/xdoc/manual/lookups.xml
Modified: logging/log4j/log4j2/trunk/src/site/site.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/site.xml?rev=1476820&r1=1476819&r2=1476820&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/site.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/site.xml Sun Apr 28 19:48:03 2013
@@ -88,6 +88,7 @@
<item name="Serialized" href="/manual/layouts.html#SerializedLayout"/>
<item name="Syslog" href="/manual/layouts.html#SyslogLayout"/>
<item name="XML" href="/manual/layouts.html#XMLLayout"/>
+ <item name="Location Information" href="/manual/layouts.html#LocationInformation"/>
</item>
<item name="Filters" href="/manual/filters.html" collapse="true">
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml?rev=1476820&r1=1476819&r2=1476820&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml Sun Apr 28 19:48:03 2013
@@ -115,7 +115,7 @@
<appenders>
<File name="MyFile" fileName="logs/app.log">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
</File>
<Asynch name="Asynch">
@@ -256,7 +256,7 @@
<RollingFile name="RollingFile" fileName="logs/app.log"
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -319,7 +319,8 @@
<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
+ <td>When set to true - the default, each write will be followed by a flush.
+ This will guarantee the data is written
to disk but could impact performance.</td>
</tr>
<tr>
@@ -358,7 +359,7 @@
<appenders>
<File name="MyFile" fileName="logs/app.log">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
</File>
</appenders>
@@ -1067,7 +1068,7 @@
<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
+ <td>When set to true - the default, each write will be followed by a flush. This will guarantee the data is written
to disk but could impact performance.</td>
</tr>
<tr>
@@ -1294,7 +1295,7 @@
<RollingFile name="RollingFile" 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>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy />
@@ -1317,7 +1318,7 @@
<RollingFile name="RollingFile" 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>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy />
@@ -1345,7 +1346,7 @@
<RollingFile name="RollingFile" 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>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy interval="6" modulate="true"/>
@@ -1421,7 +1422,7 @@
<tr>
<td>immediateFlush</td>
<td>boolean</td>
- <td>When set to true, each write will be followed by a flush.
+ <td>When set to true - the default, 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 useful when using this
@@ -1582,7 +1583,7 @@
<tr>
<td>immediateFlush</td>
<td>boolean</td>
- <td>When set to true, each write will be followed by a flush. This
+ <td>When set to true - the default, each write will be followed by a flush. This
will guarantee the data is written
to disk but could impact
performance.
@@ -1812,7 +1813,7 @@
<RollingFile name="Rolling-${sd:type}" fileName="${sd:type}.log"
filePattern="${sd:type}.%i.log.gz">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<SizeBasedTriggeringPolicy size="500" />
</RollingFile>
@@ -1988,7 +1989,8 @@
<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
+ <td>When set to true - the default, each write will be followed by a flush.
+ This will guarantee the data is written
to disk but could impact performance.</td>
</tr>
<tr>
@@ -2116,7 +2118,8 @@
<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
+ <td>When set to true - the default, each write will be followed by a flush.
+ This will guarantee the data is written
to disk but could impact performance.</td>
</tr>
<tr>
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml?rev=1476820&r1=1476819&r2=1476820&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml Sun Apr 28 19:48:03 2013
@@ -12,7 +12,7 @@
<document>
<properties>
<title>Log4j2 Asynchronous Loggers for Low-Latency Logging</title>
- <author email="remkop@yahoo.com">Remko Popma</author>
+ <author email="rpopma@apache.org">Remko Popma</author>
</properties>
<body>
<section name="Asynchronous Loggers for Low-Latency Logging">
@@ -36,6 +36,11 @@
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
@@ -46,8 +51,10 @@
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>
+ <li>(For synchronous and asynchronous use)
<b>Fast File Appenders</b>
are an alternative to Buffered File
Appenders. Under the hood, these
@@ -57,12 +64,8 @@
These appenders can also be used
with synchronous loggers
and will give the same performance benefits.
+ They do not need the disruptor jar on the classpath.
</li>
- <li><b>LMAX Disruptor technology</b>. The Asynchronous Loggers
- internally
- use the <a href="#UnderTheHood">Disruptor</a> lock-free inter-thread
- communication library instead of queues, resulting in higher
- throughput and lower latency.</li>
</ul>
<a name="Trade-offs" />
<subsection name="Trade-offs">
@@ -123,10 +126,11 @@
</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 disruptor-3.0.0.jar or higher to the classpath
+ 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>.
@@ -142,8 +146,14 @@
<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">
+
+<!-- Don't forget to set system property
+-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
+ to make all loggers asynchronous. -->
+
+<configuration status="WARN">
<appenders>
+ <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
<FastFile name="FastFile" fileName="async.log" immediateFlush="false" append="false">
<PatternLayout>
<pattern>%d %p %c{1.} [%t] %m %ex%n</pattern>
@@ -302,7 +312,8 @@
</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.</i></p>
+ <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
@@ -322,10 +333,6 @@
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
@@ -336,8 +343,13 @@
<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">
+
+<!-- No need to set system property "Log4jContextSelector" to any value
+ when using <asyncLogger> or <asyncRoot>. -->
+
+<configuration status="WARN">
<appenders>
+ <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
<FastFile name="FastFile" fileName="asyncWithLocation.log"
immediateFlush="false" append="false">
<PatternLayout>
@@ -346,7 +358,7 @@
</FastFile>
</appenders>
<loggers>
- <!-- pattern actually uses location, so we need to include it -->
+ <!-- pattern layout actually uses location, so we need to include it -->
<asyncLogger name="com.foo.Bar" level="trace" includeLocation="true">
<appender-ref ref="FastFile"/>
</asyncLogger>
@@ -526,94 +538,6 @@
<p>
<img src="../images/async-throughput-comparison.png" />
</p>
- <p>On Windows 7 (64bit) with JDK1.7.0_11, 2-core Intel i5-3317u CPU
- @1.70Ghz with hyperthreading switched on (4 virtual cores):</p>
- <table>
- <tr>
- <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,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>Log4j2: 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>Log4j2: 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>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>
@@ -710,6 +634,94 @@
<caption align="top">Throughput per thread in messages/second
</caption>
</table>
+ <p></p>
+ <p>On Windows 7 (64bit) with JDK1.7.0_11, 2-core Intel i5-3317u CPU
+ @1.70Ghz with hyperthreading switched on (4 virtual cores):</p>
+ <table>
+ <tr>
+ <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,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>Log4j2: 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>Log4j2: 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>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>
<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
@@ -875,6 +887,8 @@
<a name="FastFileAppenderPerformance" />
<h4>FileAppender vs. FastFileAppender</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>
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/configuration.xml.vm
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/configuration.xml.vm?rev=1476820&r1=1476819&r2=1476820&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/configuration.xml.vm (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/configuration.xml.vm Sun Apr 28 19:48:03 2013
@@ -459,7 +459,7 @@ public class Bar {
</filters>
</appender>
<appender type="Console" name="FLOW">
- <layout type="PatternLayout" pattern="%C{1}.%M %m %ex%n"/>
+ <layout type="PatternLayout" pattern="%C{1}.%M %m %ex%n"/><!-- class & line number -->
<filters>
<filter type="MarkerFilter" marker="FLOW" onMatch="ACCEPT" onMismatch="NEUTRAL"/>
<filter type="MarkerFilter" marker="EXCEPTION" onMatch="ACCEPT" onMismatch="DENY"/>
@@ -523,7 +523,7 @@ public class Bar {
"RollingFile": {
"name": "Rolling-${dollar}{sd:type}", "fileName": "${dollar}{filename}",
"filePattern": "target/rolling1/test1-${dollar}{sd:type}.%i.log.gz",
- "PatternLayout": {"pattern": "%d %p %C{1.} [%t] %m%n"},
+ "PatternLayout": {"pattern": "%d %p %c{1.} [%t] %m%n"},
"SizeBasedTriggeringPolicy": { "size": "500" }
}
},
@@ -566,7 +566,7 @@ public class Bar {
"RollingFile": {
"name": "Rolling-${dollar}{sd:type}", "fileName": "${dollar}{filename}",
"filePattern": "target/rolling1/test1-${dollar}{sd:type}.%i.log.gz",
- "PatternLayout": {"pattern": "%d %p %C{1.} [%t] %m%n"},
+ "PatternLayout": {"pattern": "%d %p %c{1.} [%t] %m%n"},
"SizeBasedTriggeringPolicy": { "size": "500" }
}
},
@@ -684,6 +684,7 @@ public class Bar {
<PatternLayout pattern="%m MDC%X%n"/>
</Console>
<Console name="FLOW">
+ <!-- this pattern outputs class name and line number -->
<PatternLayout pattern="%C{1}.%M %m %ex%n"/>
<filters>
<MarkerFilter marker="FLOW" onMatch="ACCEPT" onMismatch="NEUTRAL"/>
@@ -757,7 +758,7 @@ public class Bar {
<RollingFile name="Rolling-${dollar}{sd:type}" fileName="${dollar}{filename}"
filePattern="target/rolling1/test1-${dollar}{sd:type}.%i.log.gz">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<SizeBasedTriggeringPolicy size="500" />
</RollingFile>
@@ -896,7 +897,7 @@ public class Bar {
<RollingFile name="Rolling-${dollar}{sd:type}" fileName="${dollar}{filename}"
filePattern="target/rolling1/test1-${dollar}{sd:type}.%i.log.gz">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<SizeBasedTriggeringPolicy size="500" />
</RollingFile>
@@ -977,7 +978,7 @@ public class Bar {
config.plugins.LoggersPlugin for element loggers with params(loggers={EventLogger, root})
2011-11-23 17:08:00,834 DEBUG Reconfiguration completed
2011-11-23 17:08:00,846 DEBUG Calling createLayout on class org.apache.logging.log4j.core.
- layout.PatternLayout for element PatternLayout with params(pattern="%d %p %C{1.} [%t] %m%n",
+ layout.PatternLayout for element PatternLayout with params(pattern="%d %p %c{1.} [%t] %m%n",
Configuration(RoutingTest), null, charset="null")
2011-11-23 17:08:00,849 DEBUG Calling createPolicy on class org.apache.logging.log4j.core.
appender.rolling.SizeBasedTriggeringPolicy for element SizeBasedTriggeringPolicy with
@@ -988,7 +989,7 @@ public class Bar {
filePattern="target/rolling1/test1-Unknown.%i.log.gz", append="null", name="Rolling-Unknown",
bufferedIO="null", immediateFlush="null",
SizeBasedTriggeringPolicy(SizeBasedTriggeringPolicy(size=500)), null,
- PatternLayout(%d %p %C{1.} [%t] %m%n), null, suppressExceptions="null")
+ PatternLayout(%d %p %c{1.} [%t] %m%n), null, suppressExceptions="null")
2011-11-23 17:08:00,858 DEBUG Generated plugins in 0.002014000 seconds
2011-11-23 17:08:00,889 DEBUG Reconfiguration started for context sun.misc.
Launcher$AppClassLoader@37b90b39
@@ -1021,9 +1022,9 @@ public class Bar {
2011-11-23 17:08:00,831 DEBUG Calling createLogger on class org.apache.logging.log4j.core.config.LoggerConfig$RootLogger for element root with params(additivity="null", level="error", appender-ref={STDOUT}, null)
2011-11-23 17:08:00,833 DEBUG Calling createLoggers on class org.apache.logging.log4j.core.config.plugins.LoggersPlugin for element loggers with params(loggers={EventLogger, root})
2011-11-23 17:08:00,834 DEBUG Reconfiguration completed
-2011-11-23 17:08:00,846 DEBUG Calling createLayout on class org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout with params(pattern="%d %p %C{1.} [%t] %m%n", Configuration(RoutingTest), null, charset="null")
+2011-11-23 17:08:00,846 DEBUG Calling createLayout on class org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout with params(pattern="%d %p %c{1.} [%t] %m%n", Configuration(RoutingTest), null, charset="null")
2011-11-23 17:08:00,849 DEBUG Calling createPolicy on class org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy for element SizeBasedTriggeringPolicy with params(size="500")
-2011-11-23 17:08:00,851 DEBUG Calling createAppender on class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile with params(fileName="target/rolling1/rollingtest-Unknown.log", filePattern="target/rolling1/test1-Unknown.%i.log.gz", append="null", name="Rolling-Unknown", bufferedIO="null", immediateFlush="null", SizeBasedTriggeringPolicy(SizeBasedTriggeringPolicy(size=500)), null, PatternLayout(%d %p %C{1.} [%t] %m%n), null, suppressExceptions="null")
+2011-11-23 17:08:00,851 DEBUG Calling createAppender on class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile with params(fileName="target/rolling1/rollingtest-Unknown.log", filePattern="target/rolling1/test1-Unknown.%i.log.gz", append="null", name="Rolling-Unknown", bufferedIO="null", immediateFlush="null", SizeBasedTriggeringPolicy(SizeBasedTriggeringPolicy(size=500)), null, PatternLayout(%d %p %c{1.} [%t] %m%n), null, suppressExceptions="null")
2011-11-23 17:08:00,858 DEBUG Generated plugins in 0.002014000 seconds
2011-11-23 17:08:00,889 DEBUG Reconfiguration started for context sun.misc.Launcher$AppClassLoader@37b90b39
2011-11-23 17:08:00,890 DEBUG Generated plugins in 0.001355000 seconds
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/filters.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/filters.xml?rev=1476820&r1=1476819&r2=1476820&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/filters.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/filters.xml Sun Apr 28 19:48:03 2013
@@ -102,7 +102,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<BurstFilter level="INFO" rate="16" maxBurst="100"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -137,14 +137,14 @@
<appenders>
<File name="Audit" fileName="logs/audit.log">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
</File>
<RollingFile name="RollingFile" fileName="logs/app.log"
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<BurstFilter level="INFO" rate="16" maxBurst="100"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -213,7 +213,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<BurstFilter level="INFO" rate="16" maxBurst="100"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -277,7 +277,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<BurstFilter level="INFO" rate="16" maxBurst="100"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -300,7 +300,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<BurstFilter level="INFO" rate="16" maxBurst="100"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -328,7 +328,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<BurstFilter level="INFO" rate="16" maxBurst="100"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -389,7 +389,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<MarkerFilter marker="FLOW" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -449,7 +449,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<RegexFilter regex=".* test .*" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -516,7 +516,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<BurstFilter level="INFO" rate="16" maxBurst="100"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -580,7 +580,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<BurstFilter level="INFO" rate="16" maxBurst="100"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -601,7 +601,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<BurstFilter level="INFO" rate="16" maxBurst="100"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -663,7 +663,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<ThresholdFilter level="TRACE" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
@@ -733,7 +733,7 @@
filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
<TiemFilter start="05:00:00" end="05:30:00" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<TimeBasedTriggeringPolicy />
</RollingFile>
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/flowtracing.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/flowtracing.xml?rev=1476820&r1=1476819&r2=1476820&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/flowtracing.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/flowtracing.xml Sun Apr 28 19:48:03 2013
@@ -144,6 +144,8 @@ public class App {
<appenders>
<Console name="Console" target="SYSTEM_OUT">
<ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
+ <!-- Flow tracing is most useful with a pattern that shows location.
+ Below pattern outputs class, line number and method name. -->
<PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/>
</Console>
<File name="log" fileName="target/test.log" append="false">
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/layouts.xml.vm
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/layouts.xml.vm?rev=1476820&r1=1476819&r2=1476820&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/layouts.xml.vm (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/layouts.xml.vm Sun Apr 28 19:48:03 2013
@@ -64,8 +64,11 @@
<tr>
<td>locationInfo</td>
<td>boolean</td>
- <td>If true, the filename and line number will be included in the HTML output. The default value is
- false.</td>
+ <td><p>If true, the filename and line number will be included in the HTML output. The default value is
+ false.</p>
+ <p>Generating location info is an expensive operation and may impact
+ <a href="#LocationInformation">performance</a>. Use with caution.</p>
+ </td>
</tr>
<tr>
<td>title</td>
@@ -208,6 +211,8 @@ WARN [main]: Message 2</pre>
This conversion specifier can be optionally followed by<em>precision specifier</em>, that
follows the same rules as the logger name converter.
</p>
+ <p>Generating the class name of the caller is an expensive operation and may impact
+ <a href="#LocationInformation">performance</a>. Use with caution.</p>
</td>
</tr>
<tr>
@@ -296,7 +301,9 @@ WARN [main]: Message 2</pre>
<b>F</b><br />
<b>file</b>
</td>
- <td>Outputs the file name where the logging request was issued.
+ <td><p>Outputs the file name where the logging request was issued.</p>
+ <p>Generating the file information is an expensive operation and may impact
+ <a href="#LocationInformation">performance</a>. Use with caution.</p>
</td>
</tr>
<tr>
@@ -493,6 +500,8 @@ WARN [main]: Message 2</pre>
qualified name of the calling method followed by the callers source the file name and line
number between parentheses.
</p>
+ <p>Generating location information is an expensive operation and may impact
+ <a href="#LocationInformation">performance</a>. Use with caution.</p>
</td>
</tr>
<tr>
@@ -500,8 +509,10 @@ WARN [main]: Message 2</pre>
<b>L</b><br />
<b>line</b>
</td>
- <td>Outputs the line number from where the logging request
- was issued.
+ <td><p>Outputs the line number from where the logging request
+ was issued.</p>
+ <p>Generating line number information is an expensive operation and may impact
+ <a href="#LocationInformation">performance</a>. Use with caution.</p>
</td>
</tr>
<tr>
@@ -518,7 +529,9 @@ WARN [main]: Message 2</pre>
<b>M</b><br />
<b>method</b>
</td>
- <td>Outputs the method name where the logging request was issued.
+ <td><p>Outputs the method name where the logging request was issued.</p>
+ <p>Generating the method name of the caller is an expensive operation and may impact
+ <a href="#LocationInformation">performance</a>. Use with caution.</p>
</td>
</tr>
<tr>
@@ -1144,6 +1157,35 @@ at org.apache.logging.log4j.core.pattern
non ASCII characters could result in corrupted log files.
</p>
</subsection>
+ <a name="LocationInformation"/>
+ <subsection name="Location Information">
+ <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>
</section>
</body>
</document>
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/lookups.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/lookups.xml?rev=1476820&r1=1476819&r2=1476820&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/lookups.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/lookups.xml Sun Apr 28 19:48:03 2013
@@ -45,7 +45,7 @@
<pre class="prettyprint linenums"><![CDATA[
<File name="Application" fileName="application.log">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] $${ctx:loginId} %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] $${ctx:loginId} %m%n</pattern>
</PatternLayout>
</File>]]></pre>
</subsection>
@@ -60,7 +60,7 @@
<pre class="prettyprint linenums"><![CDATA[
<RollingFile name="Rolling-${map:type}" fileName="${filename}" filePattern="target/rolling1/test1-$${date:MM-dd-yyyy}.%i.log.gz">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<SizeBasedTriggeringPolicy size="500" />
</RollingFile>]]></pre>
@@ -76,7 +76,7 @@
<pre class="prettyprint linenums"><![CDATA[
<File name="Application" fileName="application.log">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] $${env:USER} %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] $${env:USER} %m%n</pattern>
</PatternLayout>
</File>]]></pre>
</subsection>
@@ -106,7 +106,7 @@
<RollingFile name="Rolling-${map:type}" fileName="${filename}"
filePattern="target/rolling1/test1-${map:type}.%i.log.gz">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<SizeBasedTriggeringPolicy size="500" />
</RollingFile>
@@ -131,7 +131,7 @@
<RollingFile name="Rolling-${sd:type}" fileName="${filename}"
filePattern="target/rolling1/test1-${sd:type}.%i.log.gz">
<PatternLayout>
- <pattern>%d %p %C{1.} [%t] %m%n</pattern>
+ <pattern>%d %p %c{1.} [%t] %m%n</pattern>
</PatternLayout>
<SizeBasedTriggeringPolicy size="500" />
</RollingFile>