Логирование¶

Одинаковый формат логов во всех сервисах: одна команда в Grafana должна одинаково работать для user, review, media и любого будущего сервиса.

`log/slog` — стандарт¶

Используй log/slog из stdlib. Никаких logrus, zap, zerolog, log.Printf в прод-коде.

Handler¶

JSON → stdout. Никогда в файл. Никогда plain text в prod (plain-текст допустим только в локальной отладке через SERVICE_LOG_FORMAT=text, если сервис поддерживает такой флаг).

Настройка в cmd/server/main.go:

func newLogger(level string) *slog.Logger {
    var lv slog.Level
    _ = lv.UnmarshalText([]byte(level))
    h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
        Level:     lv,
        AddSource: false,
    })
    return slog.New(h).With(
        "service", "review",
    )
}

service навешивается один раз на корневой логгер — дальше везде присутствует как структурное поле. AddSource=false в prod: путь к файлу и номер строки съедает cardinality в логах; включай в dev.

Уровни¶

Уровень	Когда использовать	Пример
DEBUG	Локальная отладка. В prod выключен (`INFO`-порог).	`log.Debug("cache lookup", "key", key, "hit", hit)`
INFO	Бизнес-события: «что произошло».	`log.Info("review created", "review_id", r.ID, "user_id", userID)`
WARN	Retryable ошибки, degraded path, таймаут одного из соседей.	`log.Warn("redis timeout, falling back to db", "err", err)`
ERROR	Unhandled ошибка, требует внимания.	`log.Error("publish outbox", "err", err, "topic", topic)`

DEBUG в prod всегда выключен. INFO — базовый уровень прод-логгера.

Не пиши INFO на каждый HTTP-запрос — access-лог пишет middleware. INFO на уровне service — только значимые события (создан/удалён/сменил состояние).

Обязательные структурные поля¶

На каждой записи (через middleware log.FromCtx(ctx)), как минимум:

Поле	Значение
`request_id`	Из `X-Request-Id` header'а. Генерируется `RequestID` middleware на входе.
`user_id`	`bigint` пользователя, если запрос authenticated. Иначе отсутствует.
`route`	Паттерн маршрута (`/v1/reviews/{id}`), не «фактический URL».
`service`	Имя сервиса. Навешивается один раз в `newLogger`.
`correlation_id`	Cross-service id, прокидывается из header'а и из Kafka metadata.

Логгер прокидывается через ctx:

package log

type ctxKey int
const ctxKeyLogger ctxKey = iota

func Into(ctx context.Context, l *slog.Logger) context.Context {
    return context.WithValue(ctx, ctxKeyLogger, l)
}

func FromCtx(ctx context.Context) *slog.Logger {
    if l, ok := ctx.Value(ctxKeyLogger).(*slog.Logger); ok && l != nil {
        return l
    }
    return slog.Default()
}

Middleware оборачивает базовый логгер per-request:

func WithLog(base *slog.Logger) func(http.Handler) http.Handler {
    return func(next http.Handler) http.Handler {
        return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
            l := base.With(
                "request_id", middleware.GetReqID(r.Context()),
                "route", chi.RouteContext(r.Context()).RoutePattern(),
            )
            ctx := log.Into(r.Context(), l)
            next.ServeHTTP(w, r.WithContext(ctx))
        })
    }
}

Handler / service пишет так:

log.FromCtx(ctx).Info("review created",
    "review_id", review.ID,
    "place_id", review.PlaceID,
    "user_id", userID,
)

Ошибки¶

log.FromCtx(ctx).Error("publish outbox",
    "err", err,
    "topic", topic,
    "aggregate_id", id,
)

Сообщение — статическое: "publish outbox", а не "publish outbox failed: "+err.Error(). Это даёт возможность группировать ошибки в дашборде по сообщению.
Ошибка — поле: "err", err. slog сам вызовет err.Error() и положит как строку в JSON.
Никогда не используй err.Error() как сообщение.

PII запрещено в логах¶

Категорически нельзя писать в лог в открытом виде:

email,
phone,
полный JWT (access/refresh),
password, password_hash,
OAuth access_token, OAuth refresh_token,
device_id (может быть идентификатором устройства),
IP-адрес (в ряде юрисдикций — PII).

Если нужно увидеть поле в логе — маскируй. Хелперы живут в pkg/pii/:

package pii

import "strings"

// MaskEmail: "abdymaget@gmail.com" → "a***@gmail.com"
func MaskEmail(s string) string {
    at := strings.Index(s, "@")
    if at <= 0 {
        return "***"
    }
    return s[:1] + "***" + s[at:]
}

// MaskPhone: "+77011234567" → "+7 701 *** ** 67"
func MaskPhone(s string) string {
    if len(s) < 4 {
        return "***"
    }
    return "*** " + s[len(s)-4:]
}

