Бюджеты и observability — раскладка 60s budget и app_shutdown_duration в Go

Опирается на правила: R-SHUT-OBS-1 … R-SHUT-OBS-3 и R-SHUT-OBS-X1 из Graceful Shutdown Style Guide → раздел 8. Бюджеты и observability.

Важно знать

• 60s total budget = preStop 10s + http.Server.Shutdown до 25s + горутины/outbox до 20s + kafka-go consumer до 15s.
• Фазы Go идут последовательно — в main shutdown-последовательность явная, wall clock = сумма фаз (не max). Укладываться нужно в 60s минус preStop = 50s.
• Не помещается? — сократить batch (100 → 20), не увеличивать terminationGracePeriodSeconds.
• Метрика app_shutdown_duration_seconds — promauto.NewGauge + запись через defer после всей shutdown-последовательности.
• Лог факта SIGTERM — первым, до appState.SetNotReady(): slog.InfoContext(ctx, "получили SIGTERM, начинаем graceful shutdown").
• Нормальное закрытие pgxpool/consumer — slog.Info, не slog.Error; иначе каждый деплой генерирует ложный алерт.
• Причина SIGTERM — kubectl describe pod, не в коде. Go-процесс не знает, deploy это или HPA scale-down.
• Без observability первый инцидент «shutdown не уложился в budget» — чёрный ящик.

Graceful shutdown в Go — явная последовательность: os.Signal → отменить consumer-контекст → дождаться горутин через WaitGroup → srv.Shutdown(ctx) → pool.Close(). Каждая фаза занимает реальное время. Без метрики и структурного лога невозможно понять, какая фаза поглотила бюджет во время инцидента.

Раскладка 60s budget

R-SHUT-OBS-1: cumulative timeline для Go-стека.

71s > 60s — но preStop идёт до SIGTERM: k8s ждёт окончания preStop, потом посылает SIGTERM и начинает отсчёт terminationGracePeriodSeconds. Значит Go-процессу доступно 60s после получения сигнала. Реально consumer + горутины + HTTP не все максимальны одновременно; wall clock обычно 20–35s.

В отличие от Spring (phases частично параллельны через SmartLifecycle), Go-shutdown — явная последовательность в main. Порядок фаз важен: consumer/горутины останавливаются до srv.Shutdown, пул закрывается последним.

Если не помещается

Не увеличивать terminationGracePeriodSeconds до 90s:

• Длинный rolling deploy = долгое «два кода против одной схемы БД».
• k8s kubelet default drain timeout — 30s; kubectl drain зависает.

Сократить scope:

• kafka-go reader — уменьшить MinBytes/MaxBytes, consumer обрабатывает меньше за итерацию.
• outbox-relay batch: LockOutboxBatch(ctx, 100) → LockOutboxBatch(ctx, 20).
• горутина с тяжёлым каскадом → разбить на короткие итерации с ctx.Done() проверкой.

Метрика app_shutdown_duration_seconds

R-SHUT-OBS-2: promauto gauge + slog.

// internal/server/server.go
package server

import (
    "context"
    "log/slog"
    "net/http"
    "os"
    "os/signal"
    "syscall"
    "time"

    "github.com/prometheus/client_golang/prometheus"
    "github.com/prometheus/client_golang/prometheus/promauto"
)

var shutdownDuration = promauto.NewGauge(prometheus.GaugeOpts{
    Name: "app_shutdown_duration_seconds",
    Help: "Duration of graceful shutdown in seconds",
})

func Run(ctx context.Context, srv *http.Server, cfg Config, shutdownFns []func()) error {
    sigC := make(chan os.Signal, 1)
    signal.Notify(sigC, syscall.SIGTERM, syscall.SIGINT)
    defer signal.Stop(sigC)

    errC := make(chan error, 1)
    go func() { errC <- srv.ListenAndServe() }()

    select {
    case sig := <-sigC:
        slog.InfoContext(ctx, "получили SIGTERM, начинаем graceful shutdown",
            "signal", sig.String()) // R-SHUT-OBS-3
    case err := <-errC:
        return err
    }

    start := time.Now()
    defer func() {
        dur := time.Since(start).Seconds()
        shutdownDuration.Set(dur)
        slog.InfoContext(ctx, "graceful shutdown завершён",
            "duration_s", dur) // R-SHUT-OBS-2
    }()

    slog.InfoContext(ctx, "graceful shutdown начат") // R-SHUT-OBS-2

    for _, fn := range shutdownFns {
        fn()
    }
    return nil
}

shutdownFns — явный список в main в правильном порядке:

