You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by mi...@apache.org on 2016/05/04 11:49:04 UTC
[01/19] logging-log4j2 git commit: LOG4J2-1297 improved latency
performance text and graphs
Repository: logging-log4j2
Updated Branches:
refs/heads/LOG4J2-1347 d9f2a3447 -> 6da41bf8b
LOG4J2-1297 improved latency performance text and graphs
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/79777a73
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/79777a73
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/79777a73
Branch: refs/heads/LOG4J2-1347
Commit: 79777a7326f3ed5a0c17273e8940682729916a3f
Parents: 21a9a13
Author: rpopma <rp...@apache.org>
Authored: Sun May 1 14:40:05 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Sun May 1 14:40:05 2016 +0900
----------------------------------------------------------------------
.../ResponseTimeAsyncClassicVsGcFree-label.png | Bin 31517 -> 29217 bytes
.../garbage-free2.6-SyncThroughputLinux.png | Bin 70039 -> 64440 bytes
src/site/xdoc/manual/garbagefree.xml | 72 ++++++++++++++-----
3 files changed, 54 insertions(+), 18 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/79777a73/src/site/resources/images/ResponseTimeAsyncClassicVsGcFree-label.png
----------------------------------------------------------------------
diff --git a/src/site/resources/images/ResponseTimeAsyncClassicVsGcFree-label.png b/src/site/resources/images/ResponseTimeAsyncClassicVsGcFree-label.png
index f2f1c03..70353fb 100644
Binary files a/src/site/resources/images/ResponseTimeAsyncClassicVsGcFree-label.png and b/src/site/resources/images/ResponseTimeAsyncClassicVsGcFree-label.png differ
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/79777a73/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png
----------------------------------------------------------------------
diff --git a/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png b/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png
index 5de5d9f..bea429d 100644
Binary files a/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png and b/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png differ
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/79777a73/src/site/xdoc/manual/garbagefree.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/manual/garbagefree.xml b/src/site/xdoc/manual/garbagefree.xml
index 2ecfaee..b879720 100644
--- a/src/site/xdoc/manual/garbagefree.xml
+++ b/src/site/xdoc/manual/garbagefree.xml
@@ -364,23 +364,63 @@ public void garbageFree() {
<a name="Latency" />
<h4>Response Time Latency</h4>
<p>Response time is how long it takes to log a message under a certain load.
- When measuring, each messsage has its own response time. Typically the vast majority of measurements
- are in a certain low range, with a small number of large outliers. When talking about latency,
+ What is often reported as latency is actually <em>service time</em>: how long it took to perform the operation.
+ This hides the fact that a single spike in service time adds queueing delay for many of the subsequent operations.
+ Service time is easy to measure (and often looks good on paper) but is irrelevant for users since it
+ omits the time spent waiting for service.
+ For this reason we report
+ <a href="https://en.wikipedia.org/wiki/Response_time_(technology)">response time</a>:
+ service time plus wait time.
+ </p>
+ <!--
+ <p>Response time cannot be expressed in a single number: each message has its own response time.
+ Typically the vast majority of measurements
+ are in a certain (low) range, with a small number of large outliers. When talking about latency,
we are usually interested in the outliers: how many there are and how large they are.
- "Average latency" is meaningless.
+ There is no bell curve, so "average latency" and "standard deviation" are meaningless terms
+ when talking about latency. The graphs below shows a histogram with the entire percentile spectrum.
</p>
- <p>Commonly what is reported as latency is <em>service time</em>: how long it took to perform the operation.
- This omits the queueing effect: we were trying to log at a certain rate, say 100,000 messages per second.
- A single spike in service time can delay many of the subsequent messages.
- <em>Response time</em> includes the effect of spikes.
+ -->
+ <table>
+ <tr><td>I encourage everyone to take the red pill and watch Gil Tene's presentation
+ <a href="http://www.infoq.com/presentations/latency-response-time">How NOT to measure latency</a>.
+ Be warned, this talk is about removing the wool from your eyes.
+ You will learn a lot but may not always like what you've learnt.</td></tr>
+ </table>
+ <p>The response time test results below were all derived from running the ResponseTimeTest class
+ which can be found in the Log4j 2 unit test source directory. If you want to run these tests yourself,
+ here are the command line options we used:
</p>
+ <ul>
+ <li>-Xms1G -Xmx1G (prevent heap resizing during the test)</li>
+ <li>-XX:+UnlockDiagnosticVMOptions -XX:GuaranteedSafepointInterval=500000 (by default Hotspot schedules a
+ safepoint pause every second. Reduce jitter by postponing this for the duration of the test.)</li>
+ <li>-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
+ -DAsyncLogger.WaitStrategy=busyspin (to use Async Loggers. The BusySpin wait strategy reduces some jitter.)</li>
+ <li><b>classic mode: </b>-Dlog4j2.enable.threadlocals=false -Dlog4j2.enable.direct.encoders=false<br />
+ <b>garbage-free mode: </b>-Dlog4j2.enable.threadlocals=true -Dlog4j2.enable.direct.encoders=true</li>
+ <li>-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution
+ -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime (to eyeball GC and safepoint pauses)</li>
+ </ul>
+ <!--
+ <pre style="overflow: auto; white-space: pre-wrap; word-wrap: normal;">java -Xms1G -Xmx1G -XX:+UnlockDiagnosticVMOptions -verbose:gc -XX:+PrintGCDetails
+ -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationConcurrentTime
+ -XX:+PrintGCApplicationStoppedTime -XX:GuaranteedSafepointInterval=500000
+ -XX:CompileCommand=dontinline,org.apache.logging.log4j.core.async.perftest.NoOpIdleStrategy::idle
+ -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
+ -Dlog4j2.enable.threadlocals=false -Dlog4j2.enable.direct.encoders=false -DAsyncLogger.WaitStrategy=busyspin
+ -cp .:HdrHistogram-2.1.8.jar:disruptor-3.3.4.jar:log4j-1.2.17.jar:slf4j-api-1.7.13.jar:slf4j-ext-1.7.13.jar:
+ logback-core-1.1.3.jar:logback-classic-1.1.3.jar:log4j-api-2.6-SNAPSHOT.jar:log4j-core-2.6-SNAPSHOT.jar:
+ log4j-core-2.6-SNAPSHOT-tests.jar org.apache.logging.log4j.core.async.perftest.ResponseTimeTest 1 50000</pre>
+ -->
<h4>Async Loggers</h4>
<p>The graph below compares "classic" logging to
garbage-free logging response time behaviour for Log4j's Async Loggers.
In the graph, "100k" means logging at a sustained load of 100,000 messages/second, "800k" is
- 800,000 messages/second.
+ a sustained load of 800,000 messages/second.
</p>
- <p>In classic mode we see numerous minor garbage collections which pause the application threads
+ <p><img src="../images/ResponseTimeAsyncClassicVsGcFree-label.png" /></p>
+ <p>In <b>classic</b> mode we see numerous minor garbage collections which pause the application threads
for 3 milliseconds or more. This quickly adds up to response time delays of almost 10
milliseconds.
As you can see in the graph, increasing the load shifts the curve to the left (there are more spikes).
@@ -388,28 +428,24 @@ public void garbageFree() {
We experimented a little with reducing the load to 50,000 or even 5000 messages/second,
but this did not eliminate the 3 millisecond pauses, it just made them occur less frequently.
Note that all GC pauses in this test are minor GC pauses. We did not see any full garbage collections.</p>
- <p>In garbage-free mode, maximum response time remains well below 1 millisecond under a wide range of loads.
+ <p>In <b>garbage-free</b> mode, maximum response time remains well below 1 millisecond under a wide range of loads.
(Max 780 us at 800,000 messages/sec, max 407 us at 600,000 messages/sec, with the 99% around 5 us for
all loads up to 800,000 messages/sec.) Increasing or decreasing the load does not change the response time
behaviour. We did not investigate the cause of the 200-300 microsecond pauses we saw in these tests.
</p>
<p>
- TODO title should include "lower is better".
- TODO legend should be "microseconds" (full)
- </p>
-
- <p><img src="../images/ResponseTimeAsyncClassicVsGcFree-label.png" /></p>
- <p>
When we increased the load further we begin to see larger response time pauses for both classic and
garbage-free logging.
At sustained loads of 1 million messages/second or more we start to approach the maximum throughput of
the underlying RandomAccessFile Appender (see the synchronous logging throughput chart below).
At these loads the ringbuffer starts to fill up and backpressure kicks in: attempting to add another message
- when the ringbuffer is full will block until a free slot becomes available. We start to see 20 millisecond
- response times or more; and attempting to increase the load even more results in larger and larger
+ when the ringbuffer is full will block until a free slot becomes available. We start to see response times
+ of tens of milliseconds or more; and attempting to increase the load even more results in larger and larger
response time spikes.
</p>
<h4>Synchronous Logging</h4>
+ <p>With synchronous logging, garbage-free logging still performs better, but the difference is less pronounced.
+ </p>
<p>For both classic and garbage-free logging, synchronous logging showed response times of 3-5 milliseconds
even at loads of 100,000 messages/second. It may be possible to improve on this, we did not investigate
further yet.</p>
[03/19] logging-log4j2 git commit: LOG4J2-1297 added paragraph on
Garbage-free logging with link to home page
Posted by mi...@apache.org.
LOG4J2-1297 added paragraph on Garbage-free logging with link to home page
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/3245e6ca
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/3245e6ca
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/3245e6ca
Branch: refs/heads/LOG4J2-1347
Commit: 3245e6ca5351e0c900f32d4439727fc66324608d
Parents: 29fdfdf
Author: rpopma <rp...@apache.org>
Authored: Sun May 1 15:19:01 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Sun May 1 15:19:01 2016 +0900
----------------------------------------------------------------------
src/site/xdoc/index.xml | 6 ++++++
1 file changed, 6 insertions(+)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3245e6ca/src/site/xdoc/index.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/index.xml b/src/site/xdoc/index.xml
index cd53d9e..50912cc 100644
--- a/src/site/xdoc/index.xml
+++ b/src/site/xdoc/index.xml
@@ -101,6 +101,12 @@
In Log4j 2, <a href="manual/customloglevels.html">custom log levels</a> can easily be defined in code
or in configuration. No subclassing is required.
</dd>
+ <dt>Garbage-free</dt>
+ <dd>
+ During steady state logging, Log4j 2 is <a href="manual/garbagefree.html">garbage-free</a>
+ in stand-alone applications, and low garbage in web applications.
+ This reduces pressure on the garbage collector and can give better response time performance.
+ </dd>
</dl>
<subsection name="Documentation">
[13/19] logging-log4j2 git commit: LOG4J2-1297 removed paragraph on
logging library comparison: will be moved to performance page
Posted by mi...@apache.org.
LOG4J2-1297 removed paragraph on logging library comparison: will be moved to performance page
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/286290c4
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/286290c4
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/286290c4
Branch: refs/heads/LOG4J2-1347
Commit: 286290c4a516f2d4287ac3a4173fd4f8999ae92b
Parents: 59443e1
Author: rpopma <rp...@apache.org>
Authored: Wed May 4 02:24:39 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Wed May 4 02:24:39 2016 +0900
----------------------------------------------------------------------
src/site/xdoc/manual/garbagefree.xml | 9 +--------
1 file changed, 1 insertion(+), 8 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/286290c4/src/site/xdoc/manual/garbagefree.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/manual/garbagefree.xml b/src/site/xdoc/manual/garbagefree.xml
index b879720..e552f15 100644
--- a/src/site/xdoc/manual/garbagefree.xml
+++ b/src/site/xdoc/manual/garbagefree.xml
@@ -456,14 +456,7 @@ public void garbageFree() {
<p>Throughput is roughly similar for garbage-free and classic logging.
In our measurements, Log4j 2.6 in garbage-free mode had the highest throughput in single-threaded scenarios. In multi-threaded
scenarios, Log4j 2.6 "classic" had the highest throughput, with Log4j 2.6 in garbage-free mode and Log4j 2.5
- not far behind. Our test results suggest that the throughput of the other logging frameworks we tested
- will rapidly decline in multi-threaded applications.</p>
- <p>The graph below compares Log4j 2.6 in garbage-free mode to Log4j 2.6 "classic" mode (which allocates
- temporary objects for every logging call), Log4j 2.5, Log4j 1.2.17, Logback 1.1.7 and
- Java util logging (JUL) on Oracle Java 1.8.0_45. All Log4j 2.x results use the RandomAccessFile appender.
- Log4j 1.2.17, Logback and JUL use their respective File appenders. ImmediateFlush was set to <tt>false</tt> for all
- loggers that support this. The JUL results are for the <tt>XMLFormatter</tt> (which in our measurements was
- about twice as fast as the <tt>SimpleFormatter</tt>).</p>
+ not far behind.</p>
<p>The synchronous logging throughput results below are obtained with the
<a href="http://openjdk.java.net/projects/code-tools/jmh/">JMH</a> Java benchmark harness.
See the <tt>org.apache.logging.log4j.perf.jmh.FileAppenderBenchmark</tt> source code in the log4j-perf module.</p>
[16/19] logging-log4j2 git commit: Update changes.xml with LOG4J2-1011
Posted by mi...@apache.org.
Update changes.xml with LOG4J2-1011
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/e7b80990
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/e7b80990
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/e7b80990
Branch: refs/heads/LOG4J2-1347
Commit: e7b809907207f99fd070a4ec5a9a38a28e04e0f1
Parents: c5669e4
Author: Mikael St�ldal <mi...@magine.com>
Authored: Wed May 4 10:11:31 2016 +0200
Committer: Mikael St�ldal <mi...@magine.com>
Committed: Wed May 4 10:11:31 2016 +0200
----------------------------------------------------------------------
src/changes/changes.xml | 3 +++
1 file changed, 3 insertions(+)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/e7b80990/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index cd32009..3982166 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -24,6 +24,9 @@
</properties>
<body>
<release version="2.6" date="2016-MM-DD" description="GA Release 2.6">
+ <action issue="LOG4J2-1011" dev="mikes" type="add">
+ Document dependencies for layouts.
+ </action>
<action issue="LOG4J2-621" dev="ggregory" type="add" due-to="Lee Theobald, Kamal Mettananda, Gary Gregory">
Pattern to drop first N package parts.
</action>
[19/19] logging-log4j2 git commit: Fix formatting
Posted by mi...@apache.org.
Fix formatting
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/6da41bf8
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/6da41bf8
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/6da41bf8
Branch: refs/heads/LOG4J2-1347
Commit: 6da41bf8be6298b9b859cf56609f434ba10da71e
Parents: 6cb9f99
Author: Mikael St�ldal <mi...@magine.com>
Authored: Wed May 4 13:48:50 2016 +0200
Committer: Mikael St�ldal <mi...@magine.com>
Committed: Wed May 4 13:48:50 2016 +0200
----------------------------------------------------------------------
.../log4j/core/appender/AsyncAppender.java | 86 +++++++++++---------
1 file changed, 47 insertions(+), 39 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/6da41bf8/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
index 72f9ca8..b6670d6 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
@@ -16,6 +16,13 @@
*/
package org.apache.logging.log4j.core.appender;
+import java.util.ArrayList;
+import java.util.List;
+import java.util.Map;
+import java.util.concurrent.ArrayBlockingQueue;
+import java.util.concurrent.BlockingQueue;
+import java.util.concurrent.atomic.AtomicLong;
+
import org.apache.logging.log4j.core.AbstractLogEvent;
import org.apache.logging.log4j.core.Appender;
import org.apache.logging.log4j.core.Filter;
@@ -28,17 +35,15 @@ import org.apache.logging.log4j.core.config.AppenderControl;
import org.apache.logging.log4j.core.config.AppenderRef;
import org.apache.logging.log4j.core.config.Configuration;
import org.apache.logging.log4j.core.config.ConfigurationException;
-import org.apache.logging.log4j.core.config.plugins.*;
+import org.apache.logging.log4j.core.config.plugins.Plugin;
+import org.apache.logging.log4j.core.config.plugins.PluginAliases;
+import org.apache.logging.log4j.core.config.plugins.PluginAttribute;
+import org.apache.logging.log4j.core.config.plugins.PluginConfiguration;
+import org.apache.logging.log4j.core.config.plugins.PluginElement;
+import org.apache.logging.log4j.core.config.plugins.PluginFactory;
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
import org.apache.logging.log4j.core.util.Constants;
-import java.util.ArrayList;
-import java.util.List;
-import java.util.Map;
-import java.util.concurrent.ArrayBlockingQueue;
-import java.util.concurrent.BlockingQueue;
-import java.util.concurrent.atomic.AtomicLong;
-
/**
* Appends to one or more Appenders asynchronously. You can configure an AsyncAppender with one or more Appenders and an
* Appender to append to if the queue is full. The AsyncAppender does not allow a filter to be specified on the Appender
@@ -48,7 +53,8 @@ import java.util.concurrent.atomic.AtomicLong;
public final class AsyncAppender extends AbstractAppender {
private static final int DEFAULT_QUEUE_SIZE = 128;
- private static final LogEvent SHUTDOWN = new AbstractLogEvent() { };
+ private static final LogEvent SHUTDOWN = new AbstractLogEvent() {
+ };
private static final AtomicLong THREAD_SEQUENCE = new AtomicLong(1);
@@ -65,8 +71,9 @@ public final class AsyncAppender extends AbstractAppender {
private AsyncEventRouter asyncEventRouter;
private AsyncAppender(final String name, final Filter filter, final AppenderRef[] appenderRefs,
- final String errorRef, final int queueSize, final boolean blocking, final boolean ignoreExceptions,
- final long shutdownTimeout, final Configuration config, final boolean includeLocation) {
+ final String errorRef, final int queueSize, final boolean blocking,
+ final boolean ignoreExceptions,
+ final long shutdownTimeout, final Configuration config, final boolean includeLocation) {
super(name, filter, null, ignoreExceptions);
this.queue = new ArrayBlockingQueue<>(queueSize);
this.queueSize = queueSize;
@@ -124,7 +131,7 @@ public final class AsyncAppender extends AbstractAppender {
if (DiscardingAsyncEventRouter.getDiscardCount(asyncEventRouter) > 0) {
LOGGER.trace("AsyncAppender: {} discarded {} events.", asyncEventRouter,
- DiscardingAsyncEventRouter.getDiscardCount(asyncEventRouter));
+ DiscardingAsyncEventRouter.getDiscardCount(asyncEventRouter));
}
}
@@ -202,7 +209,7 @@ public final class AsyncAppender extends AbstractAppender {
final boolean appendSuccessful = queue.offer(frozenLogEvent);
if (!appendSuccessful) {
LOGGER.warn("Interrupted while waiting for a free slot in the AsyncAppender LogEvent-queue {}",
- getName());
+ getName());
}
// set the interrupted flag again.
Thread.currentThread().interrupt();
@@ -214,37 +221,38 @@ public final class AsyncAppender extends AbstractAppender {
errorAppender.callAppender(logEvent);
}
}
+
/**
* Create an AsyncAppender.
*
- * @param appenderRefs The Appenders to reference.
- * @param errorRef An optional Appender to write to if the queue is full or other errors occur.
- * @param blocking True if the Appender should wait when the queue is full. The default is true.
- * @param shutdownTimeout How many milliseconds the Appender should wait to flush outstanding log events
- * in the queue on shutdown. The default is zero which means to wait forever.
- * @param size The size of the event queue. The default is 128.
- * @param name The name of the Appender.
- * @param includeLocation whether to include location information. The default is false.
- * @param filter The Filter or null.
- * @param config The Configuration.
+ * @param appenderRefs The Appenders to reference.
+ * @param errorRef An optional Appender to write to if the queue is full or other errors occur.
+ * @param blocking True if the Appender should wait when the queue is full. The default is true.
+ * @param shutdownTimeout How many milliseconds the Appender should wait to flush outstanding log events
+ * in the queue on shutdown. The default is zero which means to wait forever.
+ * @param size The size of the event queue. The default is 128.
+ * @param name The name of the Appender.
+ * @param includeLocation whether to include location information. The default is false.
+ * @param filter The Filter or null.
+ * @param config The Configuration.
* @param ignoreExceptions If {@code "true"} (default) exceptions encountered when appending events are logged;
- * otherwise they are propagated to the caller.
+ * otherwise they are propagated to the caller.
* @return The AsyncAppender.
*/
@PluginFactory
public static AsyncAppender createAppender(
- // @formatter:off
- @PluginElement("AppenderRef") final AppenderRef[] appenderRefs,
- @PluginAttribute("errorRef") @PluginAliases("error-ref") final String errorRef,
- @PluginAttribute(value = "blocking", defaultBoolean = true) final boolean blocking,
- @PluginAttribute(value = "shutdownTimeout", defaultLong = 0L) final long shutdownTimeout,
- @PluginAttribute(value = "bufferSize", defaultInt = DEFAULT_QUEUE_SIZE) final int size,
- @PluginAttribute("name") final String name,
- @PluginAttribute(value = "includeLocation", defaultBoolean = false) final boolean includeLocation,
- @PluginElement("Filter") final Filter filter,
- @PluginConfiguration final Configuration config,
- @PluginAttribute(value = "ignoreExceptions", defaultBoolean = true) final boolean ignoreExceptions) {
- // @formatter:on
+ // @formatter:off
+ @PluginElement("AppenderRef") final AppenderRef[] appenderRefs,
+ @PluginAttribute("errorRef") @PluginAliases("error-ref") final String errorRef,
+ @PluginAttribute(value = "blocking", defaultBoolean = true) final boolean blocking,
+ @PluginAttribute(value = "shutdownTimeout", defaultLong = 0L) final long shutdownTimeout,
+ @PluginAttribute(value = "bufferSize", defaultInt = DEFAULT_QUEUE_SIZE) final int size,
+ @PluginAttribute("name") final String name,
+ @PluginAttribute(value = "includeLocation", defaultBoolean = false) final boolean includeLocation,
+ @PluginElement("Filter") final Filter filter,
+ @PluginConfiguration final Configuration config,
+ @PluginAttribute(value = "ignoreExceptions", defaultBoolean = true) final boolean ignoreExceptions) {
+ // @formatter:on
if (name == null) {
LOGGER.error("No name provided for AsyncAppender");
return null;
@@ -254,7 +262,7 @@ public final class AsyncAppender extends AbstractAppender {
}
return new AsyncAppender(name, filter, appenderRefs, errorRef, size, blocking, ignoreExceptions,
- shutdownTimeout, config, includeLocation);
+ shutdownTimeout, config, includeLocation);
}
/**
@@ -298,7 +306,7 @@ public final class AsyncAppender extends AbstractAppender {
}
// Process any remaining items in the queue.
LOGGER.trace("AsyncAppender.AsyncThread shutting down. Processing remaining {} queue events.",
- queue.size());
+ queue.size());
int count = 0;
int ignored = 0;
while (!queue.isEmpty()) {
@@ -319,7 +327,7 @@ public final class AsyncAppender extends AbstractAppender {
}
}
LOGGER.trace("AsyncAppender.AsyncThread stopped. Queue has {} events remaining. "
- + "Processed {} and ignored {} events since shutdown started.", queue.size(), count, ignored);
+ + "Processed {} and ignored {} events since shutdown started.", queue.size(), count, ignored);
}
/**
[09/19] logging-log4j2 git commit: LOG4J2-1011 Document dependencies
for XML layout
Posted by mi...@apache.org.
LOG4J2-1011 Document dependencies for XML layout
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/50ef6235
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/50ef6235
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/50ef6235
Branch: refs/heads/LOG4J2-1347
Commit: 50ef62351f9c808f396183ed01fe5f56d338c459
Parents: ff8aede
Author: rpopma <rp...@apache.org>
Authored: Tue May 3 22:33:16 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Tue May 3 22:33:16 2016 +0900
----------------------------------------------------------------------
src/site/xdoc/runtime-dependencies.xml | 32 ++++++++++++++++++-----------
1 file changed, 20 insertions(+), 12 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/50ef6235/src/site/xdoc/runtime-dependencies.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/runtime-dependencies.xml b/src/site/xdoc/runtime-dependencies.xml
index ba7273b..6ebbc9b 100644
--- a/src/site/xdoc/runtime-dependencies.xml
+++ b/src/site/xdoc/runtime-dependencies.xml
@@ -53,6 +53,22 @@
<th>Requirements</th>
</tr>
<tr>
+ <td>XML configuration</td>
+ <td>-</td>
+ </tr>
+ <tr>
+ <td>Properties configuration</td>
+ <td>-</td>
+ </tr>
+ <tr>
+ <td>JSON configuration</td>
+ <td><a href="https://github.com/FasterXML/jackson">Jackson core and databind</a></td>
+ </tr>
+ <tr>
+ <td>YAML configuration</td>
+ <td><a href="https://github.com/FasterXML/jackson-dataformat-yaml">Jackson YAML data format</a></td>
+ </tr>
+ <tr>
<td>CSV Layout</td>
<td><a href="https://commons.apache.org/proper/commons-csv/">Apache Commons CSV</a></td>
</tr>
@@ -65,18 +81,10 @@
<td><a href="https://github.com/FasterXML/jackson">Jackson core and databind</a></td>
</tr>
<tr>
- <td>XML configuration</td>
- <td>-</td>
- </tr>
- <tr>
- <td>JSON configuration</td>
+ <td>XML Layout</td>
<td><a href="https://github.com/FasterXML/jackson">Jackson core and databind</a></td>
</tr>
<tr>
- <td>YAML configuration</td>
- <td><a href="https://github.com/FasterXML/jackson-dataformat-yaml">Jackson YAML data format</a></td>
- </tr>
- <tr>
<td>Async Loggers</td>
<td><a href="http://lmax-exchange.github.io/disruptor/">LMAX Disruptor</a></td>
</tr>
@@ -123,9 +131,9 @@
<tr>
<td>ZeroMQ Appender</td>
<td>
- The ZeroMQ appender uses the <a href="https://github.com/zeromq/jeromq">JeroMQ</a> library which is
- licensed under the terms of the GNU Lesser General Public License (LGPL). For details see the
- files <code>COPYING</code> and <code>COPYING.LESSER</code> included with the JeroMQ distribution.
+ The ZeroMQ appender uses the <a href="https://github.com/zeromq/jeromq">JeroMQ</a> library which is
+ licensed under the terms of the GNU Lesser General Public License (LGPL). For details see the
+ files <code>COPYING</code> and <code>COPYING.LESSER</code> included with the JeroMQ distribution.
</td>
</tr>
</table>
[02/19] logging-log4j2 git commit: Site: link to Log4j 1 End of Life
announcement
Posted by mi...@apache.org.
Site: link to Log4j 1 End of Life announcement
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/29fdfdf7
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/29fdfdf7
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/29fdfdf7
Branch: refs/heads/LOG4J2-1347
Commit: 29fdfdf732f36dd4ab3c1d28fdccecfcdb36dee4
Parents: 79777a7
Author: rpopma <rp...@apache.org>
Authored: Sun May 1 15:02:04 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Sun May 1 15:02:04 2016 +0900
----------------------------------------------------------------------
src/site/xdoc/manual/index.xml | 7 +++++--
1 file changed, 5 insertions(+), 2 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/29fdfdf7/src/site/xdoc/manual/index.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/manual/index.xml b/src/site/xdoc/manual/index.xml
index fde0133..94d7e82 100644
--- a/src/site/xdoc/manual/index.xml
+++ b/src/site/xdoc/manual/index.xml
@@ -83,7 +83,10 @@
Log4j 1.x has been widely adopted and used in many applications. However,
through the years development on it has slowed down. It has become more
difficult to maintain due to its need to be compliant with very old versions
- of Java. Its alternative, SLF4J/Logback made many needed improvements to the
+ of Java and became
+ <a href="https://blogs.apache.org/foundation/entry/apache_logging_services_project_announces">End
+ of Life</a> in August 2015.
+ Its alternative, SLF4J/Logback made many needed improvements to the
framework. So why bother with Log4j 2? Here are a few of the reasons.
</p>
<ol>
@@ -136,7 +139,7 @@
<li>It is an Apache Software Foundation project following the community and support
model used by all ASF projects. If you want to contribute or gain the right to
commit changes just follow the path outlined at
- <a href="http://jakarta.apache.org/site/contributing.html">Contributing</a></li>
+ <a href="http://jakarta.apache.org/site/contributing.html">Contributing</a>.</li>
</ol>
</subsection>
</section>
[06/19] logging-log4j2 git commit: [LOG4J2-494] Support merging
configurations to for a composite configuration. Fix typo.
Posted by mi...@apache.org.
[LOG4J2-494] Support merging configurations to for a composite
configuration. Fix typo.
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/ad5073c0
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/ad5073c0
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/ad5073c0
Branch: refs/heads/LOG4J2-1347
Commit: ad5073c05cefe3398e00195c14fd5cf5033e9632
Parents: fc19d68
Author: ggregory <gg...@apache.org>
Authored: Mon May 2 14:24:40 2016 -0700
Committer: ggregory <gg...@apache.org>
Committed: Mon May 2 14:24:40 2016 -0700
----------------------------------------------------------------------
src/changes/changes.xml | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/ad5073c0/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index c707409..7d77dc9 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -25,7 +25,7 @@
<body>
<release version="2.6" date="2016-MM-DD" description="GA Release 2.6">
<action issue="LOG4J2-494" dev="rgoers" type="add" due-to="Philipp Knobel">
- Support mergiing configurations to for a composite configuration.
+ Support merging configurations to for a composite configuration.
</action>
<action issue="LOG4J2-1357" dev="mikes" type="add">
Option to not log stacktraces for logged Throwables in GelfLayout.
[04/19] logging-log4j2 git commit: LOG4J2-1297 added paragraph on
Garbage-free logging with link to manual top page
Posted by mi...@apache.org.
LOG4J2-1297 added paragraph on Garbage-free logging with link to manual top page
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/ff8aedea
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/ff8aedea
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/ff8aedea
Branch: refs/heads/LOG4J2-1347
Commit: ff8aedea04b5973401f5c981ccb31c0260e11807
Parents: 3245e6c
Author: rpopma <rp...@apache.org>
Authored: Sun May 1 15:22:54 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Sun May 1 15:22:54 2016 +0900
----------------------------------------------------------------------
src/site/xdoc/manual/index.xml | 3 +++
1 file changed, 3 insertions(+)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/ff8aedea/src/site/xdoc/manual/index.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/manual/index.xml b/src/site/xdoc/manual/index.xml
index 94d7e82..ecc522d 100644
--- a/src/site/xdoc/manual/index.xml
+++ b/src/site/xdoc/manual/index.xml
@@ -99,6 +99,9 @@
on the <a href="https://lmax-exchange.github.io/disruptor/">LMAX Disruptor library</a>.
In multi-threaded scenarios Asynchronous Loggers have 10 times higher throughput and
orders of magnitude lower latency than Log4j 1.x and Logback.</li>
+ <li>Log4j 2 is <a href="garbagefree.html">garbage free</a> for
+ stand-alone applications, and low garbage for web applications during steady state logging.
+ This reduces pressure on the garbage collector and can give better response time performance.</li>
<li>Log4j 2 uses a <a href="plugins.html">Plugin system</a> that makes it extremely easy to
<a href="extending.html">extend the framework</a> by adding new <a href="appenders.html">Appenders</a>,
<a href="filters.html">Filters</a>, <a href="layouts.html">Layouts</a>, <a href="lookups.html">Lookups</a>,
[17/19] logging-log4j2 git commit: Document missing XmlLayout
dependencies
Posted by mi...@apache.org.
Document missing XmlLayout dependencies
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/acce51ac
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/acce51ac
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/acce51ac
Branch: refs/heads/LOG4J2-1347
Commit: acce51acc9d6f06e1f1292456608993437968d38
Parents: e7b8099
Author: Mikael St�ldal <mi...@magine.com>
Authored: Wed May 4 12:15:23 2016 +0200
Committer: Mikael St�ldal <mi...@magine.com>
Committed: Wed May 4 12:15:23 2016 +0200
----------------------------------------------------------------------
src/site/xdoc/runtime-dependencies.xml | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/acce51ac/src/site/xdoc/runtime-dependencies.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/runtime-dependencies.xml b/src/site/xdoc/runtime-dependencies.xml
index 6ebbc9b..c92114b 100644
--- a/src/site/xdoc/runtime-dependencies.xml
+++ b/src/site/xdoc/runtime-dependencies.xml
@@ -82,7 +82,8 @@
</tr>
<tr>
<td>XML Layout</td>
- <td><a href="https://github.com/FasterXML/jackson">Jackson core and databind</a></td>
+ <td><a href="https://github.com/FasterXML/jackson">Jackson core, databind and dataformat XML</a><br />
+ And <code>com.fasterxml.woodstox:woodstox-core:5.0.2</code></td>
</tr>
<tr>
<td>Async Loggers</td>
[15/19] logging-log4j2 git commit: LOG4J2-1179 performance page added
graph & paragraph on service time vs response time
Posted by mi...@apache.org.
LOG4J2-1179 performance page added graph & paragraph on service time vs response time
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/c5669e45
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/c5669e45
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/c5669e45
Branch: refs/heads/LOG4J2-1347
Commit: c5669e45456003568e7c41a6d1c4631f103d123e
Parents: f342618
Author: rpopma <rp...@apache.org>
Authored: Wed May 4 02:55:04 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Wed May 4 02:55:04 2016 +0900
----------------------------------------------------------------------
.../ResponseTimeVsServiceTimeAsyncLoggers.png | Bin 0 -> 34779 bytes
src/site/xdoc/performance.xml | 8 ++++++++
2 files changed, 8 insertions(+)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/c5669e45/src/site/resources/images/ResponseTimeVsServiceTimeAsyncLoggers.png
----------------------------------------------------------------------
diff --git a/src/site/resources/images/ResponseTimeVsServiceTimeAsyncLoggers.png b/src/site/resources/images/ResponseTimeVsServiceTimeAsyncLoggers.png
new file mode 100644
index 0000000..7aff300
Binary files /dev/null and b/src/site/resources/images/ResponseTimeVsServiceTimeAsyncLoggers.png differ
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/c5669e45/src/site/xdoc/performance.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/performance.xml b/src/site/xdoc/performance.xml
index f7087aa..16ac240 100644
--- a/src/site/xdoc/performance.xml
+++ b/src/site/xdoc/performance.xml
@@ -70,6 +70,14 @@
<p>
What is often measured and reported as <em>latency</em> is actually <em>service time</em>,
which unfortunately hides the wait time.
+ The below graph shows response time and service time of the same system under a load of 100,000 messages
+ per second. Out of 25 million measurements, only ~50 are more than 200 microseconds, less than 0.001%.
+ In a service time-only graph this would hardly be visible.
+ However, the wait time adds up and the response time graph shows that in reality many more events are impacted
+ by these delays.
+ </p>
+ <p><img src="images/ResponseTimeVsServiceTimeAsyncLoggers.png" /></p>
+ <p>
To learn more, watch Gil Tene's
<a href="http://www.infoq.com/presentations/latency-response-time">How NOT to measure latency</a>
(and prepare to be shocked).
[07/19] logging-log4j2 git commit: [LOG4J2-621] Pattern to drop first
N package parts. Closes #28 https://github.com/apache/logging-log4j2/pull/28
Posted by mi...@apache.org.
[LOG4J2-621] Pattern to drop first N package parts. Closes #28
https://github.com/apache/logging-log4j2/pull/28
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/23b2b367
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/23b2b367
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/23b2b367
Branch: refs/heads/LOG4J2-1347
Commit: 23b2b3670d70e4494b2dc6c1929e6eb36ac0db2d
Parents: ad5073c
Author: ggregory <gg...@apache.org>
Authored: Mon May 2 14:31:35 2016 -0700
Committer: ggregory <gg...@apache.org>
Committed: Mon May 2 14:31:35 2016 -0700
----------------------------------------------------------------------
.../log4j/core/pattern/NameAbbreviator.java | 77 ++++++-
.../log4j/core/layout/PatternLayoutTest.java | 202 +++++++++++++++++++
src/changes/changes.xml | 3 +
src/site/xdoc/manual/layouts.xml.vm | 34 +++-
4 files changed, 304 insertions(+), 12 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/23b2b367/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/NameAbbreviator.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/NameAbbreviator.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/NameAbbreviator.java
index 1271ad5..a59cc5f 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/NameAbbreviator.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/NameAbbreviator.java
@@ -52,18 +52,31 @@ public abstract class NameAbbreviator {
return DEFAULT;
}
+ boolean isNegativeNumber;
+ final String number;
+
+ // check if number is a negative number
+ if (trimmed.length() > 1 && trimmed.charAt(0) == '-') {
+ isNegativeNumber = true;
+ number = trimmed.substring(1);
+ } else {
+ isNegativeNumber = false;
+ number = trimmed;
+ }
+
int i = 0;
- while (i < trimmed.length() && trimmed.charAt(i) >= '0'
- && trimmed.charAt(i) <= '9') {
+ while (i < number.length() && number.charAt(i) >= '0'
+ && number.charAt(i) <= '9') {
i++;
}
//
// if all blanks and digits
//
- if (i == trimmed.length()) {
- return new MaxElementAbbreviator(Integer.parseInt(trimmed));
+ if (i == number.length()) {
+ return new MaxElementAbbreviator(Integer.parseInt(number),
+ isNegativeNumber? MaxElementAbbreviator.Strategy.DROP : MaxElementAbbreviator.Strategy.RETAIN);
}
final ArrayList<PatternAbbreviatorFragment> fragments = new ArrayList<>(5);
@@ -156,18 +169,45 @@ public abstract class NameAbbreviator {
* Abbreviator that drops starting path elements.
*/
private static class MaxElementAbbreviator extends NameAbbreviator {
+
+ /**
+ * <p>When the name is reduced in length by cutting parts, there can be two ways to do it.</p>
+ * 1. Remove a given number of parts starting from front - called DROP <br/>
+ * 2. Retain a given number of parts starting from the end - called RETAIN
+ */
+ private enum Strategy {
+ DROP,
+ RETAIN
+ };
+
/**
* Maximum number of path elements to output.
*/
private final int count;
/**
+ * Strategy used for cutting down the size of the name
+ */
+ private final Strategy strategy;
+
+ /**
* Create new instance.
*
- * @param count maximum number of path elements to output.
+ * @param count maximum number of path elements to drop or output.
+ * @param strategy drop or retain
*/
- public MaxElementAbbreviator(final int count) {
- this.count = count < 1 ? 1 : count;
+ public MaxElementAbbreviator(final int count, final Strategy strategy) {
+ final int minCount = getMinCount(strategy);
+ this.count = count < minCount ? minCount : count;
+ this.strategy = strategy;
+ }
+
+ private int getMinCount(final Strategy strategy) {
+ if (Strategy.DROP == strategy) {
+ return 0;
+ } else { // Strategy.RETAIN
+ return 1;
+ }
}
/**
@@ -179,7 +219,30 @@ public abstract class NameAbbreviator {
*/
@Override
public void abbreviate(final String original, final StringBuilder destination) {
+ if (Strategy.DROP == strategy) {
+ abbreviateForDrop(original, destination);
+ } else { // Strategy.RETAIN
+ abbreviateForRetain(original, destination);
+ }
+ }
+
+ private void abbreviateForDrop(String original, StringBuilder destination) {
+ // If a path does not contain enough path elements to drop, none will be dropped.
+ int start = 0;
+ int nextStart = 0;
+ for (int i = 0; i < count; i++) {
+ nextStart = original.indexOf('.', start);
+ if (nextStart == -1) {
+ destination.append(original);
+ return;
+ } else {
+ start = nextStart + 1;
+ }
+ }
+ destination.append(original, start, original.length());
+ }
+ private void abbreviateForRetain(String original, StringBuilder destination) {
// We subtract 1 from 'len' when assigning to 'end' to avoid out of
// bounds exception in return r.substring(end+1, len). This can happen if
// precision is 1 and the category name ends with a dot.
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/23b2b367/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutTest.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutTest.java
index 988b42b..6f58ebc 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/layout/PatternLayoutTest.java
@@ -398,4 +398,206 @@ public class PatternLayoutTest {
.withConfiguration(ctx.getConfiguration()).withCharset(StandardCharsets.UTF_8).build();
assertEquals(StandardCharsets.UTF_8, layout.getCharset());
}
+
+ @Test
+ public void testLoggerNameTruncationByRetainingPartsFromEnd() throws Exception {
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%c{1} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!")).build();
+ final String result1 = layout.toSerializable(event1);
+ assertEquals(this.getClass().getName().substring(this.getClass().getName().lastIndexOf(".") + 1) + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%c{2} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!")).build();
+ final String result1 = layout.toSerializable(event1);
+ String name = this.getClass().getName().substring(0, this.getClass().getName().lastIndexOf("."));
+ name = name.substring(0, name.lastIndexOf("."));
+ assertEquals(this.getClass().getName().substring(name.length() + 1) + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%c{20} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!")).build();
+ final String result1 = layout.toSerializable(event1);
+ assertEquals(this.getClass().getName() + " Hello, world 1!", new String(result1));
+ }
+ }
+
+ @Test
+ public void testCallersFqcnTruncationByRetainingPartsFromEnd() throws Exception {
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%C{1} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!"))
+ .setSource(new StackTraceElement(this.getClass().getName(), "testCallersFqcnTruncationByRetainingPartsFromEnd", this.getClass().getCanonicalName() + ".java", 440))
+ .build();
+ final String result1 = layout.toSerializable(event1);
+ assertEquals(this.getClass().getName().substring(this.getClass().getName().lastIndexOf(".") + 1) + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%C{2} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!"))
+ .setSource(new StackTraceElement(this.getClass().getName(), "testCallersFqcnTruncationByRetainingPartsFromEnd", this.getClass().getCanonicalName() + ".java", 440))
+ .build();
+ final String result1 = layout.toSerializable(event1);
+ String name = this.getClass().getName().substring(0, this.getClass().getName().lastIndexOf("."));
+ name = name.substring(0, name.lastIndexOf("."));
+ assertEquals(this.getClass().getName().substring(name.length() + 1) + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%C{20} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!"))
+ .setSource(new StackTraceElement(this.getClass().getName(), "testCallersFqcnTruncationByRetainingPartsFromEnd", this.getClass().getCanonicalName() + ".java", 440))
+ .build();
+ final String result1 = layout.toSerializable(event1);
+ assertEquals(this.getClass().getName() + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%class{1} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!"))
+ .setSource(new StackTraceElement(this.getClass().getName(), "testCallersFqcnTruncationByRetainingPartsFromEnd", this.getClass().getCanonicalName() + ".java", 440))
+ .build();
+ final String result1 = layout.toSerializable(event1);
+ assertEquals(this.getClass().getName().substring(this.getClass().getName().lastIndexOf(".") + 1) + " Hello, world 1!", new String(result1));
+ }
+ }
+
+ @Test
+ public void testLoggerNameTruncationByDroppingPartsFromFront() throws Exception {
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%c{-1} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!")).build();
+ final String result1 = layout.toSerializable(event1);
+ String name = this.getClass().getName().substring(this.getClass().getName().indexOf(".") + 1);
+ assertEquals(name + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%c{-3} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!")).build();
+ final String result1 = layout.toSerializable(event1);
+ String name = this.getClass().getName().substring(this.getClass().getName().indexOf(".") + 1);
+ name = name.substring(name.indexOf(".") + 1);
+ name = name.substring(name.indexOf(".") + 1);
+ assertEquals(name + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%logger{-3} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!")).build();
+ final String result1 = layout.toSerializable(event1);
+ String name = this.getClass().getName().substring(this.getClass().getName().indexOf(".") + 1);
+ name = name.substring(name.indexOf(".") + 1);
+ name = name.substring(name.indexOf(".") + 1);
+ assertEquals(name + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%c{-20} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!")).build();
+ final String result1 = layout.toSerializable(event1);
+ assertEquals(this.getClass().getName() + " Hello, world 1!", new String(result1));
+ }
+
+ }
+
+ @Test
+ public void testCallersFqcnTruncationByDroppingPartsFromFront() throws Exception {
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%C{-1} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!"))
+ .setSource(new StackTraceElement(this.getClass().getName(), "testCallersFqcnTruncationByDroppingPartsFromFront", this.getClass().getCanonicalName() + ".java", 546))
+ .build();
+ final String result1 = layout.toSerializable(event1);
+ String name = this.getClass().getName().substring(this.getClass().getName().indexOf(".") + 1);
+ assertEquals(name + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%C{-3} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!"))
+ .setSource(new StackTraceElement(this.getClass().getName(), "testCallersFqcnTruncationByDroppingPartsFromFront", this.getClass().getCanonicalName() + ".java", 546))
+ .build();
+ final String result1 = layout.toSerializable(event1);
+ String name = this.getClass().getName().substring(this.getClass().getName().indexOf(".") + 1);
+ name = name.substring(name.indexOf(".") + 1);
+ name = name.substring(name.indexOf(".") + 1);
+ assertEquals(name + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%class{-3} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!"))
+ .setSource(new StackTraceElement(this.getClass().getName(), "testCallersFqcnTruncationByDroppingPartsFromFront", this.getClass().getCanonicalName() + ".java", 546))
+ .build();
+ final String result1 = layout.toSerializable(event1);
+ String name = this.getClass().getName().substring(this.getClass().getName().indexOf(".") + 1);
+ name = name.substring(name.indexOf(".") + 1);
+ name = name.substring(name.indexOf(".") + 1);
+ assertEquals(name + " Hello, world 1!", new String(result1));
+ }
+ {
+ final PatternLayout layout = PatternLayout.newBuilder().withPattern("%C{-20} %m")
+ .withConfiguration(ctx.getConfiguration()).build();
+ final LogEvent event1 = Log4jLogEvent.newBuilder()
+ .setLoggerName(this.getClass().getName()).setLoggerFqcn("org.apache.logging.log4j.core.Logger")
+ .setLevel(Level.INFO)
+ .setMessage(new SimpleMessage("Hello, world 1!"))
+ .setSource(new StackTraceElement(this.getClass().getName(), "testCallersFqcnTruncationByDroppingPartsFromFront", this.getClass().getCanonicalName() + ".java", 546))
+ .build();
+ final String result1 = layout.toSerializable(event1);
+ assertEquals(this.getClass().getName() + " Hello, world 1!", new String(result1));
+ }
+
+ }
}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/23b2b367/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index 7d77dc9..77e687d 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -24,6 +24,9 @@
</properties>
<body>
<release version="2.6" date="2016-MM-DD" description="GA Release 2.6">
+ <action issue="LOG4J2-621" dev="ggregory" type="add" due-to="Lee Theobald, Kamal Mettananda, Gary Gregory">
+ Pattern to drop first N package parts.
+ </action>
<action issue="LOG4J2-494" dev="rgoers" type="add" due-to="Philipp Knobel">
Support merging configurations to for a composite configuration.
</action>
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/23b2b367/src/site/xdoc/manual/layouts.xml.vm
----------------------------------------------------------------------
diff --git a/src/site/xdoc/manual/layouts.xml.vm b/src/site/xdoc/manual/layouts.xml.vm
index e94e5e7..1a33b76 100644
--- a/src/site/xdoc/manual/layouts.xml.vm
+++ b/src/site/xdoc/manual/layouts.xml.vm
@@ -520,11 +520,15 @@ WARN [main]: Message 2</pre>
specifier can be optionally followed by <em>precision specifier</em>, which consists of a
decimal integer, or a pattern starting with a decimal integer.
</p>
- <p>If a precision specifier is given and it is an integer value, then only the corresponding number
- of right most components of the logger name will be printed. If the precision contains
- other non-integer characters then the name will be abbreviated based on the pattern. If the
- precision integer is less than one the right-most token will still be printed in full.
- By default the logger name is printed in full.
+ <p>When the precision specifier is an integer value, it reduces the size of the logger name.
+ If the number is positive, the layout prints the corresponding number of rightmost logger
+ name components. If negative, the layout removes the corresponding number of leftmost logger
+ name components.
+ </p>
+ <p>
+ If the precision contains any non-integer characters, then the layout abbreviates the name
+ based on the pattern. If the precision integer is less than one, the layout still prints
+ the right-most token in full. By default, the layout prints the logger name in full.
</p>
<table>
<tr>
@@ -543,6 +547,26 @@ WARN [main]: Message 2</pre>
<td>commons.Foo</td>
</tr>
<tr>
+ <td>%c{10}</td>
+ <td>org.apache.${break}commons.Foo</td>
+ <td>org.apache.${break}commons.Foo</td>
+ </tr>
+ <tr>
+ <td>%c{-1}</td>
+ <td>org.apache.${break}commons.Foo</td>
+ <td>apache.${break}commons.Foo</td>
+ </tr>
+ <tr>
+ <td>%c{-2}</td>
+ <td>org.apache.${break}commons.Foo</td>
+ <td>${break}commons.Foo</td>
+ </tr>
+ <tr>
+ <td>%c{-10}</td>
+ <td>org.apache.${break}commons.Foo</td>
+ <td>org.apache.${break}commons.Foo</td>
+ </tr>
+ <tr>
<td>%c{1.}</td>
<td>org.apache.${break}commons.Foo</td>
<td>o.a.c.Foo</td>
[11/19] logging-log4j2 git commit: LOG4J2-1297 fix typo in graph,
better title
Posted by mi...@apache.org.
LOG4J2-1297 fix typo in graph, better title
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/119d6b76
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/119d6b76
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/119d6b76
Branch: refs/heads/LOG4J2-1347
Commit: 119d6b76f3691f70c37c574a78a285e5a00dee3d
Parents: 57d1472
Author: rpopma <rp...@apache.org>
Authored: Wed May 4 01:53:22 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Wed May 4 01:53:22 2016 +0900
----------------------------------------------------------------------
.../garbage-free2.6-SyncThroughputLinux.png | Bin 64440 -> 65092 bytes
1 file changed, 0 insertions(+), 0 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/119d6b76/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png
----------------------------------------------------------------------
diff --git a/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png b/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png
index bea429d..f26573c 100644
Binary files a/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png and b/src/site/resources/images/garbage-free2.6-SyncThroughputLinux.png differ
[08/19] logging-log4j2 git commit: [LOG4J2-1357] Option to not log
stack traces for logged Throwables in GelfLayout. Fix typo.
Posted by mi...@apache.org.
[LOG4J2-1357] Option to not log stack traces for logged Throwables in
GelfLayout. Fix typo.
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/6dc663de
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/6dc663de
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/6dc663de
Branch: refs/heads/LOG4J2-1347
Commit: 6dc663de3b8aff55bd9650078636d97dc8a5817c
Parents: 23b2b36
Author: ggregory <gg...@apache.org>
Authored: Mon May 2 14:32:15 2016 -0700
Committer: ggregory <gg...@apache.org>
Committed: Mon May 2 14:32:15 2016 -0700
----------------------------------------------------------------------
src/changes/changes.xml | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/6dc663de/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index 77e687d..cd32009 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -31,7 +31,7 @@
Support merging configurations to for a composite configuration.
</action>
<action issue="LOG4J2-1357" dev="mikes" type="add">
- Option to not log stacktraces for logged Throwables in GelfLayout.
+ Option to not log stack traces for logged Throwables in GelfLayout.
</action>
<action issue="LOG4J2-1375" dev="rpopma" type="update">
Update SLF4J from 1.7.13 to 1.7.21.
[05/19] logging-log4j2 git commit: Make procId a field and make a
note for Java 9. Non-Java 9 impls are possible but hacky. See
https://issues.apache.org/jira/browse/LOG4J2-1377
Posted by mi...@apache.org.
Make procId a field and make a note for Java 9. Non-Java 9 impls are
possible but hacky. See
https://issues.apache.org/jira/browse/LOG4J2-1377
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/fc19d684
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/fc19d684
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/fc19d684
Branch: refs/heads/LOG4J2-1347
Commit: fc19d684a06b42d5e395277bfb3b67213b206730
Parents: ff8aede
Author: ggregory <gg...@apache.org>
Authored: Mon May 2 14:12:26 2016 -0700
Committer: ggregory <gg...@apache.org>
Committed: Mon May 2 14:12:26 2016 -0700
----------------------------------------------------------------------
.../org/apache/logging/log4j/core/layout/Rfc5424Layout.java | 5 ++++-
1 file changed, 4 insertions(+), 1 deletion(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/fc19d684/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/Rfc5424Layout.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/Rfc5424Layout.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/Rfc5424Layout.java
index b450940..cde4b36 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/Rfc5424Layout.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/Rfc5424Layout.java
@@ -119,6 +119,7 @@ public final class Rfc5424Layout extends AbstractStringLayout {
private final List<PatternFormatter> exceptionFormatters;
private final Map<String, FieldFormatter> fieldFormatters;
+ private final String procId;
private Rfc5424Layout(final Configuration config, final Facility facility, final String id, final int ein,
final boolean includeMDC, final boolean includeNL, final String escapeNL, final String mdcId,
@@ -189,6 +190,8 @@ public final class Rfc5424Layout extends AbstractStringLayout {
final String name = config == null ? null : config.getName();
configName = Strings.isNotEmpty(name) ? name : null;
this.fieldFormatters = createFieldFormatters(loggerFields, config);
+ // TODO Java 9: ProcessHandle.current().getPid();
+ this.procId = "-";
}
private Map<String, FieldFormatter> createFieldFormatters(final LoggerFields[] loggerFields,
@@ -418,7 +421,7 @@ public final class Rfc5424Layout extends AbstractStringLayout {
}
protected String getProcId() {
- return "-";
+ return procId;
}
protected List<String> getMdcExcludes() {
[18/19] logging-log4j2 git commit: Merge branch 'master' into
LOG4J2-1347
Posted by mi...@apache.org.
Merge branch 'master' into LOG4J2-1347
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/6cb9f992
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/6cb9f992
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/6cb9f992
Branch: refs/heads/LOG4J2-1347
Commit: 6cb9f99271eb2701400928f7a271c0fd162d3cc2
Parents: d9f2a34 acce51a
Author: Mikael St�ldal <mi...@magine.com>
Authored: Wed May 4 13:42:00 2016 +0200
Committer: Mikael St�ldal <mi...@magine.com>
Committed: Wed May 4 13:42:00 2016 +0200
----------------------------------------------------------------------
.../log4j/core/layout/Rfc5424Layout.java | 5 +-
.../log4j/core/pattern/NameAbbreviator.java | 77 ++++++-
.../log4j/core/layout/PatternLayoutTest.java | 202 +++++++++++++++++++
src/changes/changes.xml | 10 +-
.../ResponseTimeAsyncClassicVsGcFree-label.png | Bin 31517 -> 29217 bytes
.../ResponseTimeVsServiceTimeAsyncLoggers.png | Bin 0 -> 34779 bytes
.../SyncThroughputLoggerComparisonLinux.png | Bin 0 -> 69223 bytes
.../garbage-free2.6-SyncThroughputLinux.png | Bin 70039 -> 65092 bytes
src/site/xdoc/index.xml | 6 +
src/site/xdoc/manual/garbagefree.xml | 81 +++++---
src/site/xdoc/manual/index.xml | 10 +-
src/site/xdoc/manual/layouts.xml.vm | 34 +++-
src/site/xdoc/performance.xml | 145 +++++++++----
src/site/xdoc/runtime-dependencies.xml | 35 ++--
14 files changed, 507 insertions(+), 98 deletions(-)
----------------------------------------------------------------------
[10/19] logging-log4j2 git commit: Merge remote-tracking branch
'origin/master'
Posted by mi...@apache.org.
Merge remote-tracking branch 'origin/master'
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/57d14726
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/57d14726
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/57d14726
Branch: refs/heads/LOG4J2-1347
Commit: 57d147266a7f86e2e375b75f5933ce9a4841e3c8
Parents: 50ef623 6dc663d
Author: rpopma <rp...@apache.org>
Authored: Tue May 3 22:36:16 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Tue May 3 22:36:16 2016 +0900
----------------------------------------------------------------------
.../log4j/core/layout/Rfc5424Layout.java | 5 +-
.../log4j/core/pattern/NameAbbreviator.java | 77 ++++++-
.../log4j/core/layout/PatternLayoutTest.java | 202 +++++++++++++++++++
src/changes/changes.xml | 7 +-
src/site/xdoc/manual/layouts.xml.vm | 34 +++-
5 files changed, 310 insertions(+), 15 deletions(-)
----------------------------------------------------------------------
[12/19] logging-log4j2 git commit: LOG4J2-1179 added graph to compare
synchronous logging performance of logging libraries
Posted by mi...@apache.org.
LOG4J2-1179 added graph to compare synchronous logging performance of logging libraries
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/59443e19
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/59443e19
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/59443e19
Branch: refs/heads/LOG4J2-1347
Commit: 59443e194e7c455323ff1e8fbf1e5cacad1482c3
Parents: 119d6b7
Author: rpopma <rp...@apache.org>
Authored: Wed May 4 01:54:49 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Wed May 4 01:54:49 2016 +0900
----------------------------------------------------------------------
.../images/SyncThroughputLoggerComparisonLinux.png | Bin 0 -> 69223 bytes
1 file changed, 0 insertions(+), 0 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/59443e19/src/site/resources/images/SyncThroughputLoggerComparisonLinux.png
----------------------------------------------------------------------
diff --git a/src/site/resources/images/SyncThroughputLoggerComparisonLinux.png b/src/site/resources/images/SyncThroughputLoggerComparisonLinux.png
new file mode 100644
index 0000000..7b11fbe
Binary files /dev/null and b/src/site/resources/images/SyncThroughputLoggerComparisonLinux.png differ
[14/19] logging-log4j2 git commit: LOG4J2-1179 performance page
initial cut (work in progress)
Posted by mi...@apache.org.
LOG4J2-1179 performance page initial cut (work in progress)
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/f342618a
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/f342618a
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/f342618a
Branch: refs/heads/LOG4J2-1347
Commit: f342618a9e1c2bbca6b38d707ae3384ebc12f66c
Parents: 286290c
Author: rpopma <rp...@apache.org>
Authored: Wed May 4 02:25:36 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Wed May 4 02:25:36 2016 +0900
----------------------------------------------------------------------
src/site/xdoc/performance.xml | 137 +++++++++++++++++++++++++------------
1 file changed, 95 insertions(+), 42 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/f342618a/src/site/xdoc/performance.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/performance.xml b/src/site/xdoc/performance.xml
index 1e70baf..f7087aa 100644
--- a/src/site/xdoc/performance.xml
+++ b/src/site/xdoc/performance.xml
@@ -21,20 +21,109 @@
xsi:schemaLocation="http://maven.apache.org/XDOC/2.0 http://maven.apache.org/xsd/xdoc-2.0.xsd">
<properties>
<title>Performance</title>
+ <author email="rpopma@apache.org">Remko Popma</author>
<author email="rgoers@apache.org">Ralph Goers</author>
</properties>
<body>
<section name="Performance">
+ <!--
<p>One of the often-cited arguments against logging is its
computational cost. This is a legitimate concern as even moderately
sized applications can generate thousands of log requests. Much
effort was spent measuring and tweaking logging performance. Log4j
claims to be fast and flexible: speed first, flexibility second.
</p>
+ -->
+ <p>Apart from functional requirements, an important reason for selecting a logging library is often how well it
+ fulfills non-functional requirements like reliability and performance.</p>
+ <p>On this page we will compare the performance of a number of logging frameworks
+ (java.util.logging "JUL", Logback, Log4j 1.2 and Log4j 2.6),
+ and document some performance trade-offs for Log4j 2 functionality.
+ </p>
+ <h2>Benchmarks</h2>
+ <p>Performance can mean different things to different people. Common terms in this context are
+ throughput and latency: <em>Throughput</em> is a measure of capacity and can be expressed in a single number:
+ how many messages can be logged in a certain period of time.
+ <em>Response time latency</em> is how long it takes to log a message.
+ This cannot be expressed in a single number because each measurement has its own
+ response time and we are often most interested in the outliers: how many there were and how large they were.</p>
+ <p>We will measure and compare three performance indicators: </p>
+ <ul>
+ <li><b>Peak throughput</b> is the maximum throughput measured over a short period of time.
+ This number is useful for systems that need to log bursts of messages followed by periods of
+ relative quiet. Many systems that react to external events behave like this,
+ but for systems that need to log a lot at a constant high rate (for example, batch jobs)
+ this is less likely to be a useful measure of performance.</li>
+ <li><b>Maximum sustained throughput</b> is the throughput averaged over a long time.
+ This is a useful measure of the "upper limit" of the capacity of the logging library.
+ It is not recommended that reactive applications actually log at this rate since under this load
+ they will likely experience jitter and large response time spikes.</li>
+ <li><p>
+ <b>Response time</b> is the total amount of time it takes to log a message and is the sum of the
+ service time and wait time. The service time is the time it takes to do the work to log the message.
+ As the workload increases, the service time often varies little:
+ to do X amount of work it always takes X amount of time.
+ The wait time is how long the request had to wait in a queue before being serviced.
+ <em>As the workload increases, wait time often grows to many times the service time.</em>
+ </p>
+ <p>
+ What is often measured and reported as <em>latency</em> is actually <em>service time</em>,
+ which unfortunately hides the wait time.
+ To learn more, watch Gil Tene's
+ <a href="http://www.infoq.com/presentations/latency-response-time">How NOT to measure latency</a>
+ (and prepare to be shocked).
+ </p>
+ </li>
+ </ul>
+ <h2>Logging Library Performance Comparison</h2>
+
+ <h3>Asynchronous Logging - Peak Throughput Comparison</h3>
+ <p>Asynchronous Logging is useful to deal with bursts of events. How this works is that
+ a minimum amount of work is done by the application thread to capture all required information in a log event,
+ and this log event is then put on a queue for later processing by a background thread.
+ As long as the queue is sized large enough, the application threads should be able to spend
+ very little time on the logging call and return to the business logic very quickly.
+ </p>
+ <p>It turns out that the choice of queue is extremely important for peak throughput.
+ Log4j 2's Async Loggers use a
+ <a href="http://lmax-exchange.github.com/disruptor/">lock-free data structure</a>, whereas
+ Logback, Log4j 1.2 and Log4j 2's Asynchronous Appenders use an ArrayBlockingQueue.
+ With a blocking queue, multi-threaded applications often experience lock contention when trying to
+ enqueue the log event.
+ </p>
+ <p>The graph below illustrates the difference in peak throughput.
+ For details, see the <a href="manual/async.html">Async
+ Loggers</a> manual page.</p>
+ <p><img src="images/async-throughput-comparison.png" alt="Peak throughput comparison" />
+ </p>
+ <p>The results above were obtained with log4j-2.0-beta5, disruptor-3.0.0.beta3,
+ log4j-1.2.17 and logback-1.0.10.
+ </p>
+
+ <h3>Synchronous File Logging - Sustained Throughput Comparison</h3>
+ <p>The graph below compares Log4j 2.6 in garbage-free mode to Log4j 2.6 "classic" mode (which allocates
+ temporary objects for every logging call), Log4j 1.2.17, Logback 1.1.7 and
+ Java util logging (JUL) on Oracle Java 1.8.0_45. The Log4j 2.x results use the RandomAccessFile appender.
+ Log4j 1.2.17, Logback and JUL use their respective File appenders. ImmediateFlush was set to <tt>false</tt> for all
+ loggers that support this. The JUL results are for the <tt>XMLFormatter</tt> (which in our measurements was
+ about twice as fast as the <tt>SimpleFormatter</tt>).</p>
+ <p>Our test results suggest that the throughput of the other logging frameworks we tested
+ will rapidly decline in multi-threaded applications.</p>
+ <p><img src="images/SyncThroughputLoggerComparisonLinux.png" /></p>
+ <p>The synchronous logging throughput results above are obtained with the
+ <a href="http://openjdk.java.net/projects/code-tools/jmh/">JMH</a> Java benchmark harness.
+ See the <tt>org.apache.logging.log4j.perf.jmh.FileAppenderBenchmark</tt> source code in the log4j-perf module.</p>
+
+ <h3>Synchronous File Logging - Response Time Comparison</h3>
+
+ <h3>Synchronous Socket Sustained Throughput Comparison</h3>
+ <h3>Synchronous Syslog Sustained Throughput Comparison</h3>
+
+ <h2>Trade-offs</h2>
+
+ <!--
<p>The user should be aware of the following performance issues.</p>
- <ol>
- <li>
<h3>Logging performance when logging is turned off.</h3>
<p>When logging is turned off entirely or just for a set of Levels, the cost of a log request consists of
two method invocations plus an integer comparison. On a 2.53 GHz Intel Core 2 Duo MacBook Pro
@@ -116,16 +205,12 @@
a disproportionate price to pay in exchange for a small performance
gain.
</p>
- </li>
- <li>
<h3>The performance of deciding whether to log or not to log when logging is turned on.</h3>
<p>
Unlike Log4j, Log4j 2 Loggers don't "walk a hierarchy". Loggers point directly to the
Logger configuration that best matches the Logger's name. This incurs extra overhead when the Logger
is first created but reduces the overhead every time the Logger is used.
</p>
- </li>
- <li>
<h3>Actually outputting log messages</h3>
<p>This is the cost of formatting the log output and sending it to its target destination. Here again,
a serious effort was made to make layouts (formatters) perform as quickly as possible. The same
@@ -147,8 +232,7 @@
times more expensive than when they are disabled, so it is always recommended to take advantage of
Log4j 2's fine-grained filtering capabilities.
</p>
- </li>
- <li>
+ -->
<h3>Advanced Filtering</h3>
<p>
Both Logback and Log4j 2 support advanced filtering. Logback calls them TurboFilters while
@@ -206,8 +290,7 @@
<td>92</td>
</tr>
</table>
- </li>
- <li>
+
<h3>Client vs Server</h3>
<p>
Java supports a "client" and a "server" mode of operation. By default, applications that are
@@ -216,38 +299,8 @@
Testing has shown that Log4j 2 benefits greatly from running in server mode and user's are
strongly encouraged to configure their applications to run in server mode when using Log4j 2.
</p>
- </li>
- <li>
- <h3>Asynchronous Logging Performance Improvements</h3>
- <p>
- Log4j 2 offers Asynchronous Loggers for high throughput and low latency logging.
- Asynchronous Loggers are implemented using the
- <a href="http://lmax-exchange.github.com/disruptor/">LMAX Disruptor</a>
- inter-thread messaging library instead of the ArrayBlockingQueue used by Asynchronous Appenders.
- </p><p>
- Asynchronous Appenders already offered about 5 - 10 times more throughput than
- synchronous loggers, but this advantage remained more or less constant
- when more threads are logging. That is, if you double the number of threads
- that are logging you would expect your total throughput to increase, but
- this is not the case: the throughput per thread is roughly halved so your
- total throughput remains more or less the same.
- (Note that this happens even if the appender queue size is large enough to hold
- all messages logged during the test, so this is not caused by disk I/O.)
- </p><p>
- Asynchronous Loggers have significantly higher throughput than the legacy Asynchronous Appenders,
- especially in multi-threaded scenarios. In one test with 64 threads,
- Asynchronous Loggers were 12 times faster than the fastest Asynchronous Appender,
- and 68 times faster than the fastest synchronous logger.
- In addition to throughput, Asynchronous Loggers have attractive latency characteristics.
- Not only is average latency lower compared to Asynchronous Appenders,
- but when increasing the number of application threads that do logging,
- worst-case latency remained almost constant (10 - 20 microseconds)
- where Asynchronous Appenders start experiencing worst-case
- latency spikes in the 100 millisecond range, a difference of four orders of magnitude.
- See <a href="manual/async.html#Performance">Asynchronous Logging Performance</a> for details.
- </p>
- </li>
- </ol>
+
+
<p>
The performance results above were all derived from running the DebugDisabledPerformanceComparison,
FilterPerformanceComparison, and PerformanceComparison junit tests which can be found in the