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

    <body>
        <section name="Log4j 2 API">
          <a name="FlowTracing"/>
          <subsection name="Flow Tracing">
            <p>
              The Logger class provides logging methods that are quite useful for following the
              execution path of applications. These methods generate logging events that can be filtered
              separately from other debug logging. Liberal use of these methods is encouraged as the output has
              been found to
            </p>
            <ul>
              <li>aid in problem diagnosis in development without requiring a debug session</li>
              <li>aid in problem diagnosis in production where no debugging is possible</li>
              <li>help educate new developers in learning the application.</li>
            </ul>
            <p>
              The most used methods are the entry() or traceEntry() and exit() or traceExit() methods. entry()
              or traceEntry() should be placed at the beginning of methods, except perhaps for simple
              getters and setters. entry() can be called passing from 0 to 4 parameters. Typically these will be
              parameters passed to the method. traceEntry() can be passed a format String and a variable list of
              parameters, or a Message. The entry() and traceEntry() methods log with a level of TRACE and uses
              a Marker with a name of "ENTER" which is also a "FLOW" Marker and all message strings will begin
              with "event", even if a format String or Message is used.
            </p>
            <p>The main difference between the entry and traceEntry methods is that the entry method accepts a
              variable list of objects where presumably each is a method parameter. The traceEntry method
              accepts a format string followed by a variable list of objects, presumably included in the
              format String. It is not possible to have a single method that includes both of these as it would
              be ambiguous whether the first String is a parameter or a format String.</p>
            <p>
              An exit() or traceExit() method should be placed before any return statement or as the last statement of
              methods without a return. exit() and traceExit() can be called with or without a parameter. Typically,
              methods that return void will use exit() or traceExit() while methods that return an Object will use
              exit(Object obj) or traceExit(object, new SomeMessage(object)). The exit() and traceExit() methods log
              with a level of TRACE and uses a Marker with a name of "EXIT" which is also a "FLOW" Marker and all
              message strings will begin with "exit", even if a format String or Message is used.
            </p>
            <p>
              The throwing() method can be used by an application when it is throwing an exception that is
              unlikely to be handled, such as a RuntimeException. This will insure that proper diagnostics
              are available if needed. The logging event generated will have a level of ERROR and will have
              an associated Marker with a name of "THROWING" which is also an "EXCEPTION" Marker.
            </p>
            <p>
              The catching() method can be used by an application when it catches an Exception that it is not
              going to rethrow, either explicitly or attached to another Exception. The logging event generated
              will have a level of ERROR and will have an associated Marker with a name of "CATCHING" which is
              also an "EXCEPTION" Marker.
            </p>
            <p>
              The following example shows a simple application using these methods in a fairly typical manner. The
              throwing() is not present since no Exceptions are explicitly thrown and not handled.
            </p>
<pre class="prettyprint linenums">
package com.test;

import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.LogManager;

import java.util.Random;

public class TestService {
    private Logger logger = LogManager.getLogger(TestService.class.getName());

    private String[] messages = new String[] {
        "Hello, World",
        "Goodbye Cruel World",
        "You had me at hello"
    };
    private Random rand = new Random(1);

    public void setMessages(String[] messages) {
        logger.traceEntry(new JsonMessage(messages));
        this.messages = messages;
        logger.traceExit();
    }

    public String[] getMessages() {
        logger.traceEntry();
        return logger.traceExit(messages, new JsonMessage(messages));
    }

    public String retrieveMessage() {
        logger.entry();

        String testMsg = getMessage(getKey());

        return logger.exit(testMsg);
    }

    public void exampleException() {
        logger.entry();
        try {
            String msg = messages[messages.length];
            logger.error("An exception should have been thrown");
        } catch (Exception ex) {
            logger.catching(ex);
        }
        logger.exit();
    }

    public String getMessage(int key) {
        logger.entry(key);

        String value = messages[key];

        return logger.exit(value);
    }

    private int getKey() {
        logger.entry();
        int key = rand.nextInt(messages.length);
        return logger.exit(key);
    }
}</pre>
            <p>
              This test application uses the preceding service to generate logging events.
            </p>
<pre class="prettyprint linenums">
package com.test;

public class App {

    public static void main( String[] args ) {
        TestService service = new TestService();
        service.retrieveMessage();
        service.retrieveMessage();
        service.exampleException();
    }
}</pre>
            <p>
              The configuration below will cause all output to be routed to target/test.log. The pattern for
              the FileAppender includes the class name, line number and method name. Including these
              in the pattern are critical for the log to be of value.
            </p>
<pre class="prettyprint linenums"><![CDATA[
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="error">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
      <!-- Flow tracing is most useful with a pattern that shows location.
           Below pattern outputs class, line number and method name. -->
      <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/>
    </Console>
    <File name="log" fileName="target/test.log" append="false">
      <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/>
    </File>
  </Appenders>
  <Loggers>
    <Root level="trace">
      <AppenderRef ref="log"/>
    </Root>
  </Loggers>
</Configuration>]]></pre>
            <p>
              Here is the output that results from the Java classes and configuration above.
            </p>
            <pre>
