Log-Level und Konfiguration des Loggings

1. Die Rolle der Log-Level

Wenn log.info(...) keine Magie mehr ist, taucht ein anderes Problem auf: Wie man nicht in den eigenen und den Framework-Logs versinkt. Die Level und die Konfiguration der Logger sind genau dafür zuständig – sie verwandeln einen Strom von Meldungen in ein kontrollierbares Signal.

Stellen Sie sich vor, Logs wären ein Gespräch Ihres Dienstes mit Ihnen. Manchmal sagt der Dienst: „Ich lebe und bin gestartet“ – das ist fast immer nützlich. Manchmal sagt er: „Jeder Kurs wurde durch den Filter geschickt, hier sind die Zwischenwerte“ – das ist nur nützlich, wenn Sie die Filterung debuggen. Und manchmal schreit er: „Ich bin abgestürzt, mir geht es schlecht!“ – und das müssen Sie immer sehen. Log-Level sind eine Möglichkeit, mit der Anwendung über die „Lautstärke“ und „Wichtigkeit“ der Meldungen zu verhandeln, damit Sie Details genau dann einschalten können, wenn sie benötigt werden, und nicht in einem Zustand ewigen Informationsrauschens leben.

Der Kernpunkt: Ein Level ist nicht das „Lieblingswort des Entwicklers“, sondern eine steuerbare Skala der Wichtigkeit/Detailtiefe. Es ist wie die Modi einer Kamera: „Normal“, „Nacht“, „Super-Detail“. Sie fotografieren doch nicht jeden Tag den Passschalter in 8K HDR – aber wenn Sie die Nummer des Tickets erkennen müssen, wird es plötzlich nützlich.

2. Die Level: von ERROR bis TRACE

Man kann Log-Level philosophisch erklären, aber das brauchen wir nicht. Wir brauchen es ingenieurmäßig: Welches Signal gehört wohin, und was sehen Sie bei verschiedenen Einstellungen? In Spring Boot sehen Sie standardmäßig (im Basisszenario) normalerweise INFO, WARN, ERROR. DEBUG und TRACE hingegen sind „schalten wir ein, wenn wir ermitteln“.

Unten finden Sie eine einfache Tabelle. Sie müssen sie nicht wie ein Mantra auswendig lernen, aber es ist sehr nützlich, sie zu Rate zu ziehen, wenn Sie geneigt sind, „dann soll es halt INFO sein, damit ich es genau sehe“ zu setzen.

Schauen wir uns nun ein kleines Beispiel an, bei dem in einem Szenario verschiedene Level geloggt werden. Das ist eine gute Möglichkeit zu verstehen, dass Level nicht die „Einstellung einer Klasse“ sind, sondern die „Einstellung einer bestimmten Meldung“.

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.util.List;

public class FeaturedSelector {
    // Logger sind normalerweise static final: einer pro Klasse, nicht pro Objekt
    private static final Logger log = LoggerFactory.getLogger(FeaturedSelector.class);

    public List<String> selectFeatured(List<String> slugs, int limit) {
        // DEBUG - für Algorithmus-Details: nützlich bei Untersuchungen, aber normalerweise in Produktion ausgeschaltet
        log.debug("Selecting featured courses, limit={}", limit);

        // Hier könnte komplexe Geschäftslogik sein; im Beispiel schneiden wir einfach die Liste
        List<String> result = slugs.stream().limit(limit).toList();

        if (result.isEmpty()) {
            // WARN - Situation ist verdächtig, aber der Dienst arbeitet weiter
            log.warn("Featured selection is empty");
        }

        // INFO - kurze Zusammenfassung, die fast immer nützlich ist
        log.info("Featured courses selected, count={}", result.size());
        return result;
    }
}

Beachten Sie die Bedeutung. log.debug(...) ist ein internes Detail („welches limit haben wir angewendet“), das man normalerweise nicht in den alltäglichen Logs sehen muss. log.info(...) ist eine abschließende Tatsache („wie viele ausgewählt“), die fast immer nützlich ist. log.warn(...) ist ein Signal, dass etwas seltsam ist: Der Dienst ist nicht abgestürzt, aber die Daten sind verdächtig.

