Helidon, Logging, and MDC

Helidon is designed to have the smallest number of third party dependencies as possible. With that goal in mind, we originally decided to use Java Util Logging (JUL) as its an integral part of the JVM with no added dependencies.

In Helidon 2.2.0, however, we have decided to support the following logging frameworks and some of their features:

• Java Util Logging (JUL) — already supported and does not require any changes in Helidon
• Simple Logging Facade for Java (SLF4J) — an API that can be used to log into multiple logging implementations (logback, Log4j, JUL)
• Log4j (version 2.x) — widely used logging framework

With the addition of Log4j and SLF4J we can now offer Mapped Diagnostic Context (MDC). This highly requested feature allows users to register a value with the MDC using a static method, and then write it to the output. This value could be a tracing ID that we want to see for each message, the current user, or a similar contextual value.

As JUL does not support MDC out of the box, we have added a Helidon API called HelidonMdc to the helidon-logging-common module.

You can now choose to use the HelidonMdc, which will work with any of the supported logging frameworks, or use the logging framework specific class, such as org.slf4j.MDC. Helidon will handle the propagation of the MDC across thread boundaries in both cases.

To use Helidon MDC, you need to do three things:

1. Add a dependency on one of the supported logging frameworks.
2. Configure logging to provide the information in its output.
3. Use MDC in code.

Java Util Logging (JUL)

Dependency

<dependency>
    <groupId>io.helidon.logging</groupId>
    <artifactId>helidon-logging-jul</artifactId>
</dependency>

Configuration

For JUL, there is a requirement to either use the HelidonConsoleHandler or the HelidonFormatter (which extends the SimpleFormatter used in this configuration). The important part for MDC is %X{name} — this will print the name property available in MDC.

handlers=io.helidon.logging.jul.HelidonConsoleHandler
java.util.logging.SimpleFormatter.format=%1$tY.%1$tm.%1$td %1$tH:%1$tM:%1$tS %4$s %3$s !thread!: %5$s%6$s "%X{name}"%n
.level=INFO

Code

First we get an instance of a logger (considering class Main):

import java.util.logging.Logger;
...
private static final Logger LOGGER = Logger.getLogger(Main.class.getName());

Next we set a value to MDC:

import io.helidon.logging.common.HelidonMdc;
...
HelidonMdc.set("name", "some-name");

And then we log something:

LOGGER.info("Log using MDC, name:");

The expected output should be similar to:

2020.12.17 13:39:57 INFO Main Thread[main,5,main]: Log using MDC, name: “some-name”

Simple Logging Facade for Java (SLF4J)

Dependency

There are four dependencies for SLF4J:

• Helidon’s logging integration library
• SLF4Jj API
• JUL to SLF4J bridge (to see Helidon messages in SLF4J)
• a logging implementation (I have chosen logback for this article)

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
</dependency>
<dependency>
    <groupId>io.helidon.logging</groupId>
    <artifactId>helidon-logging-slf4j</artifactId>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jul-to-slf4j</artifactId>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
</dependency>

Configuration

Logback expects logback.xml on the classpath as one of the configuration options. The important part for MDC is %X{name} — this will print the name property available in MDC.

<configuration>
    <appender name="STDOUT"
            class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>
                %d{HH:mm:ss.SSS} %-5level [%thread] %logger{36} - %msg %X{name}%n
            </pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

Code

First we get an instance of a logger (considering class Main):

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
...
private static final Logger LOGGER = LoggerFactory.getLogger(Main.class);

Next we set a value to MDC (using SLF4J MDC or HelidonMdc):

import org.slf4j.MDC;
...
MDC.put("name", "some-name");

And then we log something:

LOGGER.info("Log using MDC, name:");

The expected output should be similar to:

13:43:52.440 INFO  [main] Main - Log using MDC, name: some-name

To see the JUL log output in the SLF4J logs, add the following setup as the first entry in your application's main class:

import org.slf4j.bridge.SLF4JBridgeHandler;
...
SLF4JBridgeHandler.removeHandlersForRootLogger();
SLF4JBridgeHandler.install();

Log4j

Dependency

There are four dependencies for Log4j:

• Helidon’s logging integration library
• Log4j API
• JUL to Log4j bridge (to see Helidon messages in Log4j and a Log4j core)

<dependency>
    <groupId>io.helidon.logging</groupId>
    <artifactId>helidon-logging-log4j</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-jul</artifactId>
</dependency>

Configuration

File-based configuration can be used when running on JVM. Once again, the important part for MDC is %X{name} — this will print the name property available in MDC.

I am using programmatic setup in this example as it is the only approach that works (at least partially) with GraalVM native image.

import org.apache.logging.log4j.core.appender.ConsoleAppender;
import org.apache.logging.log4j.core.config.Configurator;
import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory;
...
private static void configureLogging() {
    // configure log4j
    final var builder = ConfigurationBuilderFactory.newConfigurationBuilder();
    builder.setConfigurationName("root");
    builder.setStatusLevel(Level.INFO);
    final var appenderComponentBuilder = builder.newAppender("Stdout", "CONSOLE")
            .addAttribute("target", ConsoleAppender.Target.SYSTEM_OUT);
    appenderComponentBuilder.add(builder.newLayout("PatternLayout")
                                         .addAttribute("pattern", "%d{HH:mm:ss.SSS} %-5level [%t] %logger{36} - %msg "
                                                 + "\"%X{name}\"%n"));
    builder.add(appenderComponentBuilder);
    builder.add(builder.newRootLogger(Level.INFO)
                        .add(builder.newAppenderRef("Stdout")));
    Configurator.initialize(builder.build());
}

Code

First we get an instance of a logger (considering class Main):

import org.apache.logging.log4j.Logger;
...
private static final Logger LOGGER = Logger.getLogger(Main.class);

Next we set a value to MDC (using Log4j MDC or HelidonMdc):

import org.apache.logging.log4j.ThreadContext;
...
ThreadContext.put("name", "some-name");

And then we log something:

LOGGER.info("Log using MDC, name:");

The expected output should be similar to:

13:56:48.429 INFO  [main] Main - Log using MDC, name: some-name

To see the JUL log output in the Log4j logs, a system property needs to be configured when starting the process or before getting JUL loggers (this does not yet work in GraalVM native image):

java -Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager Main

Samples

Sample projects that show you how to use logging integrations can be found in the Helidon repository.

Summary

Logging integration is an important aspect for troubleshooting applications. Try it out and then let us know how we can improve it by leaving a comment to this article, as an issue in our GitHub issues tracker, or on our official Slack channel.