In Logback, walk through what happens between a call to logger.info(...) and a line appearing in a file: how the event reaches appenders, what additivity does, and how an encoder differs from a layout.
answer
- effective level = own or nearest ancestor; root always set
- event carries MDC copy + lazy caller data
- additivity walks up to root — duplicates
- filter ACCEPT/DENY/NEUTRAL per appender
- encoder owns bytes/charset; layout is legacy
basics
~20 sThe logger checks its effective level, builds a LoggingEvent, then walks up the logger hierarchy appending to every appender attached along the way (additivity). Each appender runs its filters, then an encoder turns the event into bytes and writes them.
solid answer
~50 sThe call first hits a level check against the logger's **effective level** — its own level, or the nearest ancestor's if unset; root always has one, so the check is always defined. If it passes, Logback builds a `LoggingEvent` carrying level, logger name, message pattern, argument array, thread, timestamp, a copy of the MDC and an optional throwable. The event is then given to the appenders attached to that logger and — because **additivity** defaults to true — to appenders on every ancestor up to root. That is why adding a FILE appender to `com.acme` while root holds CONSOLE yields both; `additivity="false"` stops the walk at that logger and is the standard fix for duplicated lines. Inside an appender, attached filters vote, then the **encoder** converts the event to bytes and writes to the output stream. `Layout` (event → String) is the older abstraction; the encoder owns bytes, charset and line separator, which is why `PatternLayoutEncoder` (or a JSON encoder) is what you configure today.
code
text · 8 lineslogger com.acme.billing -> [FILE] additivity=true
logger ROOT -> [CONSOLE]
info("paid") on com.acme.billing.Invoice
-> FILE (from com.acme.billing)
-> CONSOLE (from ROOT, via additivity)
set additivity=false on com.acme.billing -> FILE onlygo deeper
Be able to state the sequence: level check, event, appenders up the hierarchy, filters, encoder writes. Know that additivity explains duplicate lines.
Add the effective-level resolution rule, the eager MDC copy versus lazy caller data, and why the parameterised call form matters.
Discuss the cost model — immediateFlush, caller-data converters, appender locking — and use additivity deliberately to route audit or access logs to a single destination.
Treat the appender graph as a routing topology: shared appender instances, per-destination filters and structured encoders as the contract with downstream log processing, and set org-wide conventions rather than per-service patterns.
## The pieces Logback consists of a `LoggerContext` (one configured world per application), `Logger` objects named by dot-separated strings and arranged in a hierarchy from that naming, `Appender`s that are output destinations, and `Encoder`s that serialise an event. `LoggerFactory.getLogger("com.acme.billing.Invoice")` returns a logger whose ancestors are `com.acme.billing`, `com.acme`, `com` and `ROOT`. The hierarchy is purely lexical — nothing scans classes. ## Level check first Every logger has an optional assigned level and an **effective level**: the assigned one, else the nearest ancestor's. `ROOT` is always assigned (DEBUG by default), so resolution terminates. The check is a cheap integer comparison and is why the parameterised form `log.debug("user {} failed", id)` matters: with a disabled level, no string concatenation and no `toString()` happen, because the arguments are only formatted after the check passes. ## Building the event A passing call materialises a `LoggingEvent`. Two fields deserve attention. The **MDC** is copied into the event at creation time, so a value put on the thread after the call is not visible in that line, and an asynchronous handoff later still carries the values captured here. **Caller data** (class, method, file, line) is *not* captured eagerly — deriving it requires walking the stack, so Logback computes it lazily only if the pattern asks (`%class`, `%method`, `%line`, `%caller`). Those converters are the classic reason a hot logging path is slow. ## Appender walk and additivity The event is passed to `callAppenders`, which iterates the current logger's appenders, then repeats on the parent, and so on up to root — unless a logger has `additivity="false"`, which ends the walk after its own appenders run. Consequences worth stating in an interview: - **Duplicate lines** almost always mean an appender is attached to both a specific logger and root with additivity left on. - Additivity is not a level. A logger with `additivity="false"` and no appenders of its own drops the event entirely, which is a common accidental silencing. - The same appender instance can be referenced from several loggers; it is shared, so its filters and its output ordering apply to all of them. ## Filters, then encoder Each appender may carry filters returning `ACCEPT` (write immediately, skipping remaining filters), `DENY` (drop) or `NEUTRAL` (keep evaluating; if all are neutral the event is written). This is a per-destination decision, distinct from the logger level, so one appender can be noisier than another for the same event stream. The surviving event goes to the encoder. Historically `Layout` produced a `String` and the appender decided how to write it; since Logback 0.9.19 `Encoder` owns the event-to-bytes step, including charset, the trailing separator and any header/footer. `PatternLayoutEncoder` is a bridge that wraps a `PatternLayout`; structured logging simply swaps in a JSON encoder without touching the appender. Practically: configure `<encoder>`, not `<layout>`. ## Where writes actually land `OutputStreamAppender` (the parent of console and file appenders) writes under a lock and, by default, flushes each event — safe but syscall-heavy. `immediateFlush=false` buffers and multiplies throughput at the cost of losing the tail on a hard kill. That trade-off, not the pattern string, is what usually explains logging cost in a benchmark.
- Why is log.debug("id={}", id) preferable to log.debug("id=" + id)?With the placeholder form, the argument array is passed by reference and formatting happens only after the level check passes, so a disabled DEBUG level costs one integer comparison. String concatenation is evaluated by the caller before the method is even entered, so it pays for concatenation and any toString() regardless of level. It also keeps the message pattern constant, which structured encoders and log aggregators can group on.
- A team sees every line twice in the console. What do you check?Almost always additivity: an appender attached to an application logger while the same appender or an equivalent console appender is also on root, so the event is written on the way up. Fix by setting additivity="false" on the specific logger, or by removing the duplicate appender reference rather than the logger. Also confirm two logging backends are not both on the classpath, which produces a similar symptom for a different reason.
Additivity is a memo dropped into a mail chute: it passes every floor's inbox on the way down to the lobby unless someone seals the chute on their floor.
saying these in an interview costs you the question
- Thinking additivity is a level or a filter rather than the parent-appender walk
- Claiming a logger with no level configured logs nothing — it inherits its ancestor's
- Believing caller data (%line, %method) is free because it appears in a pattern
- Saying the MDC is read when the line is written, so late puts show up
- Configuring <layout> and assuming charset and line-separator handling come with it