blob: 486d64b7d41777a371b464bed1f1e769019c438a [file] [log] [blame]
////
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.
////
= Flow Tracing
xref:manual/api.adoc[Log4j API] provides convenience logging methods to aid the tracking of the data flow through an application, which is referred to as *flow tracing*.
<<impl,Logging implementations>> can choose to <<log-events,generate specialized log events>> allowing users to handle these messages different from the rest see <<example>>.
Flow tracing is known to help with the following use cases:
* Troubleshooting without requiring a debugging session
* Helping educate new developers in learning the application
[#usage]
== Usage
link:../javadoc/log4j-api/org/apache/logging/log4j/Logger.html[`Logger`] provides following methods for flow tracing purposes:
`traceEntry()`:: Marks the entry to a block
`traceExit()`:: Marks the exit from a block
`catching()`:: Reports caught exceptions
`throwing()`:: Reports exceptions that are either discarded or unlikely to be handled
The most used `traceEntry()` and `traceExit()` methods are intended to mark the _entry_ and _exit_ points of a particular block of code:
[#example-trace]
.Example `traceEntry()` and `traceExit()` usage
[source,java]
----
public void someMethod() {
LOGGER.traceEntry(); //<1>
// method body
LOGGER.traceExit(); //<2>
}
----
<1> `traceEntry()` marks the entry to the block
<2> `traceExit()` marks the exit from the block
Both `traceEntry()` and `traceExit()` also accept parameters.
You can use them to track the input and output of the associated block:
[#example-trace-args]
.Example `traceEntry()` and `traceExit()` usage with arguments
[source,java]
----
public String someMethod(String input) {
logger.traceEntry(null, input); // <1>
// method body
String output = ...;
return logger.traceExit(output); // <2>
}
----
<1> `traceEntry()` marks the entry to the block along with the input
<2> `traceExit()` marks the exit from the block along with the output
The `catching()` method can be used by an application when it catches an exception that it will not rethrow, either explicitly or attached to another exception:
[#example-catching]
.Example `catching()` usage
[source,java]
----
public void someMethod() {
try {
// Business logic
} catch (Exception error) {
logger.catching(error); // <1>
}
}
----
<1> `catching()` reports the caught exception
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 ensure that proper diagnostics are available if needed.
[#example-throwing]
.Example `throwing()` usage
[source,java]
----
public void someMethod() {
try {
// Business logic
} catch (RuntimeException error) {
throw logger.throwing(error); // <1>
}
}
----
<1> `thrown()` reports the caught exception that is about to be rethrown.
Plus, rethrowing the exception, contrary to <<example-catching,the `catching()` example>> suppressing the exception.
[source,java]
----
public void someMethod() {
try {
// Let's assume an exception is thrown here
String msg = messages[messages.length];
} catch (Exception ex) {
logger.throwing(ex); <1>
}
}
----
<1> The `throwing()` method logs exceptions that are thrown and not caught.
[#aop]
=== Aspect-oriented programming
Logging has been a notorious example for demonstrating https://en.wikipedia.org/wiki/Aspect-oriented_programming[aspect-oriented programming] (AOP).
For instance, using AOP, you can inject logging statements to methods that match a particular footprint, e.g., all public methods in `com.mycompany` package.
With a couple of lines of AOP instructions, you can log input and output of all matching functions.
Flow tracing methods fits like a glove to this AOP use case.
You can see a demonstration of this in https://github.com/apache/logging-log4j-samples/tree/main/log4j-samples-aspectj[the `log4j-samples-aspectj` project] demonstrating how you can implement this use case using Log4j API flow methods and Spring Boot AspectJ support.
[#impl]
== Implementation
This section explains how flow tracing is implemented by different logging implementations.
[#impl-log4j]
=== Log4j Core
Log4j Core, the reference implementation of Log4j API, implements the flow tracing methods such that
* <<impl-log4j-log-events,It generates specialized log events>>
* <<impl-log4j-config,Its behaviour is configurable>>
[#impl-log4j-log-events]
==== Log events
Log4j Core implements the flow tracing methods such that the generated log events are decorated to accommodate any need to selectively handle them:
[%header,cols="2m,1m,2,3"]
|===
|Method
|Level
|Markers
|Message
|traceEntry()
|TRACE
|`ENTER`, `FLOW`
|link:../javadoc/log4j-api/org/apache/logging/log4j/message/EntryMessage.html[`EntryMessage`] extending from link:../javadoc/log4j-api/org/apache/logging/log4j/message/FlowMessage.html[`FlowMessage`]
|traceExit()
|TRACE
|`EXIT`, `FLOW`
|link:../javadoc/log4j-api/org/apache/logging/log4j/message/EntryMessage.html[`ExitMessage`] extending from link:../javadoc/log4j-api/org/apache/logging/log4j/message/FlowMessage.html[`FlowMessage`]
| throwing()
|ERROR
|`THROWING`, `EXCEPTION`
|Plain message
| catching()
|ERROR
|`CATCHING`, `EXCEPTION`
|Plain message
|===
[#impl-log4j-config]
==== Configuration
Flow tracing implementation of Log4j Core can be configured using the following system properties:
include::partial$manual/systemproperties/properties-log4j-core-misc.adoc[leveloffset=+3,tag=flow-tracing]
[#impl-logback]
=== Logback
{logback-url}[Logback] is another logging implementation for the {slf4j-url}[SLF4J] logging API, just like Log4j Core is a logging implementation for the xref:manual/api.adoc[Log4j API].
Using Log4j-to-SLF4J bridge, Logback can be xref:manual/installation.adoc#impl-logback[configured to consume Log4j API].
Log4j-to-SLF4J bridge implements flow tracing methods such that log events are generated with same <<impl-log4j-log-events,marker and level changes of Log4j Core>>.
They only differ in generated message types, since SLF4J has no xref:manual/messages.adoc[extensible message contract] like Log4j, but plain ``String``-based messages.
This effectively means Logback also has access to the stated marker and level changes while using Log4j API flow tracing methods.
[#example]
== Example configuration
In this section, we will share logging implementation configuration examples to filter on flow tracing log events.
[#example-log4j]
=== Log4j Core
Log4j Core is the reference implementation of Log4j API.
In the example configurations below, we will employ a xref:manual/pattern-layout.adoc[] depending on the associated markers of the log event:
[tabs]
====
XML::
+
.{antora-examples-url}manual/flowtracing/log4j2.xml[log4j2.xml] snippet
[source,xml]
----
include::example$manual/flowtracing/log4j2.xml[lines=24..35,indent=0]
----
JSON::
+
.{antora-examples-url}manual/flowtracing/log4j2.json[log4j2.json] snippet
[source,json]
----
include::example$manual/flowtracing/log4j2.json[lines=4..29,indent=0]
----
YAML::
+
.{antora-examples-url}manual/flowtracing/log4j2.yaml[log4j2.yaml] snippet
[source,yaml]
----
include::example$manual/flowtracing/log4j2.yaml[lines=19..34,indent=0]
----
Properties::
+
.{antora-examples-url}manual/flowtracing/log4j2.properties[log4j2.properties] snippet
[source,properties]
----
include::example$manual/flowtracing/log4j2.properties[lines=18..33,indent=0]
----
====
<1> Accepting log events marked with `FLOW` regardless of their level
<2> By default, log event messages will be formatted with a `--` prefix
<3> Log events marked with `ENTER` (that is, generated by `traceEntry()`) will have their message formatted with a `=>` prefix
<4> Log events marked with `EXIT` (that is, generated by `traceExit()`) will have their message formatted with a `<=` prefix
[#example-logback]
=== Logback
{logback-url}[Logback] is another logging implementation for the {slf4j-url}[SLF4J] logging API, just like Log4j Core is a logging implementation for the xref:manual/api.adoc[Log4j API].
Using Log4j-to-SLF4J bridge, Logback can be xref:manual/installation.adoc#impl-logback[configured to consume Log4j API].
Below we will use a combination of `EvaluatorFilter`, `MarkerFilter`, and `OnMarkerEvaluator` in Logback to adapt the formatting pattern of messages written to console based on flow tracing specific markers:
.{antora-examples-url}manual/flowtracing/logback.xml[logback.xml] snippet
[source,xml]
----
include::example$manual/flowtracing/logback.xml[lines=27..76,indent=0]
----
<1> Accepting log events marked with `FLOW` regardless of their level
<2> In `CONSOLE_DEFAULT` appender, excluding all log events marked with `ENTER` and `EXIT`
<3> In `CONSOLE_DEFAULT` appender, log event messages will be formatted with a `-` prefix
<4> In `CONSOLE_FLOW_ENTER` appender, accepting only log events marked with `ENTER`
<5> In `CONSOLE_FLOW_ENTER` appender, log event messages will be formatted with a `→` prefix
<6> In `CONSOLE_FLOW_EXIT` appender, accepting only log events marked with `EXIT`
<7> In `CONSOLE_FLOW_EXIT` appender, log event messages will be formatted with a `←` prefix