GraalVM and logs with Yupiik LogManager: JUL and bindings (SLF4J, …​)

GraalVM native-image enables to convert a Java application to a native binary making it generally faster to start and using less memory. However, it still hits a common issue: logging framework handling.

As a quick reminder, Java logging has a few options and the "game" is generally to combine them to have an unified output:

• JUL which stands for Java Util Logging, is built-in in the JVM and provides most of you need as a logging API but the default implementations are sometimes limited, like the FileHandler (appender if you are used to Log4j terminology) which is not optimized or has an awesome rotation strategy.
• SLF4J which is mainly a "nicer" API (was pre java 1.8 and Suppliers time ;)). Its default implementation is logback but Log4j2 implements it as well for example. It has "bindings" (implementations)  for most frameworks (JUL as known as slf4j-jdk14, log4j 1 or 2, ....).
• Commons-logging: quite historical try to unify logging API, it is now way less used by new/recent apps/libraries.

What is important to understand with GraalVM native-image is that during the compilation to a native binary, the static blocks are kind of captured in the binary so it means the configuration of these static blocks are generally done at build time....and unluckily for us loggers are generally...static :(.

But it is not the worse, the LogManager (central instance managing the configuration whatever its name is in the different frameworks), is always static - no real strong reason to be honest since it does not make it faster and leads to context issues with the well known "by classloader" workarounds but it makes the API way easier to define since everything can be static then.

This is more or less explain in the documentation of JUL integration in GraalVM: https://www.graalvm.org/reference-manual/native-image/Logging/. But long story short: if you use static loggers they are configured at build time in general which is a big deal since most of the frameworks will use static loggers and you don't want to fork/patch with svm them all. But of course, you can take care of it.

Note: in this post we will use Geronimo Arthur to illustrate the native-image builds but it is usable with the plain command line too, it is just less convenient ;).

Ensure JUL static loggers are reconfigurable

To solve that issue, we created at Yupiik, a JUL LogManager which is reconfigurable at runtime, even under a GraalVM binary. The project is called yupiik-logging. High level it is mainly about ensuring the log manager uses a delegate which is lazyly initialized.

The project has some other nice stuff like some more advanced handlers for Kubernetes/Docker world but I will speak about it later.

For this GraalVM focused post, what we want is to ensure that the native-image command uses this Yupiik LogManager and see how to configure this at runtime.

The first step to use it is to set at build time the log manager:

<plugin> <!-- mvn package arthur:native-image -->
  <groupId>org.apache.geronimo.arthur</groupId>
  <artifactId>arthur-maven-plugin</artifactId>
  <version>1.0.1</version>
  <configuration>
    <graalVersion>20.3.0.r11</graalVersion>
    <main>com.company.MyMain</main>
    <customOptions> <!-- 1 -->
      <customOption>-Djava.util.logging.manager=io.yupiik.logging.jul.YupiikLogManager</customOption>
    </customOptions>
  </configuration>
</plugin>

1. Thanks to the custom options of the plugin - or system properties of native-image command - we can force the build to use YupiikLogManager.

This small setting will enable to force the JVM to use this log manager later on - in the native binary.

Then, once compiled, you can either use a properties configuration file like with any plain JUL setup, or just use system properties. For example:

./my-binary \
  -D.level=INFO \ <1>
  -D.handlers=io.yupiik.logging.jul.handler.StandardHandler \ <2>
  -Dio.yupiik.logging.jul.handler.StandardHandler.formatter=json \ <3>
  -Dcom.company.core.level=FINEST \ <4>
  -Dio.yupiik.logging.jul.handler.StandardHandler.level=FINEST <5>

1. Default log level is INFO,
2. Default handler is standard one (more or less console handler but logging all until INFO level on stdout and higher levels - until SEVERE - on stderr),
3. We force the handler to use json formatter - this is an alias of the library for the fully qualified name - which enables to log in JSON format for cloud environments,
4. We set one of our application logger in debug mode (FINEST level),
5. We enable FINEST log records on our handler to be able to se logs of the custom logger in debug mode (otherwise it would default on INFO).

Simple no? No need of any configuration file, system properties are enough and all is reconfigured at runtime :).

Make SLF4J use JUL

Now the next common issue with GraalVM logging is SLF4J. Almost no binding are GraalVM friendly except jboss-logging - used in Quarkus for example - which can be too much for what you want to achieve (in particular when building for docker where the logging is generally very simple).

Now we have a JUL integration for GraalVM, we can use slf4j-jdk14 and our logs will go to JUL and will enable us to configure them at runtime too, even if the application uses SLF4J.

There is however a small trick: you must ensure SLF4J is properly initialized at build time to have it working.

The easiest with Arthur is to use the SLF4J extension - it requires to either exclude other bindings you can use in plain JVM mode by configuration or to directly use the JUL binding. Then just import the SLF4J knight and it is enough:

<plugin> <!-- mvn [package] -Parthur arthur:native-image -e -->
  <groupId>org.apache.geronimo.arthur</groupId>
  <artifactId>arthur-maven-plugin</artifactId>
  <version>1.0.1</version>
  <configuration>
    <graalVersion>20.3.0.r11</graalVersion>
    <main>com.app.YourMain</main>
    <graalExtensions> <!-- here is the trick -->
      <graalExtension>slf4j</graalExtension>
    </graalExtensions>
    <customOptions> <!-- as before -->
      <customOption>-Djava.util.logging.manager=io.yupiik.logging.jul.YupiikLogManager</customOption>
    </customOptions>
  </configuration>
</plugin>

This simple extension does all the work. If you prefer to use native-image command line, you will have to replace it by forcing the build to initialize at build time these classes: org.slf4j.impl.JDK14LoggerAdapter, org.slf4j.impl.StaticLoggerBinder and org.slf4j.LoggerFactory.

Conclusion

In this post we saw how to use JUL and SLF4J with GraalVM and keep all loggers and handlers reconfigurable at runtime in the final binary. This means that you don't need to rebuild a binary to change your logging configuration which is a big plus compared to the out of the box GraalVM build.

I hope GraalVM native-image gets such a feature out of the box soon but in the mean time, don't be blocked to create native binaries and move to 2021 ;).