// MaskToken: возвращает короткий непривязанный хеш для поиска по логам.
func MaskToken(s string) string {
    sum := sha256.Sum256([]byte(s))
    return hex.EncodeToString(sum[:])[:16]
}

Использование:

log.FromCtx(ctx).Info("login attempt",
    "user_id", userID,
    "email_masked", pii.MaskEmail(req.Email),
)

Что можно логировать¶

user_id (bigint) — это публичный технический идентификатор, он уже безопасен.
review_id, place_id, session_id — внутренние ID.
event_type, topic — метаданные Kafka.
duration_ms, status_code.
error_code (sentinel-код ошибки) — не полное сообщение, которое мог бы показать пользователь. error_code=not_found, а не error_message="user 42 not found" (в последнем утекает существование конкретного id).

Sampling для hot path¶

Если endpoint обрабатывает > 1000 req/s — логировать каждый успешный запрос не нужно, это только греет диск. Для таких маршрутов sample 10% на уровне middleware:

func SampledLog(base *slog.Logger, rate float64) func(http.Handler) http.Handler {
    return func(next http.Handler) http.Handler {
        return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
            if rand.Float64() > rate {
                next.ServeHTTP(w, r)
                return
            }
            // ...логируем полностью...
            next.ServeHTTP(w, r)
        })
    }
}

Ошибки (WARN/ERROR) сэмплировать не надо — они важны каждая.

Correlation-Id vs Request-Id¶

Два разных ID, не путай:

Request-Id (X-Request-Id, поле request_id в логе) — идентификатор одного HTTP-запроса. Генерируется на входе в сервис (chimw.RequestID или приходит от Gateway) и живёт только в пределах этого запроса.
Correlation-Id (X-Correlation-Id, Kafka metadata Correlation-Id, поле correlation_id в логе) — идентификатор цепочки, которая может пройти через несколько сервисов и Kafka. Может совпадать с Request-Id (если Gateway положил то же значение), но не обязан.
traceparent — W3C-стандарт OpenTelemetry (trace_id + span_id), отдельный канал для distributed tracing. Не путай с Correlation-Id.

Correlation-Id прокидывается через всё:

HTTP: header X-Correlation-Id, читается middleware, кладётся в ctx и в логгер.
Kafka: metadata Correlation-Id (envelope) → при consume ложится в ctx через Watermill middleware CorrelationID.
Logger: поле correlation_id присутствует во всех записях одного запроса/сообщения.

Если header не пришёл — middleware генерирует ULID. Для исходящих HTTP-вызовов в другой сервис — передавай X-Correlation-Id из ctx.

Запреты¶

fmt.Println / fmt.Printf / log.Print в прод-коде — запрещены. CI-lint (forbidigo) отлавливает.
panic("...") ради «залогировать и упасть» — нет. Возвращай error, логируй на ERROR, решение об exit принимает вызывающий уровень.
Логирование в цикле на каждый элемент — убивает производительность и читаемость. Лог на батч — да, лог на каждую итерацию — нет.
log.FromCtx(context.Background()) в handler/service — это значит, что ты где-то потерял per-request логгер. Чини цепочку ctx.

Пример полной цепочки¶

func (h *ReviewHandler) CreateReview(w http.ResponseWriter, r *http.Request) {
    ctx := r.Context()
    var req CreateReviewRequest
    if err := decodeJSON(r, &req); err != nil {
        writeError(w, http.StatusBadRequest, "invalid_request", "bad json")
        return
    }
    if err := validate(req); err != nil {
        writeError(w, http.StatusBadRequest, "invalid_input", "validation failed")
        return
    }
    userID, _ := middleware.UserIDFrom(ctx)
    review, err := h.svc.Create(ctx, service.CreateReviewCommand{
        UserID:  userID,
        PlaceID: req.PlaceID,
        Rating:  req.Rating,
    })
    if err != nil {
        log.FromCtx(ctx).Warn("create review failed", "err", err, "place_id", req.PlaceID)
        mapServiceError(w, err)
        return
    }
    log.FromCtx(ctx).Info("review created", "review_id", review.ID, "place_id", review.PlaceID)
    writeJSON(w, http.StatusCreated, map[string]any{"data": review})
}

Вывод в stdout:

{"time":"...","level":"INFO","msg":"review created","service":"review","request_id":"01HZ..","route":"/v1/reviews","user_id":42,"review_id":1001,"place_id":7}

По этому JSON-у Grafana/Loki строит поиск за 5 секунд. По fmt.Printf("review %d created\n", id) — никак.

См. также¶

observability.md — как логи соединяются с метриками и трейсами.
security.md — правила маскирования PII, запрет логировать секреты и Authorization header.