// cmd/order-service/main.go
func main() {
    ctx := context.Background()
    pool, _ := pgxpool.New(ctx, cfg.DatabaseURL)
    appState := health.NewState()

    consumerCtx, cancelConsumer := context.WithCancel(ctx)
    var consumerWg, schedulerWg sync.WaitGroup

    consumerWg.Add(1)
    go func() {
        defer consumerWg.Done()
        if err := orderConsumer.Run(consumerCtx); err != nil {
            slog.ErrorContext(ctx, "order consumer stopped", "error", err)
        }
    }()

    schedulerWg.Add(1)
    go func() {
        defer schedulerWg.Done()
        outboxRelay.Run(consumerCtx, &schedulerWg)
    }()

    shutCtx, cancelShut := context.WithTimeout(context.Background(), cfg.ShutdownTimeout) // 25s
    defer cancelShut()

    shutdownFns := []func(){
        func() { appState.SetNotReady() },             // R-SHUT-CFG-3 — readiness → 503
        func() { cancelConsumer() },                   // R-SHUT-KFK-1 — сигнал consumer
        func() { consumerWg.Wait() },                  // ждём commit offset
        func() { schedulerWg.Wait() },                 // R-SHUT-SCHED-1 — ждём outbox batch
        func() { srv.Shutdown(shutCtx) },              // R-SHUT-HTTP-1 — drain in-flight
        func() {
            pool.Close()                               // R-SHUT-DB-1 — последним
            slog.InfoContext(ctx, "pgxpool closed")    // Info, не Error — R-SHUT-OBS-X1
        },
    }

    if err := server.Run(ctx, srv, cfg, shutdownFns); err != nil {
        slog.ErrorContext(ctx, "server error", "error", err)
        os.Exit(1)
    }
}

В Prometheus:

# Распределение по сервисам
max by (service) (app_shutdown_duration_seconds)

# Алерт если близко к budget (50s из 60s)
max(app_shutdown_duration_seconds) > 50

Лог факта SIGTERM

R-SHUT-OBS-3: Go-процесс не знает причину SIGTERM — это infrastructure-info.

В коде записываем только факт:

case sig := <-sigC:
    slog.InfoContext(ctx, "получили SIGTERM, начинаем graceful shutdown",
        "signal", sig.String())
    appState.SetNotReady()

Причину ищем через kubectl describe pod <pod-name>:

Events:
  Normal  Killing             kubelet  Stopping container order-service
  Normal  ScalingReplicaSet   dc       Scaled down replica set order-service-7c8d

Не пытаться определить причину в коде — os.Signal не несёт эту информацию.

Нормальное закрытие — Info, не Error

R-SHUT-OBS-X1: логировать закрытие пула и consumer на slog.Info, не slog.Error.

// ПРАВИЛЬНО — R-SHUT-OBS-X1
func () {
    pool.Close()
    slog.InfoContext(ctx, "pgxpool closed") // Info
}

// ПРАВИЛЬНО — закрытие kafka writer
if err := producer.Close(); err != nil {
    slog.ErrorContext(ctx, "kafka writer close error", "error", err) // Error только если реально сломалось
} else {
    slog.InfoContext(ctx, "kafka writer closed") // нормальное завершение — Info
}

Если pool.Close() и reader логировать на Error — каждый rolling deploy генерирует алерты в Slack/PagerDuty. Команда привыкает их игнорировать → реальный инцидент пропускается.

Полная временна́я шкала

T=0       SIGTERM (после preStop sleep 10s)
T=0       slog: "получили SIGTERM, начинаем graceful shutdown"
T=0       appState.SetNotReady()     → /health/ready → 503
T=0       cancelConsumer()           → consumer получает ctx.Done()
T=0..15   consumerWg.Wait()          → offset коммитится, reader закрывается
T=15..35  schedulerWg.Wait()         → outbox batch завершает итерацию
T=35..50  srv.Shutdown(shutCtx)      → in-flight HTTP дожимаются
T=50      pool.Close()               → slog: "pgxpool closed" (Info)
T=50      shutdownDuration.Set(50.0) → метрика
T=50      slog: "graceful shutdown завершён", duration_s=50

Реальный wall clock для order-service под нормальной нагрузкой — 15–25s: consumer дренирует быстро, outbox batch мал, HTTP-запросы укладываются в несколько секунд.

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

Куда дальше

• JVM/Spring конфигурация — Java-эквивалент: server.shutdown=graceful и ApplicationAvailability.
• БД и persistence — pgxpool.Pool.Close() в правильной фазе, активные транзакции.
• HTTP drain — http.Server.Shutdown и preStop 10s в chi-стеке.
• Kafka shutdown — kafka-go reader CommitMessages и writer.Close().
• Kubernetes — terminationGracePeriodSeconds: 60, probes, maxUnavailable: 0.
• Scheduled / async / outbox — sync.WaitGroup и ctx.Done() в outbox-relay.
• Идемпотентность in-flight — retry-safe операции при SIGTERM.