(((•)))
tech.interfluidity.com
a notebook by steve randy waldman
→ See also top, archive, subscribe, drafts blog, interfluidity main
2025-05-26 ⇒

# Zero-ish overhead logging facade in Scala 3

The JVM has a lot of logging libraries. There's the built-in `java.util.logging` package, the venerable log4j project (now log4j2), logback, Scala-specific libraries like scribe, etc.

As a library author, I've long been partial to logging facades, where you write to one API, and can choose which among the multiple "backends" will log the messages.

The idea was pioneered by Apache Commons Logging. slf4j is I think the most popular logging facade these days. I long ago wrote my own facade, `mlog`, initially in support of the c3p0 library, but I've used it for many, many projects. I've also wrapped it beneath a concise Scala API that I really like.

JVM logging facades, if written with care, are quite performant in practice. They are not a meaningful bottleneck. Nevertheless, there is a bit of overhead. You call the facade API, bytecode is generated for those calls, which then transform inputs and forward them to a logging library.

I've been intrigued for a while by the possibility in Scala 3 of writing logging facades that eliminate this small bit of overhead. Scala 3 has a souped up inline functionality, by which facade API calls can be transfomed into back-end API calls at compile-time, eliminating any facade overhead at runtime.

I'm building a bunch of "daemon"-style services now, for which logging will be important, so it seemed like a good time to give this a try. The result is called `LogAdapter`.

The logging API style I developed for `mlog-scala`, which I am very happy with, is to call `log` methods directly on logging levels. The messages get routed to "loggers" determined by context (more specifically, by what Scala `given` or `implicit` values are in scope). For example, I might call:

    SEVERE.log("This is bad.")

`SEVERE` is a logging level defined in my `logadapter` package, but which is not defined in `log4j`, the backend I am using.

Although it looks like I'm calling a method on `SEVERE`, there is no sign of such a method in the generated bytecode:

         236: aload_0
         237: invokevirtual #103                // Method logAdapter:()Llogadapter/log4j2/LogAdapter;
         240: astore        22
         242: aload         22
         244: astore        23
         246: aload         23
         248: invokevirtual #107                // Method logadapter/log4j2/LogAdapter.logger:()Lorg/apache/logging/log4j/Logger;
         251: astore        24
         253: getstatic     #113                // Field org/apache/logging/log4j/Level.ERROR:Lorg/apache/logging/log4j/Level;
         256: astore        25
         258: aload         24
         260: aload         25
         262: invokeinterface #119,  2          // InterfaceMethod org/apache/logging/log4j/Logger.isEnabled:(Lorg/apache/logging/log4j/Level;)Z
         267: ifeq          284
         270: aload         24
         272: aload         25
         274: ldc           #138                // String This is bad.
         276: invokeinterface #125,  3          // InterfaceMethod org/apache/logging/log4j/Logger.log:(Lorg/apache/logging/log4j/Level;Ljava/lang/String;)V

The bit of bytecode referencing `logadapter` constructs is just a field lookup, which would be necessary even using the logging libraries directly. (Typically logging libraries reference a "logger" cached as a field of an object.) The field lookup is nested behind two accessors, it's like `this.logAdapter().logger()`.

While in Java, accessing a logger might mean accessing a `static` field directly, in Scala, even using the native libraries, the field lookup would be behind an accessor. So the only additional overhead is the second, inner accessor call. Using a back-end library directly might provoke only a single hit to an accessor. But the cost of the additional accessor call is negligible.

(And, a bit overzealously, the library actually economizes accessor calls on the backend by caching in ways typical library users do not. Note that `logger` and `Level.ERROR` are looked up once, rather than twice, in the bytecode above, although they are ultimately referred to twice, as in the code snippet below. These accessor calls are likely optimized away by modern JVMs at runtime anyway.)

Beyond looking up the logger, the bytecode refers only to construct of the backend library, `org.apache.logging.log4j` constructs in this case. There is no method call on a `logadapter.Level`. There are method calls on an `org.apache.logging.log4j.Logger` supplying an `org.apache.logging.log4j.Level` as arguments.

It's exactly as if we'd called the following methods directly on the `log4j2` library (referencing that library's `Level.ERROR`, since it does not support a level `SEVERE`):

    import org.apache.logging.log4j.*

    if logger.isEnabled( Level.ERROR ) then logger.log( Level.ERROR, "This is bad." )

Again, since logging facades are not really a performance bottleneck, there's not any spectacular improvement over using `mlog`. In informal testing of just the facade — that is, excluding the cost of actual logging, by sending messages at levels below the loggable threshold — I see a roughly 25% improvement using this resolved-at-compile-time facade over resolved-at-runtime `mlog`. In practice, the improvement would be even less, because many calls will hit logging IO (or add requests for logging IO to an asynchronous queue), rendering the facades, static and dynamic, a smaller part of the overhead.

Of course one of the benefits of facades — a reason why library authors often choose them! — is precisely because which backend gets hit can be resolved at runtime. If your library will be used as part of a larger application, it's nice if it can be configured to log to the same backend that the larger application will, without having to modify and recompile library code.

But the logadapter facade is so thin, there's very little cost to using it even if its "backend" will be a runtime-configurable facade like `slf4j` or `mlog`.

And for most applications, it's fine for the logging backend to be chosen at compile time. In which case the (small) runtime performance hit of a facade can be circumvented almost entirely.

`LogAdapter` is much simpler and smaller than traditional logging facades, and can be layered on top of them at low cost where that makes sense. I think it will be a pretty good foundation for logging.

← Scala 3 inline vs implicit ordering
↑↑↑
Using Tailscale to proxy traffic to the US →