Логирование ошибок в Go — slog, WARN / ERROR, один раз на edge

Опирается на правила: R-ERR-LOG-1 … R-ERR-LOG-4 и R-ERR-LOG-X1 … R-ERR-LOG-X2 из Error Handling Style Guide → раздел 4. Логирование исключений.

Важно знать

• Domain → slog.WarnContext. Ожидаемая ошибка бизнес-правила — не баг, ERROR создаст ложные срабатывания алёртов.
• Validation → не логируем. Как и Domain, это ожидаемый путь: сигнал идёт только в метрику app_errors_total{type="validation"}. Логирование каждой ошибки валидации создаст шум без пользы.
• Integration → Warn при закрытом CB (единичный сбой), Error при открытом CB (инцидент).
• Technical и panic → slog.ErrorContext + полный стектрейс + контекст запроса.
• Логируем один раз — на edge, в httperr.Write / Recoverer-middleware. В UseCase Handler и домене — ноль slog.*.
• slog.WarnContext(ctx, "msg", "error", err) — не slog.Warn(err.Error()). Передавай err-атрибутом, а не строкой — иначе теряется структура и stacktrace.
• slog.Error(...); return err — двойное логирование: edge залогирует ещё раз.
• Correlation через context.Context — traceId и requestId прокидываются через slog.With в middleware, не передаются в каждый вызов вручную.

log/slog — стандартная библиотека Go (1.21+), JSON-handler в проде. Correlation через context.Context + middleware, который обогащает логгер до начала обработки запроса. Раскрытие правил R-ERR-LOG-* ниже.

Настройка slog и correlation

В main.go:

func main() {
	slog.SetDefault(slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
		Level: slog.LevelInfo,
	})))
	// ...
}

Middleware обогащает контекст трейс-идентификаторами:

// edge/middleware/trace.go
func TraceContext(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		traceID := r.Header.Get("X-Trace-Id")
		if traceID == "" {
			traceID = uuid.NewString()
		}
		ctx := r.Context()
		logger := slog.Default().With(
			"traceId", traceID,
			"path", r.URL.Path,
			"method", r.Method,
		)
		ctx = ctxlog.WithLogger(ctx, logger)
		next.ServeHTTP(w, r.WithContext(ctx))
	})
}

ctxlog.WithLogger / ctxlog.From — небольшая утилита, кладёт *slog.Logger в контекст. Всё остальное вызывает ctxlog.From(ctx).WarnContext(ctx, ...) — без передачи логгера явным аргументом.

R-ERR-LOG-1 — Domain → Warn

Domain — ожидаемая ошибка: пользователь запросил что-то, что нарушает бизнес-правило. Это нормальный рабочий путь, не баг.

// edge/httperr/log.go
func logByKind(ctx context.Context, k apperr.Kind, err error) {
	logger := ctxlog.From(ctx)
	switch k {
	case apperr.Domain:
		logger.WarnContext(ctx, "domain rule violated",
			"error", err,
			"errorType", typeName(err),
		)
	// ...
	}
}

Почему Warn, не Error:

• Error уровень — сигнал «здесь нужен человек, что-то сломалось». Domain-ошибки — не сломалось, это функция системы.
• Если ERROR на InsufficientFundsError — алёрт-дежурство будет проснуто в 3:00 из-за того, что у пользователя кончились деньги.
• Prometheus-метрика app_errors_total{type="domain"} уже отслеживает рост — алёрт по метрике, не по log-level.

Validation ошибки логируются на том же низком уровне, что и Domain: сигнал о валидационной ошибке идёт только в метрику (app_errors_total{type="validation"}), лог не пишется. Ввод некорректных данных — нормальный путь пользователя, а не инцидент. Детали валидационных ошибок клиент получает напрямую через errors[] в ProblemDetails-ответе.

R-ERR-LOG-2 — Integration → Warn / Error по состоянию CB

Единичный сбой внешки — ожидаем, транзиентно. Открытый CB — инцидент.

case apperr.Integration:
	if errors.Is(err, gobreaker.ErrOpenState) {
		logger.ErrorContext(ctx, "circuit breaker open — upstream degraded",
			"error", err,
			"errorType", typeName(err),
		)
	} else {
		logger.WarnContext(ctx, "integration failure",
			"error", err,
			"errorType", typeName(err),
		)
	}

