Логирование в Go: slog, JSON и context.Context

← назад к разделу

Когда в продакшне что-то идёт не так, первое, что открывают — логи. Если там написано fmt.Println("error:", err), расследование начинается с нуля: нет времени события, нет структуры, нет связи с запросом. Если же лог — JSON с полями order_id, trace_id и понятным уровнем — причину находят за минуты.

Go с версии 1.21 поставляется с log/slog: стандартная библиотека структурированного логирования без сторонних зависимостей.

Два формата: JSON в продакшне, текст при разработке

При разработке удобно читать логи как строки. В продакшне сборщики логов (Loki, ELK, Datadog) ожидают JSON — тогда они могут индексировать поля и делать сложные фильтры без регулярных выражений.

Создаём один логгер при старте сервиса по переменной окружения:

// internal/platform/log/setup.go
func New(env string) *slog.Logger {
    if env == "production" {
        return slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
            Level: slog.LevelInfo,
        }))
    }
    return slog.New(slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
        Level: slog.LevelDebug,
    }))
}

В продакшне каждая запись выглядит так:

{"time":"2026-06-18T10:02:00Z","level":"INFO","msg":"order_created","order_id":"ord-99","customer_id":"cust-7"}

При разработке — читаемая строка:

2026-06-18T10:02:00.123Z INFO order_created order_id=ord-99 customer_id=cust-7

Логгер создаётся один раз в main и передаётся в компоненты через конструкторы — не через глобальную переменную и не через slog.Default().

Логгер через конструктор

Частая ошибка — хранить логгер в глобальной переменной пакета или вызывать slog.Default() прямо внутри методов. Проблема: логгер нельзя подменить в тестах, нельзя добавить к нему постоянные поля.

Правильно: логгер — поле структуры, передаётся через конструктор.

// internal/order/handler.go
type OrderHandler struct {
    log    *slog.Logger
    orders OrderService
}

func NewOrderHandler(log *slog.Logger, orders OrderService) *OrderHandler {
    return &OrderHandler{
        log:    log.With("component", "order_handler"),
        orders: orders,
    }
}

log.With("component", "order_handler") создаёт дочерний логгер — все записи этого компонента автоматически получат поле component=order_handler без повторения в каждом вызове.

Инициализация в main:

// cmd/server/main.go
logger := platform_log.New(cfg.AppEnv)
orderHandler := order.NewOrderHandler(logger, orderService)
productHandler := product.NewProductHandler(logger, productService)

Структурные поля вместо форматирования строк

Интуитивно хочется писать так:

log.Info(fmt.Sprintf("order created: %v", order.ID)) // плохо

Но тогда значение уходит в строку msg и теряется как отдельное поле — его нельзя отфильтровать.

Правильно — отдельные ключ-значение аргументы:

h.log.InfoContext(ctx, "order_created",
    slog.String("order_id", order.ID),
    slog.String("customer_id", order.CustomerID),
)

Имя события — snake_case существительное с глаголом (order_created, payment_failed). Поля — в той же форме (order_id, customer_id). Это делает запись фильтруемой: в Loki можно написать {msg="order_created"} | order_id="ord-99".

Обратите внимание на InfoContext вместо Info: контекстные варианты (InfoContext, WarnContext, ErrorContext) передают активный OpenTelemetry-span в bridge, который автоматически добавляет trace_id и span_id к каждой записи.

Уровни логов

Четыре уровня — и у каждого конкретный смысл:

ERROR — что-то пошло не так и мы этого не ожидали: паника, сбой базы данных, недоступность платёжного провайдера. Всегда с полем error.

h.log.ErrorContext(ctx, "order_repository_failed",
    slog.String("order_id", cmd.OrderID),
    slog.String("error", err.Error()),
)

WARN — ожидаемая деградация: запрос не прошёл валидацию, повторная попытка подключения, сторонний сервис работает медленно.

h.log.WarnContext(ctx, "payment_provider_retry",
    slog.String("order_id", cmd.OrderID),
    slog.Int("attempt", attempt),
)

INFO — значимое событие в домене: заказ создан, пользователь зарегистрирован, задача завершена.

h.log.InfoContext(ctx, "order_confirmed",
    slog.String("order_id", order.ID),
    slog.String("customer_id", order.CustomerID),
)

DEBUG — детали для отладки. В продакшне выключены по умолчанию.

h.log.DebugContext(ctx, "order_aggregate_snapshot",
    slog.Any("order", order),
)

Частая ошибка: писать INFO на каждый входящий HTTP-запрос прямо в обработчике. Это шум — access-лог ведёт chi-middleware отдельно.

requestId и userId через context.Context

В Java есть MDC — хранилище полей, привязанное к потоку. В Go потоков нет, горутины не имеют локального хранилища. Вместо этого поля путешествуют через context.Context.

Middleware создаёт идентификатор запроса и кладёт его в контекст:

// internal/platform/middleware/reqid.go
type ctxKey string

const ctxRequestID ctxKey = "request_id"

func RequestID(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        id := r.Header.Get("X-Request-Id")
        if id == "" {
            id = uuid.NewString()
        }
        ctx := context.WithValue(r.Context(), ctxRequestID, id)
        w.Header().Set("X-Request-Id", id)
        next.ServeHTTP(w, r.WithContext(ctx))
    })
}

На краю обработчика — вспомогательная функция обогащает логгер полями из контекста:

// internal/platform/log/ctx.go
func FromCtx(ctx context.Context, log *slog.Logger) *slog.Logger {
    var args []any
    if id, ok := ctx.Value(ctxRequestID).(string); ok {
        args = append(args, slog.String("request_id", id))
    }
    if uid, ok := ctx.Value(ctxUserID).(string); ok {
        args = append(args, slog.String("user_id", uid))
    }
    return log.With(args...)
}

