Logging Foundations: SLF4J, Logback and the Logger Hierarchy

Logging means recording important events as an application runs (requests, errors, warnings, debugging information) so developers can monitor it and find out what it did. When a user reports a problem with "create user", the log shows how far the code got and what it saw.

Chapter 15 showed that traces give the path of a request, while logs give the details. Before collecting logs from many services (chapter 19), this chapter and the next two look at how logging works inside one application.

The pieces

• SLF4J (Simple Logging Facade for Java) is an API only: interfaces, no implementation. As in the facade design pattern, your code talks to SLF4J and does not depend on the library underneath.
• An implementation does the work: Logback (Spring Boot's default) or Log4j2 (Log4j version 2).
• The implementation hands each log event to appenders. An appender decides the destination: console, file, database, Kafka, a cloud service.
• Log aggregation tools then read from those destinations to search and display logs.

Step 1: log something

No extra dependency is needed:

@RestController
public class PaymentController {

    Logger log = LoggerFactory.getLogger(PaymentController.class);   // org.slf4j

    @GetMapping("/payments")
    public String getPayments() {
        log.info("fetch the payments successfully");
        return "successfully fetched all payments";
    }
}

GET /payments prints on the console:

2025-...  INFO 12345 --- [payment-service] [nio-8080-exec-1] c.e.payment.PaymentController : fetch the payments successfully

Three questions follow: where do the libraries come from, how does getLogger work, and how did the line reach the console with no configuration?

The dependencies

Every Spring Boot starter (spring-boot-starter-web included) depends on spring-boot-starter, which depends on spring-boot-starter-logging. That brings:

• slf4j-api.jar: the API;
• logback-classic.jar and logback-core.jar: the implementation.

Switching to Log4j2

Adding Log4j2's starter is not enough:

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

Now two SLF4J implementations are on the classpath. SLF4J warns at startup and simply uses the first one it finds:

SLF4J(W): Class path contains multiple SLF4J providers.
SLF4J(W): Found provider [ch.qos.logback.classic.spi.LogbackServiceProvider@4ca8195f]
SLF4J(W): Found provider [org.apache.logging.slf4j.SLF4JServiceProvider@65e579dc]
SLF4J(I): Actual provider is of type [ch.qos.logback.classic.spi.LogbackServiceProvider@4ca8195f]

Internally it collects the providers into a list and takes get(0), so here you got Logback, not the Log4j2 you added. It is only a warning, so the build succeeds, but which library you get depends on classpath order. Exclude the default logging starter when you switch:

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
    <exclusions>
        <exclusion>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-logging</artifactId>   <!-- brings Logback -->
        </exclusion>
    </exclusions>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

How getLogger works

LoggerFactory.getLogger(PaymentController.class):

1. LoggerFactory (SLF4J) finds the implementation to use, from the libraries on the classpath.
2. It asks that implementation's ILoggerFactory: in Logback, the LoggerContext (Log4j2 has its own equivalent).
3. The LoggerContext keeps a cache, Map<String, Logger>, keyed by logger name. If a logger with that name exists, it is returned; otherwise one is created and cached.

You receive an org.slf4j.Logger; behind it is a ch.qos.logback.classic.Logger. Ask twice for the same name and you get the same object.

The logger object

A Logback logger has four important fields: name, level, parent, and children.

Name

Any string: a class name, a package name, anything. One name means one logger object. The convention is one logger per class, named after the class: getLogger(PaymentController.class) creates the logger com.example.payment.PaymentController.

Level

There are five levels, from most to least severe:

ERROR > WARN > INFO > DEBUG > TRACE

Every logger has a level, and every log statement has one too, set by the method you call (log.error, log.info...). A logger prints a statement only if the statement's level is the same as or more severe than the logger's level.

log.error("error log");
log.warn("warning log");
log.info("info log");
log.debug("debug log");
log.trace("trace log");

Logger level	Printed
INFO (the default)	error, warning, info
DEBUG	error, warning, info, debug
WARN	error, warning

Set a logger's level in application.properties by its name:

logging.level.com.example.payment.PaymentController=DEBUG

Parent and children: the hierarchy

Loggers form a tree based on their dotted names. Creating com.example.payment.PaymentController also creates its ancestors:

The ROOT logger is the ancestor of every logger. A debugger on a Logback logger shows the chain: PaymentController's parent is com.example.payment, whose parent is com.example, then com, then ROOT.

The hierarchy gives three behaviors.

1. Level inheritance. A logger with no level of its own uses its nearest ancestor's. With a thousand classes, you do not set a thousand levels; set one on a package:

logging.level.com=DEBUG          # every logger under com, unless overridden

PaymentController now prints debug lines too.

2. Overrides. A specific child can still have its own level:

logging.level.com=DEBUG
logging.level.com.example.payment.PaymentController=WARN

Everything under com is at DEBUG, except PaymentController, which prints only error and warning.

3. Accepted events travel upward. The level check happens once, at the logger where you logged:

• Rejected (below the logger's level): discarded. Nothing else happens.
• Accepted: the event is passed to that logger's appenders, then to its parent's, then its grandparent's, all the way up to ROOT. The ancestors' levels are not checked again: once accepted, an event reaches every appender on the way up.

This upward flow is called additivity; it is on by default and can be turned off per logger.

Suppose com.example has a file appender and ROOT a console appender. PaymentController (level INFO) logs log.info(...):

The event is accepted at PaymentController and written to the file and to the console, even though com.example's own level is WARN.

So how did the first example reach the console?

PaymentController's logger had no appender, nor did com.example.payment, com.example or com. The accepted event travelled up to ROOT, and Spring Boot configures ROOT with a console appender by default. That is the only reason any log appears at all.

Next: Chapter 17 opens up appenders: configuring console and file appenders yourself, log patterns, rolling log files, and which logger gets which appender.

Check yourself

1. What is SLF4J, and why does code depend on it rather than on Logback?
2. Which jars does a Spring Boot starter bring for logging?
3. You add spring-boot-starter-log4j2 without excluding anything. What happens, and how do you fix it?
4. What does LoggerFactory.getLogger(...) do, step by step?
5. What is the naming convention for loggers?
6. List the five levels from most to least severe.
7. A logger is at WARN. Which of error, warn, info, debug, trace print?
8. What does logging.level.com=DEBUG do to com.example.payment.PaymentController?
9. How do you keep com at DEBUG but one class at WARN?
10. After a child logger accepts an event, are its ancestors' levels checked?
11. What is an appender?
12. Why do logs appear on the console without any appender configuration?

Answers

1. The Simple Logging Facade for Java: an API without implementation. Code written against it works with any implementation (Logback, Log4j2).
2. slf4j-api, logback-classic and logback-core, through spring-boot-starter-logging.
3. Two SLF4J providers are on the classpath; SLF4J warns and uses the first it finds (often Logback). Exclude spring-boot-starter-logging from the starters.
4. LoggerFactory finds the implementation on the classpath, asks its ILoggerFactory (Logback's LoggerContext) for the logger by name, which returns the cached logger or creates and caches a new one.
5. One logger per class, named after the class (getLogger(MyClass.class)).
6. ERROR, WARN, INFO, DEBUG, TRACE.
7. error and warn.
8. It inherits DEBUG (unless it has its own level), so debug statements print.
9. logging.level.com=DEBUG and logging.level.<that class>=WARN.
10. No. The level is checked once; the event then goes to every appender up to ROOT.
11. The component that decides where a log event goes: console, file, database, Kafka...
12. The accepted event travels up to ROOT, which Spring Boot gives a console appender by default.