Logowanie w serwisie backendowym zamiast println

1. Rola logów w serwisie backendowym

Szybki feedback loop jest przydatny, gdy jesteś przy aplikacji i możesz ją od razu zrestartować z IDE. Ale serwis ma jeszcze jedno życie: działa sam z siebie, a zajmować się nim trzeba już po fakcie. W tym momencie potrzebny jest nie kolejny println, lecz stały kanał diagnostyczny — logi.

Gdy piszesz aplikację konsolową, wydaje się, że najnaturalniejszy sposób na poznanie „co się dzieje" — to ustawić breakpoint i sprawdzić zmienne. W serwisie wszystko szybko staje się trudniejsze: żądania przychodzą równolegle, serwis żyje długo, a problem często objawia się w momencie, gdy ty... właśnie poszedłeś po herbatę. W tym momencie debugger nie pomaga, bo jest dobry, gdy jesteś obok i wszystko kontrolujesz, a serwis — to samodzielna bestia.

Wyobraź sobie typową sytuację: catalog-service uruchomiony nie z IDE, lecz jako zwykły proces (choćby lokalnie). Wystartował, popracował kilka godzin, ktoś trafił na /api/catalog/featured, a potem nagle „coś się stało dziwne": na stronie pusto, choć kursy na pewno są. Nie możesz „cofnąć się w czasie" i sprawdzić stan w momencie, gdy stało się dziwne. Za to prawie zawsze możesz otworzyć logi i zobaczyć łańcuch zdarzeń: serwis startował, ile kursów załadował, w jakim trybie działał, jakie ważne gałęzie wykonywał.

Na tym polega główna rola logów: rejestrują historię życia serwisu. Można postrzegać log jak „czarną skrzynkę" samolotu, tylko bez dramatycznej muzyki w tle. Debugger — to mikroskop w rękach lekarza. Logi — to karta medyczna pacjenta, którą się czyta, gdy pacjent jest już w domu i nie można ponownie „włączyć" tego samego momentu.

2. System.out.println i jego pułapki

System.out.println naprawdę wydaje się wygodny. Jest zawsze pod ręką, nie wymaga importów, można „nakropkować" kilka linii i od razu zobaczyć, co dzieje się wewnątrz metody. Do zadań edukacyjnych to normalne: uczysz się Javy i ważne jest szybkie zobaczenie wyniku. Ale gdy tylko piszesz serwis backendowy, println zaczyna działać przeciwko tobie, bo nie służy diagnostyce, lecz „szybkiemu wypisaniu czegoś".

Główny problem nawet nie w tym, że println jest „zły" (nie jest zły, po prostu nie do tego). Problem w tym, że println nie daje normalnych narzędzi zarządzania: nie możesz łatwo odróżnić ważnych komunikatów od drugorzędnych, filtrować wyjścia dla konkretnego pakietu, włączać i wyłączać szczegółowość bez edycji kodu, dodawać kontekstu systemowego (czas, wątek, źródło) w jednolity sposób. W efekcie serwis zamienia się w „gadatliwego sąsiada": mówi dużo, ale czy na temat — niejasne.

Porównajmy to konkretniej:

Jest jeszcze jedna subtelność: println bardzo łatwo zamienia się w „własnorobny protokół", który psuje się przy każdym refaktoringu. Piszesz System.out.println("here 1"), potem po tygodniu zapominasz, co to „here 1", i zaczyna się archeologia po repozytorium. Tak, archeologia to przydatna umiejętność, ale niech to będzie zajęcie dodatkowe, a nie codzienność.

Mini-przykład „jak zwykle robią na początku":

public void start() {
    // Zły nawyk: println nie daje poziomu ważności i nie dodaje kontekstu automatycznie
    System.out.println("started"); // started
}

Wyjście będzie, ale nie odpowiada na pytania „kto wystartował? co dokładnie? czy to normalne czy błąd? kiedy dokładnie?". Dla żywego serwisu to za mało informacji.

3. Zdarzenie, kontekst i ważność w logach