Und hier ein Beispiel für ERROR – wenn wir eine Exception loggen. Das ist dann schon „im Raum ist es dunkel, die Sicherungen sind durchgebrannt“.

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class CourseLookup {
    private static final Logger log = LoggerFactory.getLogger(CourseLookup.class);

    public String safeFindBySlug(String slug) {
        try {
            // Im echten Code würde hier ein Zugriff auf Repository/Cache/Datei etc. stehen
            return "spring-boot"; // stellen wir uns vor, das sei ein repository-Aufruf
        } catch (RuntimeException ex) {
            // ERROR - die Operation ist fehlgeschlagen, und Kontext + Stacktrace sind wichtig
            log.error("Course lookup failed, slug={}", slug, ex);
            // Oft wird die Exception weitergereicht: Wir loggen hier nur, wenn dies der Verantwortungspunkt ist
            throw ex;
        }
    }
}

Hier sind zwei Dinge wichtig. Erstens: Die Meldung sagt, was gemacht wurde und mit welchem Kontext (slug). Zweitens: Wir haben ex übergeben, damit der Stacktrace nicht verloren geht. Ein Log ohne Stacktrace ist wie „es hat gebrannt“, aber ohne Adresse.

Über TRACE sage ich ehrlich: In einem kleinen Dienst wie catalog-service wird es meistens nicht benötigt. Es ist nützlich, wenn Sie eine sehr komplexe Infrastruktur haben oder etwas auf niedriger Ebene debuggen. Aber zu wissen, dass es einen solchen Level gibt, ist nützlich: Manchmal ist DEBUG bereits „viel“ und TRACE „zu viel“.

3. Root-Logger: der allgemeine „Lautstärkeregler“ der Anwendung

root logger ist der grundlegende Log-Level „standardmäßig“ für die gesamte Anwendung, wenn Sie keinen Level für ein bestimmtes Paket/ eine bestimmte Klasse konfiguriert haben. Stellen Sie sich einfach vor: Der root ist der Lautstärkeregler an der Box, und die Package-Logger sind die Lautstärkeregler für einzelne Instrumente im Mischpult. Wenn Sie root auf DEBUG stellen und sich dann wundern, dass Spring Ihnen einen Roman in 12 Bänden schreibt – dann ist Spring nicht „gesprächig“, sondern Sie haben den Modus „erzähl mir alles“ eingeschaltet.

In Spring Boot wird der Root-Level über logging.level.root konfiguriert. Die einfachste Variante in application.yaml sieht so aus:

logging:
  level:
    # Root ist der Standard-Level für die gesamte Anwendung und alle Abhängigkeiten
    root: INFO

Eine wichtige Regel (sie ist ganz einfach, aber wird ständig verwechselt): Wenn der Logger-Level INFO ist, sehen Sie INFO, WARN, ERROR, aber nicht DEBUG und TRACE. Der Level ist also faktisch eine „Schwelle“.

Diese kleine Tabelle ist fast die gesamte Mathematik der Level:

Warum wird root fast immer auf INFO belassen? Weil root nicht nur Ihren Code steuert, sondern auch die Logs aller Abhängigkeiten: Spring Framework, Tomcat, Jackson und so weiter. Und wenn Sie root auf DEBUG setzen, werden Sie am Ende nicht das Katalogproblem untersuchen, sondern das Problem „warum kann ich in diesem Lärm überhaupt nichts finden“.

4. Logger-Hierarchie: Konfiguration nach Paketen

Damit die Konfiguration „nach Paketen“ funktioniert, muss der Logger irgendwie verstehen, zu welchem Paket die Meldung gehört. Und hier gibt es keine Magie: Der Logger hat einen Namen. Wenn Sie LoggerFactory.getLogger(CourseCatalogService.class) schreiben, erstellt SLF4J (und dann Logback) einen Logger mit dem Namen, der dem vollqualifizierten Klassennamen (FQCN) entspricht.

