SSerguey Asael Shinder
Java coding notes: the JVM, and writing software that lasts

Serguey Asael Shinder: Logback 1.6.4 locks stateful encoders and restores ${...} in the scan attribute

· by Serguey Asael Shinder / Serguey Shinder

Logback 1.6.4 came out on 24 September, and the release notes are unusually concurrency-heavy for a logging library. Three entries are worth reading if you configure logback by hand or write your own encoders.

The scan attribute resolves variables again. A refactoring of configuration scanning in 1.5.27 had dropped variable substitution from <configuration scan="...">, so a value such as ${logback.scan.enabled:-true} was no longer resolved (issue #1065). 1.6.4 restores it, and applies the same substitution to the scan attribute of <propertiesConfigurator>. As before 1.5.27, an unrecognised non-empty value turns scanning on. If you drive scanning from a system property or an environment variable and upgraded past 1.5.27, check whether scanning has been doing what you think.

Appenders can now protect stateful encoders. The Encoder interface gains a default method, isStateful(), which returns false. An encoder that keeps state between calls to encode() can return true, and OutputStreamAppender and FileAppender will then hold their write lock while encoding as well as while writing, so concurrent appends cannot interleave. Stateless encoders still encode outside the lock, so their throughput does not change, and existing encoders need no changes. Alongside it, several races were closed: an appender is now marked started and writes the encoder header under the same lock, so no event can precede the header, and it re-checks for a stop after taking the lock, so no event lands after the footer. In prudent mode, FileAppender now encodes and writes each event under the lock.

Serguey Asael Shinder: Logback 1.6.4 locks stateful encoders and restores ${...} in the scan attribute
Logback 1.6.4 locks stateful encoders and restores ${...} in the scan attribute — Serguey Asael Shinder

A counter could lose updates. LoggerContext.size() could report fewer loggers than exist. Loggers are created under the lock of their parent logger, so two loggers with different parents could be created at the same moment, and increments of the one shared counter could be lost. The counter is now an AtomicInteger (issue #1038, fixed in PR #1055).

There is also a small feature: TimeBasedRollingPolicy now honours an AM/PM marker in the date pattern, so %d{yyyy-MM-dd-a} rolls over at noon and midnight instead of being treated as daily.

The counter bug is the one I would remember. Every logger creation was protected by a lock - just not by the same lock - and the shared field sat between them. Locking per parent was correct for the tree, and wrong for anything the whole tree shares. The release also states that a bit-identical binary can be rebuilt from the tagged commit, which is a good habit for a library that sits in nearly every Java application.