Logowanie w Golang: slog i log, logi strukturalne w Go

slog w jednym przykładzie

log/slog (Go 1.21) zapisuje rekordy strukturalne: komunikat, poziom i atrybuty klucz-wartość.

package main

import (
	"log/slog"
	"os"
)

func main() {
	opts := &slog.HandlerOptions{Level: slog.LevelDebug}
	logger := slog.New(slog.NewTextHandler(os.Stdout, opts))

	logger.Debug("cache lookup", "key", "user:42", "hit", false)
	logger.Info("user logged in", "user", "ada", "attempts", 1)
	logger.Warn("slow query", "table", "orders", "ms", 812)
	logger.Error("payment failed", "order", 1017, "err", "card declined")
}

Każda linia wychodzi w postaci time=... level=INFO msg="user logged in" user=ada attempts=1. Ponieważ każda wartość jest osobnym polem, system zbierania logów (Loki, Elasticsearch, CloudWatch, Datadog) może filtrować po user=ada albo level=ERROR bez wyrażeń regularnych na swobodnym tekście.

Przykłady na tej stronie piszą do os.Stdout, żeby wynik pojawiał się po kolei. W prawdziwym serwisie logi zwykle trafiają do os.Stderr, gdzie pisze też domyślny logger.

Poziomy

Handler odrzuca rekordy poniżej swojego minimalnego poziomu, a domyślne minimum to Info. Dlatego slog.Debug(...) nic nie wypisuje, dopóki nie skonfigurujesz handlera z Level: slog.LevelDebug. Odstępy między wartościami zostawiają miejsce na własne poziomy, np. slog.Level(2).

Aby zmieniać poziom w trakcie działania (z flagi, endpointu administracyjnego albo sygnału), umieść w opcjach slog.LevelVar i później wywołuj na nim Set:

var level slog.LevelVar // zero value: Info
logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: &level}))
level.Set(slog.LevelDebug) // from now on, debug records are written

Tekst czy JSON

slog.NewTextHandler zapisuje pary key=value, łatwe do czytania w terminalu. slog.NewJSONHandler zapisuje jeden obiekt JSON na linię, czyli format, którego oczekuje większość potoków logów. Wywołania logujące pozostają takie same; zmienia się tylko handler.

package main

import (
	"errors"
	"log/slog"
	"os"
	"time"
)

func main() {
	// Drop the time attribute so the output is the same on every run.
	noTime := func(groups []string, a slog.Attr) slog.Attr {
		if a.Key == slog.TimeKey && len(groups) == 0 {
			return slog.Attr{}
		}
		return a
	}

	text := slog.New(slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{ReplaceAttr: noTime}))
	json := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{ReplaceAttr: noTime}))

	for _, l := range []*slog.Logger{text, json} {
		l.Info("request served",
			"method", "GET",
			"path", "/items/7",
			"status", 200,
			"duration", 42*time.Millisecond,
		)
		l.Error("request failed", "err", errors.New("db timeout"), "retry", true)
	}
}

Wartości zachowują swoje typy: status w wyniku JSON jest liczbą, a retry wartością logiczną, time.Duration wypisuje się jako 42ms w tekście i jako nanosekundy w JSON, a error wypisuje swój komunikat. ReplaceAttr to punkt zaczepienia do przepisywania lub usuwania atrybutów; tutaj usuwa znacznik czasu, a w praktyce służy do zmiany nazw kluczy (msg na message) albo maskowania wartości.

Atrybuty

Luźno typowana forma przeplata klucze i wartości: "user", "ada", "attempts", 3. Jest krótka i ma jeden sposób na błąd: nieparzystą liczbę argumentów. Pozostała wartość zostaje zalogowana pod kluczem !BADKEY. go vet to wyłapuje:

./main.go:14:2: call to slog.Info missing a final value

Dla bezpieczeństwa typów i nieco mniejszej liczby alokacji używaj konstruktorów atrybutów, a przy logowaniu na gorącej ścieżce LogAttrs:

logger.Info("order placed",
	slog.Int("order_id", 1017),
	slog.String("currency", "EUR"),
	slog.Float64("total", 59.90),
	slog.Duration("took", elapsed),
)

logger.LogAttrs(ctx, slog.LevelInfo, "order placed", slog.Int("order_id", 1017))

Stosuj jedną konwencję nazewnictwa kluczy w całym kodzie (user_id wszędzie, a nie userID w jednym pakiecie i uid w innym). Zależą od tego zapytania w twoim systemie logów.

With: loggery, które niosą kontekst

logger.With(attrs...) zwraca nowy logger, który dodaje te atrybuty do każdego rekordu. Utwórz go dla każdego żądania albo zadania, a wszystkie zapisane przez niego linie da się ze sobą powiązać:

package main

import (
	"log/slog"
	"os"
)

func handleRequest(base *slog.Logger, requestID, user string) {
	log := base.With("request_id", requestID, "user", user)

	log.Info("loading cart")
	log.Info("charging card", slog.Group("payment", "amount", 25, "currency", "USD"))
	log.Warn("inventory low", "sku", "A-17", "left", 2)
}

func main() {
	noTime := func(groups []string, a slog.Attr) slog.Attr {
		if a.Key == slog.TimeKey && len(groups) == 0 {
			return slog.Attr{}
		}
		return a
	}
	base := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{ReplaceAttr: noTime}))
	base = base.With("service", "checkout", "version", "1.4.2")

	handleRequest(base, "req-81", "ada")
}