Zum Beispiel für unser Projekt wäre das etwa com.example.catalogservice.catalog.service.CourseCatalogService. Und dann greift eine sehr verständliche Hierarchie: Alles links vom Punkt ist der „übergeordnete“ Logger. Daher kann man den Level direkt für das Paket com.example.catalogservice.catalog konfigurieren, und er gilt für alle Klassen innerhalb von catalog, einschließlich catalog.service, catalog.repository, catalog.web.

Hier eine kleine Visualisierung dieses „Stammbaums“:

flowchart TD
    root["root"]
    com["com"]
    ex["com.example"]
    app["com.example.catalogservice"]
    catalog["com.example.catalogservice.catalog"]
    service["com.example.catalogservice.catalog.service"]
    cls["...CourseCatalogService"]

    root --> com --> ex --> app --> catalog --> service --> cls

Dieses Schaubild erklärt zwei wichtige praktische Fakten.

Erster Fakt: Wenn Sie keinen Level für einen bestimmten Logger konfiguriert haben, „erbt“ er den Level vom nächsten konfigurierten Vorfahren (und letztendlich vom root).

Zweiter Fakt: „Konfiguration nach Paketen“ bedeutet buchstäblich die Konfiguration des Levels auf ein Namenspräfix. Das heißt, logging.level.com.example.catalogservice.catalog=DEBUG bedeutet: „Alles, was mit com.example.catalogservice.catalog beginnt, logge ab DEBUG“.

Wenn Sie das praktisch nachvollziehen möchten, ist es hilfreich zu wissen, dass der Logger seinen eigenen Namen nennen kann. Das wird im echten Code selten benötigt, aber als Übungsprüfung ist es hervorragend:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class LoggerNameDemo {
    private static final Logger log = LoggerFactory.getLogger(LoggerNameDemo.class);

    public void printLoggerName() {
        // getName() hilft zu verstehen, welcher "Schlüssel" für logging.level.* benötigt wird
        log.info("Logger name is {}", log.getName());
        // Beispiel: "Logger name is com.example.catalogservice.support.LoggerNameDemo"
    }
}

Diese Hierarchie wird nicht nur für Business-Logs benötigt. Über dieselben Namen kann man später sehr bequem seine eigenen Zeilen von org.springframework... trennen, besonders wenn man den Start der Anwendung betrachtet und schnell verstehen möchte, wo die Infrastruktur ist und wo bereits der eigene Code.

5. Konfiguration der Level in application.yaml

In unserem Kurs sind wir YAML-first, das heißt, wir konfigurieren die Log-Level über application.yaml (oder profil-spezifisches YAML, aber daraus machen wir jetzt keine separate Strategie). Die Grundidee einer gesunden Konfiguration ist: root bleibt „menschlich“ (INFO), und Details schalten wir punktuell – für unsere eigenen Pakete oder für bestimmte Problemstellen.

Unten sehen Sie ein Beispiel einer Konfiguration, die normalerweise sehr gut für den Übungsdienst catalog-service geeignet ist:

logging:
  level:
    # Allgemeiner Standard-Level: kein Lärm, kein Versinken in Logs von Abhängigkeiten
    root: INFO

    # Eigener Code kann detaillierter sein (hilft beim Debuggen)
    com.example.catalogservice.catalog: DEBUG
    com.example.catalogservice.config: INFO

    # Framework eindämmen, damit es die Anwendungsmeldungen nicht überlagert
    org.springframework: WARN

Was passiert hier inhaltlich? Root sagt: „Insgesamt lebt der Dienst auf INFO“. Das Paket catalog bekommt DEBUG, weil es unsere Domäne und unsere Geschäftslogik ist; manchmal ist es nützlich, Details der Filterung und Auswahlen zu sehen. Das Paket config belassen wir auf INFO, weil die Konfiguration verständlich sein und nicht lärmen soll. Und org.springframework: WARN drückt das Framework sanft zurück, damit es nicht um unsere Aufmerksamkeit konkurriert.

Ein wichtiger Punkt: „Spring auf WARN drücken“ ist kein Naturgesetz. Wenn Sie etwas Komplexes entwickeln und z.B. Details des Controller-Mappings sehen möchten, können Sie vorübergehend org.springframework.web auf INFO oder DEBUG anheben. Aber tun Sie das bewusst und lokal, sonst erzielen Sie sehr schnell den Effekt „ich schreibe einen Katalogdienst, lese aber die Autobiographie von DispatcherServlet“.

