Структурное логирование slog: хендлеры, атрибуты, уровни и цена каждой строки

Logger, Handler, Writer

Зачем стандартной библиотеке вообще второй логирующий API? Потому что log.Printf производит прозу — а прозу надо запрашивать регексами, которые ломаются при малейшем изменении формулировки. log/slog делит логирование на тонкий фронтенд и подключаемый бэкенд. Logger — это API, которое зовёт ваш код; он собирает Record — таймстамп, уровень, сообщение, атрибуты — и отдаёт его Handler, который решает формат и назначение: JSONHandler и TextHandler идут в коробке, кастомные хендлеры оборачивают другие, добавляя сэмплирование, редакцию или fan-out. Хендлер пишет в io.Writer. Именно это разделение объясняет, почему slog победил: библиотеки логируют в нейтральное API, а приложение выбирает формат вывода один раз.

logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{
	Level: slog.LevelInfo,
}))
slog.SetDefault(logger) // заодно перенаправляет легаси-пакет log через slog

logger.Info("payment captured",
	slog.String("order_id", orderID),
	slog.Int("amount_cents", amount),
	slog.Duration("elapsed", elapsed),
)

Две конвенции вызова не эквивалентны. Чередующиеся ключ-значение аргументы — logger.Info("msg", "key", val) — удобны и боксируют каждое значение в any, аллоцируя для большинства не-указательных типов, а пропущенный ключ даёт !BADKEY-атрибут в рантайме вместо ошибки компиляции. Типизированные конструкторы — slog.String, slog.Int, slog.Duration — хранят значение внутри slog.Value, маленького union-типа, минуя кучу для распространённых видов; LogAttrs — самая строгая и быстрая форма. И одна ловушка переживает все конвенции: аргументы вычисляются до проверки уровня. logger.Debug("x", "stats", computeStats()) при хендлере на Info не выпустит ни строки, но computeStats() выполнится каждый раз — охраняйте дорогие выражения через logger.Enabled(ctx, slog.LevelDebug) или утаскивайте ленивость в LogValuer.

Уровни — контракт с дежурным

Спросите себя: если эта строка лога выстрелит в два ночи, должен ли кто-то проснуться? Один вопрос — вся нужная семантика уровней. Уровни не значат ничего, пока команда не даст им операционную семантику, а полезная семантика — про то, кто должен действовать. Debug: в проде выключен, включается на инцидент; считайте, что его никто не видит. Info: редкие смены состояния, которые стоит грепать потом, — деплои, установленные соединения, завершённые джобы; если оно стреляет на каждый запрос — это объём, а не сигнал. Warn: что-то деградировало и само починилось — ретрай прошёл, fallback включился; никто не просыпается, кто-то завтра смотрит агрегат. Error: человек обязан действовать; этот уровень питает алерты и пейджи. Самая частая порча — логировать ожидаемые клиентские отказы — ошибки валидации, 404 — на Error: пейджер привыкает, пороги алертов поднимают, чтобы выжить, и единственный важный Error тонет в шуме. Если по событию никто не должен действовать — это не Error.

Редакция на типе, а не на месте вызова

Утечка номеров карт из крючка случается потому, что редакцию оставили дисциплине мест вызова — каждый инженер обязан помнить, вечно, на каждой строке. LogValuer переносит правило в систему типов:

type CardNumber string

func (CardNumber) LogValue() slog.Value {
	return slog.StringValue("[REDACTED]")
}

Хендлер разрешает LogValue() на этапе форматирования, так что сырое значение никогда не доходит до писателя — кто бы его ни логировал, где и внутри какой структуры через группу. Тот же хук работает ленивым вычислением: LogValuer, считающий дорогую сводку, выполняется только когда запись реально прошла гейт уровня — это чистый фикс ловушки из первого квиза. Сочетайте его с редакцией через Stringer из урока о конфигурации, чтобы закрыть и fmt-пути — два интерфейса охраняют разные выходы.

Per-request логгеры и корреляция с трейсами

Логгер со скоупом запроса превращает каждую строку в улику: middleware делает l := logger.With(slog.String("request_id", id)) и передаёт l вниз — обычно через контекст. With дёшев по дизайну: хендлер пре-форматирует прикреплённые атрибуты один раз (JSONHandler рендерит их в переиспользуемый байтовый префикс), так что request_id стоит один раз на запрос, а не на строку. Перенос логгера в контексте технически гнёт правило прошлого урока про зависимости в context.Value — это принятое, с открытыми глазами, исключение в большинстве больших Go-кодбаз: логирование амбиентно, а fallback на дефолтный логгер делает режим отказа безвредным. Более строгая альтернатива: передавать чистый ctx и звать InfoContext, а кастомный хендлер достаёт trace_id и span_id из контекста при форматировании. Цель в обоих случаях одна — каждая запись несёт идентификаторы, позволяющие развернуться от строки лога к полному распределённому трейсу и обратно.

Когда логирование — узкое место

Числа, которые должны жить в голове: JSON-строка с горсткой атрибутов стоит порядка микросекунды CPU плюс syscall писателя, а писатель — это мьютекс: все горутины, логирующие в общий os.Stderr, сериализуются на нём. На 100k строк в секунду вы тратите десять с лишним процентов ядра на одно форматирование, дерётесь за лок писателя и отгружаете порядка 25 ГБ в час в ингест-пайплайн, который выставляет счёт за гигабайт. Дисциплина горячих путей: логируйте решения и отказы, а не прогресс; сэмплируйте высокообъёмный Info (первые N на ключ в окне или 1-из-N), но никогда не сэмплируйте ошибки; частоты отдавайте метриками вместо строк — счётчик инкрементируется за наносекунды и агрегируется бесплатно. Консьюмер из крючка оставил одну строку на батч и сэмплированную одну на тысячу сообщений; пропускная способность вернулась — вместе с бюджетом на ингест.