Logging to journald from Java application using Logback and Foreign Function and Memory API

When we deploy a web application, the primary way to understand what’s happening inside it is through logs. There are numerous ways to deploy apps on the web, and even more ways to write and collect logs. In this article, I’d like to outline how it’s possible to use journald for a Java application deployed as a systemd service. It’s not the purpose of this article to compare systemd and Docker, nor argue whether you should use journald instead of other structured logging solutions — these are the topics for another article. Rather, I’d like to show what I found interesting about writing logs from a Java application to journald.

Setup and default behavior

I have a rather small Spring web application that writes simple, unstructured text logs to stdout using Logback. This web application is deployed as a systemd service on Linux VPS. In my case, journald is responsible for handling the logs on the machine, which means systemd forwards application stdout logs to journald. Consider this code sample that logs several messages:

public final class LogbackJournaldFfmApi {

  private static final Logger log = LoggerFactory.getLogger(LogbackJournaldFfmApi.class);

  public static void main(final String[] args) {
    log.debug("This is a debug message");
    log.info("This is an information message");
    log.warn("This is a warning");

    try {
      methodThatThrowsException();
    } catch (final IllegalStateException e) {
      log.error("Error with an exception", e);
    }
  }

  private static void methodThatThrowsException() {
    throw new IllegalStateException("Some exception");
  }
}

We can use journalctl to view the logs:

Jan 1 00:00:00 hostname logback-journald-ffm-api[73619]: main com.github.LogbackJournaldFfmApi.main(14) - This is a debug message
Jan 1 00:00:00 hostname logback-journald-ffm-api[73619]: main com.github.LogbackJournaldFfmApi.main(15) - This is an information message
Jan 1 00:00:00 hostname logback-journald-ffm-api[73619]: main com.github.LogbackJournaldFfmApi.main(16) - This is a warning
Jan 1 00:00:00 hostname logback-journald-ffm-api[73619]: main com.github.LogbackJournaldFfmApi.main(21) - Error with an exception
Jan 1 00:00:00 hostname logback-journald-ffm-api[73619]: java.lang.IllegalStateException: Some exception
Jan 1 00:00:00 hostname logback-journald-ffm-api[73619]:         at com.github.LogbackJournaldFfmApi.methodThatThrowsException(LogbackJournaldFfmApi.java:26)
Jan 1 00:00:00 hostname logback-journald-ffm-api[73619]:         at com.github.LogbackJournaldFfmApi.main(LogbackJournaldFfmApi.java:19)

There are several problems with this output. The first problem is that the application logs each message with a different level, but journald cannot distinguish this level because it accepts raw stdout bytes, so it assigns some default level to each message (which is usually INFO). Without level it’s hard to understand whether this particular message is important or not. Next, multiline log messages are considered multiple log messages, one per line — again, this is how journald handles stdout forwarding, which is reasonable. This is dangerous as messages can get mixed together, rendering logs almost useless, especially exception stack traces.

Here’s what log output should look like:

Jan 1 00:00:00 hostname java[73619]: main com.github.LogbackJournaldFfmApi.main(14) - This is a debug message
Jan 1 00:00:00 hostname java[73619]: main com.github.LogbackJournaldFfmApi.main(15) - This is an information message
Jan 1 00:00:00 hostname java[73619]: main com.github.LogbackJournaldFfmApi.main(16) - This is a warning
Jan 1 00:00:00 hostname java[73619]: main com.github.LogbackJournaldFfmApi.main(21) - Error with an exception
    java.lang.IllegalStateException: Some exception
            at com.github.LogbackJournaldFfmApi.methodThatThrowsException(LogbackJournaldFfmApi.java:26)
            at com.github.LogbackJournaldFfmApi.main(LogbackJournaldFfmApi.java:19)

Log levels are obvious, multiline messages are displayed correctly, it’s possible to filter messages via different properties, etc. Much better.

I lived with the first type of logs for some time, but eventually I decided to fix it. I didn’t manage to find a simple, out-of-the-box way (like unit configuration option) of telling journald how it should detect structure in my simple text logs. Then I stumbled upon the journald C API (which is part of systemd API) that allows writing structured logs (preserving level, exact location inside codebase, etc.). Around the same time, finalized FFM API went into production as part of JDK 22 release, offering a modern way to deal with native stuff, and the picture finally came together for me.

Implementation

The overall solution is simple (here’s an  example project). First, you wrap your native calls using FFM API (we’ll dive into this in a moment). For our task we need sd_journal_send_with_location from libsystemd. This function allows sending a message to journald with additional parameters such as source file name and line number.

Once done, create a custom ch.qos.logback.core.Appender:

public class JournaldAppender extends AppenderBase<ILoggingEvent> {