Ein weiterer nützlicher Trick ist, den Level auf eine bestimmte Klasse zu konfigurieren, wenn Sie etwas sehr Lokales untersuchen. Das geht genauso, nur wird der Schlüssel länger:

logging:
  level:
    root: INFO
    # DEBUG genau für eine Klasse – „Skalpell“ statt „Axt“
    com.example.catalogservice.catalog.service.CourseCatalogService: DEBUG

Das sollte man selten verwenden, weil lange Schlüssel schwer zu pflegen sind. Aber als „Skalpell“ für Untersuchungen funktioniert es hervorragend.

6. Beispiel für catalog-service: Level im Code

Jetzt machen wir das Wichtigste: Wir verknüpfen die Level mit lebendigen Klassen unseres Projekts. Denn „Level im luftleeren Raum“ klingen vernünftig, aber solange Sie nicht versucht haben, log.debug(...) zu schreiben und zu sehen, dass es verschwindet (weil root INFO ist), wird das Thema nicht zu Ihrem.

Beginnen wir mit StartupSummaryRunner. Für die Startzusammenfassung ist INFO das ideale Level: Es ist ein kurzes, stabiles, nützliches Signal, das fast immer benötigt wird.

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.ApplicationArguments;
import org.springframework.boot.ApplicationRunner;
import org.springframework.stereotype.Component;

@Component
public class StartupSummaryRunner implements ApplicationRunner {
    private static final Logger log = LoggerFactory.getLogger(StartupSummaryRunner.class);

    @Override
    public void run(ApplicationArguments args) {
        // INFO - „Dienst ist hochgefahren und bereit“: Ein solches Signal ist in fast jeder Umgebung nützlich
        log.info("catalog-service started: startup summary prepared");
    }
}

Stellen wir uns nun die Filterung/Suche in CourseCatalogService vor. Hier ist DEBUG angebracht, wenn Sie verstehen möchten, warum eine bestimmte Anfrage leer oder zu viele Ergebnisse geliefert hat. Und INFO ist angebracht für das abschließende „was dabei herausgekommen ist“.

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.util.List;

public class CourseCatalogService {
    private static final Logger log = LoggerFactory.getLogger(CourseCatalogService.class);

    public List<String> findSlugs(boolean publishedOnly, int limit) {
        // DEBUG - Zwischenparameter der Suche/Filterung (für Untersuchungen)
        log.debug("Finding courses: publishedOnly={}, limit={}", publishedOnly, limit);

        // In Wirklichkeit gäbe es hier eine Filterung der Katalogdaten
        List<String> result = List.of("spring-boot"); // stellen wir uns vor, das sei das Filterergebnis

        // INFO - kompakte Zusammenfassung der Methode
        log.info("Courses selected, count={}", result.size());
        return result;
    }
}

Und hier ist, wo WARN angebracht ist. Angenommen, unsere catalog-data.yaml wird geladen, aber nach dem Filter publishedOnly=true bleibt kein einziger Kurs übrig. Der Dienst lebt, die Endpoints antworten, aber die Daten sind offensichtlich „nicht die richtigen“. Das ist eine klassische Warnung.

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.util.List;

public class PublishedCoursesChecker {
    private static final Logger log = LoggerFactory.getLogger(PublishedCoursesChecker.class);

    public void warnIfEmpty(List<String> publishedSlugs) {
        if (publishedSlugs.isEmpty()) {
            // WARN - Daten sind verdächtig, aber es ist kein Dienstausfall
            log.warn("No published courses found (check catalog-data.yaml)");
        }
    }
}

Beachten Sie: Das ist kein ERROR. Der Dienst ist nicht abgestürzt, wir haben nur eine schlechte Datensituation. WARN ist genau dafür da, dass solche Dinge nicht durchgehen, „als ob alles normal wäre“.

