Модуль: Observability · Уровень: Middle+/Senior

TL;DR#

Структурированное логирование = логи как набор key-value (обычно JSON), а не текстовая строка → машинно-парсятся, фильтруются и агрегируются в Loki/ELK по полям. В Go 1.21+ это стандарт log/slog: LoggerHandler (JSONHandler/TextHandler/кастомный) → Record из Attr. Уровни через slog.LevelVar можно менять в рантайме без рестарта. Контекстные поля добавляются через With/WithGroup. Ключевая senior-практика — корреляция: кастомный Handler достаёт trace_id/span_id из context.Context (OTel SpanContext) и пишет в каждую запись через InfoContext. PII не логировать (пароли, токены, карты, email) — маскировать через LogValuer или ReplaceAttr. При высоком RPS — sampling/rate-limiting логов. Производительность: slog имеет zero-alloc путь при использовании типизированных Attr и ленивых LogValuer, плюс проверку Enabled, чтобы не вычислять дорогие поля при отключённом уровне.

Теория#

Зачем структурированные логи#

Текстовый лог log.Printf("user %s failed login from %s", u, ip) нельзя надёжно отфильтровать в системе логов: нужен парсинг строки регэкспами. Структурный:

{"time":"2026-06-15T10:00:00Z","level":"WARN","msg":"login failed","user_id":"u_42","ip":"10.0.0.1","trace_id":"4bf9..."}

→ запрос level=WARN AND msg="login failed" в Loki/ELK, агрегация по user_id, дашборды по полям. Машинно-читаемо, консистентно, корректно при многострочных значениях.

Архитектура slog#

slog.Logger  — фронт API (Info/Warn/Error/Debug, With, WithGroup)
   │ передаёт
slog.Record  — одна запись (time, level, message, []Attr)
   │ обрабатывает
slog.Handler — интерфейс: Enabled, Handle, WithAttrs, WithGroup
   ├─ slog.JSONHandler   (структурный JSON — для прода)
   ├─ slog.TextHandler   (logfmt — для локалки)
   └─ кастомный Handler   (обёртка: trace correlation, sampling, redaction)

slog.Attr / slog.Value — типизированная пара ключ-значение (zero-alloc путь)
import "log/slog"

func setup() {
    h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
        Level:     slog.LevelInfo,
        AddSource: false, // file:line — дорого, только при необходимости
    })
    slog.SetDefault(slog.New(h)) // глобальный логгер для slog.Info(...)
}

Уровни и динамическая смена#

var lvl = new(slog.LevelVar) // потокобезопасный, меняется в рантайме
lvl.Set(slog.LevelInfo)

h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: lvl})
logger := slog.New(h)

// где-то в HTTP-хендлере /debug/loglevel — поднять Debug на лету без рестарта
lvl.Set(slog.LevelDebug)

Уровни: Debug(-4), Info(0), Warn(4), Error(8). Числовые → можно кастомные (Trace = -8, Fatal = 12). В проде обычно Info, Debug поднимают временно через LevelVar.

Контекстные поля: With / WithGroup#

// Логгер с базовыми полями, переиспользуется
reqLog := logger.With(
    slog.String("request_id", reqID),
    slog.String("route", "/checkout"),
)
reqLog.Info("started")
reqLog.Error("db error", slog.Any("err", err))

// Группировка (вложенный объект в JSON)
logger.WithGroup("http").Info("done",
    slog.Int("status", 200), slog.Duration("latency", d))
// => {"http":{"status":200,"latency":...}}

// Разовая группа в одном вызове
logger.Info("payment", slog.Group("card", slog.String("brand","visa")))

Корреляция с трейсами: кастомный Handler#

Лучший паттерн — Handler-обёртка, которая достаёт trace_id/span_id из context.Context и добавляет в каждую запись. Тогда InfoContext(ctx, ...) автоматически коррелирует лог с трейсом.

import (
    "context"
    "log/slog"
    "go.opentelemetry.io/otel/trace"
)

type traceHandler struct{ slog.Handler }

func (h traceHandler) Handle(ctx context.Context, r slog.Record) error {
    if sc := trace.SpanContextFromContext(ctx); sc.IsValid() {
        r.AddAttrs(
            slog.String("trace_id", sc.TraceID().String()),
            slog.String("span_id", sc.SpanID().String()),
        )
    }
    return h.Handler.Handle(ctx, r)
}

