<?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>Log4j 2 API Log Builder</title>
    <author email="rgoers@apache.org">Ralph Goers</author>
  </properties>

  <body>
    <section name="Log4j 2 API">
      <subsection name="Log Builder">
        <a name="Building Log Messages"/>
        <p>
          Log4j has traditionally been used with logging statements like
          <pre class="prettyprint linenums"><![CDATA[
          logger.error("Unable to process request due to {}", code, exception);]]></pre>
          This has resulted in some confusion as to whether the exception should be a parameter to the message or
          if Log4j should handle it as a throwable. In order to make logging clearer a builder pattern has been
          added to the API. Using the builder syntax the above would be handled as:
          <pre class="prettyprint linenums"><![CDATA[
          logger.atError().withThrowable(exception).log("Unable to process request due to {}", code);]]></pre></p>
        <p>
          With this syntax it is clear that the exception is to be treated as a Throwable by Log4j.
        </p>
        <p>
          The Logger class now returns a LogBuilder when any of the atTrace, atDebug, atInfo, atWarn, atError,
          atFatal, always, or atLevel(Level) methods are called. The logBuilder then allows a Marker, Throwable,
          and/or location to be added to the event before it is logged. A call to the log method always causes the
          log event to be finalized and sent.
        </p>
        <p>
          A logging statement with a Marker, Throwable, and location would look like:
          <pre class="prettyprint linenums"><![CDATA[
          logger.atInfo().withMarker(marker).withLocation().withThrowable(exception).log("Login for user {} failed", userId);]]></pre>
        </p>
        <p>
          Providing the location method on the LogBuilder provides two distinct advantages:
          <ol>
            <li>Logging wrappers can use it to provide the location information to be used by Log4j.</li>
            <li>The overhead of capturing location information when using the location method with no
            parameters is much better than having to calculate the location information when it is needed. Log4j
            can simply ask for the stack trace entry at a fixed index instead of having to walk the stack trace
            to determine the calling class. Of course, if the location information will not be used by the layout
            this will result in slower performance.</li>
          </ol>
        </p>
        <h4>Location Performance</h4>
        <p>
          The table below shows some of the results from the FileAppenderBenchmark and FileAppenderWithLocationBenchmark
          classes in the log4j-perf project when configured to use 4 threads. The results show that lazily including
          the location information is about 8 times slower than not including location information. While using the
          withLocation method of LogBuilder is about 3 times faster than lazily calculating the location information
          it is still about 2.5 times slower than not including location information.
        </p>
          <p>
            The tests were run on a 2018 MacBook Pro with a
            2.9 GHz Intel Core i9 processor with 6 cores, 32 GB of memory and 1 TB of SSD storage on Java 11 using
            Log4j 2.13.0 and Logback 1.2.3.
          </p>
        <img src="../images/LocationPerf.png" title="Location Performance"
             alt="Location Performance"/>
        <table>
          <tr>
            <th>Test</th>
            <th>Print Location Info</th>
            <th>No Location Info Printed</th>
          </tr>
          <tr>
            <td>Log4j2 File</td>
            <td>191,509.724 ± 11339.978  ops/s</td>
            <td>1,407,329.130 ± 22595.997  ops/s</td>
          </tr>
          <tr>
            <td>Log4j2 Log Builder withLocation()</td>
            <td>469,200.684 ± 50025.985  ops/s</td>
            <td>577,127.463 ± 11464.342  ops/s</td>
          </tr>
          <tr>
            <td>Logback File</td>
            <td>159,116.538 ± 1884.969  ops/s</td>
            <td>1,240,438.384 ± 76619.873  ops/s</td>
          </tr>
        </table>
        <p>
          As expected, when using LogBuilder with a call to the withLocation() method logging is much faster when
          location information is used in the output but significantly slower when it is not.
        </p>
        <p>
          Note: Running the tests at various times provides varying results. Although some results have been as much
          as 10% higher all results are generally affected similarly so the comparisons between them stay the same.
        </p>
      </subsection>
    </section>
  </body>
</document>