HTTP-обработчик вызывает её один раз в начале:

func (h *CustomerHTTPHandler) GetProfile(w http.ResponseWriter, r *http.Request) {
    log := platform_log.FromCtx(r.Context(), h.log)
    customerID := chi.URLParam(r, "id")
    profile, err := h.customers.GetProfile(r.Context(), customerID)
    if err != nil {
        log.WarnContext(r.Context(), "customer_profile_not_found",
            slog.String("customer_id", customerID),
            slog.String("error", err.Error()),
        )
        httperr.Write(w, r, err)
        return
    }
    log.InfoContext(r.Context(), "customer_profile_fetched",
        slog.String("customer_id", customerID),
    )
    render.JSON(w, r, profile)
}

Порядок middleware в chi важен: OTel-middleware регистрируется первым (чтобы span был открыт), затем RequestID и Auth:

r := chi.NewRouter()
r.Use(otelhttp.NewMiddleware("order-service"))
r.Use(RequestID)
r.Use(Auth(tokenVerifier))

Автоматический traceId через OTel-bridge

Если в проекте используется OpenTelemetry, trace_id и span_id можно добавлять в логи автоматически — через otelslog bridge. Тогда не нужно руками тянуть идентификатор трейса из контекста.

// internal/platform/log/setup.go
import (
    "go.opentelemetry.io/contrib/bridges/otelslog"
    slogmulti "github.com/samber/slog-multi"
)

func NewWithOTel(env string) *slog.Logger {
    var base slog.Handler
    if env == "production" {
        base = slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: slog.LevelInfo})
    } else {
        base = slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{Level: slog.LevelDebug})
    }
    otelHandler := otelslog.NewHandler("order-service",
        otelslog.WithLoggerProvider(otel.GetLoggerProvider()),
    )
    return slog.New(slogmulti.Fanout(base, otelHandler))
}

slogmulti.Fanout направляет каждую запись одновременно в оба обработчика: в stdout для оператора и в OTel-pipeline для трейс-коллектора. Достаточно везде использовать InfoContext(ctx, ...) — bridge сам достанет span из контекста.

Логи на границах с внешним миром

Хорошее место для логирования — точки, где сервис пересекает границу: HTTP-вызов во внешний сервис, запрос к базе данных, работа планировщика.

Адаптер к платёжному провайдеру:

// internal/payment/http_adapter.go
func (a *PaymentHTTPAdapter) Charge(ctx context.Context, cmd ChargeCommand) (*ChargeResult, error) {
    a.log.InfoContext(ctx, "payment_charge_started",
        slog.String("order_id", cmd.OrderID),
    )
    resp, err := a.client.Do(req.WithContext(ctx))
    if err != nil {
        a.log.ErrorContext(ctx, "payment_charge_network_failed",
            slog.String("order_id", cmd.OrderID),
            slog.String("error", err.Error()),
        )
        return nil, fmt.Errorf("charge: %w", err)
    }
    a.log.InfoContext(ctx, "payment_charge_completed",
        slog.String("order_id", cmd.OrderID),
    )
    return result, nil
}

Запрос к базе данных:

// internal/order/postgres_repository.go
func (r *OrderPostgresRepository) Load(ctx context.Context, id string) (*Order, error) {
    r.log.DebugContext(ctx, "order_load_started", slog.String("order_id", id))
    row, err := r.queries.GetOrder(ctx, id)
    if err != nil {
        r.log.WarnContext(ctx, "order_not_found", slog.String("order_id", id))
        return nil, &apperr.NotFoundError{Entity: "Order", ID: id}
    }
    return mapOrderRow(row), nil
}

Внутри бизнес-логики — только события принятых решений. «Вошли в метод» или «загрузили N строк» — это шум, не информация.

Персональные данные в логах

Персональные данные (ФИО, email, номер телефона, токены, данные карты) нельзя писать в логи. Причина простая: логи хранятся дольше, чем нужно, доступны большему числу людей, чем нужно, и их сложно вычистить постфактум.

Правило: в лог идут только идентификаторы (order_id, customer_id, amount), не значения полей (card_token, address, email).

Частые ошибки и как их избежать:

• fmt.Sprintf("user: %+v", user) — попадут все поля структуры, включая email. Логировать только user.ID.
• slog.Any("request_body", body) для платёжного эндпоинта — может попасть номер карты. Логировать только нужные поля явно.
• log.ErrorContext(ctx, err.Error()) — сообщение об ошибке иногда содержит введённые пользователем данные. Использовать slog.String("error", err.Error()) как отдельный атрибут и проверять, что туда попадает.

Коротко

• Два обработчика: slog.NewJSONHandler в продакшне (для Loki/ELK), slog.NewTextHandler при разработке — выбор по APP_ENV при старте.
• Логгер — поле структуры, передаётся через конструктор. slog.Default() и глобальные переменные не использовать.
• Все переменные — через slog.String / slog.Int / slog.Any, не через fmt.Sprintf в строку сообщения.
• Всегда InfoContext(ctx, ...), не Info(...) — тогда OTel-bridge подшивает trace_id и span_id автоматически.
• requestId и userId хранятся в context.Context, middleware кладёт их туда, обработчик читает через вспомогательную функцию.
• Уровни: ERROR — неожиданный сбой, WARN — ожидаемая деградация, INFO — доменное событие, DEBUG — детали отладки.
• Персональные данные в логах запрещены: только идентификаторы, не значения.

Что почитать дальше

• Tracing в Go — OTel-slog bridge, ручные span для обработчиков.
• Metrics в Go — promauto, RED-middleware на chi, бизнес-метрики.
• Context propagation в Go — как requestId и userId путешествуют через context.Context.