Структурированное логирование в Go на slog: рабочие приёмы

С Go 1.21 в стандартной библиотеке появился пакет log/slog — структурированное логирование без сторонних зависимостей. До него команды тащили zap, zerolog или писали свои обёртки над log. Теперь у большинства сервисов есть встроенный инструмент, но пользуются им часто неправильно: ключи не совпадают между вызовами, контекст запроса теряется, а в проде вместо JSON лежат человекочитаемые строки, которые не парсит ни один сборщик логов.

Разбираем приёмы, которые встречаются в живых сервисах на Go 1.21–1.23: как передавать сквозной контекст, зачем нужны группы, где slog тормозит и как выбрать между текстовым и JSON-выводом. Настройку внешних сборщиков (Loki, ELK) не трогаем — здесь только то, что происходит внутри приложения.

Почему log.Printf перестаёт работать

Классическая строка log.Printf("user %d order %d failed: %v", userID, orderID, err) читается человеком, но не машиной. Когда логов сотни тысяч в час и вы ищете все события по одному orderID, регулярками по свободному тексту это делать больно. Структурированный лог кладёт значения в отдельные поля:

logger.Error("order failed",
    "user_id", userID,
    "order_id", orderID,
    "err", err)

На выходе — JSON, где по order_id можно фильтровать точно. Но у такого API есть ловушка: пары ключ-значение передаются как ...any, и компилятор не проверит, что вы не забыли значение. Об этом ниже.

Приём 1: типизированные атрибуты вместо голых пар

Вариант с чередованием ключей и значений ("user_id", userID) короче, но опечатка вида пропущенного значения превратит следующий ключ в значение, и лог поедет. Для критичных мест используйте типизированные атрибуты slog.Attr:

package main

import (
	"log/slog"
	"os"
)

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))

	userID := 42
	orderID := 1007

	// Типизированные конструкторы: компилятор проверит типы
	logger.Info("order created",
		slog.Int("user_id", userID),
		slog.Int("order_id", orderID),
		slog.String("status", "pending"),
	)
}

Здесь slog.Int, slog.String, slog.Bool, slog.Time, slog.Duration берут значение нужного типа. Опечатку в количестве аргументов уже не сделать. Плата — многословность.

Когда что

• Разовый Info/Debug в глубине функции — можно голыми парами, короче.
• Логи в горячих путях и в местах, где важна точность полей (аудит, деньги, ошибки) — типизированные атрибуты.

Приём 2: сквозной контекст через With и context

Самая частая боль: request_id нужно протащить через десяток функций, и добавлять его в каждый вызов лога вручную — путь к ошибкам. Есть два механизма.

Дочерний логгер через With. Он возвращает новый *slog.Logger с прикреплёнными атрибутами, которые попадут в каждую запись:

reqLogger := logger.With(
	slog.String("request_id", reqID),
	slog.Int("user_id", userID),
)

reqLogger.Info("handling request")   // в записи уже есть request_id и user_id
reqLogger.Warn("slow db query", slog.Duration("took", elapsed))

Через context.Context. Если логгер неудобно тащить параметром, кладите его в контекст и доставайте где нужно. С Go 1.21 у логгера есть контекстные методы InfoContext, ErrorContext и т. д. — они передают контекст в обработчик, что важно для трассировки:

package logutil

import (
	"context"
	"log/slog"
)

type ctxKey struct{}

// Кладём логгер в контекст
func WithLogger(ctx context.Context, l *slog.Logger) context.Context {
	return context.WithValue(ctx, ctxKey{}, l)
}

// Достаём; если нет — отдаём дефолтный
func FromContext(ctx context.Context) *slog.Logger {
	if l, ok := ctx.Value(ctxKey{}).(*slog.Logger); ok {
		return l
	}
	return slog.Default()
}

В middleware вы создаёте reqLogger через With, кладёте его в контекст запроса, а вниз по стеку каждый слой достаёт готовый логгер с уже прикреплённым request_id.

Логгер с прикреплённым контекстом — это не «удобно», а способ гарантировать, что ни одна запись в рамках запроса не потеряет идентификатор. Ищете инцидент по одному request_id — и видите всю цепочку, а не разрозненные строки.

Приём 3: группы для вложенности