ERROR heben wir uns für Situationen auf, in denen eine Anfrage/Operation tatsächlich fehlgeschlagen ist. Zum Beispiel hat das Repository eine Exception geworfen, oder wir haben selbst eine IllegalStateException aufgrund einer defekten Invariante erhalten. Wichtig: In catalog-service sind wir read-only und ohne DB, daher gibt es weniger echte „Produktions“-Fehler, aber gerade deshalb ist es wichtig, ERROR nicht wahllos zu verstreuen, damit dieses Signal stark bleibt.

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class CatalogRepositoryFacade {
    private static final Logger log = LoggerFactory.getLogger(CatalogRepositoryFacade.class);

    public String findBySlug(String slug) {
        try {
            // Im echten Dienst gäbe es hier eine Abfrage an die Datenquelle
            return "spring-boot"; // bedingter repository-Aufruf
        } catch (RuntimeException ex) {
            // ERROR - Operation nicht ausgeführt; Stacktrace bewahren ist wichtig
            log.error("Repository lookup failed, slug={}", slug, ex);
            throw ex;
        }
    }
}

7. Log erscheint nicht: Typische Ursachen

Irgendwann werden Sie garantiert in der Situation sein: „Ich habe log.debug(...) geschrieben, die Anwendung neu gestartet … und da ist nichts“. Und das ist der Moment, in dem viele anfangen, „wahllos an allem zu drehen“, indem sie root auf DEBUG setzen, --debug einschalten und überhaupt ein Festival zufälliger Aktionen veranstalten. Viel nützlicher ist es, ein kurzes und ruhiges mentales Modell zu haben.

Die häufigste Ursache ist einfach: Ihr effektiver Level ist INFO. Das bedeutet, dass DEBUG-Meldungen herausgefiltert werden. Das wird nicht durch Umschreiben des Codes behoben, sondern durch Konfiguration des Levels für das betreffende Paket. Wenn zum Beispiel CourseCatalogService in com.example.catalogservice.catalog.service liegt, dann muss die Konfiguration in dieses Präfix fallen:

logging:
  level:
    root: INFO
    # DEBUG nur dort einschalten, wo wir diagnostische Meldungen erwarten
    com.example.catalogservice.catalog: DEBUG

Der zweithäufigste Grund: Sie haben „das falsche Paket“ konfiguriert. Der Level pro Paket ist eine Zeichenkette, und ein Tippfehler führt zu „Funkstille“. Manchmal fehlt ein Teil wie catalogservice, manchmal schreibt man com.example.catalog (zu kurz), manchmal verwechselt man catalog.web und catalog.service. In solchen Fällen ist ein guter Trick, kurz den tatsächlichen Loggernamen in der Logzeile anzusehen (dort ist er normalerweise sichtbar) oder vorübergehend log.getName() auszugeben.

Der dritte Grund: Sie erwarten, dass die Konfiguration „im laufenden Betrieb“ wirkt. Im Rahmen dieser Vorlesung gehen wir davon aus, dass Sie application.yaml ändern und die Anwendung neu starten (Boot + DevTools können den Zyklus beschleunigen, aber die Logik selbst – „YAML gelesen → Level konfiguriert“ – findet ohnehin beim Start statt).

Und noch ein sehr praktischer Punkt: Wenn Sie org.springframework: WARN gesetzt haben und dann versuchen, in den Logs zu finden, „welcher Controller hochgefahren ist“, haben Sie sich selbst das Fenster zugeklebt. Das ist kein Fehler des Frameworks, sondern Ihre Konfiguration, die sagt: „Spring, sei still, störe nicht“. Die Konfiguration nach Paketen ist gerade deshalb gut, weil Sie vorübergehend einen bestimmten Bereich abschwächen oder verstärken können – aber Sie müssen sich bewusst sein, dass Sie den Regler in der Hand halten.

Ein Hinweis zur Performance und „teuren“ Debug-Logs

In Vorlesung 2 haben wir bereits besprochen, dass String-Konkatenation in Logs eine schlechte Idee ist und man besser log.debug("x={}", x) schreibt. Jetzt fügen wir einen weiteren Punkt hinzu, der speziell durch die Levels aufkommt: DEBUG und TRACE sind oft ausgeschaltet, und in diesem Fall ist es besonders wichtig, keine „teure Arbeit“ für eine Meldung zu erledigen, die ohnehin verworfen wird.

