Repository: logging-log4j2
Updated Branches:
  refs/heads/master 86e8caa1e -> 59a9c2d4d


LOG4J2-1802: Convert garbage-free manual page to asciidoc


Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/59a9c2d4
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/59a9c2d4
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/59a9c2d4

Branch: refs/heads/master
Commit: 59a9c2d4dce1c5f034aabe87eb939196b775b42e
Parents: bd15f9d
Author: Matt Sicker <boa...@gmail.com>
Authored: Sun Apr 8 20:08:36 2018 -0500
Committer: Matt Sicker <boa...@gmail.com>
Committed: Sun Apr 8 20:08:49 2018 -0500

----------------------------------------------------------------------
 src/site/asciidoc/manual/garbagefree.adoc | 578 ++++++++++++++++++++++++
 src/site/xdoc/manual/garbagefree.xml      | 598 -------------------------
 2 files changed, 578 insertions(+), 598 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/59a9c2d4/src/site/asciidoc/manual/garbagefree.adoc
----------------------------------------------------------------------
diff --git a/src/site/asciidoc/manual/garbagefree.adoc 
b/src/site/asciidoc/manual/garbagefree.adoc
new file mode 100644
index 0000000..0b88426
--- /dev/null
+++ b/src/site/asciidoc/manual/garbagefree.adoc
@@ -0,0 +1,578 @@
+////
+    Licensed to the Apache Software Foundation (ASF) under one or more
+    contributor license agreements.  See the NOTICE file distributed with
+    this work for additional information regarding copyright ownership.
+    The ASF licenses this file to You under the Apache License, Version 2.0
+    (the "License"); you may not use this file except in compliance with
+    the License.  You may obtain a copy of the License at
+
+         http://www.apache.org/licenses/LICENSE-2.0
+
+    Unless required by applicable law or agreed to in writing, software
+    distributed under the License is distributed on an "AS IS" BASIS,
+    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+    See the License for the specific language governing permissions and
+    limitations under the License.
+////
+= Garbage-free Steady State Logging
+Remko Popma <rpo...@apache.org>
+
+////
+Different applications have different performance requirements.
+Some only need to worry about throughput, but for many
+the most important performance consideration is latency (response time).
+Users of such applications would consider it a serious problem
+if the system becomes unresponsive for more than a few seconds, or even 
milliseconds in some cases.
+In financial trading for example predictable low latency is so important that 
it is often considered
+worthwhile to trade off some throughput in return for a consistent response 
time.
+////
+
+Garbage collection pauses are a common cause of latency spikes and for
+many systems significant effort is spent on controlling these pauses.
+
+Many logging libraries, including previous versions of Log4j, allocate
+temporary objects like log event objects, Strings, char arrays, byte
+arrays and more during steady state logging. This contributes to
+pressure on the garbage collector and increases the frequency with which
+GC pauses occur.
+
+From version 2.6, Log4j runs in "garbage free" mode by default where
+objects and buffers are reused and no temporary objects are allocated as
+much as possible. There is also a "low garbage" mode which is not
+completely garbage free but does not use ThreadLocal fields. This is the
+default mode when Log4j link:#Config[detects] it is running in a web
+application. Finally, it is possible to switch off all garbage-free
+logic and run in "classic mode" instead. For details, see the
+link:#Config[Configuration] section below.
+
+[#jfr]
+== A Contrived Example
+
+To highlight the difference that garbage-free logging can make, we used
+Java Flight Recorder to measure a simple application that does nothing
+but log a simple string as often as possible for about 12 seconds.
+
+The application was configured to use Async Loggers, a RandomAccessFile
+appender and a "%d %p %c{1.} [%t] %m %ex%n" pattern layout. (Async
+Loggers used the Yield WaitStrategy.)
+
+Mission Control shows that with Log4j 2.5 this application allocates
+memory at a rate of about 809 MB/sec, resulting in 141 minor
+collections. Log4j 2.6 does not allocate temporary objects in this
+configuration, and as a result the same application with Log4j 2.6 has a
+memory allocation rate of 1.6 MB/sec and was GC-free with 0 (zero)
+garbage collections.
+
+[cols="2*"]
+|===
+|link:../images/log4j-2.5-FlightRecording.png[image:../images/log4j-2.5-FlightRecording-thumbnail40pct.png[image]]
 +
+With Log4j 2.5: memory allocation rate 809 MB/sec, 141 minor
+collections.
+|link:../images/log4j-2.6-FlightRecording.png[image:../images/log4j-2.6-FlightRecording-thumbnail40pct.png[image]]
 +
+Log4j 2.6 did not allocate temporary objects: 0 (zero) garbage
+collections.
+|===
+
+[#Config]
+== Configuration
+
+Garbage-free logging in Log4j 2.6 is partially implemented by reusing
+objects in ThreadLocal fields, and partially by reusing buffers when
+converting text to bytes.
+
+ThreadLocal fields holding non-JDK classes can cause memory leaks in web
+applications when the application server's thread pool continues to
+reference these fields after the web application is undeployed. To avoid
+causing memory leaks, Log4j will not use these ThreadLocals when it
+detects that it is used in a web application (when the
+`javax.servlet.Servlet` class is in the classpath, or when system
+property `log4j2.isWebapp` is set to "true").
+
+Some garbage-reducing functionality does not rely on ThreadLocals and is
+enabled by default for all applications: in Log4j 2.6, converting log
+events to text and text to bytes can be done by directly encoding text
+into a reused ByteBuffer without creating intermediary Strings, char
+arrays and byte arrays. So while logging is not completely garbage-free
+for web applications yet, the pressure on the garbage collector can
+still be significantly reduced.
+
+NOTE: As of version 2.6, a Log4j configuration containing a
+`<Properties>` section will result in temporary objects being created
+during steady-state logging.
+
+NOTE: The Async Logger Timeout wait strategy (the default) and the
+Block wait strategy cause
+`java.util.concurrent.locks.AbstractQueuedSynchronizer$Node` objects to
+be created. The Yield and Sleep wait strategies are garbage-free. (See
+link:async.html#SysPropsAllAsync[here] and
+link:async.html#SysPropsMixedSync-Async[here].)
+
+=== Disabling Garbage-free Logging
+
+There are two separate system properties for manually controlling the
+mechanisms Log4j uses to avoid creating temporary objects:
+
+* `log4j2.enableThreadlocals` - if "true" (the default for non-web
+applications) objects are stored in ThreadLocal fields and reused,
+otherwise new objects are created for each log event.
+* `log4j2.enableDirectEncoders` - if "true" (the default) log events are
+converted to text and this text is converted to bytes without creating
+temporary objects. Note: _synchronous_ logging performance may be worse
+for multi-threaded applications in this mode due to synchronization on
+the shared buffer. If your application is multi-threaded and logging
+performance is important, consider using Async Loggers.
+* The ThreadContext map is _not_ garbage-free by default, but from Log4j
+2.7 it can be configured to be garbage-free by setting system property
+`log4j2.garbagefreeThreadContextMap` to "true".
+
+Instead of system properties, the above properties can also be specified
+in a file named `log4j2.component.properties` by including this file in
+the classpath of the application. See the
+link:configuration.html#SystemProperties[manual regarding system
+properties] for more info.
+
+[#Appenders]
+=== Supported Appenders
+
+The following link:appenders.html[appenders] are garbage-free during
+steady-state logging:
+
+* Console
+* File
+* RollingFile (some temporary objects are created during file rollover)
+* RandomAccessFile
+* RollingRandomAccessFile (some temporary objects are created during
+file rollover)
+* MemoryMappedFile
+
+Any other appenders not in the above list (including AsyncAppender)
+create temporary objects during steady-state logging. Instead of
+AsyncAppender, use link:async.html[Async Loggers] to log asynchronously
+in a garbage-free manner.
+
+[#Filters]
+=== Supported Filters
+
+The following link:filters.html[filters] are garbage-free during
+steady-state logging:
+
+* CompositeFilter (adding and removing element filters creates temporary
+objects for thread safety)
+* DynamicThresholdFilter
+* LevelRangeFilter (garbage free since 2.8)
+* MapFilter (garbage free since 2.8)
+* MarkerFilter (garbage free since 2.8)
+* StructuredDataFilter (garbage free since 2.8)
+* ThreadContextMapFilter (garbage free since 2.8)
+* ThresholdFilter (garbage free since 2.8)
+* TimeFilter (garbage free since 2.8)
+
+Other filters like BurstFilter, RegexFilter and ScriptFilter are not
+trivial to make garbage free, and there is currently no plan to change
+them.
+
+[#Layouts]
+=== Supported Layouts
+
+==== GelfLayout
+
+GelfLayout is garbage-free when used with compressionType="OFF", as long
+as no additional field contains '${' (variable substitution).
+
+==== PatternLayout
+
+PatternLayout with the following limited set of conversion patterns is
+garbage-free. Format modifiers to control such things as field width,
+padding, left and right justification will not generate garbage.
+
+[cols="1,2"]
+|===
+|Conversion Pattern |Description
+
+|%c{precision}, %logger{precision}
+|Logger name
+
+|%d, %date
+a|
+Note: Only the predefined date formats are garbage-free: (millisecond
+separator may be either a comma ',' or a period '.')
+
+!===
+!Pattern !Example
+
+!%d{DEFAULT}
+!2012-11-02 14:34:02,781
+
+!%d{ISO8601}
+!2012-11-02T14:34:02,781
+
+!%d{ISO8601_BASIC}
+!20121102T143402,781
+
+!%d{ABSOLUTE}
+!14:34:02,781
+
+!%d{DATE}
+!02 Nov 2012 14:34:02,781
+
+!%d{COMPACT}
+!20121102143402781
+
+!%d{HH:mm:ss,SSS}
+!14:34:02,781
+
+!%d{dd MMM yyyy HH:mm:ss,SSS}
+!02 Nov 2012 14:34:02,781
+
+!%d{HH:mm:ss}{GMT+0}
+!18:34:02
+
+!%d{UNIX}
+!1351866842
+
+!%d{UNIX_MILLIS}
+!1351866842781
+!===
+
+|%enc{pattern}, %encode{pattern}
+|Encodes special characters such as
+'\n' and HTML characters to help prevent log forging and some XSS
+attacks that could occur when displaying logs in a web browser -
+garbage-free since 2.8
+
+|%equals{pattern}{test}{substitution},
+%equalsIgnoreCase{pattern}{test}{substitution}
+|Replaces occurrences
+of 'test', a string, with its replacement 'substitution' in the string
+resulting from evaluation of the pattern - garbage-free since 2.8
+
+|%highlight{pattern}{style}
+|Adds ANSI colors - garbage-free since 2.7
+(unless nested pattern is not garbage free)
+
+|%K{key}, %map{key}, %MAP{key}
+|Outputs the entries in a
+link:../log4j-api/apidocs/org/apache/logging/log4j/message/MapMessage.html[MapMessage],
+if one is present in the event - garbage-free since 2.8.
+
+|%m, %msg, %message
+|Log message (garbage-free unless message text
+contains '${')
+
+|%marker
+|The full name of the marker (including parents) - garbage-free
+since 2.8
+
+|%markerSimpleName
+|The simple name of the marker (not including
+parents)
+
+|%maxLen, %maxLength
+|Truncates another pattern to some max number of
+characters - garbage-free since 2.8
+
+|%n
+|The platform dependent line separator
+
+|%N, %nano
+|System.nanoTime() when the event was logged
+
+|%notEmpty{pattern}, %varsNotEmpty{pattern},
+%variablesNotEmpty{pattern}
+|Outputs the result of evaluating the
+pattern if and only if all variables in the pattern are not empty -
+garbage-free since 2.8
+
+|%p, %level
+|The level of the logging event
+
+|%r, %relative
+|The number of milliseconds elapsed since the JVM was
+started until the creation of the logging event - garbage-free since 2.8
+
+|%sn, %sequenceNumber
+|A sequence number that will be incremented in
+every event - garbage-free since 2.8
+
+|%style{pattern}{ANSI style}
+|Style the message - garbage-free since
+2.7 (unless nested pattern is not garbage free)
+
+|%T, %tid, %threadId
+|The ID of the thread that generated the logging
+event
+
+|%t, %tn, %thread, %threadName
+|The name of the thread that generated
+the logging event
+
+|%tp
+|The priority of the thread that generated the logging event
+
+|%X{key[,key2...]}, %mdc{key[,key2...]}, %MDC{key[,key2...]}
+|Outputs
+the Thread Context Map (also known as the Mapped Diagnostic Context or
+MDC) associated with the thread that generated the logging event -
+garbage-free since 2.8
+
+|literal text
+|Garbage-free unless literal contains '${' (variable
+substitution)
+|===
+
+Other PatternLayout conversion patterns, and other Layouts may be
+updated to avoid creating temporary objects in future releases. (Patches
+welcome!)
+
+NOTE: Logging exceptions and stack traces will create temporary
+objects with any layout. (However, Layouts will only create these
+temporary objects when an exception actually occurs.) We haven't figured
+out a way to log exceptions and stack traces without creating temporary
+objects. That is unfortunate, but you probably still want to log them
+when they happen.
+
+****
+NOTE: patterns containing regular expressions and lookups for property
+substitution will result in temporary objects being created during
+steady-state logging.
+
+Including location information is done by walking the stacktrace of an
+exception, which creates temporary objects, so the following patterns
+are not garbage-free:
+
+* %C, %class - Class Name
+* %F, %file - File Location
+* %l, %location - Location
+* %L, %line - Line Location
+* %M, %method - Method Location
+
+Also, the pattern converters for formatting Throwables are not
+garbage-free:
+
+* %ex, %exception, %throwable - The Throwable trace bound to the
+LoggingEvent
+* %rEx, %rException %rThrowable - Same as %ex but with wrapping
+exceptions
+* %xEx, %xException, %xThrowable - Same as %ex but with class packaging
+information
+* %u, %uuid - Creates a new random or time-based UUID while formatting
+
+****
+
+[#api]
+=== API Changes
+
+Methods have been added to the `Logger` interface so that no vararg
+array objects are created when logging messages with up to ten
+parameters.
+
+Also, methods have been added to the `Logger` interface to log
+`java.lang.CharSequence` messages. User-defined objects that implement
+the `CharSequence` interface can be logged without creating temporary
+objects: Log4j will try to turn CharSequence messages, Object messages
+and message parameters into text by appending them to a StringBuilder as
+a CharSequence. This avoids calling `toString()` on these objects.
+
+An alternative is to implement the
+http://logging.apache.org/log4j/2.x/log4j-api/xref/org/apache/logging/log4j/util/StringBuilderFormattable.html[`org.apache.logging.log4j.util.StringBuilderFormattable`]
+interface. If an object is logged that implements this interface, its
+`formatTo` method is called instead of `toString()`.
+
+Log4j may call `toString()` on message and parameter objects when
+garbage-free logging is disabled (when system property
+`log4j2.enableThreadlocals` is set to "false".)
+
+[#codeImpact]
+=== Impact on Application Code: Autoboxing
+
+We made an effort to make logging garbage-free without requiring code
+changes in existing applications, but there is one area where this was
+not possible. When logging primitive values (i.e. int, double, boolean,
+etc.) the JVM autoboxes these primitive values to their Object wrapper
+equivalents, creating garbage.
+
+Log4j provides an `Unbox` utility to prevent autoboxing of primitive
+parameters. This utility contains a thread-local pool of reused
+`StringBuilder`s. The `Unbox.box(primitive)` methods write directly into
+a StringBuilder, and the resulting text will be copied into the final
+log message text without creating temporary objects.
+
+[source,java]
+----
+import static org.apache.logging.log4j.util.Unbox.box;
+
+// ...
+public void garbageFree() {
+    logger.debug("Prevent primitive autoboxing {} {}", box(10L), box(2.6d));
+}
+----
+
+****
+NOTE: not all logging is garbage free. Specifically:
+
+* The ThreadContext map is not garbage-free by default, but can be
+configured to be garbage-free by setting system property
+`log4j2.garbagefreeThreadContextMap` to "true".
+* The ThreadContext stack is not garbage-free.
+* Logging more than 10 parameters creates vararg arrays.
+* Logging very large messages (more than 518 characters) when all
+loggers are Async Loggers will cause the internal StringBuilder in the
+RingBuffer to be trimmed back to their max size.
+* Logging messages containing '${': substituting a ${variable} creates
+temporary objects.
+* Logging a lambda _as a parameter_
+(`logger.info("lambda value is {}", () -> callExpensiveMethod())`)
+creates a vararg array. Logging a lambda expression by itself is
+garbage-free: `logger.debug(() -> callExpensiveMethod())`.
+* The `Logger.traceEntry` and `Logger.traceExit` methods create
+temporary objects.
+****
+
+[#Performance]
+== Performance
+
+[#Latency]
+=== Response Time Latency
+
+Response time is how long it takes to log a message under a certain
+load. What is often reported as latency is actually _service time_: 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 response time: service time plus
+wait time. See the link:../performance.html#responseTime[response time
+section] of the performance page for more detail.
+
+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:
+
+* -Xms1G -Xmx1G (prevent heap resizing during the test)
+* 
-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
+-DAsyncLogger.WaitStrategy=busyspin (to use Async Loggers. The BusySpin
+wait strategy reduces some jitter.)
+* *classic mode:* -Dlog4j2.enable.threadlocals=false
+-Dlog4j2.enable.direct.encoders=false +
+*garbage-free mode:* -Dlog4j2.enable.threadlocals=true
+-Dlog4j2.enable.direct.encoders=true
+* 
-XX:CompileCommand=dontinline,org.apache.logging.log4j.core.async.perftest.NoOpIdleStrategy::idle
+* -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps
+-XX:+PrintTenuringDistribution -XX:+PrintGCApplicationConcurrentTime
+-XX:+PrintGCApplicationStoppedTime (to eyeball GC and safepoint pauses)
+
+=== Async Loggers
+
+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
+a sustained load of 800,000 messages/second.
+
+image:../images/ResponseTimeAsyncClassicVsGcFree-label.png[image]
+
+In *classic* 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). This makes sense: logging more means more pressure on the
+garbage collector resulting in more minor GC pauses. 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.
+
+In *garbage-free* 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.
+
+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 response times of tens of
+milliseconds or more; and attempting to increase the load even more
+results in larger and larger response time spikes.
+
+=== Synchronous File Logging
+
+With synchronous file logging, garbage-free logging still performs
+better than classic logging, but the difference is less pronounced.
+
+At a workload of 100,000 messages/second, classic logging max response
+time was a little over 2 milliseconds where garbage-free logging was a
+little over 1 millisecond. When the workload is increased to 300,000
+messages/second, classic logging shows response time pauses of 6
+milliseconds where the garbage-free response times were less than 3
+milliseconds. It may be possible to improve on this, we did not
+investigate further yet.
+
+image:../images/ResponseTimeSyncClassicVsGcFree.png[image]
+
+The above results are obtained with the ResponseTimeTest class which can
+be found in the Log4j 2 unit test source directory, running on JDK
+1.8.0_45 on RHEL 6.5 (Linux 2.6.32-573.1.1.el6.x86_64) with 10-core Xeon
+CPU E5-2660 v3 @2.60GHz with hyperthreading switched on (20 virtual
+cores).
+
+[#Throughput]
+=== Classic Logging has Slightly Higher Throughput
+
+Throughput is slightly worse for garbage-free logging, compared to
+classic logging. This is true for both synchronous and asynchronous
+logging. The graph below compares the sustained throughput of
+synchronous logging to a file with Log4j 2.6 in garbage-free mode,
+classic mode and Log4j 2.5.
+
+image:../images/garbage-free2.6-SyncThroughputLinux.png[Throughput of
+Log4j 2.6 in garbage-free mode is slightly worse than in classic mode,
+but on par with 2.5 and much better than alternatives logging libraries]
+
+The results above are obtained with the
+http://openjdk.java.net/projects/code-tools/jmh/[JMH] Java benchmark
+harness. See the FileAppenderBenchmark source code in the log4j-perf
+module.
+
+[#UnderTheHood]
+== Under the Hood
+
+Custom Message implementations that implement
+`org.apache.logging.log4j.util.StringBuilderFormattable` can be
+converted to text by garbage-free Layouts without creating temporary
+objects. PatternLayout uses this mechanism and other layouts that
+convert LogEvents to text will likely also look for this interface.
+
+Custom Layouts that want to be garbage-free should implement the
+`Encoder<LogEvent>` interface. For custom Layouts that convert a
+LogEvent to a text representation, the
+`org.apache.logging.log4j.core.layout.StringBuilderEncoder` class may be
+useful to convert this text to bytes in a garbage-free manner.
+
+Custom Appenders that want to be garbage-free should provide their
+Layout with a `ByteBufferDestination` implementation that the Layout can
+directly write into.
+
+`AbstractOutputStreamAppender` has been modified to make the
+ConsoleAppender, (Rolling)FileAppender,
+(Rolling)RandomAccessFileAppender and MemoryMappedFileAppender
+garbage-free. An effort has been made to minimize impact on custom
+Appenders that extend `AbstractOutputStreamAppender`, but it is
+impossible to guarantee that changing the superclass will not impact any
+and all subclasses. Custom Appenders that extend
+`AbstractOutputStreamAppender` should verify that they still function
+correctly. In case there is a problem, system property
+`log4j2.enable.direct.encoders` can be set to "false" to revert to the
+pre-Log4j 2.6 behaviour.
+
+////
+TODO Applications that wish to reuse custom Message instances with Async 
Loggers should let
+their Message classes implement the 
`org.apache.logging.log4j.message.ReusableMessage` interface.
+TODO This is not sufficient: see LOG4J2-1342, would be nice if we could solve 
this in a generic way.
+////

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/59a9c2d4/src/site/xdoc/manual/garbagefree.xml
----------------------------------------------------------------------
diff --git a/src/site/xdoc/manual/garbagefree.xml 
b/src/site/xdoc/manual/garbagefree.xml
deleted file mode 100644
index b0852bc..0000000
--- a/src/site/xdoc/manual/garbagefree.xml
+++ /dev/null
@@ -1,598 +0,0 @@
-<?xml version="1.0"?>
-<!-- Licensed to the Apache Software Foundation (ASF) under one or more 
contributor
-  license agreements. See the NOTICE file distributed with this work for 
additional
-  information regarding copyright ownership. The ASF licenses this file to
-  You under the Apache License, Version 2.0 (the "License"); you may not use
-  this file except in compliance with the License. You may obtain a copy of
-  the License at http://www.apache.org/licenses/LICENSE-2.0 Unless required
-  by applicable law or agreed to in writing, software distributed under the
-  License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS
-  OF ANY KIND, either express or implied. See the License for the specific
-  language governing permissions and limitations under the License. -->
-<document xmlns="http://maven.apache.org/XDOC/2.0"; 
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance";
-  xsi:schemaLocation="http://maven.apache.org/XDOC/2.0 
http://maven.apache.org/xsd/xdoc-2.0.xsd";>
-  <properties>
-    <title>Garbage-free Steady State Logging</title>
-    <author email="rpo...@apache.org">Remko Popma</author>
-  </properties>
-  <body>
-    <section name="Garbage-free Steady State Logging">
-      <!--
-      <p>
-        Different applications have different performance requirements.
-        Some only need to worry about throughput, but for many
-        the most important performance consideration is latency (response 
time).
-        Users of such applications would consider it a serious problem
-        if the system becomes unresponsive for more than a few seconds, or 
even milliseconds in some cases.
-        In financial trading for example predictable low latency is so 
important that it is often considered
-        worthwhile to trade off some throughput in return for a consistent 
response time.
-      </p>
-      -->
-      <p>
-        Garbage collection pauses are a common cause of latency spikes and for 
many systems
-        significant effort is spent on controlling these pauses.
-      </p>
-      <p>
-        Many logging libraries, including previous versions of Log4j, allocate 
temporary objects like
-        log event objects, Strings, char arrays, byte arrays and more during 
steady state logging.
-        This contributes to pressure on the garbage collector and increases 
the frequency with which GC pauses occur.
-      </p>
-      <p>
-        From version 2.6, Log4j runs in "garbage free" mode by default
-        where objects and buffers are reused and no temporary objects are 
allocated as much as possible.
-        There is also a "low garbage" mode which is not completely garbage 
free but does not use ThreadLocal fields.
-        This is the default mode when Log4j <a href="#Config">detects</a> it 
is running in a web application.
-        <!--
-      </p>
-      <p>
-      -->
-        Finally, it is possible to switch off all garbage-free logic and run 
in "classic mode" instead.
-        For details, see the <a href="#Config">Configuration</a> section below.
-      </p>
-      <a name="jfr" />
-      <subsection name="A Contrived Example">
-        <p>
-          To highlight the difference that garbage-free logging can make, we 
used Java Flight Recorder
-          to measure a simple application that does nothing but log a simple 
string as often as possible
-          for about 12 seconds.
-        </p>
-        <p>
-          The application was configured to use Async Loggers, a 
RandomAccessFile appender and a
-          "%d %p %c{1.} [%t] %m %ex%n" pattern layout. (Async Loggers used the 
Yield WaitStrategy.)
-        </p>
-        <p>
-          Mission Control shows that with Log4j 2.5 this application allocates 
memory at a rate of about 809 MB/sec,
-          resulting in 141 minor collections.
-          Log4j 2.6 does not allocate temporary objects in this configuration, 
and as a result
-          the same application with Log4j 2.6 has a memory allocation rate of 
1.6 MB/sec and
-          was GC-free with 0 (zero) garbage collections.
-        </p>
-        <table>
-          <tr>
-            <td>
-        <a href="../images/log4j-2.5-FlightRecording.png"><img
-            src="../images/log4j-2.5-FlightRecording-thumbnail40pct.png" 
/></a><br />
-              With Log4j 2.5: memory allocation rate 809 MB/sec, 141 minor 
collections.
-            </td>
-            <td>
-              <a href="../images/log4j-2.6-FlightRecording.png"><img
-                  src="../images/log4j-2.6-FlightRecording-thumbnail40pct.png" 
/></a>
-              <br />
-              Log4j 2.6 did not allocate temporary objects: 0 (zero) garbage 
collections.
-            </td>
-          </tr>
-        </table>
-      </subsection>
-
-      <a name="Config" />
-      <subsection name="Configuration">
-        <p>Garbage-free logging in Log4j 2.6 is partially implemented by 
reusing objects in ThreadLocal fields,
-          and partially by reusing buffers when converting text to bytes.
-        </p>
-        <p>
-          ThreadLocal fields holding non-JDK classes can cause memory leaks in
-          web applications when the application server's thread pool continues 
to reference
-          these fields after the web application is undeployed.
-          To avoid causing memory leaks, Log4j will not use these ThreadLocals 
when
-          it detects that it is used in a web application
-          (when the <tt>javax.servlet.Servlet</tt> class is in the classpath,
-          or when system property <tt>log4j2.isWebapp</tt> is set to "true").
-        </p>
-          <p>
-            Some garbage-reducing functionality does not rely on ThreadLocals 
and is
-            enabled by default for all applications:
-            in Log4j 2.6, converting log events to text and text to bytes can 
be done by directly encoding text
-            into a reused ByteBuffer without creating intermediary Strings, 
char arrays and byte arrays.
-            So while logging is not completely garbage-free for web 
applications yet,
-            the pressure on the garbage collector can still be significantly 
reduced.
-          </p>
-          <table><tr><td><p>
-            <b>Note 1:</b> as of version 2.6, a Log4j configuration containing 
a <tt>&lt;Properties&gt;</tt> section
-            will result in temporary objects being created during steady-state 
logging.
-            </p>
-            <p>
-              <b>Note 2:</b> the Async Logger Timeout wait strategy (the 
default) and the Block wait strategy
-              cause 
<tt>java.util.concurrent.locks.AbstractQueuedSynchronizer$Node</tt> objects to 
be created.
-              The Yield and Sleep wait strategies are garbage-free. (See
-              <a href="async.html#SysPropsAllAsync">here</a> and
-              <a href="async.html#SysPropsMixedSync-Async">here</a>.)
-            </p>
-          </td></tr></table>
-          <h4>Disabling Garbage-free Logging</h4>
-          <p>
-            There are two separate system properties for manually controlling 
the mechanisms Log4j uses to avoid
-            creating temporary objects:
-          </p>
-          <ul>
-            <li><tt>log4j2.enableThreadlocals</tt> - if "true" (the default 
for non-web applications)
-              objects are stored in ThreadLocal fields and reused, otherwise 
new
-              objects are created for each log event.</li>
-            <li><tt>log4j2.enableDirectEncoders</tt> - if "true" (the default) 
log events are converted to text and this
-              text is converted to bytes without creating temporary objects. 
Note:
-              <em>synchronous</em> logging performance may be worse for 
multi-threaded applications in this mode due to
-              synchronization on the shared buffer. If your application is 
multi-threaded and logging performance
-              is important, consider using Async Loggers.
-              </li>
-            <li>The ThreadContext map is <em>not</em> garbage-free by default, 
but from Log4j 2.7 it can be configured
-              to be garbage-free by setting system property 
<tt>log4j2.garbagefreeThreadContextMap</tt> to "true".</li>
-          </ul>
-          <p>
-            Instead of system properties, the above properties can also be 
specified in a file named
-            <tt>log4j2.component.properties</tt> by including this file in the 
classpath of the application.
-            See the <a href="configuration.html#SystemProperties">manual 
regarding system properties</a> for more info.
-          </p>
-        <a name="Appenders" />
-          <h4>Supported Appenders</h4>
-          <p>
-            The following <a href="appenders.html">appenders</a> are 
garbage-free during steady-state logging:
-          </p>
-          <ul>
-            <li>Console</li>
-            <li>File</li>
-            <li>RollingFile (some temporary objects are created during file 
rollover)</li>
-            <li>RandomAccessFile</li>
-            <li>RollingRandomAccessFile (some temporary objects are created 
during file rollover)</li>
-            <li>MemoryMappedFile</li>
-          </ul>
-          <p>
-            Any other appenders not in the above list (including 
AsyncAppender) create temporary objects
-            during steady-state logging. Instead of AsyncAppender, use <a 
href="async.html">Async Loggers</a>
-            to log asynchronously in a garbage-free manner.
-          </p>
-
-        <a name="Filters" />
-        <h4>Supported Filters</h4>
-        <p>
-          The following <a href="filters.html">filters</a> are garbage-free 
during steady-state logging:
-        </p>
-        <ul>
-          <li>CompositeFilter (adding and removing element filters creates 
temporary objects for thread safety)</li>
-          <li>DynamicThresholdFilter</li>
-          <li>LevelRangeFilter (garbage free since 2.8)</li>
-          <li>MapFilter (garbage free since 2.8)</li>
-          <li>MarkerFilter (garbage free since 2.8)</li>
-          <li>StructuredDataFilter (garbage free since 2.8)</li>
-          <li>ThreadContextMapFilter (garbage free since 2.8)</li>
-          <li>ThresholdFilter (garbage free since 2.8)</li>
-          <li>TimeFilter (garbage free since 2.8)</li>
-        </ul>
-        <p>
-          Other filters like BurstFilter, RegexFilter and ScriptFilter are not 
trivial to make garbage free,
-          and there is currently no plan to change them.
-        </p>
-        <a name="Layouts" />
-          <h4>Supported Layouts</h4>
-
-          <h5>GelfLayout</h5>
-          <p>GelfLayout is garbage-free when used with compressionType="OFF",
-            as long as no additional field contains '${' (variable 
substitution).</p>
-
-          <h5>PatternLayout</h5>
-          <p>
-            PatternLayout with the following limited set of conversion 
patterns is garbage-free.
-            Format modifiers to control such things as field width, padding, 
left and right justification will not
-            generate garbage.
-          </p>
-          <table style="width: 80%">
-            <tr>
-              <th>Conversion Pattern</th>
-              <th>Description</th>
-            </tr>
-            <tr>
-              <td>%c{precision}, %logger{precision}</td>
-              <td>Logger name</td>
-            </tr>
-            <tr>
-              <td>%d, %date</td>
-              <td>Note: Only the predefined date formats are garbage-free: 
(millisecond separator may be either
-                a comma ',' or a period '.')
-                <table>
-                  <tr>
-                    <th>Pattern</th>
-                    <th>Example</th>
-                  </tr>
-                  <tr>
-                    <td>%d{DEFAULT}</td>
-                    <td>2012-11-02 14:34:02,781</td>
-                  </tr>
-                  <tr>
-                    <td>%d{ISO8601}</td>
-                    <td>2012-11-02T14:34:02,781</td>
-                  </tr>
-                  <tr>
-                    <td>%d{ISO8601_BASIC}</td>
-                    <td>20121102T143402,781</td>
-                  </tr>
-                  <tr>
-                    <td>%d{ABSOLUTE}</td>
-                    <td>14:34:02,781</td>
-                  </tr>
-                  <tr>
-                    <td>%d{DATE}</td>
-                    <td>02 Nov 2012 14:34:02,781</td>
-                  </tr>
-                  <tr>
-                    <td>%d{COMPACT}</td>
-                    <td>20121102143402781</td>
-                  </tr>
-                  <tr>
-                    <td>%d{HH:mm:ss,SSS}</td>
-                    <td>14:34:02,781</td>
-                  </tr>
-                  <tr>
-                    <td>%d{dd MMM yyyy HH:mm:ss,SSS}</td>
-                    <td>02 Nov 2012 14:34:02,781</td>
-                  </tr>
-                  <tr>
-                    <td>%d{HH:mm:ss}{GMT+0}</td>
-                    <td>18:34:02</td>
-                  </tr>
-                  <tr>
-                    <td>%d{UNIX}</td>
-                    <td>1351866842</td>
-                  </tr>
-                  <tr>
-                    <td>%d{UNIX_MILLIS}</td>
-                    <td>1351866842781</td>
-                  </tr>
-                </table>
-              </td>
-            </tr>
-            <tr>
-              <td>%enc{pattern},
-                %encode{pattern}</td>
-              <td>Encodes special characters such as '\n' and HTML characters 
to help prevent
-                log forging and some XSS attacks that could occur when 
displaying logs in
-                a web browser - garbage-free since 2.8</td>
-            </tr>
-            <tr>
-              <td>%equals{pattern}{test}{substitution},
-                %equalsIgnoreCase{pattern}{test}{substitution}</td>
-              <td>Replaces occurrences of 'test', a string, with its 
replacement 'substitution'
-                in the string resulting from evaluation of the pattern - 
garbage-free since 2.8</td>
-            </tr>
-            <tr>
-              <td>%highlight{pattern}{style}</td>
-              <td>Adds ANSI colors - garbage-free since 2.7 (unless nested 
pattern is not garbage free)</td>
-            </tr>
-            <tr>
-              <td>K{key}, map{key}, MAP{key}
-              </td>
-              <td>Outputs the entries in a
-                <a class="javadoc" 
href="../log4j-api/apidocs/org/apache/logging/log4j/message/MapMessage.html">MapMessage</a>,
-                if one is present in the event  - garbage-free since 2.8.</td>
-            </tr>
-            <tr>
-              <td>%m, %msg, %message</td>
-              <td>Log message (garbage-free unless message text contains 
'${')</td>
-            </tr>
-            <tr>
-              <td>%marker</td>
-              <td>The full name of the marker (including parents) - 
garbage-free since 2.8</td>
-            </tr>
-            <tr>
-              <td>%markerSimpleName</td>
-              <td>The simple name of the marker (not including parents)</td>
-            </tr>
-            <tr>
-              <td>%maxLen, %maxLength</td>
-              <td>Truncates another pattern to some max number of characters - 
garbage-free since 2.8</td>
-            </tr>
-            <tr>
-              <td>%n</td>
-              <td>The platform dependent line separator</td>
-            </tr>
-            <tr>
-              <td>%N, %nano</td>
-              <td>System.nanoTime() when the event was logged</td>
-            </tr>
-            <tr>
-              <td>%notEmpty{pattern},
-                %varsNotEmpty{pattern},
-                %variablesNotEmpty{pattern}
-              </td>
-              <td>Outputs the result of evaluating the pattern if and only if
-                all variables in the pattern are not empty - garbage-free 
since 2.8</td>
-            </tr>
-            <tr>
-              <td>%p, %level</td>
-              <td>The level of the logging event</td>
-            </tr>
-            <tr>
-              <td>%r,
-                %relative</td>
-              <td>The number of milliseconds elapsed since the JVM was started 
until the creation of the logging event
-                  - garbage-free since 2.8</td>
-            </tr>
-            <tr>
-              <td>%sn, %sequenceNumber</td>
-              <td>A sequence number that will be incremented in every event - 
garbage-free since 2.8</td>
-            </tr>
-            <tr>
-              <td>%style{pattern}{ANSI style}</td>
-              <td>Style the message - garbage-free since 2.7 (unless nested 
pattern is not garbage free)</td>
-            </tr>
-            <tr>
-              <td>%T, %tid, %threadId</td>
-              <td>The ID of the thread that generated the logging event</td>
-            </tr>
-            <tr>
-              <td>%t, %tn, %thread, %threadName</td>
-              <td>The name of the thread that generated the logging event</td>
-            </tr>
-            <tr>
-              <td>%tp</td>
-              <td>The priority of the thread that generated the logging 
event</td>
-            </tr>
-            <tr>
-              <td>%X{key[,key2...]},
-                %mdc{key[,key2...]},
-                %MDC{key[,key2...]}</td>
-              <td>Outputs the Thread Context Map (also known as the Mapped 
Diagnostic Context or MDC)
-                associated with the thread that generated the logging event - 
garbage-free since 2.8</td>
-            </tr>
-            <tr>
-              <td>literal text</td>
-              <td>Garbage-free unless literal contains '${' (variable 
substitution)</td>
-            </tr>
-          </table>
-          <p>
-            Other PatternLayout conversion patterns, and other Layouts may be 
updated
-            to avoid creating temporary objects in future releases. (Patches 
welcome!)
-          </p>
-          <p>
-            <em>Note</em>: Logging exceptions and stack traces will create 
temporary objects with any layout.
-            (However, Layouts will only create these temporary objects when an 
exception actually occurs.)
-            We haven't figured out a way to log exceptions and stack traces 
without creating temporary objects.
-            That is unfortunate, but you probably still want to log them when 
they happen.
-          </p>
-          <table><tr><td><b>Note:</b> patterns containing regular expressions 
and lookups for property substitution
-            will result in temporary objects being created during steady-state 
logging.
-            <p>
-              Including location information is done by walking the stacktrace 
of an exception, which creates temporary
-              objects, so the following patterns are not garbage-free:
-            </p>
-            <ul>
-              <li>%C, %class - Class Name</li>
-              <li>%F, %file - File Location</li>
-              <li>%l, %location - Location</li>
-              <li>%L, %line - Line Location</li>
-              <li>%M, %method - Method Location</li>
-            </ul>
-            Also, the pattern converters for formatting Throwables are not 
garbage-free:
-            <ul>
-              <li>%ex, %exception, %throwable - The Throwable trace bound to 
the LoggingEvent</li>
-              <li>%rEx, %rException %rThrowable - Same as %ex but with 
wrapping exceptions</li>
-              <li>%xEx, %xException, %xThrowable - Same as %ex but with class 
packaging information</li>
-              <li>%u, %uuid - Creates a new random or time-based UUID while 
formatting</li>
-            </ul>
-
-          </td></tr></table>
-        <a name="api" />
-          <h4>API Changes</h4>
-          <p>
-            Methods have been added to the <tt>Logger</tt> interface so that 
no vararg array objects are created
-            when logging messages with up to ten parameters.
-          </p>
-          <p>
-            Also, methods have been added to the <tt>Logger</tt> interface to 
log <tt>java.lang.CharSequence</tt> messages.
-            User-defined objects that implement the <tt>CharSequence</tt> 
interface can be logged without creating
-            temporary objects: Log4j will try to turn CharSequence messages,
-            Object messages and message parameters
-            into text by appending them to a StringBuilder as a CharSequence.
-            This avoids calling <tt>toString()</tt> on these objects.
-          </p>
-          <p>
-            An alternative is to implement the
-            <a 
href="http://logging.apache.org/log4j/2.x/log4j-api/xref/org/apache/logging/log4j/util/StringBuilderFormattable.html";><tt>org.apache.logging.log4j.util.StringBuilderFormattable</tt></a>
-            interface.
-            If an object is logged that implements this interface, its 
<tt>formatTo</tt> method is called instead of
-            <tt>toString()</tt>.
-          </p>
-          <p>
-            Log4j may call <tt>toString()</tt> on message and parameter 
objects when garbage-free logging
-            is disabled (when system property 
<tt>log4j2.enableThreadlocals</tt> is set to "false".)
-          </p>
-        <a name="codeImpact" />
-        <h4>Impact on Application Code: Autoboxing</h4>
-        <p>
-          We made an effort to make logging garbage-free without requiring 
code changes in existing applications,
-          but there is one area where this was not possible.
-          When logging primitive values (i.e. int, double, boolean, etc.) the 
JVM
-          autoboxes these primitive values to their Object wrapper 
equivalents, creating garbage.
-        </p>
-        <p>
-          Log4j provides an <tt>Unbox</tt> utility to prevent autoboxing of 
primitive parameters.
-          This utility contains a thread-local pool of reused 
<tt>StringBuilder</tt>s.
-          The <tt>Unbox.box(primitive)</tt> methods write directly into a 
StringBuilder, and
-          the resulting text will be copied into the final log message text 
without creating temporary objects.
-        </p>
-        <pre class="prettyprint linenums">import static 
org.apache.logging.log4j.util.Unbox.box;
-
-...
-public void garbageFree() {
-    logger.debug("Prevent primitive autoboxing {} {}", box(10L), box(2.6d));
-}
-</pre>
-          <table><tr><td>
-            <p>
-              <b>Note:</b> not all logging is garbage free. Specifically:
-            </p>
-            <ul>
-              <li>The ThreadContext map is not garbage-free by default, but 
can be configured to be garbage-free
-              by setting system property 
<tt>log4j2.garbagefreeThreadContextMap</tt> to "true".</li>
-              <li>The ThreadContext stack is not garbage-free.</li>
-              <li>Logging more than 10 parameters creates vararg arrays.</li>
-              <li>Logging very large messages (more than 518 characters) when 
all loggers are Async Loggers
-                will cause the internal StringBuilder in the RingBuffer to be 
trimmed back to their max size.
-              </li>
-              <li>Logging messages containing '${': substituting a ${variable} 
creates temporary objects.</li>
-              <li>Logging a lambda <em>as a parameter</em>
-                (<tt>logger.info("lambda value is {}", () -> 
callExpensiveMethod())</tt>) creates a vararg array.
-                Logging a lambda expression by itself is garbage-free:
-                <tt>logger.debug(() -> callExpensiveMethod())</tt>.
-              </li>
-              <li>The <tt>Logger.traceEntry</tt> and <tt>Logger.traceExit</tt> 
methods create temporary objects.</li>
-            </ul>
-          </td></tr></table>
-        <p>
-        </p>
-        <p>
-        </p>
-      </subsection>
-      <a name="Performance" />
-      <subsection name="Performance">
-        <a name="Latency" />
-        <h4>Response Time Latency</h4>
-        <p>Response time is how long it takes to log a message under a certain 
load.
-          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 response time: service time plus wait time.
-          See the <a href="../performance.html#responseTime">response time 
section</a> of the performance page for more detail.
-        </p>
-        <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>-XX:CompileCommand=dontinline,org.apache.logging.log4j.core.async.perftest.NoOpIdleStrategy::idle</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
-          a sustained load of 800,000 messages/second.
-        </p>
-        <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).
-          This makes sense: logging more means more pressure on the garbage 
collector resulting in more minor GC pauses.
-          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 <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>
-          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 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 File Logging</h4>
-        <p>With synchronous file logging, garbage-free logging still performs 
better than classic logging,
-          but the difference is less pronounced.
-        </p>
-        <p>At a workload of 100,000 messages/second, classic logging max 
response time was a little over 2 milliseconds
-          where garbage-free logging was a little over 1 millisecond.
-          When the workload is increased to 300,000 messages/second, classic 
logging shows response time pauses of 6
-          milliseconds where the garbage-free response times were less than 3 
milliseconds.
-          It may be possible to improve on this, we did not investigate 
further yet.</p>
-        <p><img src="../images/ResponseTimeSyncClassicVsGcFree.png" /></p>
-        <p>The above results are obtained with the ResponseTimeTest class 
which can be found in the Log4j 2
-          unit test source directory, running on JDK 1.8.0_45 on RHEL 6.5 
(Linux 2.6.32-573.1.1.el6.x86_64)
-          with 10-core Xeon CPU E5-2660 v3 @2.60GHz with hyperthreading 
switched on (20 virtual cores).</p>
-
-        <a name="Throughput" />
-        <h4>Classic Logging has Slightly Higher Throughput</h4>
-        <p>Throughput is slightly worse for garbage-free logging, compared to 
classic logging.
-          This is true for both synchronous and asynchronous logging.
-          The graph below compares the sustained throughput of synchronous 
logging to a file with Log4j 2.6 in
-          garbage-free mode, classic mode and Log4j 2.5.</p>
-        <p><img src="../images/garbage-free2.6-SyncThroughputLinux.png"
-            alt="Throughput of Log4j 2.6 in garbage-free mode is slightly 
worse than in classic mode, but on par with 2.5 and much better than 
alternatives logging libraries" /></p>
-        <p>The results above are obtained with the
-          <a href="http://openjdk.java.net/projects/code-tools/jmh/";>JMH</a> 
Java benchmark harness.
-          See the FileAppenderBenchmark source code in the log4j-perf 
module.</p>
-      </subsection>
-      <a name="UnderTheHood" />
-      <subsection name="Under the Hood">
-        <p>
-          Custom Message implementations that implement 
<tt>org.apache.logging.log4j.util.StringBuilderFormattable</tt>
-          can be converted to text by garbage-free Layouts without creating 
temporary objects.
-          PatternLayout uses this mechanism and other layouts that convert 
LogEvents to text
-          will likely also look for this interface.
-        </p>
-        <p>
-          Custom Layouts that want to be garbage-free should implement the 
<tt>Encoder&lt;LogEvent&gt;</tt> interface.
-          For custom Layouts that convert a LogEvent to a text representation,
-          the 
<tt>org.apache.logging.log4j.core.layout.StringBuilderEncoder</tt> class may be 
useful to convert this
-          text to bytes in a garbage-free manner.
-        </p>
-        <p>
-          Custom Appenders that want to be garbage-free should provide their 
Layout with a
-          <tt>ByteBufferDestination</tt> implementation that the Layout can 
directly write into.
-        </p>
-        <p>
-          <tt>AbstractOutputStreamAppender</tt> has been modified to make the 
ConsoleAppender, (Rolling)FileAppender,
-          (Rolling)RandomAccessFileAppender and MemoryMappedFileAppender 
garbage-free.
-          An effort has been made to minimize impact on custom Appenders that 
extend
-          <tt>AbstractOutputStreamAppender</tt>, but it is impossible to 
guarantee that changing the superclass
-          will not impact any and all subclasses. Custom Appenders that extend
-          <tt>AbstractOutputStreamAppender</tt> should verify that they still 
function correctly.
-          In case there is a problem, system property 
<tt>log4j2.enable.direct.encoders</tt> can be set to "false"
-          to revert to the pre-Log4j 2.6 behaviour.
-        </p>
-        <!--
-        <p>
-          TODO Applications that wish to reuse custom Message instances with 
Async Loggers should let
-          their Message classes implement the 
<tt>org.apache.logging.log4j.message.ReusableMessage</tt> interface.
-          TODO This is not sufficient: see LOG4J2-1342, would be nice if we 
could solve this in a generic way.
-        </p>
-        -->
-      </subsection>
-    </section>
-  </body>
-</document>

Reply via email to