Бюджеты shutdown и наблюдаемость в Go

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

Когда приложение завершает работу неожиданно долго, сложно понять, что именно «встало». Без метрики и нормального лога — это чёрный ящик: деплой завис, алерты пришли, а где конкретно — непонятно. В этой статье разберём, сколько времени есть у Go-приложения на завершение, как разложить это время по фазам и как сделать завершение видимым.

Сколько времени есть у приложения

Kubernetes завершает поды по определённому сценарию. Отсчёт terminationGracePeriodSeconds начинается в момент удаления пода; затем kubelet выполняет preStop-хук (например, sleep 10) и только после него отправляет процессу SIGTERM. Если по истечении бюджета процесс всё ещё жив — приходит SIGKILL. Значение по умолчанию — 30 секунд; для сервиса с Kafka и базой его поднимают до 60, как это выбирают — в статье про Kubernetes.

Важная деталь: preStop-хук отрабатывает до SIGTERM, но из того же бюджета. Значит Go-процессу после сигнала остаётся не 60 секунд, а 60 минус preStop — при паузе в 10 секунд это 50. А если хук сам не уложился в бюджет, kubelet оборвёт его и пришлёт SIGTERM, оставив процессу минимальные две секунды до SIGKILL.

Типичный бюджет для Go-сервиса с Kafka и PostgreSQL:

Сумма фаз больше оставшихся 50 секунд, но это нормально: не все максимумы случаются одновременно. На реальной нагрузке завершение обычно занимает 15–35 секунд. Но если что-то пойдёт не так — запас нужен.

В Go shutdown — явная последовательность в main, не параллельные фазы как в Spring. Wall clock — это сумма времени каждого шага по порядку.

Что делать, если не укладываемся в бюджет

Первый порыв — увеличить terminationGracePeriodSeconds до 90 секунд. Это ошибка:

• При rolling deploy оба поколения кода работают против одной схемы БД дольше.
• kubectl drain и автомасштабирование узлов ждут, пока каждый выселяемый под не отработает свой бюджет: с бюджетом 90 обновление узла растягивается пропорционально, а ждёт его тот, кто обновляет кластер.

Правильный путь — сокращать объём работы в каждой фазе:

• Укоротить таймаут обработки одного сообщения у потребителя: после отмены контекста он доводит только текущее сообщение, и дольше этого таймаута его ждать не придётся.
• Уменьшить размер пачки outbox: LockOutboxBatch(ctx, 100) → LockOutboxBatch(ctx, 20).
• В тяжёлых горутинах разбить работу на короткие итерации с проверкой ctx.Done() после каждого шага.

Метрика времени завершения

Чтобы знать, сколько реально занимал shutdown на каждом деплое, заводится Prometheus gauge app_shutdown_duration_seconds. Его нужно записать после того, как все фазы завершены — удобно делать это через defer.

// 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())
    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)
    }()

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

shutdownFns — явный список в main в нужном порядке:

// cmd/order-service/main.go
shutdownFns := []func(){
    func() { appState.SetNotReady() },       // readiness → 503
    func() { cancelConsumer() },             // сигнал consumer'у остановиться
    func() { consumerWg.Wait() },            // ждём коммит offset
    func() { schedulerWg.Wait() },           // ждём outbox-батч
    func() { srv.Shutdown(shutCtx) },        // дожимаем in-flight HTTP
    func() {
        pool.Close()
        slog.InfoContext(ctx, "pgxpool closed")
    },
}

Здесь спрятана ловушка, которой не видно в коде. Prometheus приходит за метриками сам, раз в 15–60 секунд, а gauge выставлен последней строкой остановки: HTTP-сервер с /metrics уже закрыт шагом раньше, и через миллисекунды процесс выйдет. В pull-модели это значение почти никогда не будет прочитано. Поэтому строка лога с duration_s рядом — не дубль, а основной источник: агент логов заберёт её и после выхода процесса. Gauge начинает работать, когда метрики уходят push-моделью — экспортер OTLP с вызовом MeterProvider.Shutdown(ctx) после записи, который досылает последние значения, или Pushgateway.

В Prometheus потом можно смотреть по сервисам и настроить алерт:

# Максимальное время завершения по сервисам
max by (service) (app_shutdown_duration_seconds)

# Алерт: shutdown занял больше 40 из 50 секунд после SIGTERM
max(app_shutdown_duration_seconds) > 40

Первое, что нужно залогировать

Сразу при получении сигнала — до любых действий — нужно записать факт SIGTERM:

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

Go-процесс не знает причину SIGTERM — это deploy, масштабирование вниз (HPA scale-down) или что-то ещё. Определять причину в коде не нужно: os.Signal эту информацию не несёт. Причину смотрят в kubectl describe pod <pod-name> по полю Events.

Частая ошибка: закрытие пула на Error

При завершении приложения pgxpool закрывается штатно — это нормальная операция, не ошибка. Если логировать её как slog.Error, каждый rolling deploy будет генерировать алерты в мониторинг.

// Правильно: закрытие пула — Info
pool.Close()
slog.InfoContext(ctx, "pgxpool closed")

// Правильно: ошибка при закрытии kafka writer — другое дело
if err := producer.Close(); err != nil {
    slog.ErrorContext(ctx, "kafka writer close error", "error", err)
} else {
    slog.InfoContext(ctx, "kafka writer closed")
}

Команда привыкает игнорировать ложные Error-сообщения в деплоях — и в какой-то момент пропускает реальный инцидент. Разделяйте «нормальное завершение» (Info) и «что-то сломалось» (Error).

Как выглядит полное завершение

На реальной нагрузке order-service укладывается в 15–25 секунд: consumer дренирует быстро, пачка outbox небольшая, HTTP-запросы короткие.

Коротко

• Бюджет terminationGracePeriodSeconds считается с момента удаления пода: preStop идёт до SIGTERM, но из тех же 60 секунд, процессу остаётся 50.
• Shutdown в Go — явная последовательность шагов: consumer → горутины → HTTP → база. Wall clock — сумма фаз.
• Если не укладываетесь — уменьшайте размер пачек и итераций, не увеличивайте terminationGracePeriodSeconds.
• app_shutdown_duration_seconds через promauto.NewGauge + defer после последнего шага; в pull-модели её не успеют забрать, поэтому длительность обязательно и в лог, а gauge — при push через OTLP или Pushgateway.
• Первое действие при получении SIGTERM — лог факта. Причину сигнала смотрят через kubectl describe pod.
• Нормальное завершение (закрытие пула, consumer'а) — slog.Info, не slog.Error. Ошибка — только если что-то реально сломалось.

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

• HTTP drain в Go — как http.Server.Shutdown дожидается in-flight запросов.
• Kafka shutdown в Go — kafka-go reader, коммит offset и закрытие writer.
• БД и persistence в Go — pgxpool в правильную фазу, активные транзакции.
• Kubernetes и graceful shutdown — terminationGracePeriodSeconds, probes, maxUnavailable.