// WithAttrs/WithGroup должны сохранять обёртку
func (h traceHandler) WithAttrs(a []slog.Attr) slog.Handler {
    return traceHandler{h.Handler.WithAttrs(a)}
}
func (h traceHandler) WithGroup(name string) slog.Handler {
    return traceHandler{h.Handler.WithGroup(name)}
}

func newLogger(w io.Writer, lvl slog.Leveler) *slog.Logger {
    base := slog.NewJSONHandler(w, &slog.HandlerOptions{Level: lvl})
    return slog.New(traceHandler{base})
}
// в хендлере: ВАЖНО использовать *Context методы и прокидывать ctx
logger.InfoContext(ctx, "charge ok", slog.Int("amount", 100))
// => {... "trace_id":"4bf9...","span_id":"00f0..."}

Альтернатива — otelslog bridge (go.opentelemetry.io/contrib/bridges/otelslog), который ещё и экспортирует логи по OTLP с привязкой к трейсу.

logger-in-context vs trace-id-in-context: можно класть в ctx сам логгер (с уже привязанными полями) или только trace_id, а логгер брать дефолтный + Handler достаёт trace_id. Второй вариант чище: ctx несёт минимум, а корреляция — в Handler.

Что НЕ логировать (PII) и как маскировать#

Никогда: пароли, токены/секреты, полный PAN карты, CVV, email/phone в открытом виде, персональные данные под GDPR, тела запросов с чувствительным содержимым.

LogValuer — тип сам решает, как себя залогировать (маскирует на источнике):

type Card struct{ Number string }

func (c Card) LogValue() slog.Value {
    masked := "****" + c.Number[len(c.Number)-4:]
    return slog.StringValue(masked) // в лог попадёт только "****1234"
}

logger.Info("paid", slog.Any("card", Card{Number: "4111111111111111"}))
// => "card":"****1111" — исходный номер НИКОГДА не материализуется в лог

ReplaceAttr — глобальный фильтр на уровне Handler (редактирование/удаление полей по ключу):

opts := &slog.HandlerOptions{
    ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
        switch a.Key {
        case "password", "authorization", "set-cookie":
            return slog.Attr{} // удалить полностью
        case "email":
            return slog.String("email", "<redacted>")
        }
        return a
    },
}

LogValuer предпочтительнее для доменных типов (маскирование рядом с данными, типобезопасно); ReplaceAttr — глобальная страховочная сетка, но вызывается на каждый Attr → следи за производительностью.

Sampling и rate-limiting логов#

При высоком RPS логировать каждый запрос дорого (стоимость хранения, шум, нагрузка на pipeline). Стратегии:

  • Sampling: писать N% info-логов, но все ошибки.
  • Dedup/rate-limit повторяющихся ошибок: «БД недоступна» в цикле → одна запись + счётчик, а не 10k строк.
  • Tail sampling логов: если запрос завершился ошибкой/медленно — поднять детальность логов этого запроса (буферизация per-request и flush при ошибке).

Реализуется кастомным Handler, который в Handle решает, пропускать ли запись (token bucket, sampler по уровню).

type sampledHandler struct {
    slog.Handler
    limiter *rate.Limiter
}
func (h sampledHandler) Handle(ctx context.Context, r slog.Record) error {
    if r.Level < slog.LevelError && !h.limiter.Allow() {
        return nil // дропаем info под нагрузкой, ошибки всегда пишем
    }
    return h.Handler.Handle(ctx, r)
}

Производительность slog#

  • Zero-alloc путь: типизированные Attr (slog.String, slog.Int) и Value избегают аллокаций в boxing; ...any ("key", val) медленнее и аллоцирует.
  • Enabled(ctx, level) — проверяй перед дорогой подготовкой полей: при отключённом Debug не вычисляй тяжёлый дамп.
if logger.Enabled(ctx, slog.LevelDebug) {
    logger.DebugContext(ctx, "state", slog.Any("dump", expensiveDump()))
}
  • LogValuer ленив: LogValue() вызывается только если запись реально пишется — дорогую сериализацию откладываем до момента вывода (и она не выполнится при отключённом уровне).