19:08:07.056 TRACE com.test.TestService 19 retrieveMessage -  entry
19:08:07.060 TRACE com.test.TestService 46 getKey -  entry
19:08:07.060 TRACE com.test.TestService 48 getKey -  exit with (0)
19:08:07.060 TRACE com.test.TestService 38 getMessage -  entry parms(0)
19:08:07.060 TRACE com.test.TestService 42 getMessage -  exit with (Hello, World)
19:08:07.060 TRACE com.test.TestService 23 retrieveMessage -  exit with (Hello, World)
19:08:07.061 TRACE com.test.TestService 19 retrieveMessage -  entry
19:08:07.061 TRACE com.test.TestService 46 getKey -  entry
19:08:07.061 TRACE com.test.TestService 48 getKey -  exit with (1)
19:08:07.061 TRACE com.test.TestService 38 getMessage -  entry parms(1)
19:08:07.061 TRACE com.test.TestService 42 getMessage -  exit with (Goodbye Cruel World)
19:08:07.061 TRACE com.test.TestService 23 retrieveMessage -  exit with (Goodbye Cruel World)
19:08:07.062 TRACE com.test.TestService 27 exampleException -  entry
19:08:07.077 DEBUG com.test.TestService 32 exampleException - catching java.lang.ArrayIndexOutOfBoundsException: 3
        at com.test.TestService.exampleException(TestService.java:29) [classes/:?]
        at com.test.App.main(App.java:9) [classes/:?]
        at com.test.AppTest.testApp(AppTest.java:15) [test-classes/:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.6.0_29]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[?:1.6.0_29]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[?:1.6.0_29]
        at java.lang.reflect.Method.invoke(Method.java:597) ~[?:1.6.0_29]
        at org.junit.internal.runners.TestMethodRunner.executeMethodBody(TestMethodRunner.java:99) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestMethodRunner.runUnprotected(TestMethodRunner.java:81) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.BeforeAndAfterRunner.runProtected(BeforeAndAfterRunner.java:34) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestMethodRunner.runMethod(TestMethodRunner.java:75) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestMethodRunner.run(TestMethodRunner.java:45) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestClassMethodsRunner.invokeTestMethod(TestClassMethodsRunner.java:66) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestClassMethodsRunner.run(TestClassMethodsRunner.java:35) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestClassRunner$1.runUnprotected(TestClassRunner.java:42) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.BeforeAndAfterRunner.runProtected(BeforeAndAfterRunner.java:34) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestClassRunner.run(TestClassRunner.java:52) [junit-4.3.1.jar:?]
        at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:35) [surefire-junit4-2.7.2.jar:2.7.2]
        at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:115) [surefire-junit4-2.7.2.jar:2.7.2]
        at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:97) [surefire-junit4-2.7.2.jar:2.7.2]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.6.0_29]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[?:1.6.0_29]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[?:1.6.0_29]
        at java.lang.reflect.Method.invoke(Method.java:597) ~[?:1.6.0_29]
        at org.apache.maven.surefire.booter.ProviderFactory$ClassLoaderProxy.invoke(ProviderFactory.java:103) [surefire-booter-2.7.2.jar:2.7.2]
        at $Proxy0.invoke(Unknown Source) [?:?]
        at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:150) [surefire-booter-2.7.2.jar:2.7.2]
        at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcess(SurefireStarter.java:91) [surefire-booter-2.7.2.jar:2.7.2]
        at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:69) [surefire-booter-2.7.2.jar:2.7.2]
19:08:07.087 TRACE com.test.TestService 34 exampleException -  exit</pre>
            <p>
              Simply changing the root logger level to DEBUG in the example above will reduce the output
              considerably.
            </p>
            <pre>
19:13:24.963 DEBUG com.test.TestService 32 exampleException - catching java.lang.ArrayIndexOutOfBoundsException: 3
        at com.test.TestService.exampleException(TestService.java:29) [classes/:?]
        at com.test.App.main(App.java:9) [classes/:?]
        at com.test.AppTest.testApp(AppTest.java:15) [test-classes/:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.6.0_29]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[?:1.6.0_29]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[?:1.6.0_29]
        at java.lang.reflect.Method.invoke(Method.java:597) ~[?:1.6.0_29]
        at org.junit.internal.runners.TestMethodRunner.executeMethodBody(TestMethodRunner.java:99) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestMethodRunner.runUnprotected(TestMethodRunner.java:81) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.BeforeAndAfterRunner.runProtected(BeforeAndAfterRunner.java:34) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestMethodRunner.runMethod(TestMethodRunner.java:75) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestMethodRunner.run(TestMethodRunner.java:45) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestClassMethodsRunner.invokeTestMethod(TestClassMethodsRunner.java:66) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestClassMethodsRunner.run(TestClassMethodsRunner.java:35) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestClassRunner$1.runUnprotected(TestClassRunner.java:42) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.BeforeAndAfterRunner.runProtected(BeforeAndAfterRunner.java:34) [junit-4.3.1.jar:?]
        at org.junit.internal.runners.TestClassRunner.run(TestClassRunner.java:52) [junit-4.3.1.jar:?]
        at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:35) [surefire-junit4-2.7.2.jar:2.7.2]
        at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:115) [surefire-junit4-2.7.2.jar:2.7.2]
        at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:97) [surefire-junit4-2.7.2.jar:2.7.2]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.6.0_29]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[?:1.6.0_29]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[?:1.6.0_29]
        at java.lang.reflect.Method.invoke(Method.java:597) ~[?:1.6.0_29]
        at org.apache.maven.surefire.booter.ProviderFactory$ClassLoaderProxy.invoke(ProviderFactory.java:103) [surefire-booter-2.7.2.jar:2.7.2]
        at $Proxy0.invoke(Unknown Source) [?:?]
        at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:150) [surefire-booter-2.7.2.jar:2.7.2]
        at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcess(SurefireStarter.java:91) [surefire-booter-2.7.2.jar:2.7.2]
        at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:69) [surefire-booter-2.7.2.jar:2.7.2]</pre>
          </subsection>
        </section>
    </body>
</document>
