Logging in a Java library

It can be useful to emit logs in a library. When doing so, one needs to consider when to emit, how to filter and who is responsible for printing/handling the logs. Correct logging should also be tested.

When to log

There are different reasons to emit a message, for instance on important events, undefined behaviour or different levels of debug events.

Any potentially useful message should be emitted. However, in order to not clutter the terminal, output should be refined.

Filtering the logs

A library logging level should be configurable according to user preference:

/**  Possible logging levels. */
public enum Level {
    /**  No log messages */
    OFF(0),
    /** Informational messages and errors only */
    INFO(1),
    /* Debug messages */
    DEBUG(2),
    /* All messages, including fine traces */
    ALL(3);
}

It is expected that important and error messages are emitted by default, so Level.INFO should be the default setting.

However, if finer traces are required, the filter could be set to DEBUG:

Library.loggingLevel = Level.DEBUG

The library should then filter the messages according to level:

static void logDebug(String message) {
    if (loggingLevel >= Level.DEBUG) {
        loggingFramework.logDebug(message);
    }
}

Example of filtering implementation in hmkit-android library.

Choosing a logging framework

The user could be using any java subsystem, or maybe emitting the messages to a web service. For this reason, the library should never output to System.out.println or android.util.Log. Instead, it should be an interface from where the logs are emitted, and it should be up to the user to choose where the messages are output in the end.

A popular logging facade is slf4j. api part of it should be included in our library:

implementation 'org.slf4j:slf4j-api:1.7.25'

Then logs can be emitted through a Logger instance:

// sample informational log
logger = LoggerFactory.getLogger(Library.class);
...
logger.info("Library initialised")

Our library user could then continue using his favourite logging framework and add an slf4j binding to see the messages. For instance, a Timber binding:

implementation 'at.favre.lib:slf4j-timber:1.0.0'

Testing the emitted logs

To verify the emitted logs, a test setup is necessary. Mockk can be used to mock the slf4j and verify calls to it’s Logger.

For this to work, each test could inherit from BaseTest, which initialises the mock:

lateinit var mockLogger:org.slf4j.Logger

@BeforeEach
fun before() {
  mockLogger = mockk()
  mockkStatic(MyLoggerFactory::class)
  every { MyLoggerFactory.getLogger() } returns mockLogger

  every { mockLogger.warn(allAny()) } just Runs
  every { mockLogger.debug(allAny()) } just Runs
  every { mockLogger.error(allAny()) } just Runs
}

This class could also contain convenience lambda methods to assert the emitted logs:

fun debugLogExpected(runnable: Runnable, count: Int = 1) {
    runnable.run()
    verify(exactly = count) { mockLogger.debug(allAny()) }
}

From the derived class’s test method, an assertion can be then written about the log message:

@Test fun invalidStartControlControlModeThrows() {
    debugLogExpected { 
        val action = Library.resolve()
    }
}

This test will succeed if one debug message is emitted to the slf4j interface.

Please see auto-api-java as an example of using this pattern.

Conclusion

Logging in a library can be very beneficial. The maintainer should however be aware of the library user’s perspective, and filter too precise logs by default. Log printing should also be left to the user, and correct log emittance should be tested with unit tests.