Żeby log był przydatny, musi być nie „strumieniem myśli dewelopera", lecz opisem zdarzeń serwisu. Dobre komunikaty logów zazwyczaj robią trzy rzeczy: nazywają zdarzenie, dodają kontekst i pokazują ważność. Właśnie dlatego logowanie — to dyscyplina: nie po prostu drukujesz tekst, lecz zostawiasz ślad, który potem ktoś (w tym ty za miesiąc) będzie czytał i próbował zrozumieć, co się stało.

Zdarzenie — to odpowiedź na pytanie „co się stało?". Kontekst — to „z jakimi wartościami/w jakim trybie?". Ważność — to „jak to poważne?". Nawet jeśli nie czujesz się jeszcze pewnie z poziomami ważności (będziemy je rozwijać dalej), sama idea ważności od razu czyni log bardziej czytelnym: różne zdarzenia powinny brzmieć inaczej.

Na razie traktuj log po prostu jako roboczy obiekt logowania, a {} — jako sposób podstawiania wartości bez sklejania ciągów. Tu ważna jest sama forma komunikatu: zdarzenie i fakt.

Spójrz na różnicę komunikatów:

// Źle: nic nie mówi o zdarzeniu
log.info("done");

// Lepiej: mówi, co dokładnie zrobiono, i pokazuje wynik
// {} — placeholdery; wartości przekazywane oddzielnie, bez konkatenacji ciągów
log.info("Featured courses prepared, count={}", featured.size());

Nawet nie wiedząc nic o wnętrznościach logowania, już czujesz: drugi komunikat można czytać jako część historii, pierwszy — jako przypadkową replikę.

Jeszcze jeden ważny punkt: log nie powinien opowiadać każdej linijki implementacji. Jeśli metoda robi 12 kroków i zalogujesz wszystkie 12 na jednym poziomie, dostaniesz „powieść w 12 tomach", której nikt nie doczyta. W logach chcemy widzieć punkty orientacyjne: początek ważnego procesu, wynik ważnego procesu, podejrzany stan, błąd.

Właśnie dlatego w catalog-service właściwe są komunikaty w stylu „katalog załadowany, kursów tyle" i „podborka featured gotowa", natomiast „teraz robię stream().filter()" — nie. Stream — to szczegół implementacji, a nie zdarzenie domenowe.

4. Co logować w catalog-service

Gdy zaczynasz logować, najczęstszy błąd — albo logować wszystko po kolei („na wszelki wypadek"), albo prawie nic nie logować („potem się ogarnie"). W projekcie ćwiczebnym chcemy znaleźć złoty środek: zostawić wystarczająco sygnałów, żeby serwis można było wytłumaczyć i zdiagnozować, ale nie zamieniać logów w biały szum.

W catalog-service bardzo naturalnym pierwszym punktem logowania jest start i ładowanie danych katalogu z konfiguracji. Nasze dane pochodzą z CatalogProperties, więc przy starcie przydatne jest potwierdzenie, że konfiguracja została poprawnie odczytana i powiązana. To nie „zbędna gadanina", lecz sprawdzenie zdrowia aplikacji na wczesnym etapie: jeśli nagle jest 0 kursów, to ważny sygnał.

Jeszcze jeden dobry punkt — formowanie „podborki featured". To aplikacyjna, domenowa rzecz: zależy od danych i ustawień i łatwo po niej zauważyć podejrzany stan. Na przykład, jeśli maxFeaturedCount=4, a w wyniku 0 — to niekoniecznie błąd, ale zdecydowanie powód do czujności.

Poniżej mały fragment serwisu, gdzie log „ściska" ważne zdarzenie do jednej linii, a nie opowiada implementację:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Service;

@Service
public class CourseCatalogService {
    // Logger powiązany z klasą: po nim w logach widać źródło komunikatu
    private static final Logger log = LoggerFactory.getLogger(CourseCatalogService.class);

    public void logFeaturedPrepared(int limit, int actualCount) {
        // Rejestrujemy zdarzenie domenowe + ważny kontekst (limit i fakt)
        log.info("Featured courses prepared, limit={}, count={}", limit, actualCount);
    }
}