  // simplified example, consult repository for actual code
  @Override
  protected void append(final ILoggingEvent eventObject) {
    final var invoker = SystemdJournal.sd_journal_send_with_location.makeInvoker(
        // message
        SystemdJournal.C_POINTER,
        // priority
        SystemdJournal.C_POINTER,
        // trailing null pointer
        SystemdJournal.C_POINTER
    );

    final String codeFile = getCodeFile(eventObject);
    final String codeLine = getCodeLine(eventObject);
    final String codeFunc = getCodeFunc(eventObject);
    final String message = getMessage(eventObject);
    final String priority = getPriority(eventObject);

    try (final var arena = Arena.ofConfined()) {
      invoker.apply(
          arena.allocateFrom(codeFile),
          arena.allocateFrom(codeLine),
          arena.allocateFrom(codeFunc),

          arena.allocateFrom("MESSAGE=%s"),
          arena.allocateFrom(message),

          arena.allocateFrom(priority),
          MemorySegment.NULL
      );
    } catch (final Exception e) {
      addError("Failed to invoke sd_journal_send_with_location", e);
    }
  }
}

Finally, provide Logback configuration which uses your newly created appender:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender class="com.github.JournaldAppender" name="journald">
    <encoder>
      <pattern>%thread %logger.%M\(%line{5}\) - %msg%n</pattern>
    </encoder>
  </appender>

  <root level="debug">
    <appender-ref ref="journald"/>
  </root>
</configuration>

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">
  <!-- omitted for brevity -->
</configuration>

And that’s it. The only real difficulty is to get your native calls right. Wrapping native code pretty much comes down to describing memory layouts for different data types (for basic ones, such as int and boolean, and for complex ones, such as structures) and constructing function calls as specific Java objects. While it may sound easy, there are pitfalls, especially if you’re not as experienced in C or similar languages, and those pitfalls can be fatal for the application process.

There are essentially two ways to get our native code wrappers ready. The first approach — the dangerous one — is writing FFM code manually while consulting various sources such as Javadocs, search engines and LLMs — just like we usually write code in Java. The approach is dangerous because FFM API does not protect you from making silly mistakes like passing an int value where a pointer is expected. Consider this code for calling sd_journal_send_with_location and compare it with the previous example in JournaldAppender:

final var invoker = SystemdJournal.sd_journal_send_with_location.makeInvoker(
    // message
    SystemdJournal.C_POINTER,
    // priority
    SystemdJournal.C_POINTER,
    // trailing null pointer. Here we must actually use C_POINTER
    // instead of C_INT
    SystemdJournal.C_INT
);

try (final var arena = Arena.ofConfined()) {
  invoker.apply(
      arena.allocateFrom(codeFile),
      arena.allocateFrom(codeLine),
      arena.allocateFrom(codeFunc),

      arena.allocateFrom("MESSAGE=%s"),
      arena.allocateFrom(message),

      arena.allocateFrom(priority),
      0 // Passing 4-byte int where 8-byte null pointer is expected - wrong!
  );
}

This way of passing NULL to varargs results in a segmentation fault, leading to JVM crash, but the worst part is that it will actually work for the first hundreds or thousands of log messages! The problem is that we pass 4-byte zero value as an 8-byte pointer on a 64-bit system, resulting in undefined behavior.

So the less FFM code we write, the better. This is why FFM API developers provide us with the second, safer approach for writing FFM code – we can generate a good portion of boilerplate with the help of  jextract. jextract is a simple CLI utility which takes C header files as input and produces ready-to-use Java sources:

./jextract-22/bin/jextract \
    --target-package com.github \
    --header-class-name SystemdJournal \
    --output src/main/java \
    --library systemd \
    --include-function sd_journal_send_with_location \
    /usr/include/systemd/sd-journal.h

This command will analyze sd-journal.h, looking for sd_journal_send_with_location function, and generate com.github.SystemdJournal Java class at src/main/java/com/github/SystemdJournal.java containing lots of FFM API boilerplate code, leaving you with only the necessary parts for calling the function.

In order to call a function from some native library, generated code must first find and load it at runtime — this is what --library argument is for. It’s possible to load a native library by name or by exact path to some .so or .dll file. In the command example above, we specify the library by name (--library systemd). Of course, in order to load a library by name, it must be installed system-wide (e.g., with libsystemd-dev apt package under Ubuntu).

Libraries can contain dozens of methods and structures that we don’t really need. Generating code for such redundant stuff might result in an overwhelming amount of code that is never going to be used. For such case, jextract allows filtering out unnecessary declarations from code generation with the help of --include-... options (--include-function, --include-struct, etc.). For our purposes, we only need sd_journal_send_with_location function, specified as --include-function sd_journal_send_with_location.

Note that you do not need to integrate jextract code generation into your build process. As mentioned in the jextract usage guide:

Jextract assumes that the version of a native library that a  project uses is relatively stable. Therefore, jextract is intended to be run once, and then for the generated sources to be added to  the project. Jextract only needs to be run again when the native library, or jextract itself are updated.