Każda linia niesie service, version, request_id i user bez powtarzania ich przy każdym wywołaniu. slog.Group zagnieżdża atrybuty, które handler JSON zapisuje jako zagnieżdżony obiekt ("payment":{"amount":25,"currency":"USD"}), a handler tekstowy jako klucze z kropkami (payment.amount=25). logger.WithGroup("db") umieszcza każdy późniejszy atrybut tego loggera w grupie.

Przekazuj logger danego żądania w dół jako parametr albo pole struktury. Przechowywanie go w context.Context jest możliwe, ale ukrywa zależność; metody slog InfoContext(ctx, ...) przekazują kontekst do handlera, a własny handler może z niego wyciągnąć identyfikatory śledzenia.

Ukrywanie sekretów przez LogValuer

Typ może kontrolować, jak jest logowany, implementując slog.LogValuer. Dzięki temu hasła i tokeny nie trafiają do logów, niezależnie od tego, kto loguje wartość:

package main

import (
	"log/slog"
	"os"
)

type Token string

func (Token) LogValue() slog.Value {
	return slog.StringValue("REDACTED")
}

type User struct {
	ID    int
	Email string
	Token Token
}

func (u User) LogValue() slog.Value {
	return slog.GroupValue(
		slog.Int("id", u.ID),
		slog.String("email", u.Email),
	)
}

func main() {
	noTime := func(groups []string, a slog.Attr) slog.Attr {
		if a.Key == slog.TimeKey && len(groups) == 0 {
			return slog.Attr{}
		}
		return a
	}
	logger := slog.New(slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{ReplaceAttr: noTime}))

	u := User{ID: 7, Email: "ada@example.com", Token: "s3cr3t"}
	logger.Info("login", "user", u)
	logger.Info("token refresh", "token", u.Token)
}

User loguje tylko swoje ID i e-mail, a Token zalogowany samodzielnie wypisuje REDACTED. Handler wywołuje LogValue dopiero wtedy, gdy rekord faktycznie jest zapisywany, więc działa to także dla wartości kosztownych do obliczenia.

Klasyczny pakiet log

log jest starszy niż slog i nadal dobrze sprawdza się w małych programach i skryptach. Zapisuje linie na standardowe wyjście błędów z prefiksem z datą i godziną:

package main

import (
	"log"
	"os"
)

func main() {
	log.SetOutput(os.Stdout) // default is os.Stderr
	log.SetFlags(0)          // no timestamp, so the output is the same every run
	log.Println("plain line")
	log.Printf("processed %d files", 12)

	log.SetFlags(log.Lshortfile)
	log.SetPrefix("[worker] ")
	log.Println("with file:line and a prefix")

	errLog := log.New(os.Stdout, "ERROR ", log.Lmsgprefix)
	errLog.Println("a separate logger with its own prefix")
}

Trzy funkcje kończą program albo wywołują panikę, a różnica ma znaczenie:

• log.Fatal, log.Fatalf, log.Fatalln wypisują komunikat, a potem wywołują os.Exit(1). Wywołania odroczone się nie wykonują. Używaj ich w main przy błędach startu, nigdy w kodzie bibliotek ani w handlerach żądań.
• log.Panic i pokrewne wypisują komunikat, a potem wywołują panikę, więc wywołania odroczone się wykonują, a panikę można przechwycić.
• Każda inna funkcja po prostu zapisuje linię.

Aby logować do pliku, otwórz go i przekaż do log.New albo log.SetOutput; io.MultiWriter(os.Stderr, f) zapisuje do obu miejsc.

log i slog razem

slog.SetDefault(logger) ustawia logger jako domyślny dla funkcji najwyższego poziomu, takich jak slog.Info, a także kieruje przez niego wyjście pakietu log. Istniejące wywołania log.Printf w twoim kodzie albo w zależnościach wychodzą wtedy jako rekordy strukturalne na poziomie Info:

slog.SetDefault(slog.New(slog.NewJSONHandler(os.Stderr, nil)))
log.Printf("legacy message") // {"time":"...","level":"INFO","msg":"legacy message"}

Przed SetDefault domyślny logger slog pisze przez pakiet log, dlatego samo slog.Info("hi") wypisuje 2026/09/23 14:30:00 INFO hi.

Praktyczne zasady

• Loguj błąd albo go zwracaj, nie jedno i drugie. Funkcja, która loguje błąd i go zwraca, sprawia, że ta sama awaria jest logowana na każdym poziomie stosu wywołań. Zwracaj błędy w górę z kontekstem i loguj raz, tam gdzie są obsługiwane.
• Zmienne dane umieszczaj w atrybutach, a nie w komunikacie. logger.Info("user created", "user_id", id) dobrze się grupuje w systemie logów; logger.Info(fmt.Sprintf("user %d created", id)) tworzy inny komunikat dla każdego użytkownika.
• Nigdy nie loguj sekretów ani pełnych body żądań. Do maskowania używaj LogValuer albo ReplaceAttr.
• JSON na produkcji, tekst w developmencie. Wybieraj handler przy starcie na podstawie flagi albo zmiennej środowiskowej.
• Świadomie dobieraj poziomy. Jeśli wszystko jest logowane na poziomie Error, alerty o błędach stają się szumem.