| <!DOCTYPE html> |
| <!-- |
| | Generated by Apache Maven Doxia Site Renderer 1.9.1 from src/site/xdoc/manual/async.xml at 2020-02-25 |
| | Rendered using Apache Maven Fluido Skin 1.8 |
| --> |
| <html xmlns="http://www.w3.org/1999/xhtml" lang="en"> |
| <head> |
| <meta charset="UTF-8" /> |
| <meta name="viewport" content="width=device-width, initial-scale=1" /> |
| <meta name="generator" content="Apache Maven Doxia Site Renderer 1.9.1" /> |
| <meta name="author" content="Remko Popma" /> |
| <title>Log4j – Log4j 2 Lock-free Asynchronous Loggers for Low-Latency Logging</title> |
| <link rel="stylesheet" href="../css/apache-maven-fluido-1.8.min.css" /> |
| <link rel="stylesheet" href="../css/site.css" /> |
| <link rel="stylesheet" href="../css/print.css" media="print" /> |
| <script src="../js/apache-maven-fluido-1.8.min.js"></script> |
| </head> |
| <body class="topBarDisabled"> |
| <div class="container-fluid"> |
| <header> |
| <div id="banner"> |
| <div class="pull-left"><a href="http://logging.apache.org" id="bannerLeft"><img src="../images/ls-logo.jpg" alt=""/></a></div> |
| <div class="pull-right"><a href="http://logging.apache.org/log4j/2.x" id="bannerRight"><img src="../images/logo.png" alt=""/></a></div> |
| <div class="clear"><hr/></div> |
| </div> |
| |
| <div id="breadcrumbs"> |
| <ul class="breadcrumb"> |
| <li id="publishDate">Last Published: 2020-02-25<span class="divider">|</span> |
| </li> |
| <li id="projectVersion">Version: 2.13.1</li> |
| <li class="pull-right"><span class="divider">|</span> |
| <a href="https://github.com/apache/logging-log4j2" class="externalLink" title="GitHub">GitHub</a></li> |
| <li class="pull-right"><span class="divider">|</span> |
| <a href="https://analysis.apache.org/dashboard/index/org.apache.logging.log4j:log4j" class="externalLink" title="Sonar">Sonar</a></li> |
| <li class="pull-right"><span class="divider">|</span> |
| <a href="../../../" title="Logging Services">Logging Services</a></li> |
| <li class="pull-right"><span class="divider">|</span> |
| <a href="https://www.apache.org/" class="externalLink" title="Apache">Apache</a></li> |
| <li class="pull-right"><a href="https://cwiki.apache.org/confluence/display/LOGGING/Log4j" class="externalLink" title="Logging Wiki">Logging Wiki</a></li> |
| </ul> |
| </div> |
| </header> |
| <div class="row-fluid"> |
| <header id="leftColumn" class="span2"> |
| <nav class="well sidebar-nav"> |
| <ul class="nav nav-list"> |
| <li class="nav-header"><img class="imageLink" src="../img/glyphicons/home.png" alt="Apache Log4j™ 2" border="0"/> Apache Log4j™ 2</li> |
| <li><a href="../index.html" title="About"><span class="none"></span>About</a></li> |
| <li><a href="../download.html" title="Download"><span class="none"></span>Download</a></li> |
| <li><a href="../javadoc.html" title="Javadoc"><span class="icon-chevron-right"></span>Javadoc</a></li> |
| <li><a href="../maven-artifacts.html" title="Maven, Ivy, Gradle Artifacts"><span class="icon-chevron-right"></span>Maven, Ivy, Gradle Artifacts</a></li> |
| <li><a href="../runtime-dependencies.html" title="Runtime Dependencies"><span class="none"></span>Runtime Dependencies</a></li> |
| <li><a href="../changelog.html" title="Changelog"><span class="none"></span>Changelog</a></li> |
| <li><a href="../faq.html" title="FAQ"><span class="none"></span>FAQ</a></li> |
| <li><a href="../performance.html" title="Performance"><span class="icon-chevron-right"></span>Performance</a></li> |
| <li><a href="../articles.html" title="Articles and Tutorials"><span class="none"></span>Articles and Tutorials</a></li> |
| <li><a href="../support.html" title="Support"><span class="none"></span>Support</a></li> |
| <li><a href="../thanks.html" title="Thanks"><span class="none"></span>Thanks</a></li> |
| <li class="nav-header"><img class="imageLink" src="../img/glyphicons/pencil.png" alt="For Contributors" border="0"/> For Contributors</li> |
| <li><a href="../build.html" title="Building Log4j from Source"><span class="none"></span>Building Log4j from Source</a></li> |
| <li><a href="../guidelines.html" title="Guidelines"><span class="none"></span>Guidelines</a></li> |
| <li><a href="../javastyle.html" title="Style Guide"><span class="none"></span>Style Guide</a></li> |
| <li class="nav-header"><img class="imageLink" src="../img/glyphicons/book.png" alt="Manual" border="0"/> Manual</li> |
| <li><a href="../manual/index.html" title="Introduction"><span class="none"></span>Introduction</a></li> |
| <li><a href="../manual/architecture.html" title="Architecture"><span class="none"></span>Architecture</a></li> |
| <li><a href="../manual/compatibility.html" title="Log4j 1.x Compatibility"><span class="none"></span>Log4j 1.x Compatibility</a></li> |
| <li><a href="../manual/migration.html" title="Log4j 1.x Migration"><span class="none"></span>Log4j 1.x Migration</a></li> |
| <li><a href="../manual/api.html" title="Java API"><span class="icon-chevron-right"></span>Java API</a></li> |
| <li><a href="../manual/scala-api.html" title="Scala API"><span class="none"></span>Scala API</a></li> |
| <li><a href="../manual/configuration.html" title="Configuration"><span class="icon-chevron-right"></span>Configuration</a></li> |
| <li><a href="../manual/usage.html" title="Usage"><span class="icon-chevron-right"></span>Usage</a></li> |
| <li><a href="../manual/webapp.html" title="Web Applications and JSPs"><span class="icon-chevron-right"></span>Web Applications and JSPs</a></li> |
| <li><a href="../manual/lookups.html" title="Lookups"><span class="icon-chevron-right"></span>Lookups</a></li> |
| <li><a href="../manual/appenders.html" title="Appenders"><span class="icon-chevron-right"></span>Appenders</a></li> |
| <li><a href="../manual/layouts.html" title="Layouts"><span class="icon-chevron-right"></span>Layouts</a></li> |
| <li><a href="../manual/filters.html" title="Filters"><span class="icon-chevron-right"></span>Filters</a></li> |
| <li class="active"><a href="#"><span class="icon-chevron-down"></span>Async Loggers</a> |
| <ul class="nav nav-list"> |
| <li><a href="../manual/async.html#Trade-offs" title="Trade-offs"><span class="none"></span>Trade-offs</a></li> |
| <li><a href="../manual/async.html#AllAsync" title="All Loggers Async"><span class="none"></span>All Loggers Async</a></li> |
| <li><a href="../manual/async.html#MixedSync-Async" title="Mixed Sync & Async"><span class="none"></span>Mixed Sync & Async</a></li> |
| <li><a href="../manual/async.html#Location" title="Location"><span class="none"></span>Location</a></li> |
| <li><a href="../manual/async.html#Performance" title="Performance"><span class="none"></span>Performance</a></li> |
| <li><a href="../manual/async.html#UnderTheHood" title="Under The Hood"><span class="none"></span>Under The Hood</a></li> |
| </ul></li> |
| <li><a href="../manual/garbagefree.html" title="Garbage-free Logging"><span class="icon-chevron-right"></span>Garbage-free Logging</a></li> |
| <li><a href="../manual/jmx.html" title="JMX"><span class="none"></span>JMX</a></li> |
| <li><a href="../manual/logsep.html" title="Logging Separation"><span class="none"></span>Logging Separation</a></li> |
| <li><a href="../manual/extending.html" title="Extending Log4j"><span class="icon-chevron-right"></span>Extending Log4j</a></li> |
| <li><a href="../manual/plugins.html" title="Plugins"><span class="icon-chevron-right"></span>Plugins</a></li> |
| <li><a href="../manual/customconfig.html" title="Programmatic Log4j Configuration"><span class="icon-chevron-right"></span>Programmatic Log4j Configuration</a></li> |
| <li><a href="../manual/customloglevels.html" title="Custom Log Levels"><span class="icon-chevron-right"></span>Custom Log Levels</a></li> |
| <li class="nav-header"><img class="imageLink" src="../img/glyphicons/tag.png" alt="Related Projects" border="0"/> Related Projects</li> |
| <li><a href="http://logging.apache.org/log4j/scala/index.html" class="externalLink" title="Log4j-Scala"><span class="none"></span>Log4j-Scala</a></li> |
| <li class="nav-header"><img class="imageLink" src="../img/glyphicons/link.png" alt="Legacy Sites" border="0"/> Legacy Sites</li> |
| <li><a href="http://logging.apache.org/log4j/1.2/" class="externalLink" title="Log4j 1.2 - End of Life"><span class="none"></span>Log4j 1.2 - End of Life</a></li> |
| <li><a href="http://logging.apache.org/log4j/log4j-2.3/" class="externalLink" title="Log4j 2.3 - Java 6"><span class="none"></span>Log4j 2.3 - Java 6</a></li> |
| <li><a href="http://logging.apache.org/log4j/log4j-2.12.1" class="externalLink" title="Log4j 2.12.1 - Java 7"><span class="none"></span>Log4j 2.12.1 - Java 7</a></li> |
| <li class="nav-header"><img class="imageLink" src="../img/glyphicons/cog.png" alt="Components" border="0"/> Components</li> |
| <li><a href="../log4j-api/index.html" title="API"><span class="none"></span>API</a></li> |
| <li><a href="../log4j-core/index.html" title="Implementation"><span class="none"></span>Implementation</a></li> |
| <li><a href="../log4j-jcl/index.html" title="Commons Logging Bridge"><span class="none"></span>Commons Logging Bridge</a></li> |
| <li><a href="../log4j-1.2-api/index.html" title="Log4j 1.2 API"><span class="none"></span>Log4j 1.2 API</a></li> |
| <li><a href="../log4j-slf4j-impl/index.html" title="SLF4J Binding"><span class="none"></span>SLF4J Binding</a></li> |
| <li><a href="../log4j-jul/index.html" title="JUL Adapter"><span class="none"></span>JUL Adapter</a></li> |
| <li><a href="../log4j-to-slf4j/index.html" title="Log4j 2 to SLF4J Adapter"><span class="none"></span>Log4j 2 to SLF4J Adapter</a></li> |
| <li><a href="../log4j-flume-ng/index.html" title="Apache Flume Appender"><span class="none"></span>Apache Flume Appender</a></li> |
| <li><a href="../log4j-taglib/index.html" title="Log4j Tag Library"><span class="none"></span>Log4j Tag Library</a></li> |
| <li><a href="../log4j-jmx-gui/index.html" title="Log4j JMX GUI"><span class="none"></span>Log4j JMX GUI</a></li> |
| <li><a href="../log4j-web/index.html" title="Log4j Web Application Support"><span class="none"></span>Log4j Web Application Support</a></li> |
| <li><a href="../log4j-appserver/index.html" title="Log4j Application Server Integration"><span class="none"></span>Log4j Application Server Integration</a></li> |
| <li><a href="../log4j-couchdb/index.html" title="Log4j CouchDB appender"><span class="none"></span>Log4j CouchDB appender</a></li> |
| <li><a href="../log4j-mongodb2/index.html" title="Log4j MongoDB2 appender"><span class="none"></span>Log4j MongoDB2 appender</a></li> |
| <li><a href="../log4j-mongodb3/index.html" title="Log4j MongoDB3 appender"><span class="none"></span>Log4j MongoDB3 appender</a></li> |
| <li><a href="../log4j-cassandra/index.html" title="Log4j Cassandra appender"><span class="none"></span>Log4j Cassandra appender</a></li> |
| <li><a href="../log4j-iostreams/index.html" title="Log4j IO Streams"><span class="none"></span>Log4j IO Streams</a></li> |
| <li><a href="../log4j-liquibase/index.html" title="Log4j Liquibase Binding"><span class="none"></span>Log4j Liquibase Binding</a></li> |
| <li><a href="../log4j-docker/index.html" title="Log4j Docker Support"><span class="none"></span>Log4j Docker Support</a></li> |
| <li><a href="../log4j-spring-cloud-config/log4j-spring-cloud-config-client/index.html" title="Log4j Spring Cloud Config Client"><span class="none"></span>Log4j Spring Cloud Config Client</a></li> |
| <li class="nav-header"><img class="imageLink" src="../img/glyphicons/info.png" alt="Project Information" border="0"/> Project Information</li> |
| <li><a href="../dependency-convergence.html" title="Dependency Convergence"><span class="none"></span>Dependency Convergence</a></li> |
| <li><a href="../dependency-management.html" title="Dependency Management"><span class="none"></span>Dependency Management</a></li> |
| <li><a href="../team-list.html" title="Project Team"><span class="none"></span>Project Team</a></li> |
| <li><a href="../mail-lists.html" title="Mailing Lists"><span class="none"></span>Mailing Lists</a></li> |
| <li><a href="../issue-tracking.html" title="Issue Tracking"><span class="none"></span>Issue Tracking</a></li> |
| <li><a href="../license.html" title="Project License"><span class="none"></span>Project License</a></li> |
| <li><a href="../source-repository.html" title="Source Repository"><span class="none"></span>Source Repository</a></li> |
| <li><a href="../project-summary.html" title="Project Summary"><span class="none"></span>Project Summary</a></li> |
| <li class="nav-header"><img class="imageLink" src="../img/glyphicons/layers.png" alt="Project Reports" border="0"/> Project Reports</li> |
| <li><a href="../changes-report.html" title="Changes Report"><span class="none"></span>Changes Report</a></li> |
| <li><a href="../jira-report.html" title="JIRA Report"><span class="none"></span>JIRA Report</a></li> |
| <li><a href="../rat-report.html" title="RAT Report"><span class="none"></span>RAT Report</a></li> |
| </ul> |
| </nav> |
| <div class="well sidebar-nav"> |
| <hr /> |
| <div id="poweredBy"> |
| <div class="clear"></div> |
| <div class="clear"></div> |
| <div class="clear"></div> |
| <a href="http://maven.apache.org/" title="Built by Maven" class="poweredBy"><img class="builtBy" alt="Built by Maven" src="../images/logos/maven-feather.png" /></a> |
| </div> |
| </div> |
| </header> |
| <main id="bodyColumn" class="span10" > |
| |
| |
| <section> |
| <h2><a name="Asynchronous_Loggers_for_Low-Latency_Logging"></a>Asynchronous Loggers for Low-Latency Logging</h2> |
| |
| <p> |
| Asynchronous logging can improve your application's performance by executing the I/O operations |
| in a separate thread. Log4j 2 makes a number of improvements in this area. |
| </p> |
| |
| <ul> |
| |
| <li> |
| <b>Asynchronous Loggers</b> are a new addition in Log4j 2. |
| Their aim is to return from the call to Logger.log to the application as |
| soon as possible. You can choose between making all Loggers asynchronous |
| or using a mixture of synchronous and asynchronous Loggers. Making all |
| Loggers asynchronous will give the best performance, while mixing |
| gives you more flexibility. |
| </li> |
| |
| <li> |
| <b>LMAX Disruptor technology</b>. Asynchronous Loggers internally use the |
| <a href="#UnderTheHood">Disruptor</a>, a lock-free inter-thread |
| communication library, instead of queues, resulting in higher throughput and lower latency. |
| </li> |
| |
| <li> |
| As part of the work for Async Loggers, <b>Asynchronous Appenders</b> have |
| been enhanced to flush to disk at the end of a batch (when the queue is empty). |
| This produces the same result as configuring "immediateFlush=true", that is, all |
| received log events are always available on disk, but is more efficient because it does not need to |
| touch the disk on each and every log event. (Async Appenders use ArrayBlockingQueue internally and |
| do not need the disruptor jar on the classpath.) |
| </li> |
| </ul> |
| <a name="Trade-offs"></a> |
| <section> |
| <h3><a name="Trade-offs"></a>Trade-offs</h3> |
| |
| <p> |
| Although asynchronous logging can give significant performance benefits, |
| there are situations where you may want to choose synchronous logging. |
| This section describes some of the trade-offs of asynchronous logging. |
| </p> |
| |
| <p> |
| <b>Benefits</b> |
| </p> |
| |
| <ul> |
| |
| <li> |
| |
| <p>Higher peak <a href="#Performance">throughput</a>. With an asynchronous logger |
| your application can log messages at 6 - 68 times the rate of a synchronous logger.</p> |
| |
| <p>This is especially interesting for applications that occasionally need to log |
| bursts of messages. Async logging can help prevent or dampen latency spikes by shortening |
| the wait time until the next message can be logged. If the queue size is configured |
| large enough to handle the burst, asynchronous logging will help prevent your |
| application from falling behind (as much) during a sudden increase of activity. |
| </p> |
| </li> |
| |
| <li> |
| Lower logging response time <a href="#Latency">latency</a>. |
| Response time latency is the time it takes for a call to Logger.log to return under a given workload. |
| Asynchronous Loggers have consistently lower latency than synchronous loggers or even |
| queue-based asynchronous appenders. |
| </li> |
| </ul> |
| <b>Drawbacks</b> |
| |
| <ul> |
| |
| <li> |
| Error handling. If a problem happens during the logging process and an exception is thrown, |
| it is less easy for an asynchronous logger or appender to signal this problem to the |
| application. This can partly be alleviated by configuring an ExceptionHandler, |
| but this may still not cover all cases. For this reason, if logging is part of your business logic, |
| for example if you are using Log4j as an audit logging framework, we would |
| recommend to synchronously log those audit messages. |
| (Note that you can still <a href="#MixedSync-Async">combine</a> them |
| and use asynchronous logging for debug/trace logging in addition to synchronous |
| logging for the audit trail.) |
| </li> |
| |
| <li> |
| In some rare cases, care must be taken with mutable messages. |
| Most of the time you don't need to worry about this. Log4 will ensure that log messages like |
| logger.debug("My object is {}", myObject) will use the state of the |
| myObject parameter at the time of the call to logger.debug(). |
| The log message will not change even if myObject is modified later. |
| It is safe to asynchronously log mutable objects because most |
| <a href="../log4j-api/apidocs/org/apache/logging/log4j/message/Message.html" class="javadoc">Message</a> |
| implementations built-in to Log4j take a snapshot of the parameters. |
| There are some exceptions however: |
| <a href="../log4j-api/apidocs/org/apache/logging/log4j/message/MapMessage.html" class="javadoc">MapMessage</a> |
| and |
| <a href="../log4j-api/apidocs/org/apache/logging/log4j/message/StructuredDataMessage.html" class="javadoc">StructuredDataMessage</a> |
| are mutable by design: fields can be added to these messages after the message object was created. |
| These messages should not be modified after they are logged with asynchronous loggers or |
| asynchronous appenders; you may or may not see the modifications in the resulting log output. |
| Similarly, custom |
| <a href="../log4j-api/apidocs/org/apache/logging/log4j/message/Message.html" class="javadoc">Message</a> |
| implementations should be designed with asynchronous use in mind, and either take a snapshot |
| of their parameters at construction time, or document their thread-safety characteristics. |
| </li> |
| |
| <li>If your application is running in an environment where CPU resources are scarce, like a machine |
| with one CPU with a single core, starting another thread is not likely |
| to give better performance.</li> |
| |
| <li> |
| If the <i>sustained rate</i> at which your application is logging messages is faster than the |
| maximum sustained throughput of the underlying appender, the queue will fill up and the |
| application will end up logging at the speed of the slowest appender. |
| If this happens, consider selecting a <a href="../performance.html#whichAppender">faster |
| appender</a>, or logging less. |
| If neither of these is an option, you may get better throughput and fewer latency spikes by |
| logging synchronously. |
| </li> |
| </ul> |
| </section> |
| <a name="AllAsync"></a> |
| <section> |
| <h3><a name="Making_All_Loggers_Asynchronous"></a>Making All Loggers Asynchronous</h3> |
| |
| <p> |
| <i>Log4j-2.9 and higher require disruptor-3.3.4.jar or higher on the classpath. |
| Prior to Log4j-2.9, disruptor-3.0.0.jar or higher was required. |
| </i> |
| </p> |
| |
| <p> |
| This is simplest to configure and gives the best performance. To make all loggers asynchronous, |
| add the disruptor jar to the classpath and set the system property log4j2.contextSelector |
| to org.apache.logging.log4j.core.async.AsyncLoggerContextSelector. |
| </p> |
| |
| <p> |
| By default, <a href="#Location">location</a> is not passed to the I/O thread by |
| asynchronous loggers. If one of your layouts or custom filters needs location information, you need to set |
| "includeLocation=true" in the configuration of all relevant loggers, including the root logger. |
| </p> |
| |
| <p> |
| A configuration that does not require location might look like: |
| </p> |
| |
| <div> |
| <pre class="prettyprint linenums"><?xml version="1.0" encoding="UTF-8"?> |
| |
| <!-- Don't forget to set system property |
| -Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector |
| to make all loggers asynchronous. --> |
| |
| <Configuration status="WARN"> |
| <Appenders> |
| <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. --> |
| <RandomAccessFile name="RandomAccessFile" fileName="async.log" immediateFlush="false" append="false"> |
| <PatternLayout> |
| <Pattern>%d %p %c{1.} [%t] %m %ex%n</Pattern> |
| </PatternLayout> |
| </RandomAccessFile> |
| </Appenders> |
| <Loggers> |
| <Root level="info" includeLocation="false"> |
| <AppenderRef ref="RandomAccessFile"/> |
| </Root> |
| </Loggers> |
| </Configuration></pre></div> |
| |
| <p> |
| When AsyncLoggerContextSelector is used to make all loggers asynchronous, make sure to use normal |
| <root> and <logger> elements in the configuration. The |
| AsyncLoggerContextSelector will ensure that all loggers are asynchronous, using a mechanism |
| that is different from what happens when you configure <asyncRoot> |
| or <asyncLogger>. |
| The latter elements are intended for mixing async with sync loggers. If you use both mechanisms |
| together you will end up with two background threads, where your application passes the log |
| message to thread A, which passes the message to thread B, which then finally |
| logs the message to disk. This works, but there will be an unnecessary step in the middle. |
| </p> |
| |
| <p> |
| There are a few system properties you can use to control aspects of the asynchronous logging subsystem. |
| Some of these can be used to tune logging performance. |
| </p> |
| |
| <p> |
| The below properties can also be specified by creating a file named |
| log4j2.component.properties and including this file in the classpath of the application. |
| </p> |
| |
| <p> |
| Note that system properties were renamed into a more consistent style in Log4j 2.10.0. All old property |
| names are still supported which are documented <a href="configuration.html#SystemProperties">here</a>. |
| </p> |
| <a name="SysPropsAllAsync"></a> |
| |
| <table border="0" class="table table-striped"><caption align="top">System Properties to configure all asynchronous loggers |
| </caption> |
| |
| |
| <tr class="a"> |
| |
| <th>System Property</th> |
| |
| <th>Default Value</th> |
| |
| <th>Description</th> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>log4j2.asyncLoggerExceptionHandler</td> |
| |
| <td> |
| default handler |
| </td> |
| |
| <td> |
| Fully qualified name of a class that implements the com.lmax.disruptor.ExceptionHandler |
| interface. The class needs to have a public zero-argument constructor. |
| If specified, this class will be notified when an exception occurs while logging the messages. |
| |
| <p> |
| If not specified, the default exception handler will print a message and stack trace to the standard |
| error output stream. |
| </p> |
| </td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>log4j2.asyncLoggerRingBufferSize</td> |
| |
| <td>256 * 1024</td> |
| |
| <td> |
| Size (number of slots) in the RingBuffer used by the asynchronous logging subsystem. |
| Make this value large enough to deal with bursts of activity. The minimum size is 128. |
| The RingBuffer will be pre-allocated at first use and will never grow or shrink |
| during the life of the system. |
| |
| <p> |
| When the application is logging faster than the underlying appender can keep up with |
| for a long enough time to fill up the queue, the behaviour is determined by the |
| <a href="../log4j-core/apidocs/org/apache/logging/log4j/core/async/AsyncQueueFullPolicy.html">AsyncQueueFullPolicy</a>. |
| </p> |
| </td> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>log4j2.asyncLoggerWaitStrategy</td> |
| |
| <td> |
| Timeout |
| </td> |
| |
| <td> |
| Valid values: Block, Timeout, Sleep, Yield. |
| <br /> |
| Block is a strategy that uses a lock and condition variable for the I/O thread waiting for log events. |
| Block can be used when throughput and low-latency are not as important as CPU resource. |
| Recommended for resource constrained/virtualised environments. |
| <br /> |
| Timeout is a variation of the Block strategy that will periodically |
| wake up from the lock condition await() call. This ensures that if a notification is missed somehow |
| the consumer thread is not stuck but will recover with a small latency delay (default 10ms). |
| <br /> |
| Sleep is a strategy that initially spins, then uses a Thread.yield(), and |
| eventually parks for the minimum number of nanos the OS and JVM will allow |
| while the I/O thread is waiting for log events. Sleep is a good compromise between performance |
| and CPU resource. |
| This strategy has very low impact on the application thread, in exchange for some additional |
| latency for actually getting the message logged. |
| <br /> |
| Yield is a strategy that uses a Thread.yield() for waiting for log events after an initially spinning. |
| Yield is a good compromise between performance and CPU resource, but may use more CPU than Sleep |
| in order to get the message logged to disk sooner. |
| </td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>AsyncLogger.SynchronizeEnqueueWhenQueueFull</td> |
| |
| <td> |
| true |
| </td> |
| |
| <td> |
| Synchronizes access to the Disruptor ring buffer for blocking enqueue operations when the queue is full. |
| Users encountered excessive CPU utilization with Disruptor v3.4.2 when the application |
| was logging more than the underlying appender could keep up with and the ring buffer became full, |
| especially when the number of application threads vastly outnumbered the number of cores. |
| CPU utilization is significantly reduced by restricting access to the enqueue operation. Setting this value |
| to false may lead to very high CPU utilization when the async logging queue is full. |
| </td> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>log4j2.asyncLoggerThreadNameStrategy</td> |
| |
| <td> |
| CACHED |
| </td> |
| |
| <td> |
| Valid values: CACHED, UNCACHED. |
| <br /> |
| By default, AsyncLogger caches the thread name in a ThreadLocal variable to improve performance. |
| Specify the UNCACHED option if your application modifies the thread name at runtime (with |
| Thread.currentThread().setName()) |
| and you want to see the new thread name reflected in the log. |
| </td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>log4j2.clock</td> |
| |
| <td> |
| SystemClock |
| </td> |
| |
| <td> |
| |
| <p> |
| Implementation of the org.apache.logging.log4j.core.util.Clock |
| interface that is used for timestamping the log events when all loggers are asynchronous. |
| <br /> |
| By default, System.currentTimeMillis is called on every log event. |
| </p> |
| |
| <p> |
| CachedClock is an optimization intended for low-latency applications where |
| time stamps are generated from a clock that updates its internal time in a background thread once |
| every millisecond, or every 1024 log events, whichever comes first. |
| This reduces logging latency a little, at the cost of some precision in the logged time stamps. |
| Unless you are logging many events, you may see "jumps" of 10-16 milliseconds between log time stamps. |
| WEB APPLICATION WARNING: The use of a background thread may cause issues |
| for web applications and OSGi applications so CachedClock is not recommended for this kind |
| of applications. |
| </p> |
| |
| <p> |
| You can also specify the fully qualified class name of a custom class that implements the |
| Clock interface. |
| </p> |
| </td> |
| </tr> |
| </table> |
| |
| <p> |
| There are also a few system properties that can be used to maintain application throughput even when |
| the underlying appender cannot keep up with the logging rate and the queue is filling up. |
| See the details for system properties |
| <a href="configuration.html#asyncQueueFullPolicy">log4j2.asyncQueueFullPolicy and |
| log4j2.discardThreshold</a>. |
| </p> |
| </section> |
| <a name="MixedSync-Async"></a> |
| <section> |
| <h3><a name="Mixing_Synchronous_and_Asynchronous_Loggers"></a>Mixing Synchronous and Asynchronous Loggers</h3> |
| |
| <p> |
| <i>Log4j-2.9 and higher require disruptor-3.3.4.jar or higher on the classpath. |
| Prior to Log4j-2.9, disruptor-3.0.0.jar or higher was required. |
| There is no need to set system property "Log4jContextSelector" to any value.</i></p> |
| |
| <p> |
| Synchronous and asynchronous loggers can be combined in configuration. |
| This gives you more flexibility at the cost of a slight loss in performance (compared to making |
| all loggers asynchronous). Use the <asyncRoot> or <asyncLogger> |
| configuration elements to specify the loggers that need to be asynchronous. |
| A configuration can contain only one root logger (either a <root> |
| or an <asyncRoot> element), but otherwise async and non-async loggers may be |
| combined. |
| For example, a configuration file containing <asyncLogger> elements |
| can also contain <root> and |
| <logger> elements for the synchronous loggers. |
| </p> |
| |
| <p> |
| By default, <a href="#Location">location</a> is not passed to the I/O thread by asynchronous loggers. |
| If one of your layouts or custom filters needs location information, you need to set |
| "includeLocation=true" in the configuration of all relevant loggers, including the root logger. |
| </p> |
| |
| <p> |
| A configuration that mixes asynchronous loggers might look like: |
| </p> |
| |
| <div> |
| <pre class="prettyprint linenums"><?xml version="1.0" encoding="UTF-8"?> |
| |
| <!-- No need to set system property "log4j2.contextSelector" to any value |
| when using <asyncLogger> or <asyncRoot>. --> |
| |
| <Configuration status="WARN"> |
| <Appenders> |
| <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. --> |
| <RandomAccessFile name="RandomAccessFile" fileName="asyncWithLocation.log" |
| immediateFlush="false" append="false"> |
| <PatternLayout> |
| <Pattern>%d %p %class{1.} [%t] %location %m %ex%n</Pattern> |
| </PatternLayout> |
| </RandomAccessFile> |
| </Appenders> |
| <Loggers> |
| <!-- pattern layout actually uses location, so we need to include it --> |
| <AsyncLogger name="com.foo.Bar" level="trace" includeLocation="true"> |
| <AppenderRef ref="RandomAccessFile"/> |
| </AsyncLogger> |
| <Root level="info" includeLocation="true"> |
| <AppenderRef ref="RandomAccessFile"/> |
| </Root> |
| </Loggers> |
| </Configuration></pre></div> |
| |
| <p> |
| There are a few system properties you can use to control aspects of the asynchronous logging subsystem. |
| Some of these can be used to tune logging performance. |
| </p> |
| |
| <p> |
| The below properties can also be specified by creating a file named |
| log4j2.component.properties and including this file in the classpath of the application. |
| </p> |
| |
| <p> |
| Note that system properties were renamed into a more consistent style in Log4j 2.10. All old property |
| names are still supported which are documented <a href="configuration.html#SystemProperties">here</a>. |
| </p> |
| <a name="SysPropsMixedSync-Async"></a> |
| |
| <table border="0" class="table table-striped"><caption align="top">System Properties to configure mixed asynchronous and normal loggers</caption> |
| |
| |
| <tr class="a"> |
| |
| <th>System Property</th> |
| |
| <th>Default Value</th> |
| |
| <th>Description</th> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>log4j2.asyncLoggerConfigExceptionHandler</td> |
| |
| <td> |
| default handler |
| </td> |
| |
| <td> |
| Fully qualified name of a class that implements the com.lmax.disruptor.ExceptionHandler |
| interface. The class needs to have a public zero-argument constructor. |
| If specified, this class will be notified when an exception occurs while logging the messages. |
| |
| <p> |
| If not specified, the default exception handler will print a message and stack trace to the standard |
| error output stream. |
| </p> |
| </td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>log4j2.asyncLoggerConfigRingBufferSize</td> |
| |
| <td>256 * 1024</td> |
| |
| <td> |
| Size (number of slots) in the RingBuffer used by the asynchronous logging subsystem. |
| Make this value large enough to deal with bursts of activity. The minimum size is 128. |
| The RingBuffer will be pre-allocated at first use and will never grow |
| or shrink during the life of the system. |
| |
| <p> |
| When the application is logging faster than the underlying appender can keep up with |
| for a long enough time to fill up the queue, the behavious is determined by the |
| <a href="../log4j-core/apidocs/org/apache/logging/log4j/core/async/AsyncQueueFullPolicy.html">AsyncQueueFullPolicy</a>. |
| </p> |
| </td> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>log4j2.asyncLoggerConfigWaitStrategy</td> |
| |
| <td> |
| Timeout |
| </td> |
| |
| <td> |
| Valid values: Block, Timeout, Sleep, Yield. |
| <br /> |
| Block is a strategy that uses a lock and condition variable for the I/O thread waiting for log events. |
| Block can be used when throughput and low-latency are not as important as CPU resource. |
| Recommended for resource constrained/virtualised environments. |
| <br /> |
| Timeout is a variation of the Block strategy that will periodically |
| wake up from the lock condition await() call. This ensures that if a notification is missed somehow |
| the consumer thread is not stuck but will recover with a small latency delay (default 10ms). |
| <br /> |
| Sleep is a strategy that initially spins, then uses a Thread.yield(), and |
| eventually parks for the minimum number of nanos the OS and JVM will allow |
| while the I/O thread is waiting for log events. Sleep is a good compromise between performance |
| and CPU resource. |
| This strategy has very low impact on the application thread, in exchange for some additional |
| latency for actually getting the message logged. |
| <br /> |
| Yield is a strategy that uses a Thread.yield() for waiting for log events after an initially spinning. |
| Yield is a good compromise between performance and CPU resource, but may use more CPU than Sleep |
| in order to get the message logged to disk sooner. |
| </td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>AsyncLoggerConfig.SynchronizeEnqueueWhenQueueFull</td> |
| |
| <td> |
| true |
| </td> |
| |
| <td> |
| Synchronizes access to the Disruptor ring buffer for blocking enqueue operations when the queue is full. |
| Users encountered excessive CPU utilization with Disruptor v3.4.2 when the application |
| was logging more than the underlying appender could keep up with and the ring buffer became full, |
| especially when the number of application threads vastly outnumbered the number of cores. |
| CPU utilization is significantly reduced by restricting access to the enqueue operation. Setting this value |
| to false may lead to very high CPU utilization when the async logging queue is full. |
| </td> |
| </tr> |
| </table> |
| |
| <p> |
| There are also a few system properties that can be used to maintain application throughput even when |
| the underlying appender cannot keep up with the logging rate and the queue is filling up. |
| See the details for system properties |
| <a href="configuration.html#asyncQueueFullPolicy">log4j2.asyncQueueFullPolicy and |
| log4j2.discardThreshold</a>. |
| </p> |
| </section> |
| <a name="Location"></a> |
| <section> |
| <h3><a name="Location.2C_location.2C_location..."></a>Location, location, location...</h3> |
| |
| <p> |
| If one of the layouts is configured with a location-related attribute like HTML |
| <a href="layouts.html#HtmlLocationInfo">locationInfo</a>, |
| or one of the patterns <a href="layouts.html#PatternClass">%C or $class</a>, |
| <a href="layouts.html#PatternFile">%F or %file</a>, |
| <a href="layouts.html#PatternLocation">%l or %location</a>, |
| <a href="layouts.html#PatternLine">%L or %line</a>, |
| <a href="layouts.html#PatternMethod">%M or %method</a>, |
| Log4j will take a snapshot of the stack, and walk the stack trace to find the location information. |
| </p> |
| |
| <p> |
| This is an expensive operation: 1.3 - 5 times slower for synchronous loggers. Synchronous loggers wait as |
| long as possible before they take this stack snapshot. If no location is required, the snapshot will never be taken. |
| </p> |
| |
| <p> |
| However, asynchronous loggers need to make this decision before passing the |
| log message to another thread; the location information will be lost after that point. |
| The <a href="../performance.html#asyncLoggingWithLocation">performance impact</a> of taking a stack trace snapshot is even higher for asynchronous loggers: |
| logging with location is 30-100 times slower than without location. |
| For this reason, asynchronous loggers and asynchronous appenders do not include location information by default. |
| </p> |
| |
| <p> |
| You can override the default behaviour in your logger or asynchronous appender configuration |
| by specifying includeLocation="true". |
| </p> |
| |
| <p> |
| </p> |
| </section> |
| <a name="Performance"></a> |
| <section> |
| <h3><a name="Asynchronous_Logging_Performance"></a>Asynchronous Logging Performance</h3> |
| |
| <p> |
| The throughput performance results below were derived from running the PerfTest, MTPerfTest and PerfTestDriver |
| classes which can be found in the Log4j 2 unit test source directory. |
| For throughput tests, the methodology used was: |
| </p> |
| |
| <ul> |
| |
| <li>First, warm up the JVM by logging 200,000 log messages of 500 characters. |
| </li> |
| |
| <li>Repeat the warm-up 10 times, then wait 10 seconds for the I/O thread to catch up and buffers to drain.</li> |
| |
| <li>Measure how long it takes to execute 256 * 1024 / threadCount calls to Logger.log |
| and express the result in messages per second. |
| </li> |
| |
| <li>Repeat the test 5 times and average the results.</li> |
| </ul> |
| |
| <p>The results below were obtained with log4j-2.0-beta5, disruptor-3.0.0.beta3, |
| log4j-1.2.17 and logback-1.0.10. |
| </p> |
| <section> |
| <h4><a name="Logging_Peak_Throughput"></a>Logging Peak Throughput</h4> |
| |
| <p> |
| The graph below compares the throughput of synchronous loggers, asynchronous appenders and asynchronous |
| loggers. This is the total throughput of all threads together. In the test with 64 threads, |
| asynchronous loggers are 12 times faster than asynchronous appenders, and 68 times faster than |
| synchronous loggers. |
| </p> |
| |
| <p> |
| Asynchronous loggers' throughput increases with the number of threads, |
| whereas both synchronous loggers and asynchronous appenders |
| have more or less constant throughput regardless of the number of |
| threads that are doing the logging. |
| </p> |
| |
| <p> |
| <img src="../images/async-vs-sync-throughput.png" alt="Async loggers have much higher throughput than sync loggers." /> |
| </p> |
| |
| </section><section> |
| <h4><a name="Asynchronous_Throughput_Comparison_with_Other_Logging_Packages"></a>Asynchronous Throughput Comparison with Other Logging Packages</h4> |
| |
| <p> |
| We also compared peak throughput of asynchronous loggers to the synchronous loggers and asynchronous |
| appenders available in other logging packages, specifically log4j-1.2.17 and |
| logback-1.0.10, with similar results. For asynchronous appenders, total logging throughput of all |
| threads together remains roughly constant when adding more threads. |
| Asynchronous loggers make more effective use of the multiple cores |
| available on the machine in multi-threaded scenarios. |
| </p> |
| |
| <p> |
| <img src="../images/async-throughput-comparison.png" alt="Async loggers have the highest throughput." /> |
| </p> |
| |
| <p>On Solaris 10 (64bit) with JDK1.7.0_06, 4-core Xeon X5570 dual CPU |
| @2.93Ghz with hyperthreading switched on (16 virtual cores): |
| </p> |
| |
| <table border="0" class="table table-striped"><caption align="top">Throughput per thread in |
| messages/second</caption> |
| |
| |
| <tr class="a"> |
| |
| <th>Logger</th> |
| |
| <th>1 thread</th> |
| |
| <th>2 threads</th> |
| |
| <th>4 threads</th> |
| |
| <th>8 threads</th> |
| |
| <th>16 threads</th> |
| |
| <th>32 threads</th> |
| |
| <th>64 threads</th> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>Log4j 2: Loggers all asynchronous</td> |
| |
| <td align="right">2,652,412</td> |
| |
| <td align="right">909,119</td> |
| |
| <td align="right">776,993</td> |
| |
| <td align="right">516,365</td> |
| |
| <td align="right">239,246</td> |
| |
| <td align="right">253,791</td> |
| |
| <td align="right">288,997</td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>Log4j 2: Loggers mixed sync/async</td> |
| |
| <td align="right">2,454,358</td> |
| |
| <td align="right">839,394</td> |
| |
| <td align="right">854,578</td> |
| |
| <td align="right">597,913</td> |
| |
| <td align="right">261,003</td> |
| |
| <td align="right">216,863</td> |
| |
| <td align="right">218,937</td> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>Log4j 2: Async Appender</td> |
| |
| <td align="right">1,713,429</td> |
| |
| <td align="right">603,019</td> |
| |
| <td align="right">331,506</td> |
| |
| <td align="right">149,408</td> |
| |
| <td align="right">86,107</td> |
| |
| <td align="right">45,529</td> |
| |
| <td align="right">23,980</td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>Log4j1: Async Appender</td> |
| |
| <td align="right">2,239,664</td> |
| |
| <td align="right">494,470</td> |
| |
| <td align="right">221,402</td> |
| |
| <td align="right">109,314</td> |
| |
| <td align="right">60,580</td> |
| |
| <td align="right">31,706</td> |
| |
| <td align="right">14,072</td> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>Logback: Async Appender</td> |
| |
| <td align="right">2,206,907</td> |
| |
| <td align="right">624,082</td> |
| |
| <td align="right">307,500</td> |
| |
| <td align="right">160,096</td> |
| |
| <td align="right">85,701</td> |
| |
| <td align="right">43,422</td> |
| |
| <td align="right">21,303</td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>Log4j 2: Synchronous</td> |
| |
| <td align="right">273,536</td> |
| |
| <td align="right">136,523</td> |
| |
| <td align="right">67,609</td> |
| |
| <td align="right">34,404</td> |
| |
| <td align="right">15,373</td> |
| |
| <td align="right">7,903</td> |
| |
| <td align="right">4,253</td> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>Log4j1: Synchronous</td> |
| |
| <td align="right">326,894</td> |
| |
| <td align="right">105,591</td> |
| |
| <td align="right">57,036</td> |
| |
| <td align="right">30,511</td> |
| |
| <td align="right">13,900</td> |
| |
| <td align="right">7,094</td> |
| |
| <td align="right">3,509</td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>Logback: Synchronous</td> |
| |
| <td align="right">178,063</td> |
| |
| <td align="right">65,000</td> |
| |
| <td align="right">34,372</td> |
| |
| <td align="right">16,903</td> |
| |
| <td align="right">8,334</td> |
| |
| <td align="right">3,985</td> |
| |
| <td align="right">1,967</td> |
| </tr> |
| </table> |
| |
| <p></p> |
| |
| <p>On Windows 7 (64bit) with JDK1.7.0_11, 2-core Intel i5-3317u CPU |
| @1.70Ghz with hyperthreading switched on (4 virtual cores): |
| </p> |
| |
| <table border="0" class="table table-striped"><caption align="top">Throughput per thread in |
| messages/second</caption> |
| |
| |
| <tr class="a"> |
| |
| <th>Logger</th> |
| |
| <th>1 thread</th> |
| |
| <th>2 threads</th> |
| |
| <th>4 threads</th> |
| |
| <th>8 threads</th> |
| |
| <th>16 threads</th> |
| |
| <th>32 threads</th> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>Log4j 2: Loggers all asynchronous</td> |
| |
| <td align="right">1,715,344</td> |
| |
| <td align="right">928,951</td> |
| |
| <td align="right">1,045,265</td> |
| |
| <td align="right">1,509,109</td> |
| |
| <td align="right">1,708,989</td> |
| |
| <td align="right">773,565</td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>Log4j 2: Loggers mixed sync/async</td> |
| |
| <td align="right">571,099</td> |
| |
| <td align="right">1,204,774</td> |
| |
| <td align="right">1,632,204</td> |
| |
| <td align="right">1,368,041</td> |
| |
| <td align="right">462,093</td> |
| |
| <td align="right">908,529</td> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>Log4j 2: Async Appender</td> |
| |
| <td align="right">1,236,548</td> |
| |
| <td align="right">1,006,287</td> |
| |
| <td align="right">511,571</td> |
| |
| <td align="right">302,230</td> |
| |
| <td align="right">160,094</td> |
| |
| <td align="right">60,152</td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>Log4j1: Async Appender</td> |
| |
| <td align="right">1,373,195</td> |
| |
| <td align="right">911,657</td> |
| |
| <td align="right">636,899</td> |
| |
| <td align="right">406,405</td> |
| |
| <td align="right">202,777</td> |
| |
| <td align="right">162,964</td> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>Logback: Async Appender</td> |
| |
| <td align="right">1,979,515</td> |
| |
| <td align="right">783,722</td> |
| |
| <td align="right">582,935</td> |
| |
| <td align="right">289,905</td> |
| |
| <td align="right">172,463</td> |
| |
| <td align="right">133,435</td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>Log4j 2: Synchronous</td> |
| |
| <td align="right">281,250</td> |
| |
| <td align="right">225,731</td> |
| |
| <td align="right">129,015</td> |
| |
| <td align="right">66,590</td> |
| |
| <td align="right">34,401</td> |
| |
| <td align="right">17,347</td> |
| </tr> |
| |
| <tr class="b"> |
| |
| <td>Log4j1: Synchronous</td> |
| |
| <td align="right">147,824</td> |
| |
| <td align="right">72,383</td> |
| |
| <td align="right">32,865</td> |
| |
| <td align="right">18,025</td> |
| |
| <td align="right">8,937</td> |
| |
| <td align="right">4,440</td> |
| </tr> |
| |
| <tr class="a"> |
| |
| <td>Logback: Synchronous</td> |
| |
| <td align="right">149,811</td> |
| |
| <td align="right">66,301</td> |
| |
| <td align="right">32,341</td> |
| |
| <td align="right">16,962</td> |
| |
| <td align="right">8,431</td> |
| |
| <td align="right">3,610</td> |
| </tr> |
| </table> |
| |
| <a name="Latency"></a> |
| </section><section> |
| <h4><a name="Response_Time_Latency"></a>Response Time Latency</h4> |
| |
| <table border="0" class="table table-striped"> |
| |
| <tr class="a"> |
| <td>This section has been rewritten with the Log4j 2.6 release. |
| The previous version only reported <i>service time</i> instead of <i>response time</i>. |
| See the <a href="../performance.html#responseTime">response time</a> side bar on the |
| performance page on why this is too optimistic. |
| Furthermore the previous version reported average latency, which does not make sense since |
| latency is not a normal distribution. |
| Finally, the previous version of this section only reported the maximum latency of up to 99.99% |
| of the measurements, which does not tell you how bad the worst 0.01% were. |
| This is unfortunate because often the "outliers" are all that matter when it comes to response time. |
| From this release we will try to do better and report response time latency |
| across the full range of percentages, including all the outliers. |
| Our thanks to Gil Tene for his |
| <a class="externalLink" href="http://www.infoq.com/presentations/latency-response-time">How NOT to measure latency</a> |
| presentation. (Now we know why this is also known as the "Oh s#@t!" presentation.) |
| </td></tr> |
| </table> |
| |
| <p><a href="../performance.html#responseTime">Response time</a> is how long it takes to log a message under a certain load. |
| What is often reported as latency is actually <i>service time</i>: 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. |
| </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>-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> |
| |
| <p> |
| The graph below compares response time latency of the |
| ArrayBlockingQueue-based asynchronous appenders in Logback 1.1.7, Log4j 1.2.17 to the |
| various options for asynchronous logging that Log4j 2.6 offers. |
| Under a workload of 128,000 messages per second, using 16 threads (each logging at a rate of 8,000 messages |
| per second), we see that Logback 1.1.7, Log4j 1.2.17 experience latency spikes that are orders |
| of magnitude larger than Log4j 2. |
| </p> |
| |
| <p> |
| <img src="../images/ResponseTimeAsyncLogging16Threads@8kEach.png" alt="When 16 threads generate a total workload of 128,000 msg/sec, Logback 1.1.7 and Log4j 1.2.17 experience latency spikes that are orders of magnitude larger than Log4j 2" /> |
| </p> |
| |
| <p> |
| The graph below zooms in on the Log4j 2 results for the same test. |
| We see that the worst-case response time is highest for the ArrayBlockingQueue-based Async Appender. |
| <a href="garbagefree.html">Garbage-free</a> async loggers have the best response time behaviour. |
| </p> |
| |
| <p> |
| <img src="../images/ResponseTimeAsyncLogging16Threads@8kEachLog4j2Only-labeled.png" alt="" /> |
| </p> |
| |
| </section></section> |
| |
| <a name="UnderTheHood"></a> |
| <section> |
| <h3><a name="Under_The_Hood"></a>Under The Hood</h3> |
| |
| <p> |
| Asynchronous Loggers are implemented using the |
| <a class="externalLink" href="http://lmax-exchange.github.com/disruptor/">LMAX Disruptor</a> |
| inter-thread messaging library. From the LMAX web site: |
| </p> |
| |
| <blockquote> |
| |
| <p>... using queues to pass data between stages of the system was introducing latency, so we |
| focused on optimising this area. The Disruptor is the result of our research and testing. |
| We found that cache misses at the CPU-level, and locks requiring kernel arbitration are both |
| extremely costly, so we created a framework which has "mechanical sympathy" for |
| the hardware it's running on, and that's lock-free. |
| </p> |
| </blockquote> |
| |
| |
| <p> |
| LMAX Disruptor internal performance comparisons with java.util.concurrent.ArrayBlockingQueue |
| can be found |
| <a class="externalLink" href="https://github.com/LMAX-Exchange/disruptor/wiki/Performance-Results">here</a>. |
| </p> |
| </section> |
| </section> |
| |
| |
| </main> |
| </div> |
| </div> |
| <hr/> |
| <footer> |
| <div class="container-fluid"> |
| <div class="row-fluid"> |
| <p align="center">Copyright © 1999-2020 <a class="external" href="http://www.apache.org">The Apache Software Foundation</a>. All Rights Reserved.<br> |
| Apache Logging, Apache Log4j, Log4j, Apache, the Apache feather logo, and the Apache Logging project logo are trademarks of The Apache Software Foundation.</p> |
| </div> |
| </div> |
| </footer> |
| </body> |
| </html> |