Log nie opowiada, jak dokładnie wybierałeś kursy, ale rejestruje fakt: „podborka gotowa" i pokazuje dwie liczby, które naprawdę pomagają w diagnostyce.

Jeszcze jeden przykład — „maintenance mode". U nas to flaga konfiguracyjna (maintenanceMode). Nawet jeśli teraz wpływa na zachowanie minimalnie, sam fakt trybu — to ważny kontekst. Idea prosta: jeśli serwis jest w trybie konserwacji, dziwne zachowanie (np. puste odpowiedzi) może być oczekiwane. I wtedy jeden log przy starcie oszczędza ci pół godziny dochodzenia.

5. Gdzie stawiać logi w warstwach serwisu

W serwisie są warstwy: warstwa web (controller), warstwa aplikacyjna (service), warstwa dostępu do danych (repository), plus kod bootstrap startu. Jeśli logujesz chaotycznie, łatwo dostać trzy identyczne komunikaty na jedno zdarzenie: kontroler napisał „zaczynam", serwis napisał „robię", repozytorium napisało „robię", a potem wszystko powtórzyło się przy obsłudze wyjątku. W efekcie nie pomogłeś diagnostyce, po prostu zwielokrotniłeś szum.

Przydatny model mentalny: logowanie — to jak znaki drogowe. Jeśli postawisz znak „Uwaga, zakręt" co dwa metry, kierowca przestanie je zauważać. Jeśli postawisz go tam, gdzie jest naprawdę niebezpiecznie, będzie działał. Dlatego warto logować w miejscach, które są naprawdę ważne dla rozumienia systemu: granice scenariuszy, wyniki końcowe, stany niestandardowe.

Prosty schemat, gdzie zazwyczaj „mieszkają" przydatne logi w naszym projekcie:

flowchart TD
    A["Startup / bootstrap"] --> B[Service layer]
    B --> C[Repository layer]
    D[Web layer] --> B

    A:::good -->|"Startup summary, liczby, tryby"| L1["Logi"]
    B:::good -->|"Zdarzenie domenowe: przygotowano featured"| L1
    D:::meh -->|"Logi tylko jeśli jest wyraźna przyczyna"| L1
    C:::meh -->|"Ostrożnie: łatwo zrobić szum"| L1

    classDef good fill:#e7ffe7,stroke:#2f7d32,stroke-width:1px;
    classDef meh fill:#fff7e6,stroke:#b26a00,stroke-width:1px;

Bootstrap i warstwa service — to dobre kandydatury na pierwsze sensowne logi w catalog-service. Warstwa controller i repozytorium wymagają ostrożności: tam łatwo zacząć „logować każdy drobiazg", szczególnie gdy chce się widzieć każde żądanie. Ale na tym poziomie ważniejsze jest rozumienie stanu serwisu, a nie zamienianie logu w tracker każdego ruchu.

Jeszcze jedno kryterium „gdzie się zatrzymać": log powinien być zrozumiały bez czytania całej klasy. Jeśli komunikat brzmi „step=3 reached", rozumie go tylko autor (i to przez pierwsze dwa dni). Jeśli brzmi „Catalog loaded, courses=12", zrozumie go każdy, kto zna domenę.

6. Refaktoryzacja: println → log

Przejście od println do logowania najlepiej robić nie „rewolucją w całym projekcie", lecz małymi, zrozumiałymi krokami. Najwłaściwszy „pierwszy krok" — wziąć miejsce, gdzie już coś wypisywałeś na konsolę (np. startup summary) i przejść na log. Tak nie zmieniasz zachowania biznesowego, nie dodajesz nowej funkcji, a po prostu czynisz wyjście informacji diagnostycznych bardziej dojrzałym.

Najpierw zobaczmy, jak wygląda naiwna wersja (i tak, wszyscy tak robiliśmy — nawet ci, którzy teraz udają, że nigdy):

import org.springframework.boot.ApplicationArguments;
import org.springframework.boot.ApplicationRunner;
import org.springframework.stereotype.Component;

@Component
public class StartupSummaryRunner implements ApplicationRunner {

