Michael Bien's Weblog

I just wrote JFRLog - a lightweight SLF4J logger implementation which lets you log directly into the Java Flight Recorder. Since SLF4J (Simple Logging Facade for Java) has a binding to basically every logging framework out there, it doesn't even matter how the logging is done or how many frameworks the application or the dependencies use (hopefully not many).

Why? I was mostly curious how practical something like that would be and it turned out it works great. If you are running linux its likely that most of the logging is already centralized and stored in binary form and you need tools like journalctl to read it. If you ever had to correlate log files with events of a JFR recording you probably also asked yourself why isn't everything in the recording in the first place. Having everything in one place simplifies containers too.

JFRLog

The project is available on github under the MIT License. It requires JDK 8+ to run but JDK 14+ to build/test since the JUnit tests rely on the event streaming API. JFRLog's only dependency is the SLF4J API.

quickstart

The basic 2.5 steps to get it working are:

1. replace your SLF4J compatible logging impl with slf4j-jfr-bridge-x.x.x.jar
2. start the JVM with JFR enabled (e.g. -XX:StartFlightRecording:filename=logs/dump.jfr,dumponexit=true) or enable recording later
3. check the flight recorder repository or recording dump for log.* events

update: artifacts of the first release are now available on maven central.

    <dependencies>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.30</version>
        </dependency>
        <!-- depends on slf4j-api -->
        <dependency>
            <groupId>dev.mbien.jfrlog</groupId>
            <artifactId>slf4j-jfr-bridge</artifactId>
            <version>0.1.0</version>
        </dependency>
    </dependencies>

(adding slf4j-api is optional since it is already a dependency of JFRLog but it is a good practice to depend on the interface and makes it also more obvious what is going on)

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class HelloJFRLog {
    private final static Logger log = LoggerFactory.getLogger(HelloJFRLog.class);
    public static void main(String[] args) {
        log.info("does it work?");
    }
}

inspect the flight record:

$ jfr print --events "log.*" test_dump.jfr
log.Info {
  startTime = 11:52:15.954
  message = "does it work?"
  origin = "dev.mbien.jfrlogtestproject.HelloJFRLog"
  throwable = N/A
  eventThread = "main" (javaThreadId = 1)
}

Thats it! Log and JFR events all in one place.

configuration

Configuration is straight forward. You can set log levels via java -D arguments or via a jfrlog.properties file and place it into the classpath. Java -D args are treated with higher priority than the configuration file to simplify testing.

# Sets MyKlass to debug, the rest of the package to error and the default log level
# to info (for everything which isn't explicitly configured). 
# The most specific rule wins (order does not matter).
jfrlog.default=info
jfrlog.dev.cool.app=error
jfrlog.dev.cool.app.MyKlass=debug

You can also disable entire log levels by disabling the corresponding events in the JFR recording profile if so desired.

this blog you are reading is using it right now

The Apache Roller blog is a big dusty webapp with many dependencies. Since dependencies use their own favorite logging framework its a nice example of a near-worst-case-scenario a.k.a.: the LoggingHell (extends JarHell). Half of the Apache libs use the old Java Commons Logging layer, struts2 depends on log4j2 for some reason, some webjars use java.util.logging, eclipselink uses its own (!) logging but thankfully with a SLF4J compatibility extension and roller used log4j1 at some point (the version in my WIP branch uses log4j2). Ah, and the web server needs some logging too, but thankfully Jetty uses the SLF4J layer so it doesn't care that much.

So, to see some text in a file, all what is needed is:

• jcl-over-slf4j to connect the JCL abstraction layer to the SLF4J layer for spring etc
• log4j-to-slf4j to make struts happy
• jul-to-slf4j for webjars (i think)
• org.eclipse.persistence.extension to bridge eclipselink's personal logger to SLF4J

Beautiful, all logs lead to SLF4J now. We only forgot about the logging impl itself. Usually you would have a log4j-slf4j-impl or logback-classic there - most likely. But to enable JFRLog all what is needed is to replace it with slf4j-jfr-bridge and that was exactly what I did.

I also wrote some java (single file java program) scripts using the JFR streaming API for easy inspection of the logging repository. (but that is probably a story for another time update: CLI tools blog entry)

How many new logging frameworks or abstraction layers will the current pandemic give us?

Let me know what you think.

fly safe (and keep JFR on)