Eine parametrisierte Meldung schützt vor unnötiger String-Verkettung, aber nicht davor, dass Sie das Argument bereits berechnet haben. Wenn Sie log.debug("report={}", buildBigReport()) schreiben, wird buildBigReport() auch dann ausgeführt, wenn DEBUG ausgeschaltet ist. Wenn Sie also wirklich eine schwere Sache haben (im Übungsprojekt gibt es das fast nie, aber es ist gut, die Gewohnheit früh zu entwickeln), gibt es einen einfachen Trick: Überprüfen Sie isDebugEnabled().

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class ExpensiveDebugLog {
    private static final Logger log = LoggerFactory.getLogger(ExpensiveDebugLog.class);

    public void logExpensiveDetails() {
        // Die Level-Prüfung schützt vor „teuren“ Berechnungen, wenn DEBUG ohnehin ausgeschaltet ist
        if (log.isDebugEnabled()) {
            // Hier könnte das Sammeln großer Berichte, Serialisierung etc. stattfinden
            String report = "very-big-report"; // stellen wir uns vor, das hätten wir lange berechnet
            log.debug("Debug report prepared: {}", report);
        }
    }
}

Das ist kein „obligatorischer Stil für jeden Log“. Es ist eher eine Absicherung, wenn Sie wirklich verstehen, dass Sie etwas Schweres nur für die Diagnose bauen.

8. Typische Fehler bei der Log-Konfiguration

Fehler Nr. 1: root: DEBUG einschalten „nur um ja alles zu sehen“.
So bekommen Sie eine Lawine von Logs von Spring, Tomcat und anderen Bibliotheken, und Ihre Anwendungsinformationen gehen darin unter. Am Ende untersuchen Sie nicht das Problem, sondern betreiben Archäologie in einem Textberg. Viel nützlicher ist es, root auf INFO zu lassen und den Level punktuell für Ihre eigenen Pakete anzuheben.

Fehler Nr. 2: ERROR und WARN als emotionale Markierungen verwenden.
Manchmal schreibt ein Entwickler log.error("User not found"), obwohl es sich um eine normale Situation handelt, die korrekt behandelt wird (z.B. Rückgabe 404). Dieser Ansatz zerstört den Sinn der Level: ERROR ist dann kein Signal mehr für „etwas ist kaputt“, und bei einem echten Vorfall können Sie nicht mehr erkennen, wo wirklich Feuer ist.

Fehler Nr. 3: Erwarten, dass ein DEBUG-Log bei root=INFO erscheint.
Das ist ein Klassiker. Sie haben log.debug(...) geschrieben, Stille gesehen und entschieden, dass der Logger „nicht funktioniert“. Dabei funktioniert er einwandfrei – er filtert nur die Meldungen nach Level. Behandelt wird es durch Konfiguration des Levels für das betreffende Paket in application.yaml, nicht durch Umschreiben des Codes oder Rückkehr zu System.out.println().

Fehler Nr. 4: Tippfehler im Paketnamen in der Konfiguration logging.level.*.
Da die Konfiguration als Zeichenkette erfolgt, wird aus einem einzigen zusätzlichen Punkt oder einem fehlenden Segment Ihr Diagnoseversuch zu „nichts hat sich geändert“. Wenn Sie com.example.catalogservice.catalog konfigurieren, Ihre tatsächlichen Klassen aber in com.example.catalogservice.catalogs liegen (beispielshalber), haben Sie einfach ein nicht existierendes Präfix konfiguriert.

Fehler Nr. 5: Zu viel auf INFO in heißen Stellen loggen.
Wenn eine Methode häufig aufgerufen wird (z.B. bei jeder Anfrage) und Sie dort „für alle Fälle“ ein log.info("...") setzen, werden die Logs schnell zu Rauschen, und die Anwendung beginnt, unnötige Zeit für IO zu verschwenden. Für sich wiederholende technische Details ist normalerweise DEBUG besser geeignet, und INFO sollte man für wichtige, seltene und verständliche Ereignisse reservieren.