Airframe Log: A Modern Logging Library for Scala

Using logging is one of the best practices to see what is happening in your code. Displaying human-readable log messages, however, is sometimes called printf() debugging, and can lead to messy code, slow execution, and requires cleanup by removing logs after you have finished debugging.

In practice, well-managed printf() debugging is not so bad at all. Especially in Scala we can solve these logging issues elegantly if we use modern logging libraries, such as airframe-log and scribe.

These two libraries are relatively new and not yet very popular, but in terms of the usability and performance they are already superior to the existing logging libraries such as slf4j (Simple Logging Facade for Java), scala-logging (slf4j wrapper for Scala), twitter/util-logging (an wrapper of java.util.logging, developed by Twitter), etc. It’s a good timing to refresh your knowledge about logging.

Airframe: airframe-log

I’ve created airframe-log to simplify logging in Scala. In this blog post, I’ll explain why I needed this library and how it can simplify daily programming using loggers. I will not argue which one is better by comparing airframe-log and scribe because both of them are already good enough and stable for production use. A major difference is that airframe-log is based on java.util.logging (a built-in logger in Java package), while scribe is a pure-Scala logging library.

Why do we need a new logging library?

You might be already satisfied with slf4 or its wrapper (e.g., scala-logging). Why do we need another logging library? What I needed for the logging library is best described by the following characteristics:

• Simple to use
• Light-weight (little or no performance overhead)
• Configurable at ease
• Production-ready (to support advanced configurations, such as log rotation, asynchronous logging, etc.)

Unfortunately, none of slf4, scala-logging, and twitter/util-logging meet all of these requirements simultaneously. For example, scala-logging makes easier to use slf4j in Scala, but configuring it (e.g., changing log levels and log formats from your code) is not straightforward because scala-logging is designed to be just a simple wrapper over slf4j, and it doesn’t extend the functionality of slf4j.

Let’s look at each of these requirements in the following sections:

Simple Usage

Using logging methods (e.g., info(...), debug(...)) is pretty easy no matter which logging library you use. But what if you want to enrich log messages with source code locations? You may also want to use colors for improving the readability of logs on the console.

Generating such logs with airframe-log is easy. Just add airframe-log to your dependencies (check the latest version at the project page) and add LogSupport trait to your class.

The log messages will be shown in a colorful format with the source code locations:

That’s it! No special configuration is required for using airframe-log. In this example, the debug log message is suppressed because the default log level is set to INFO. Showing source code locations might look like a subtle thing, but this feature has helped me a lot to identify the exact locations if something went wrong.

Using airframe-log with slf4j: No worries even if your projects are already using slf4j and have difficulty in switching the logging code. In this case you can simply redirect logs from airframe-log to slf4j. This can be done by adding the following dependency:

libraryDependencies += "org.slf4j" % "slf4j-jdk14" % "1.7.25"

With this setting, you can enjoy the benefits of airframe-log even in slf4j based projects. If you are using log4j logger (for example, Hadoop, Spark, etc. are using log4j), you can use log4j-jul adapter as well.

What’s wrong in slf4j? slf4 is the most popular logging library both in Java and Scala world. One of the major pain points in using slf4j is that it forces writing boilerplate code. For example, to start using slf4j logger, you always need to call LoggerFactory.getLogger(classOf[X])as follows:

The LogSupport trait in airframe-log removes this redundancy automatically by providing this code, so you don’t need to repeat calling getLogger method for each of your classes. Modern Scala logging libraries have similar convenient traits to reduce boilerplate code.

slf4j also lacks the capability to programmatically customize the behavior. This is because slf4j itself is just an API for generating string logs, so there is no API for customizing log formats and log output files. The same thing can be said of scala-logging since it’s just an wrapper over slf4j API.

To customize the logging behavior you need a help from slf4j binding implementations, such as logback. logback has many configurations parameters, and requires XML (or groovy) configuration files (meh!) Even if you fully understand these specifications, you still cannot customize the choice of ANSI colors in your log messages unless you develop your own slf4j binding in Java. That’s sad news. Actually I was using slf4j before and needed to read the above documentation multiple times. After creating airframe-log, I’m totally free from such complicated configurations.

Light-Weight Logging

airframe-log uses Scala macros to generate logging code. This is useful for avoiding the overhead of log message generation. For example, this logging code:

debug(s"heavy debug log generation ${obj.toString}")

will be translated into the following code at compile-time:

if(logger.isDebugEnabled) {
   debug(s"heavy debug log generation ${obj.toString}")
}

If debug mode is not enabled, any string object for the debug log will not be generated. There is almost no performance overhead since checking the current log level is a cheap operation. scribe and scala-logging are also using the same macro-based code generation. twitter/util-logging is not implementing this approach yet, so you need to manually wrap logging code with if-block.

