You should be using Async UL when collecting GC logs!

TL;DR:

If you are on a modern JDK (25 or newer) and perform GC log analysis, you probably want to add this startup argument:

-Xlog:async:stall

It will make all GC logging asynchronous, while guaranteeing that no messages will be dropped. The older mode, which was accessed with -Xlog:async, could potentially drop messages. This mode will instead stall producer threads to allow the output thread to catch up.

Use -XX:AsyncLogBufferSize=N to change the buffer size, an increased buffer size helps with temporary hiccups in output speed. A complete invocation could look something like this:

java -XX:AsyncLogBufferSize=8M -Xlog:async:stall -Xlog:gc*:file=gc-%p-%t.log:uptime,level,tags:filecount=5,filesize=20M

Run java -Xlog:help for more information.

Background

GC logs are one of those things that have become standard to enable for your Java application. You turn them on, forget about them, and then one day they are the only thing standing between you and a very annoying afternoon.

Unfortunately, collecting logs is not free. The VM has to write the messages somewhere, and that work has to happen at some point. Under the default Unified Logging system (the machinery powering all VM logs, including GC), printing log messages is a fully synchronous process: The producer thread, meaning the thread that produces a log message, is also the one that outputs it. This can be extremely detrimental to pause times, as your GC must now await the log write to finish before continuing.

In JDK 17, the UL system gained an asynchronous mode. Instead of making the producer thread also do the output work, the VM can enqueue the message and let a separate output thread flush it out.

This is a very nice idea. The GC can go back to doing GC things, and the boring output work can happen somewhere else. In the happy case, this gives us what we want: lower disruption from the logging itself, while still getting the log file we asked for.

Unfortunately, nothing is allowed to be quite that simple.

The buffer used by asynchronous logging is bounded. It has to be, otherwise a sufficiently enthusiastic logging configuration could just turn memory into a sad little text warehouse. So, there is an obvious question: what happens when producer threads create messages faster than the output thread can write them?

Before JDK 25, the answer was that producer threads would drop any messages that there isn’t room for.

This is not a bad answer. If you ask for non-blocking logging, then non-blocking logging is what you get. The VM keeps moving, the application keeps moving, and the output thread can catch up. For some kinds of logging this is a perfectly reasonable trade-off. For GC logs, though, this can be the wrong trade-off.

If I am collecting GC logs, it is usually because I want to analyze them later. Maybe I want to understand latency. Maybe I want to compare collectors. Maybe I want to explain why some service decided to have a dramatic little moment in production. In all of these cases, having a chunk of log messages dropped because your output thread stumbled a bit can have a real impact on your analysis.

I thought that we can do better, so I decided to have a look at how we can alleviate any user’s worries regarding dropping asynchronous messages. I developed a solution which ships in JDK 25. In this release, Unified Logging gained another asynchronous mode. Instead of dropping messages when the buffer is full, it will stall all producer threads until the output thread has caught up.

Now, instead of specifying -Xlog:async you may append a mode to the startup argument, that mode either being :drop or :stall. The new mode is :stall, that’s what you want to add if you don’t want any messages to be dropped. Plain -Xlog:async is still the best-effort version.

This may sound like we have just reinvented synchronous logging with extra steps, but we have not. Most of the time, logging still works asynchronously. The producer thread enqueues the log message and continues. The output thread handles the slow part. The stalling only matters when the buffer fills up, which is exactly the moment where the old behavior could silently lose data.

So the trade-off becomes much nicer:

Compared with synchronous logging, most log messages do not have to pay the direct output cost.
Compared with dropping asynchronous logging, the log file remains complete.

This is what we in Sweden call a “lagom” solution. You get lower collection costs in the common case, and when the logging system is under pressure, you preserve the thing you actually wanted: a trustworthy log.

If you already have a GC logging line, keep it. Add the async mode next to it. For example, the important part of the configuration may look like this:

java -Xlog:async:stall -Xlog:gc*:file=gc-%p-%t.log:uptime,level,tags:filecount=5,filesize=20M

This is not only useful on multi-core machines. On a single-core system, asynchronous logging can still be a sensible arrangement. Since the output thread can sleep while waiting for a piece of output to be written to file, it will yield and the application threads can continue doing useful work.

Implementation overview

The asynchronous logging implementation uses a ping-pong buffer design. There are two fixed-size buffers: one active buffer used by producer threads, and one flushing buffer used by the output thread from which messages are taken and written to output devices.

At a high level, the normal flow looks like this:

producer threads
   | push log message
   | signal: data available
   v
+-------------+       output thread wakes
| active      |---------------------------+
| buffer      |                           |
+-------------+                           |
      ^                                   |
      | output thread swaps buffers <-----+
      v                                   |
+-------------+                           v
| flushing    | ----> output thread writes to output devices --->
| buffer      |
+-------------+

When a producer thread emits a log message, it takes a lock, appends the message to the active buffer, signals that data is available, and then continues. The output thread waits for that signal. Once there is work to do, it takes the lock, swaps the active and staging buffers, and releases the lock again. The output thread competes with the producer threads for the lock. We could have been more clever here, but we’ve found that in practice there is no starvation, and this let’s the buffer be filled with more than just one message before the output thread claims the locks.

After the swap, the output thread writes the contents of the staging buffer. This is the central point of the design: the lock is held while buffers are exchanged, but not while log output is written. Producer threads therefore avoid waiting for the ordinary I/O path in the common case.

In stall mode, a full active buffer is handled differently from the original dropping mode. If a message does not fit, the producer thread creates a temporary message area sized for that message, posts it for the output thread, and waits until it has been written. This prevents all other producer threads from progressing as well.

active buffer full

producer thread -> [ one-off waiting message ] ---> output thread
       ^                                            |
       |                                            v
       +-------------- wake after write <-----------+

The output thread writes the ordinary buffer first, then writes the waiting message, and finally wakes the stalled producer thread. The result is that the common case remains asynchronous, while the full-buffer case becomes explicit waiting instead of silent message loss.