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

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

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

Kubernetes при удалении pod ждёт максимум terminationGracePeriodSeconds секунд и после убивает процесс. По умолчанию это 30 секунд — для приложения, которое дренирует запросы, доделывает задачи планировщика и дочитывает сообщения, обычно мало. Дальше в разделе мы исходим из поднятого бюджета в 60 секунд. Что успевает произойти за это время?

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

ШагМаксимальное времяЧто происходит
preStop sleep10 секундkube-proxy успевает убрать pod из маршрутизации
Spring HTTP drainдо 25 секундTomcat дожидается текущих запросов
Планировщик / @Asyncдо 20 секундзадачи успевают завершить текущую итерацию
Kafka listenerдо 15 секундпотребитель обрабатывает последнее сообщение

Сложим максимумы — получится 70 секунд, и это больше бюджета. Здесь важно понимать, как Spring на самом деле гасит приложение: он не выключает всё разом, а идёт группами, одна за другой, и таймаут spring.lifecycle.timeout-per-shutdown-phase действует на каждую группу отдельно. Первыми останавливаются потребители очередей и планировщик, последним — веб-сервер. То есть бюджеты складываются, а не накладываются друг на друга.

Отсюда практический вывод: чтобы уложиться, уменьшают не общий лимит, а объём работы в каждой группе — об этом ниже.

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

T=0     SIGTERM
T=0     Spring публикует ContextClosedEvent
T=0     Группа с высшей фазой: Kafka listener.stop() (до 15s)
T=15s   Следующая группа: планировщик и @Async (до 20s)
T=35s   Последним — Tomcat graceful drain (до 25s)
T=50s   ApplicationContext.close() — закрытие DataSource и прочего
T=52s   Процесс завершён

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

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

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

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

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

  • 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 c.example.OrderConsumer - Consumer stopped, interrupting poll
ERROR c.example.OutboxRelay  - Relay shutting down, 12 events pending

Это нормальные события, которые происходят при каждом деплое. На уровне 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+ — удлиняет окно несовместимости версий и растягивает вывод узла из работы. Лучше сократить объём работы.
  • Нет метрики длительности — при проблемах с деплоем невозможно понять, какая фаза не успела.
  • Нет лога о получении SIGTERM — shutdown начинается, но в логах нет точки отсчёта.
  • Выставить все таймауты на максимум одновременно — все фазы длятся по 25 секунд, фактически превращая параллельное выполнение в последовательное.
  • Пытаться определить причину SIGTERM в коде — вместо этого смотреть kubectl describe pod.

Коротко

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

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