Additionally airframe-log embeds the source code location to the log message at compile-time. Neither of scala-logging and twitter/util-logging support reporting source code location. You may be able to use lihaoyi/sourdecode library to manually pass the source code location, but it requires implicit parameters and writing the same code for each logging point will be cumbersome.

Logging source code locations in Java is tricky since Java provides no such mechanism other than generating stack traces. Although it’s technically possible to report source code locations with logback, it will have significant performance overhead.

Macro-based light-weight logging is possible only in Scala, which can do powerful meta-programming with Scala macros. I would like to have the same functionality in Kotlin as well, but unfortunately Kotlin doesn’t yet support such advanced meta-programming.

Easy Configuration

If you use slf4j or java.util.logging directly, you need to learn complex parameters or cryptic configuration formats. Essentially airframe-log provides a short cut for using loggers in Scala. If necessary, you can change the log format by using pre-defined log formatters, or define your own one to customize the format and coloring.

Changing Log Levels: Other than log formats, the most frequently changed configuration in logger would be the log levels of individual classes or packages. For example, by setting the default log level to DEBUG, you can show the previously hidden log message:

An easy way to configure log level is calling Logger.setDefaultLogLevel:

Logger.setDefaultLogLevel(LogLevel.DEBUG)

A more convenient way is using log-level scanner of airframe-log, which periodically scans the log level configuration from files. This will be useful while debugging or testing your code:

import wvlet.log.Logger  
// Start log level file scanner to reload log levels every 60s
Logger.scheduleLogLevelScan

If your class path contains log.properties or log-test.properties files, log level will be refreshed every 60s by default by reading these files. Each line of log.properties file is a pair of a package name and its log level:

# src/test/resources/log-test.properties
wvlet.airframe=debug
org.eclipse.jetty=info
org.apache.http=info
com.amazonaws=info

I usually use the log-level scanner with ScalaTest to reload log-level configuration for each test run, by overriding the run method of ScalaTest like this:

In this manner, you can change the log level without recompiling the code for debugging, and it makes efficient your code development.

A key difference from slf4j is whether the logger is programmatically configurable or not. slf4j (and scala-logging) requires configuration files, while airframe-log (and scribe, twitter-logging) can be configured from your code. Whether to use log.properties file or not, or using another file, can be programmatically configured in airframe-log.

Production Readiness

Rotating Log Files: Log messages usually need to be stored on disk or elsewhere for future investigation purposes. Rotating and compressing log files is important so as not to fill up your machine’s disk. airframe-log has a built-in log rotation handlers, and you can add this with a simple configuration:

For sending log messages through network, airframe-log also has an asynchronous log handler so that you can process log messages in a background thread.

JMX-Based Configuration: If you find some issues in production systems, you may need more information about the code behavior. Changing the configuration files within the production system might not be possible due to security policies or deployment method (e.g., docker containers). To configure the log level of running applications, it is important to have JMX interface so that we can change the log level from external processes. airframe-log uses java.util.logging as a backend logger, which natively supports JMX, so such emergency operation is also available.

Dependency Hell of slf4j: slf4j is quite popular, and ironically because of that, it often causes dependency problems. Many projects include their own slf4j binding implementations into their dependencies. In slf4j we cannot use multiple slf4j bindings, such as slf4j-log4j, logback-classic, etc., at the same time so major projects, such as Hadoop, Spark, Akka, etc., use different slf4j bindings and users need to manually remove unnecessary slf4j-bindings from the dependencies. Surprisingly there is an sbt-plugin just for managing such complicated slf4j dependencies!

slf4j itself provides a simple API, but managing its bindings can be tricky because of its design choice to find a single binding from the classpath.

So, How Should I Choose A Logging Library?

The first two choices will be airframe-log or scribe. These two projects are well-maintained for multiple Scala versions and have already reached to the stable point.

• airframe-log is already a feature-complete library for daily logging in Scala and Scala.js.
• If you like pure-Scala libraries, scribe can be a choice because it additionally supports Scala Native. scribe is also trying to add support for Slack, LogStash, etc.
• If you have project dependencies that are sending logs to java.util.logging, such as Facebook Presto, Finagle, airframe-log is a better choice because it’s an wrapper of java.util.logging. scribe can redirect logs through slf4j to java.util.logging, but it has significant performance overhead.
• If you have projects that use slf4j, both airframe-log and scribe can redirect logs to slf4j without any difficulty.
• If you are going to start a new project, there will be no practical reason to use slf4j, scala-logging, twitter/util-logging, unless you need to use logger specific features like MDC, Markers, etc. Even if you are using libraries from Twitter which uses twitter/util-logging, airframe-log can be used for enhancing these log messages.
• The default log formats are a bit different between airframe-log and scribe. This is just a matter of your taste and can be configured at ease:

The default log formats of ariframe-log and scribe

I hope this article will be helpful for you to start enjoying modern logging in Scala!