Когда атрибутов много, плоский JSON превращается в кашу. slog.Group вкладывает поля под общим ключом:

logger.Info("payment processed",
	slog.Group("payment",
		slog.Int("amount", 1500),
		slog.String("currency", "RUB"),
		slog.String("provider", "acquiring"),
	),
	slog.String("request_id", reqID),
)

В JSON-выводе получится вложенный объект payment с тремя полями. Это удобно, когда у вас несколько групп полей с одинаковыми именами (например, from.user_id и to.user_id) — без группы они бы конфликтовали.

Приём 4: уровни и Handler-опции

Уровень логирования задаётся не на логгере, а на обработчике через slog.HandlerOptions. Чтобы менять его без перезапуска, используйте slog.LevelVar:

package main

import (
	"log/slog"
	"os"
)

func main() {
	levelVar := new(slog.LevelVar) // по умолчанию Info

	handler := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
		Level:     levelVar,
		AddSource: true, // добавит файл и строку вызова
	})
	logger := slog.New(handler)

	logger.Debug("not visible")   // ниже Info — не выведется
	logger.Info("visible")

	// Переключаем уровень в рантайме, например по сигналу или HTTP-ручке
	levelVar.Set(slog.LevelDebug)
	logger.Debug("now visible")
}

AddSource: true добавляет позицию вызова, но стоит производительности — включайте осознанно, не на всех уровнях в проде.

Приём 5: скрытие чувствительных полей

Токены и пароли не должны попадать в лог. Опция ReplaceAttr в HandlerOptions перехватывает каждый атрибут перед записью:

opts := &slog.HandlerOptions{
	ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
		if a.Key == "password" || a.Key == "token" {
			return slog.String(a.Key, "[REDACTED]")
		}
		return a
	},
}
logger := slog.New(slog.NewJSONHandler(os.Stdout, opts))

Через ReplaceAttr удобно и переименовывать стандартные ключи (time, level, msg), чтобы они совпадали со схемой вашего сборщика логов.

Текст или JSON: что выбирать

slog из коробки даёт два обработчика. Выбор зависит от того, кто читает лог.

Рабочая схема: TextHandler локально, JSONHandler в контейнере. Переключайте по переменной окружения при инициализации, а не по всему коду.

Что ломается на производительности

slog быстрее log.Printf на структурированных данных, но медленнее zap в его типизированном режиме — из-за интерфейса any в API с парами и аллокаций при упаковке значений. Типичные грабли:

• Дорогие аргументы вычисляются всегда. В logger.Debug("dump", "payload", expensiveMarshal(obj)) функция выполнится, даже если уровень Debug выключен — Go вычислит аргументы до вызова. Для дорогих вычислений оборачивайте в slog.LogValuer или проверяйте уровень через logger.Enabled(ctx, slog.LevelDebug).
• Логирование в горячем цикле. Даже отброшенная запись проходит через аргументы. В путях на миллионы вызовов выносите лог из цикла или агрегируйте.
• Синхронный вывод в stdout. Под нагрузкой запись в неблокирующий терминал или медленный диск становится узким местом. Пишите в буфер или в файл, ротацию отдавайте отдельному процессу.

Если логи в горячем пути реально стали узким местом, померьте это до оптимизации: go test -bench на репрезентативной нагрузке или профиль аллокаций через go test -memprofile. Не переписывайте на zap по ощущению — сначала цифры.

Ленивое вычисление через LogValuer

type User struct {
	ID    int
	Email string
}

// LogValue вызовется только если запись реально пишется
func (u User) LogValue() slog.Value {
	return slog.GroupValue(
		slog.Int("id", u.ID),
		slog.String("email", "[REDACTED]"), // маскируем прямо здесь
	)
}

// Использование
logger.Debug("current user", slog.Any("user", user))

Что делать дальше

Соберите один пакет-обёртку на проект: инициализация логгера по переменной окружения (текст/JSON, уровень), функции WithLogger/FromContext для контекста и middleware, который прикрепляет request_id. Дальше — договоритесь в команде о едином наборе ключей (request_id, user_id, err) и вынесите их в константы, чтобы не расходились написания. В проде смотрите на две вещи: не растёт ли задержка на записи логов под пиком и не утекают ли в лог поля, которых там быть не должно.