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

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

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

Kubernetes завершает поды по определённому сценарию. Сначала выполняется preStop-хук (например, sleep 10s), потом pod'у отправляется SIGTERM, и начинается отсчёт terminationGracePeriodSeconds. Стандартное значение — 60 секунд. Если процесс не завершился — приходит SIGKILL.

Важная деталь: preStop-хук отрабатывает до SIGTERM. Значит Go-процессу остаётся 60 секунд после получения сигнала, а не 60 минус preStop.

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

ФазаСколько времени
preStop sleep (Kubernetes)10s — до SIGTERM
Остановка Kafka-consumerдо 15s
Горутины и outbox-relayдо 20s
Drain HTTP-соединенийдо 25s
Закрытие pgxpoolменьше 1s

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

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

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

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

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

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

  • Уменьшить MinBytes/MaxBytes у kafka-go reader — consumer обрабатывает меньше за итерацию.
  • Уменьшить размер пачки 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 потом можно смотреть по сервисам и настроить алерт:

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

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

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

Сразу при получении сигнала — до любых действий — нужно записать факт 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).

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

T=0 SIGTERM после preStop-паузы в 10 с T=0 SetNotReady: /health/ready отвечает 503 T=0 cancelConsumer: потребитель видит ctx.Done() T=0…15 с ждём потребителя: офсет зафиксирован, reader закрыт T=15…35 с ждём планировщик: батч outbox дожимает итерацию T=35…50 с srv.Shutdown: текущие HTTP-запросы дожаты T=50 с pool.Close и запись метрики длительности

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

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

Коротко

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

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