| <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd"> |
| <!-- |
| | Generated by Apache Maven Doxia at Jun 9, 2012 |
| | Rendered using Apache Maven Fluido Skin |
| --> |
| <html xmlns="http://www.w3.org/1999/xhtml" xml:lang="en" lang="en"> |
| <head> |
| <meta http-equiv="Content-Type" content="text/html; charset=UTF-8" /> |
| <meta name="viewport" content="width=device-width, initial-scale=1.0" /> |
| <title> |
| Performance</title> |
| <link rel="stylesheet" href="./css/apache-maven-fluido.min.css" /> |
| <link rel="stylesheet" href="./css/site.css" /> |
| <link rel="stylesheet" href="./css/print.css" media="print" /> |
| |
| |
| <script type="text/javascript" src="./js/apache-maven-fluido.min.js"></script> |
| |
| |
| <meta name="author" content="Ralph Goers" /> |
| <meta name="Date-Revision-yyyymmdd" content="20120609" /> |
| <meta http-equiv="Content-Language" content="en" /> |
| |
| </head> |
| <body class="topBarDisabled"> |
| |
| |
| |
| |
| <div class="container-fluid"> |
| <div id="banner"> |
| <div class="pull-left"> |
| <a href="../../" id="bannerLeft"> |
| <img src="images/ls-logo.jpg" alt="Apache Logging Services™"/> |
| </a> |
| </div> |
| <div class="pull-right"> <div id="bannerRight"> |
| <img src="images/logo.jpg" /> |
| </div> |
| </div> |
| <div class="clear"><hr/></div> |
| </div> |
| |
| <div id="breadcrumbs"> |
| <ul class="breadcrumb"> |
| |
| |
| <li id="publishDate">Last Published: 2012-06-09</li> |
| <li class="divider">|</li> <li id="projectVersion">Version: 2.0-alpha1-SNAPSHOT</li> |
| |
| |
| |
| |
| |
| <li class="pull-right"> <a href="http://wiki.apache.org/logging" class="externalLink" title="Logging Wiki">Logging Wiki</a> |
| </li> |
| |
| <li class="divider pull-right">|</li> |
| |
| <li class="pull-right"> <a href="http://www.apache.org/" class="externalLink" title="Apache">Apache</a> |
| </li> |
| |
| <li class="divider pull-right">|</li> |
| |
| <li class="pull-right"> <a href="../../" title="Logging Services">Logging Services</a> |
| </li> |
| |
| <li class="divider pull-right">|</li> |
| |
| <li class="pull-right"> <a href="../" title="Log4j">Log4j</a> |
| </li> |
| |
| <li class="divider pull-right">|</li> |
| |
| <li class="pull-right"> <a href="../companions" title="Log4j Companions">Log4j Companions</a> |
| </li> |
| |
| </ul> |
| </div> |
| |
| <div class="row-fluid"> |
| <div id="leftColumn" class="span3"> |
| <div class="well sidebar-nav"> |
| |
| |
| <h3>Apache Log4j™ 2</h3> |
| <ul> |
| <li class="none"> |
| <a href="index.html" title="About">About</a> |
| </li> |
| <li class="none"> |
| <a href="download.html" title="Download">Download</a> |
| </li> |
| <li class="none"> |
| <a href="build.html" title="Build and Install">Build and Install</a> |
| </li> |
| <li class="none"> |
| <a href="changelog.html" title="Changelog">Changelog</a> |
| </li> |
| </ul> |
| <h3>Manual</h3> |
| <ul> |
| <li class="none"> |
| <a href="manual/index.html" title="Introduction">Introduction</a> |
| </li> |
| <li class="none"> |
| <a href="manual/architecture.html" title="Architecture">Architecture</a> |
| </li> |
| <li class="collapsed"> |
| <a href="manual/api.html" title="API">API</a> |
| </li> |
| <li class="collapsed"> |
| <a href="manual/configuration.html" title="Configuration">Configuration</a> |
| </li> |
| <li class="collapsed"> |
| <a href="manual/plugins.html" title="Plugins">Plugins</a> |
| </li> |
| <li class="collapsed"> |
| <a href="manual/lookups.html" title="Lookups">Lookups</a> |
| </li> |
| <li class="collapsed"> |
| <a href="manual/appenders.html" title="Appenders">Appenders</a> |
| </li> |
| <li class="collapsed"> |
| <a href="manual/layouts.html" title="Layouts">Layouts</a> |
| </li> |
| <li class="collapsed"> |
| <a href="manual/filters.html" title="Filters">Filters</a> |
| </li> |
| <li class="none"> |
| <a href="manual/jmx.html" title="JMX">JMX</a> |
| </li> |
| <li class="none"> |
| <a href="manual/logsep.html" title="Logging Separation">Logging Separation</a> |
| </li> |
| <li class="collapsed"> |
| <a href="manual/extending.html" title="Extending Log4j">Extending Log4j</a> |
| </li> |
| </ul> |
| <h3>Logging Adapters</h3> |
| <ul> |
| <li class="none"> |
| <a href="log4j12-api/api.html" title="Log4j 1.x API">Log4j 1.x API</a> |
| </li> |
| <li class="none"> |
| <a href="log4j2-jcl/api.html" title="Commons Logging">Commons Logging</a> |
| </li> |
| <li class="none"> |
| <a href="slf4j-impl/api.html" title="SLF4J">SLF4J</a> |
| </li> |
| </ul> |
| <h3>Components</h3> |
| <ul> |
| <li class="none"> |
| <a href="log4j-api/index.html" title="API">API</a> |
| </li> |
| <li class="none"> |
| <a href="log4j-core/index.html" title="Impl">Impl</a> |
| </li> |
| <li class="none"> |
| <a href="log4j12-api/index.html" title="Log4J 1.2 API">Log4J 1.2 API</a> |
| </li> |
| <li class="none"> |
| <a href="log4j-jcl/index.html" title="Commons Logging Bridge">Commons Logging Bridge</a> |
| </li> |
| <li class="none"> |
| <a href="slf4j-impl/index.html" title="SLF4J Binding">SLF4J Binding</a> |
| </li> |
| <li class="none"> |
| <a href="log4j-flume-og/index.html" title="Flume OG">Flume OG</a> |
| </li> |
| <li class="none"> |
| <a href="log4j-flume-ng/index.html" title="Flume NG">Flume NG</a> |
| </li> |
| </ul> |
| <h3>Project Documentation</h3> |
| <ul> |
| <li class="collapsed"> |
| <a href="project-info.html" title="Project Information">Project Information</a> |
| </li> |
| <li class="collapsed"> |
| <a href="project-reports.html" title="Project Reports">Project Reports</a> |
| </li> |
| </ul> |
| |
| |
| |
| <hr class="divider" /> |
| |
| <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="poweredBy" alt="Built by Maven" src="./images/logos/maven-feather.png" /> |
| </a> |
| </div> |
| </div> |
| </div> |
| |
| <div id="bodyColumn" class="span9" > |
| |
| <!-- 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. --> |
| |
| <div class="section"><h2>Performance<a name="Performance"></a></h2> |
| <p>One of the often-cited arguments against logging is its |
| computational cost. This is a legitimate concern as even moderately |
| sized applications can generate thousands of log requests. Much |
| effort was spent measuring and tweaking logging performance. Log4j |
| claims to be fast and flexible: speed first, flexibility second. |
| </p> |
| <p>The user should be aware of the following performance issues.</p> |
| <ol style="list-style-type: decimal"> |
| <li> |
| <b>Logging performance when logging is turned off.</b> |
| <br /> |
| <p>When logging is turned off entirely or just for a set of Levels, the cost of a log request consists of |
| two method invocations plus an integer comparison. On a 2.53 GHz Intel Core 2 Duo MacBook Pro |
| calling isDebugEnabled 10 million times produces an average result in nanoseconds of: <br /> |
| </p><div><pre> |
| Log4j: 4 |
| Logback: 5 |
| Log4j 2: 3 |
| </pre></div> |
| The numbers above will vary slightly from run to run so the only conclusion that should be |
| drawn is that all 3 frameworks perform similarly on this task. |
| |
| <p>However, The method invocation involves the "hidden" cost of parameter construction. |
| </p> |
| <p>For example, |
| </p><div><pre> |
| logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i])); |
| </pre></div> |
| incurs the cost of constructing the message parameter, i.e. converting both integer |
| <tt>i</tt> and <tt>entry[i]</tt> to a String, and concatenating intermediate strings, |
| regardless of whether the message will be logged or not. |
| |
| This cost of parameter construction can be quite high and it |
| depends on the size of the parameters involved. |
| |
| A comparison run on the same hardware as above yields: |
| <div><pre> |
| Log4j: 188 |
| Logback: 183 |
| Log4j 2: 188 |
| </pre></div> |
| |
| Again, no conclusion should be drawn regarding relative differences between the frameworks on |
| this task, but it should be obvious that it is considerably more expensive than simply testing |
| the level. |
| |
| <p> |
| The best approach to avoid the cost of parameter construction is to use Log4j 2's formatting |
| capabilities. For example, instead of the above write: |
| </p><div><pre> |
| logger.debug("Entry number: {} is {}", i, entry[i]); |
| </pre></div> |
| Using this approach, a comparison run again on the same hardware produces: |
| <div><pre> |
| Log4j: Not supported |
| Logback: 9 |
| Log4j 2: 4 |
| </pre></div> |
| These results show that the difference in performance between the call to isDebugEnabled and |
| logger.debug is barely discernable. |
| |
| <p>In some circumstances one of the parameters to logger.debug will be a costly method call that |
| should be avoided if debugging is disabled. In those cases write: |
| </p><div><pre> |
| if(logger.isDebugEnabled() { |
| logger.debug("Entry number: " + i + " is " + entry[i].toString()); |
| } |
| </pre></div> |
| |
| <p>This will not incur the cost of whatever the toString() method needs to do if debugging is disabled. |
| On the other hand, if the logger is enabled for the debug level, it will incur twice the cost of |
| evaluating whether the logger is enabled or not: once |
| in <tt>isDebugEnabled</tt> and once in <tt>debug</tt>. This is an insignificant |
| overhead because evaluating a logger takes about 1% of the time it takes to actually log. |
| </p> |
| <p>Certain users resort to preprocessing or compile-time |
| techniques to compile out all log statements. This leads to perfect |
| performance efficiency with respect to logging. However, since the |
| resulting application binary does not contain any log statements, |
| logging cannot be turned on for that binary. This seems to be |
| a disproportionate price to pay in exchange for a small performance |
| gain. |
| </p> |
| </li> |
| <li> |
| <b>The performance of deciding whether to log or not to log when logging is turned on.</b> |
| <br /> |
| <p> |
| Unlike Log4j and Logback, Log4j 2 Loggers don't "walk a hierarchy". Loggers point directly to the |
| Logger configuration that best matches the Logger's name. This incurs extra overhead when the Logger |
| is first created but reduces the overhead every time the Logger is used. |
| </p> |
| </li> |
| <li> |
| <b>Actually outputting log messages</b> |
| <br /> |
| <p>This is the cost of formatting the log output and sending it to its target destination. Here again, |
| a serious effort was made to make layouts (formatters) perform as quickly as possible. The same |
| is true for appenders. One of the fundamental tenants of Log4j 2 is to use immutable objects whenever |
| possible and to lock at the lowest granularity possible. However, the cost of actually formatting and |
| delivering log events will never be insignificant. For example, the results of writing to a simple log |
| file using the same format using Log4j, Logback and Log4j 2 are: |
| </p><div><pre> |
| Log4j: 4220 |
| Logback: 9671 |
| Log4j 2: 4615 |
| </pre></div> |
| |
| <p> |
| These results show that actually writing out the events can be at least 1000 times more expensive than |
| when they are disabled. |
| </p> |
| </li> |
| <li> |
| <b>Advanced Filtering</b> |
| <br /> |
| <p> |
| Both Logback and Log4j 2 support advanced filtering. Logback calls them TurboFilters while |
| Log4j 2 has a single Filter object. Advanced filtering provides the capability to filter |
| LogEvents using more than just the Level before the events are passed to Appenders. |
| However, this flexibility does come with some cost. Since multi-threading can also have an impact on the |
| performance of advanced filtering, the table below shows the difference in performance in two different |
| sets of context-wide filters running on the same hardware as the previous tests using |
| various numbers of threads. |
| </p> |
| <table border="0" class="zebra-striped"> |
| <tr class="a"> |
| <th>Test</th> |
| <th>1 thread</th> |
| <th>2 threads</th> |
| <th>5 threads</th> |
| <th>10 threads</th> |
| <th>20 threads</th> |
| <th>50 threads</th> |
| </tr> |
| <tr class="b"> |
| <td>Logback MDCFilter</td> |
| <td>37</td> |
| <td>50</td> |
| <td>145</td> |
| <td>316</td> |
| <td>606</td> |
| <td>1670</td> |
| </tr> |
| <tr class="a"> |
| <td>Log4j 2 ThreadContextMapFilter</td> |
| <td>30</td> |
| <td>35</td> |
| <td>85</td> |
| <td>165</td> |
| <td>341</td> |
| <td>864</td> |
| </tr> |
| <tr class="b"> |
| <td>Logback MarkerFilter</td> |
| <td>17</td> |
| <td>24</td> |
| <td>59</td> |
| <td>115</td> |
| <td>234</td> |
| <td>547</td> |
| </tr> |
| <tr class="a"> |
| <td>Log4j 2 MarkerFilter</td> |
| <td>4</td> |
| <td>5</td> |
| <td>7</td> |
| <td>20</td> |
| <td>35</td> |
| <td>92</td> |
| </tr> |
| </table> |
| </li> |
| |
| </ol> |
| <p> |
| The performance results above were all derived from running the DebugDisabledPerformanceComparison, |
| FilterPerformanceComparison, and PerformanceComparison junit tests which can be found in the |
| Log4j 2 unit test source directory. |
| </p> |
| </div> |
| |
| |
| </div> |
| </div> |
| |
| <hr/> |
| |
| <footer> |
| <div class="container-fluid"> |
| <div class="row span16">Copyright © 1999-2012 |
| <a href="http://www.apache.org">Apache Software Foundation</a>. |
| All Rights Reserved. |
| |
| </div> |
| |
| |
| |
| </div> |
| </footer> |
| </body> |
| </html> |
