Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve api.adoc et al. #2604

Merged
merged 14 commits into from
May 24, 2024
Merged
3 changes: 3 additions & 0 deletions antora-playbook.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -90,6 +90,9 @@ ui:
.doc .colist>table code, .doc p code, .doc thead code { font-size: 0.8em; }
.doc pre { font-size: 0.7rem; }
.doc .colist { font-size: 0.75rem; }
/* Make links more visible: */
.doc a { text-decoration: underline; }
.doc a code { text-decoration: underline; color: #1565c0; }
/* Tab header fonts aren't rendered good, adjusting the font weight: */
.tablist > ul li { font-weight: 500; }
/* `page-toclevels` greater than 4 are not supported by Antora UI, patching it: */
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@

public final class MarkerExample {

private static final Logger logger = LogManager.getLogger("example.MarkerExample");
private static final Logger LOGGER = LogManager.getLogger("example.MarkerExample");
// tag::create-marker[]
private static final Marker SQL_MARKER = MarkerManager.getMarker("SQL");
// end::create-marker[]
Expand All @@ -43,21 +43,21 @@ public static void main(final String[] args) {
public static void doQuery(String table) {
// Do business logic here
// tag::use-marker[]
logger.debug(SQL_MARKER, "SELECT * FROM {}", table);
LOGGER.debug(SQL_MARKER, "SELECT * FROM {}", table);
// end::use-marker[]
}

public static void doQueryParent(String table) {
// Do business logic here
// tag::use-marker-parent[]
logger.debug(QUERY_MARKER, "SELECT * FROM {}", table);
LOGGER.debug(QUERY_MARKER, "SELECT * FROM {}", table);
// end::use-marker-parent[]
}

public static void doUpdate(String table, String column, String value) {
// Do business logic here
// tag::use-marker-parent[]
logger.debug(UPDATE_MARKER, "UPDATE {} SET {} = {}", table, column, value);
LOGGER.debug(UPDATE_MARKER, "UPDATE {} SET {} = {}", table, column, value);
// end::use-marker-parent[]
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -24,42 +24,43 @@
import org.apache.logging.log4j.message.SimpleMessage;

public class MessagesExample {
private static final Logger logger = LogManager.getLogger();

private static final Logger LOGGER = LogManager.getLogger();

public static void main(String[] args) {
Throwable e = new RuntimeException();
doLogSimple(e);
doLogParameterized("foo", "bar", e);
Throwable exception = new RuntimeException();
doLogSimple(exception);
doLogParameterized("foo", "bar", exception);

InetSocketAddress socketAddress = InetSocketAddress.createUnresolved("192.0.2.17", 1234);
LoginFailureEvent event = new LoginFailureEvent("root", socketAddress);
failedLogin(event);
}

private static void doLogSimple(Throwable e) {
private static void doLogSimple(Throwable exception) {
// tag::simple[]
logger.error("Houston, we have a problem.", e);
logger.error(new SimpleMessage("Houston, we have a problem."), e);
LOGGER.error("Houston, we have a problem.", exception);
LOGGER.error(new SimpleMessage("Houston, we have a problem."), exception);
// end::simple[]
}

private static void doLogParameterized(String action, String cause, Throwable e) {
private static void doLogParameterized(String userId, Throwable exception) {
// tag::parameterized[]
logger.error("Unable to {}, because {} occurred", action, cause, e);
logger.error(new ParameterizedMessage("Unable to {}, because {} occurred", action, cause), e);
LOGGER.error("Unable process user with ID `{}`", userId, exception);
LOGGER.error(new ParameterizedMessage("Unable process user with ID `{}`", userId), exception);
// end::parameterized[]
}

private static void failedLogin(LoginFailureEvent event) {
// tag::complex[]
logger.info(
LOGGER.info(
"Connection closed by authenticating user {} {} port {} [preauth]",
event.userName(),
event.remoteAddress().getHostName(),
event.remoteAddress().getPort());
// end::complex[]
// tag::complex-message[]
logger.info(event);
LOGGER.info(event);
// end::complex-message[]
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@
import org.apache.logging.log4j.util.StringBuilderFormattable;

public class StringBuilderFormattableExample {
private static final Logger logger = LogManager.getLogger();
private static final Logger LOGGER = LogManager.getLogger();

public static void main(String[] args) {
InetSocketAddress socketAddress = InetSocketAddress.createUnresolved("192.0.2.17", 1234);
Expand All @@ -32,7 +32,7 @@ public static void main(String[] args) {
}

private static void failedLogin(LoginFailureEvent event) {
logger.info(event);
LOGGER.info(event);
}

// tag::loginFailure[]
Expand Down
35 changes: 13 additions & 22 deletions src/site/antora/modules/ROOT/nav.adoc
Original file line number Diff line number Diff line change
Expand Up @@ -25,45 +25,36 @@
.Resources
* xref:faq.adoc[F.A.Q.]
* xref:5min.adoc[]
* xref:manual/migration.adoc[]
* xref:manual/cloud.adoc[]
* xref:development.adoc[]

.xref:manual/index.adoc[]
* xref:manual/installation.adoc[]
* xref:manual/architecture.adoc[]
* xref:manual/migration.adoc[]
* xref:manual/api.adoc[]
* xref:manual/api.adoc[API]
** xref:manual/customloglevels.adoc[]
** xref:manual/logbuilder.adoc[]
** xref:manual/flowtracing.adoc[]
** xref:manual/markers.adoc[]
** xref:manual/eventlogging.adoc[]
** xref:manual/messages.adoc[]
** xref:manual/thread-context.adoc[]
** xref:manual/scoped-context.adoc[]
** xref:manual/thread-context.adoc[]
** xref:manual/messages.adoc[]
** xref:manual/flowtracing.adoc[]
** xref:manual/eventlogging.adoc[]
** xref:manual/resource-logger.adoc[]
* Configuration
** xref:manual/configuration.adoc[Configuration file]
** xref:manual/systemproperties.adoc[]
** xref:manual/customconfig.adoc[]
** xref:manual/appenders.adoc[]
** xref:manual/layouts.adoc[]
*** xref:manual/json-template-layout.adoc[]
** xref:manual/lookups.adoc[]
** xref:manual/customloglevels.adoc[]
** xref:manual/filters.adoc[]
** xref:manual/scripts.adoc[]
** xref:manual/systemproperties.adoc[]
* xref:manual/usage.adoc[]
* xref:manual/cloud.adoc[]
* xref:manual/lookups.adoc[]
* xref:manual/appenders.adoc[]
* xref:manual/layouts.adoc[]
** xref:manual/json-template-layout.adoc[]
* xref:manual/filters.adoc[]
* xref:manual/extending.adoc[]
** xref:manual/customconfig.adoc[]
* xref:manual/plugins.adoc[]
* xref:manual/customconfig.adoc[]
* xref:manual/customloglevels.adoc[]
* xref:manual/jmx.adoc[]
* xref:manual/logsep.adoc[]
** xref:manual/jmx.adoc[]
* xref:manual/extending.adoc[Extending]
** xref:manual/plugins.adoc[]
* xref:manual/performance.adoc[]
** xref:manual/async.adoc[]
** xref:manual/garbagefree.adoc[]
Expand Down
148 changes: 18 additions & 130 deletions src/site/antora/modules/ROOT/pages/5min.adoc
Original file line number Diff line number Diff line change
Expand Up @@ -129,144 +129,32 @@ dependencies {
[#logging]
== How do I write logs using Log4j?

To write logs, you need a `Logger` instance which you will retrieve from the `LogManager`.
The `Logger` instance is thread-safe and reusable.
include::partial$manual/api-intro.adoc[]

Second, you can use the `Logger` instance to write logs by using methods like `info()`, `warn()`, `error()`, etc.
These methods are named after the log levels they represent, a way to categorize log events by severity.
The log message can also contain placeholders written as `{}` that will be replaced by the arguments passed to the method.
[#best-practice]
=== Best practices

[source,java]
----
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.LogManager;

public class DbTableService {

private static final Logger LOGGER = LogManager.getLogger(); // <1>

public void truncateTable(String tableName) throws IOException {
LOGGER.warn("truncating table `{}`", tableName); // <2>
db.truncate(tableName);
}

}
----
<1> This is a thread-safe, reusable `Logger` instance.
<2> The placeholder `{}` in the message will be replaced with the value of `tableName`

The generated **log event** will be enriched with the **log level** (i.e., `WARN`),
but also timestamp, class & method name, line number, and several other information.

As already mentioned Log levels are used to categorize log events by severity and control the verbosity of the logs.
Log4j knows various levels, but the most common are `DEBUG`, `INFO`, `WARN`, and `ERROR`.
With them, you can filter out less important logs and focus on the most critical ones.
Previously we used `LOGGER.warn()` to log a warning message, which could mean that something is not right, but the application can continue.
Log levels have a priority, and `WARN` is less severe than `ERROR`.

Exceptions are often also errors.
In this case, we might use the `ERROR` log level.
Make sure to log exceptions that have diagnostics value - we can simply pass the exception as the last argument to the log method.

[source,java]
----
LOGGER.warn("truncating table `{}`", tableName);
try {
db.truncate(tableName);
} catch (IOException exception) {
LOGGER.error("failed truncating table `{}`", tableName, exception); // <1>
throw new IOException("failed truncating table: " + tableName, exception);
}
----
<1> By using `error()` instead of `warn()`, we signal that the operation failed.

While there is only one placeholder in the message, we pass two arguments: `tableName` and `exception`.
Log4j will attach the last extra argument of type `Throwable` in a separate field to the generated log event.

[#pitfalls]
=== Common pitfalls

There are several widespread bad practices.
Let's try to walk through the most common ones.
There are several widespread bad practices while using Log4j API.
Below we will walk through the most common ones and see how to fix them.
For a complete list, refer to xref:manual/api.adoc#best-practice[the Log4j API best practices page].

[#pitfal-toString]
[#best-practice-toString]
==== Don't use `toString()`

* [ ] Don't use `Object#toString()` in arguments, it is redundant!
+
[source,java]
----
/* BAD! */ LOGGER.info("userId: {}", userId.toString());
----

* [x] Underlying message type and layout will deal with arguments:
+
[source,java]
----
/* GOOD */ LOGGER.info("userId: {}", userId);
----
include::partial$manual/api-best-practice-dont-use-toString.adoc[]

[#pitfall-exception]
[#best-practice-exception]
==== Pass exception as the last extra argument

* [ ] Don't call `Throwable#printStackTrace()`!
This not only circumvents the logging but can also leak sensitive information!
+
[source,java]
----
/* BAD! */ exception.printStackTrace();
----

* [ ] Don't use `Throwable#getMessage()`!
This prevents the log event from getting enriched with the exception.
+
[source,java]
----
/* BAD! */ LOGGER.info("failed", exception.getMessage());
/* BAD! */ LOGGER.info("failed for user ID `{}`: {}", userId, exception.getMessage());
----

* [ ] Don't provide both `Throwable#getMessage()` and `Throwable` itself!
This bloats the log message with a duplicate exception message.
+
[source,java]
----
/* BAD! */ LOGGER.info("failed for user ID `{}`: {}", userId, exception.getMessage(), exception);
----

* [x] Pass exception as the last extra argument:
+
[source,java]
----
/* GOOD */ LOGGER.error("failed", exception);
/* GOOD */ LOGGER.error("failed for user ID `{}`", userId, exception);
----
include::partial$manual/api-best-practice-exception-as-last-argument.adoc[]

[#pitfal-concat]
[#best-practice-concat]
==== Don't use string concatenation

If you are using `String` concatenation while logging, you are doing something very wrong and dangerous!

* [ ] Don't use `String` concatenation to format arguments!
This circumvents the handling of arguments by message type and layout.
More importantly, **this approach is prone to attacks!**
Imagine `userId` being provided by the user with the following content:
`placeholders for non-existing args to trigger failure: {} {} \{dangerousLookup}`
+
[source,java]
----
/* BAD! */ LOGGER.info("failed for user ID: " + userId);
----

* [x] Use message parameters
+
[source,java]
----
/* GOOD */ LOGGER.info("failed for user ID `{}`", userId);
----
include::partial$manual/api-best-practice-dont-use-string-concat.adoc[]

[#basic-log4j-architecture]
== Basic Log4j Architecture
[#architecture]
== Architecture

In a nutshell, Log4j operates with two main parts: the API and the Core.
With this structure, Log4j allows you to log events using the API and route them through the Core.
Expand Down Expand Up @@ -376,15 +264,15 @@ Save the following XML document to `src/**main**/resources/log4j2.xml`.
https://logging.apache.org/xml/ns/log4j-config-2.xsd">

<appenders><!--1-->
<Console name="console"><!--2-->
<Console name="CONSOLE"><!--2-->
<JsonTemplateLayout/><!--3-->
</Console>
</appenders>

<loggers>
<logger name="com.mycompany" level="INFO"/><!--4-->
<root level="WARN"><!--5-->
<AppenderRef ref="console"/><!--6-->
<AppenderRef ref="CONSOLE"/><!--6-->
</root>
</loggers>

Expand Down Expand Up @@ -544,15 +432,15 @@ Save the following XML document to `src/**test**/resources/log4j2-test.xml`.
https://logging.apache.org/xml/ns/log4j-config-2.xsd">

<appenders>
<Console name="console">
<Console name="CONSOLE">
<PatternLayout pattern="%d [%t] %5p %c{1.} - %m%n"/><!--1-->
</Console>
</appenders>

<loggers>
<logger name="com.mycompany" level="DEBUG"/><!--2-->
<root level="WARN">
<AppenderRef ref="console"/>
<AppenderRef ref="CONSOLE"/>
</root>
</loggers>

Expand Down
3 changes: 1 addition & 2 deletions src/site/antora/modules/ROOT/pages/index.adoc
Original file line number Diff line number Diff line change
Expand Up @@ -18,8 +18,7 @@
= Apache Log4j

Apache Log4j is a versatile, industrial-grade Java logging framework composed of an API, its implementation, and components to assist the deployment for various use cases.
Log4j is https://security.googleblog.com/2021/12/apache-log4j-vulnerability.html[used by 8% of the Maven ecosystem] and listed as one of https://docs.google.com/spreadsheets/d/1ONZ4qeMq8xmeCHX03lIgIYE4MEXVfVL6oj05lbuXTDM/edit#gid=1024997528[the top 100 critical open source software projects].
The project is actively maintained by a {logging-services-url}/team-list.html[team] of several volunteers and {logging-services-url}/support[support]ed by a big community.
The project is actively maintained by a {logging-services-url}/team-list.html[team] of volunteers and {logging-services-url}/support[support]ed by a big community.

[#shortcuts]
== Shortcuts
Expand Down
Loading