    @Override
    public void run(ApplicationArguments args) {
        // Naiwny wariant: komunikat trafi bezpośrednio na stdout i wypadnie z ogólnego systemu logowania
        System.out.println("Catalog startup summary prepared"); // Catalog startup summary prepared
    }
}

Komunikat się pojawi, ale nie jest w żaden sposób powiązany z systemem logowania. Dalej zastępujemy go komunikatem logowania, który już będzie częścią ogólnego obrazu startu:

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 {
    // Logger SLF4J: dalej formatowaniem/poziomami/wyjściem zarządza konfiguracja logowania
    private static final Logger log = LoggerFactory.getLogger(StartupSummaryRunner.class);

    @Override
    public void run(ApplicationArguments args) {
        // Teraz komunikat trafia do ogólnego strumienia logów aplikacji
        log.info("Catalog startup summary prepared");
    }
}

Zwróć uwagę: nie „skomplikowaliśmy świata", po prostu zmieniliśmy kanał wyjścia. Ale ten mały krok daje dużą korzyść: teraz komunikat przechodzi przez system logowania, czyli będzie sformatowany tak samo jak reszta wyjścia Spring Boot, można go filtrować i nie będzie wyglądał jak „przyklejony taśmą klejącą" do konsoli.

Na tym kroku wystarczy zobaczyć samo przejście stdout → logging. Pełny startup summary — to już osobne zadanie: tam ważne są profile, port i wskaźniki domenowe, a nie sam fakt komunikatu.

7. Typowe błędy przy przechodzeniu na logi

Gdy zaczynasz logować, chce się albo „prze-logować" wszystko (i dostać szum), albo logować tak samo bezsensownie jak wcześniej wypisywano na konsolę. To normalna faza wzrostu: najpierw piszemy dużo, potem uczymy się pisać na temat. Poniżej kilka błędów, które spotykają prawie wszystkich nowicjuszy i przez które logi szybko przestają pomagać.

Błąd nr 1: zostawiać System.out.println w serwisach i klasach runner'ów „bo szybciej".
println naprawdę jest szybszy do napisania, ale prawie zawsze zostaje w kodzie dłużej, niż planowałeś. W efekcie część informacji żyje w logach, część — w przypadkowych wydrukach i czytasz dwa różne „światy". Jeśli komunikat jest ważny — niech będzie komunikatem log. Jeśli nie jest ważny — prawdopodobnie w ogóle go nie powinno być.

Błąd nr 2: pisać komunikaty w stylu here, ok, done, step1.
Takie komunikaty tworzą iluzję kontroli („widzę, że kod dotarł tutaj"), ale nie pomagają zrozumieć stanu serwisu. Za tydzień zobaczysz done i nie przypomnisz sobie, co dokładnie „done". Dobry log nazywa zdarzenie ludzkimi słowami i dodaje wymierny wynik: courses=12, maintenanceMode=true, limit=4.

Błąd nr 3: logować implementację, a nie zdarzenie.
Jeśli piszesz log przed każdą linijką, zamieniasz log w „komentarze, które się drukują". To nie diagnostyka, to serial „Jak robiłem stream().filter()". Log powinien opisywać początek i koniec ważnego kroku, a nie kopiować wewnętrzną kuchnię metody.

Błąd nr 4: logować wszystko na jednym poziomie „żeby tylko było widać".
Nowicjusze często wszystko robią info, bo „tak widać w konsoli". Ale wtedy nie ma różnicy między ważnym zdarzeniem a tłem. Nawet jeśli nie jesteś pewny co do poziomów, przydatne jest przynajmniej intuicyjne rozróżnienie: „ważne podsumowanie" i „szczegół do diagnostyki".

Błąd nr 5: drukować cały obiekt „na wszelki wypadek".
Frazy takie jak log.info("properties={}", properties) wyglądają kusząco, ale zazwyczaj tworzą ogromne linie, które trudno czytać. O wiele przydatniej wybrać 1–3 pola, które naprawdę tłumaczą stan, i je wypisać. „Ściskać kontekst" — to jeden z głównych celów logowania.