The Silent Failures of Logback

A Case Study in Logging Library Design and Configuration Pitfalls

Logging frameworks are foundational infrastructure in any application, yet their design often creates subtle failure modes that manifest as silent misconfiguration rather than clear errors. Some time ago I consulted for a company whose engineering team had spent many man-weeks debugging a production incident, which I was able to solve by fixing a problem with their logging subsystem. The root cause turned out to be embarrassingly simple, but the investigation had been derailed because critical log messages were never written to the log files. The logging configuration contained subtle errors that silently suppressed the very messages that would have pointed directly to the problem. When I reviewed their setup, I found three independent misconfigurations, each one invisible, each one contributing to the silence.

This experience stayed with me because it revealed something uncomfortable about our industry. Logging is not some peripheral utility or optional convenience. It is foundational infrastructure that every serious software project depends on for debugging, monitoring, auditing, and incident response. Yet logging frameworks are designed in ways that make silent failure not just possible but common. The Log4j vulnerability disclosed in December, 2021 demonstrated this importance in the starkest possible terms. A security flaw in a logging library, code that most developers barely think about, became one of the most serious vulnerabilities in recent memory, affecting hundreds of millions of devices worldwide. The vulnerability had existed in the code for years, quietly waiting. If a logging library can harbor critical security flaws for that long, what does it say about how carefully we treat this infrastructure?

Logging frameworks deserve the same rigor we apply to databases, network protocols, and security systems. Yet their design often creates subtle failure modes that manifest as silent misconfiguration rather than clear errors. This article examines a series of interconnected issues encountered while configuring Logback programmatically in a Scala 3 application. Through this case study, we identify patterns that affect not just Logback but logging frameworks in general, and propose principles for more robust logging system design.

The Contradiction

A developer sets the root logger level to TRACE. They verify the setting was applied and the root logger reports TRACE. Yet when they check a specific logger, it reports isTraceEnabled as false. The level is correct, but nothing works. This scenario, frustrating in its apparent contradiction, reveals deep issues in how logging frameworks handle configuration, initialization, and failure states.

This article documents a debugging journey through Logback’s configuration system, examining how multiple independent issues combined to create a particularly difficult troubleshooting experience. More importantly, it extracts general lessons about logging library design that apply broadly to infrastructure software.

Configuring Logback Programmatically

This tutorial demonstrates how to configure Logback programmatically in a Scala 3 application using cats-effect. The approach shown here avoids the common pitfalls discussed earlier by implementing proper initialization order, explicit error checking, and sensible fallback chains.

Dependencies

Add the following to your build.sbt file.

libraryDependencies ++= Seq(
  “org.typelevel” %% “cats-effect” % “3.5.2”,
  “org.typelevel” %% “log4cats-slf4j” % “2.6.0”,
  “ch.qos.logback” % “logback-classic” % “1.4.14”
)

The Problem with Default Initialization

Logback automatically configures itself from logback.xml when the first logger is requested. This happens before your application code runs, which creates problems if you need to configure logging based on runtime values such as environment variables or external configuration files. Consider this typical cats-effect application.

import cats.effect.{IO, IOApp, ExitCode}
import org.typelevel.log4cats.slf4j.Slf4jLogger
import org.typelevel.log4cats.SelfAwareStructuredLogger

object BrokenExample extends IOApp.Simple:
  
  // This logger is created at class load time, before run executes
  val logger: SelfAwareStructuredLogger[IO] = 
        Slf4jLogger.getLoggerFromName[IO](”MyApp”)
  
  val run: IO[Unit] =
    for
      _ <- loadConfigAndSetupLogging  // Too late, logger already exists
      _ <- logger.info(”Starting application”)
    yield ()

The logger obtains its configuration when the class loads, not when you call logging methods. If logback.xml sets the level to INFO, your programmatic attempt to change it to TRACE will appear to succeed but have no effect.

A Correct Initialization Pattern

The solution is to configure Logback before any loggers are created and to reset the context to clear any auto-configuration that may have occurred.