Подводные камни / gotchas#

  • log.Println/Printf — не структурный: строка, которую нельзя надёжно фильтровать. Миграция на slog.
  • Нечётное число аргументов в ...any (logger.Info("msg", "key") без значения) → запись с !BADKEY. Используй типизированные Attr.
  • Дорогие вычисления в полях считаются даже при отключённом уровне, если переданы напрямую (slog.Any("x", expensive())expensive() уже вызван). Спасают Enabled и LogValuer.
  • Утечка PII — самый частый инцидент безопасности логов; маскируй на источнике (LogValuer) + сетка ReplaceAttr.
  • Логирование в hot path — каждый лог это I/O/сериализация; в горячем цикле убивает латенси. Сэмплируй.
  • Не прокинут ctx или вызван Info вместо InfoContext → нет trace_id, корреляция теряется.
  • ReplaceAttr дорогой — вызывается на каждый Attr каждой записи; тяжёлая логика там бьёт по всему логированию.
  • Дублирование логов и трейсов: writing всё и в лог, и в span events удваивает стоимость; реши, где источник истины.
  • AddSource: true добавляет file:line через runtime.Caller — заметный оверхед, не включай глобально в проде.
  • Не настроены динамические уровни → нельзя поднять Debug в инциденте без рестарта; используй LevelVar.

Вопросы на собеседовании#

В: Как добавить trace_id в каждую лог-запись через slog? О: Кастомный Handler-обёртка: в Handle(ctx, record) достать trace.SpanContextFromContext(ctx) и, если валиден, record.AddAttrs(trace_id, span_id). Обязательно прокинуть обёртку в WithAttrs/WithGroup, и использовать InfoContext(ctx,...) с прокинутым ctx. Либо otelslog bridge, который ещё и шлёт логи по OTLP с привязкой к трейсу.

В: Чем LogValuer лучше ReplaceAttr для маскирования PII? О: LogValuer.LogValue() маскирует прямо в доменном типе (карта сама отдаёт ****1234), типобезопасно, лениво (вызывается только при реальной записи) и исходное значение не материализуется. ReplaceAttr — глобальный фильтр по ключам, вызывается на каждый Attr (оверхед) и завязан на имена полей. Лучшая практика: LogValuer для доменных типов + ReplaceAttr как страховочная сетка.

В: Как менять уровень логирования без рестарта? О: slog.LevelVar — потокобезопасный изменяемый уровень, переданный в HandlerOptions.Level. По админ-эндпоинту вызвать lvl.Set(slog.LevelDebug) и поднять детальность во время инцидента, потом вернуть Info. Без рестарта и без потери стейта.

В: Почему важна проверка Enabled и ленивость LogValuer? О: Если передать slog.Any("x", expensiveDump()), функция вычисляется до вызова Info, даже при отключённом Debug. if logger.Enabled(ctx, LevelDebug) пропускает дорогую подготовку. LogValuer.LogValue() вызывается только когда запись реально пишется, откладывая дорогую сериализацию и пропуская её при отключённом уровне.

В: Когда и как сэмплировать логи? О: При высоком RPS, чтобы снизить стоимость и шум: писать долю info-логов, но все ошибки; дедуплицировать повторяющиеся ошибки (счётчик вместо 10k строк); tail-sampling — буферизовать per-request и flush детально только при ошибке/медленном запросе. Реализация — кастомный Handler с token bucket в Handle, дропающий info под нагрузкой и всегда пропускающий Error.

В: Что НЕ логировать и почему? О: Пароли, токены, полный PAN/CVV, email/phone в открытом виде, PII под GDPR, чувствительные тела запросов. Причины: утечка через лог-пайплайн (логи часто менее защищены, чем БД), комплаенс (GDPR/PCI), и доступ к логам у широкого круга. Маскировать на источнике через LogValuer и фильтровать ReplaceAttr.

В: В чём разница Info и InfoContext, и почему предпочесть второй? О: InfoContext принимает context.Context, который передаётся в Handler.Handle — это позволяет Handler’у достать trace_id из ctx, учесть отмену/дедлайны и per-request данные. Info использует context.Background() → теряется корреляция с трейсом. В сервисном коде всегда *Context-методы с прокинутым ctx.

На что копают на senior+#

  • Кастомный Handler для trace-корреляции: правильная реализация Handle/WithAttrs/WithGroup, сохранение обёртки, интеграция с OTel.
  • PII redaction: LogValuer vs ReplaceAttr, маскирование на источнике, аудит логов на утечки, комплаенс.
  • Динамические уровни через LevelVar без рестарта и per-component уровни.
  • Sampling/rate-limiting логов: token bucket, dedup, tail-sampling per-request, баланс стоимость/детальность.
  • Стоимость и cardinality в Loki: лейблы Loki ≠ поля лога; высококардинальные поля в лейблах Loki убивают его так же, как в Prometheus.
  • Logs vs traces — когда что: span events vs log lines, избегание дублирования, источник истины.
  • Производительность slog внутри: zero-alloc Attr/Value, Record-механика, почему ...any медленнее, ленивость.