Бюджеты завершения и наблюдаемость graceful shutdown

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

Когда graceful shutdown занял слишком долго и pod выбили принудительно — как понять, что именно не успело? Без метрик и логов можно только гадать. Разберём, как рассчитать реалистичный бюджет времени и что добавить в код, чтобы замечать проблемы до аварии.

Откуда берётся 60 секунд

Kubernetes при удалении pod ждёт максимум terminationGracePeriodSeconds секунд и после убивает процесс. Стандартное значение — 60 секунд. Что успевает произойти за это время?

Shutdown состоит из нескольких шагов:

Если сложить максимумы — получится 70 секунд, что больше бюджета в 60. На практике это не проблема: Spring завершает HTTP drain, планировщик и Kafka параллельно, а не по очереди. Реальный wall clock — 25–40 секунд. Бюджет в 60 секунд даёт запас на замедленные завершения под высокой нагрузкой.

Схема параллельного выполнения:

T=0     SIGTERM
T=0     Spring публикует ContextClosedEvent
T=0     Параллельно стартуют:
        ├── Kafka listener.stop() (до 15s)
        ├── Планировщик shutdown() (до 20s)
        └── Tomcat graceful drain (до 25s)
T=25s   Все три фазы завершены
T=25s   ApplicationContext.close() — закрытие DataSource и прочего
T=30s   Процесс завершён

Что делать, если не укладываетесь

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

Длинный shutdown удлиняет скользящее обновление (rolling deploy). Пока старый pod ещё работает, новый уже принимает трафик: обе версии кода работают против одной базы данных. Чем дольше это окно — тем выше шанс проблем с совместимостью схем. К тому же kubectl drain по умолчанию ждёт 30 секунд: если pod не успел завершиться, дрейн зависнет.

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

• Kafka max.poll.records: 500 → 100: listener завершит обработку за 5 секунд вместо 25.
• Задачи @Async с длинными цепочками → разбить на короткие шаги.
• Тяжёлые @Scheduled-задачи → уменьшить размер порции (50 записей вместо 500).

Метрика длительности завершения

Без метрики единственный способ понять, сколько занял shutdown — пролистать логи каждого pod вручную. С метрикой это видно сразу на графике.

Добавляем gauge, который обновляется на протяжении всего shutdown:

@Component
@Slf4j
public class ShutdownObserver {

    private final MeterRegistry meterRegistry;
    private final long terminationGracePeriodSeconds;
    private volatile long shutdownStartMs;

    public ShutdownObserver(MeterRegistry meterRegistry,
                            @Value("${terminationGracePeriodSeconds:60}") long terminationGracePeriodSeconds) {
        this.meterRegistry = meterRegistry;
        this.terminationGracePeriodSeconds = terminationGracePeriodSeconds;
    }

    @EventListener(ContextClosedEvent.class)
    public void onShutdown() {
        shutdownStartMs = System.currentTimeMillis();
        log.info("Graceful shutdown started, deadline={}s", terminationGracePeriodSeconds);
        meterRegistry.gauge(
            "app_shutdown_duration_seconds",
            this,
            obs -> (System.currentTimeMillis() - obs.shutdownStartMs) / 1000.0
        );
    }

    @PreDestroy
    public void onPreDestroy() {
        var durationMs = System.currentTimeMillis() - shutdownStartMs;
        log.info("Graceful shutdown completed in {}ms", durationMs);
    }
}

Полезные запросы в Prometheus:

# Сколько длился shutdown по сервисам
max by (service) (app_shutdown_duration_seconds)

# Предупреждение, если подходим к бюджету
max(app_shutdown_duration_seconds) > 50

Алерт на 50 секунд (из бюджета в 60) даёт время обнаружить проблему до того, как начнутся принудительные убийства pod.

Почему получили SIGTERM — как разобраться

Spring не знает, по какой причине пришёл сигнал завершения. Причин может быть несколько:

• обычный rolling deploy;
• HPA уменьшил число реплик;
• вручную удалили pod через kubectl delete pod;
• OOM killer завершил процесс по нехватке памяти;
• обслуживание ноды кластера.

В коде нет смысла пытаться определить причину — это информация уровня инфраструктуры, не приложения. Приложение только фиксирует факт:

@EventListener(ContextClosedEvent.class)
public void onShutdown() {
    log.info("SIGTERM received, starting graceful shutdown");
}

Причину ищут через kubectl describe pod <имя> — раздел Events покажет, кто и почему удалил pod:

Events:
  Type    Reason             Age   From                       Message
  ----    ------             ----  ----                       -------
  Normal  Killing            2m    kubelet                    Stopping container app
  Normal  ScalingReplicaSet  10m   deployment-controller      Scaled down replica set

Для глубокого расследования есть audit log Kubernetes.

Обычные события завершения — не ERROR

Распространённая ошибка: в стандартной конфигурации некоторые библиотеки пишут сообщения о завершении на уровне ERROR.

ERROR HikariPool-1 - Shutdown initiated...
ERROR Closing JPA EntityManagerFactory for persistence unit 'default'
ERROR org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor - Shutting down...

Это нормальные события, которые происходят при каждом деплое. На уровне ERROR они попадают в alert-канал — Slack или PagerDuty. Команда получает десятки ложных алертов за каждый деплой и учится их игнорировать. Когда случается настоящий сбой — реакция запаздывает.

Решение — явно выставить правильный уровень в logback-spring.xml:

<logger name="com.zaxxer.hikari" level="INFO"/>
<logger name="org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor" level="INFO"/>
<logger name="org.springframework.kafka.listener.KafkaMessageListenerContainer" level="INFO"/>

На уровне ERROR должны оставаться только реальные проблемы: принудительное завершение с потерей данных, разрыв соединения в неожиданный момент, исключения, которые не должны происходить при штатном завершении.

Частые ошибки

• Увеличить terminationGracePeriodSeconds до 90+ — удлиняет окно несовместимости версий и блокирует kubectl drain. Лучше сократить объём работы.
• Нет метрики длительности — при проблемах с деплоем невозможно понять, какая фаза не успела.
• Нет лога о получении SIGTERM — shutdown начинается, но в логах нет точки отсчёта.
• Выставить все таймауты на максимум одновременно — все фазы длятся по 25 секунд, фактически превращая параллельное выполнение в последовательное.
• Пытаться определить причину SIGTERM в коде — вместо этого смотреть kubectl describe pod.

Коротко

• Бюджет в 60 секунд складывается из четырёх фаз, но три из них идут параллельно — реальное время завершения 25–40 секунд.
• Не укладываетесь — сократите объём работы (меньше записей в пакете), не увеличивайте бюджет.
• Метрика app_shutdown_duration_seconds и лог о начале shutdown — минимум для расследования проблем с деплоем.
• Причину SIGTERM приложение не знает — смотрите kubectl describe pod.
• Обычные события завершения (HikariPool, EntityManagerFactory) — уровень INFO, не ERROR.

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

• JVM и Spring конфигурация — timeout-per-shutdown-phase и прочие параметры.
• HTTP drain — preStop sleep и Tomcat drain до 25 секунд.
• Kafka shutdown — как Kafka listener завершает работу.
• Планировщик и @Async — ожидание плановых задач.
• Kubernetes — terminationGracePeriodSeconds и конфигурация pod.