import cats.effect.IO
import ch.qos.logback.classic.{Level, Logger => LBLogger, LoggerContext}
import ch.qos.logback.classic.encoder.PatternLayoutEncoder
import ch.qos.logback.classic.spi.ILoggingEvent
import ch.qos.logback.core.rolling.{RollingFileAppender, SizeAndTimeBasedRollingPolicy}
import ch.qos.logback.core.util.FileSize
import ch.qos.logback.core.status.Status
import org.slf4j.LoggerFactory
import java.nio.file.{Files, Path}
import scala.jdk.CollectionConverters.*

object LogbackConfigurator:

  val DefaultPattern = “%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n”

  def configure(
    logDir: Path,
    appName: String,
    level: Level = Level.INFO
  ): IO[Unit] = IO {
    val ctx = LoggerFactory.getILoggerFactory.asInstanceOf[LoggerContext]
    
    // Clear any auto-configuration from XML
    ctx.reset()
    
    // Ensure log directory exists
    Files.createDirectories(logDir)
    
    // Create encoder
    val encoder = PatternLayoutEncoder()
    encoder.setContext(ctx)
    encoder.setPattern(DefaultPattern)
    encoder.start()
    
    // Create console appender
    val consoleAppender = ch.qos.logback.core.ConsoleAppender[ILoggingEvent]()
    consoleAppender.setContext(ctx)
    consoleAppender.setName(”CONSOLE”)
    consoleAppender.setEncoder(encoder)
    consoleAppender.start()
    
    // Create file encoder (separate instance required)
    val fileEncoder = PatternLayoutEncoder()
    fileEncoder.setContext(ctx)
    fileEncoder.setPattern(DefaultPattern)
    fileEncoder.start()
    
    // Create rolling file appender
    val fileAppender = RollingFileAppender[ILoggingEvent]()
    fileAppender.setContext(ctx)
    fileAppender.setName(”FILE”)
    fileAppender.setFile(logDir.resolve(s”$appName.log”).toString)
    fileAppender.setEncoder(fileEncoder)
    fileAppender.setImmediateFlush(true)
    
    // Configure rolling policy
    val rollingPolicy = SizeAndTimeBasedRollingPolicy[ILoggingEvent]()
    rollingPolicy.setContext(ctx)
    rollingPolicy.setParent(fileAppender)
    rollingPolicy.setFileNamePattern(
      logDir.resolve(s”$appName.%d{yyyy-MM-dd}.%i.log.gz”).toString
    )
    rollingPolicy.setMaxFileSize(FileSize.valueOf(”10MB”))
    rollingPolicy.setMaxHistory(30)
    rollingPolicy.setTotalSizeCap(FileSize.valueOf(”1GB”))
    rollingPolicy.start()
    
    fileAppender.setRollingPolicy(rollingPolicy)
    fileAppender.start()
    
    // Verify appender started successfully
    if !fileAppender.isStarted then
      val errors = ctx.getStatusManager.getCopyOfStatusList.asScala
        .filter(_.getLevel >= Status.WARN)
        .map(_.getMessage)
        .mkString(”; “)
      throw IllegalStateException(
        s”File appender failed to start: $errors”)
    
    // Configure root logger
    val rootLogger = ctx.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME)
    rootLogger.setLevel(level)
    rootLogger.addAppender(consoleAppender)
    rootLogger.addAppender(fileAppender)
  }

  def verifyConfiguration: IO[Unit] = IO {
    val ctx = LoggerFactory.
         getILoggerFactory.asInstanceOf[LoggerContext]
    val root = ctx.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME)
    
    println(s”Root logger level: ${root.getLevel}”)
    println(s”Appenders: ${root.iteratorForAppenders().asScala.map(_.getName).mkString(”, “)}”)
    
    val errors = ctx.getStatusManager.getCopyOfStatusList.asScala
      .filter(_.getLevel >= Status.WARN)
    
    if errors.nonEmpty then
      errors.foreach(s => println(s”[WARN] ${s.getMessage}”))
      throw IllegalStateException(”Logback configuration has warnings”)
  }