Когда CB переходит в открытое состояние, gobreaker начинает сразу возвращать ErrOpenState без вызова внешки. Первый такой Error в логах — сигнал дежурному: внешняя система недоступна, не «один запрос упал».

Для Sber-специфичных операций добавляем систему в атрибут:

var gw *payment.GatewayError
if errors.As(err, &gw) {
	logger.WarnContext(ctx, "payment gateway failure",
		"error", err,
		"system", "sber-payment",
		"operation", gw.Op,
	)
}

R-ERR-LOG-3 — Technical и panic → Error + стектрейс

Technical и неклассифицированные ошибки — это баги, нужен полный контекст.

default: // Technical
	logger.ErrorContext(ctx, "unexpected error",
		"error", err,
		"errorType", typeName(err),
	)

Recoverer-middleware при panic:

// edge/middleware/recover.go
defer func() {
	if v := recover(); v != nil {
		logger := ctxlog.From(r.Context())
		logger.ErrorContext(r.Context(), "panic recovered",
			"panic", fmt.Sprintf("%v", v),
			"stack", string(debug.Stack()),
		)
		appErrorsTotal.WithLabelValues("unexpected", "panic").Inc()
		httperr.WritePanic(w, r)
	}
}()

slog при "error", err сериализует err.Error(). Для полного стектрейса Go-программы используем debug.Stack() — явно, потому что slog не добавляет stacktrace автоматически (в отличие от logrus с WithError).

R-ERR-LOG-4 — один раз, на edge

// edge/httperr/render.go
func Write(w http.ResponseWriter, r *http.Request, err error) {
	kind := apperr.KindOf(err)
	logByKind(r.Context(), kind, err) // ← ОДИН РАЗ, здесь
	// ...
}

В UseCase Handler — никакого slog.*:

// ХОРОШО
func (h *CancelOrderHandler) Handle(ctx context.Context, cmd CancelOrderCommand) error {
	ord, err := h.repo.FindByID(ctx, cmd.OrderID)
	if err != nil {
		return fmt.Errorf("cancel order %s: find: %w", cmd.OrderID, err)
	}
	if err := ord.Cancel(cmd.Reason); err != nil {
		return fmt.Errorf("cancel order %s: %w", cmd.OrderID, err)
	}
	return h.repo.Save(ctx, ord)
}

Никакого slog.Warn или slog.Error внутри handler'а — ошибка пробросится с контекстом "cancel order <id>: ..." в сообщении, edge залогирует её один раз.

Что запрещено

R-ERR-LOG-X1 — двойное логирование:

// ПЛОХО
func (r *orderRepo) FindByID(ctx context.Context, id string) (Order, error) {
	row, err := r.db.QueryRowContext(ctx, query, id)
	if err != nil {
		slog.ErrorContext(ctx, "db query failed", "error", err) // ← логируем здесь
		return Order{}, fmt.Errorf("find order: %w", err)       // ← И пробрасываем
	}
	// ...
}

Edge вызовет logByKind и залогирует ту же ошибку второй раз. В логах — два события для одного запроса, трудно разобраться, что это один сбой. В метриках — один инкремент (правильно), но в логах — шум.

R-ERR-LOG-X2 — потеря структуры:

// ПЛОХО
slog.Error(err.Error())                         // ← строка, не структура; нет context
slog.ErrorContext(ctx, err.Error())              // ← то же самое
slog.WarnContext(ctx, "domain", "msg", err.Error()) // ← stringified

// ХОРОШО
slog.ErrorContext(ctx, "unexpected error", "error", err)
slog.WarnContext(ctx, "domain rule violated", "error", err, "errorType", typeName(err))

slog при "error", err вызывает err.Error() — строка сохраняется. Но передача err как value сохраняет тип для structured backends (OpenTelemetry, Loki), которые умеют извлекать атрибуты.

Куда дальше

• Иерархия ошибок — откуда берётся Domain / Integration / Technical.
• Где return, где обрабатывать — почему логирование только на edge.
• Mapping в ProblemDetails — logByKind вызывается внутри httperr.Write.
• Observability ошибок — метрика app_errors_total как дополнение к логам.
• Retry-семантика — Integration Error при открытом CB влияет на алёрты.
• Errors-as-values vs panic — Recoverer-middleware логирует panic как Error.
• Shared-контракт R-ERR-LOG — нормативные формулировки.