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

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

Важно знать

• 60s total budget = preStop 10s + uvicorn graceful до 25s + asyncio-задачи/APScheduler до 20s + aiokafka consumer до 15s.
• Фазы uvicorn + lifespan идут последовательно: lifespan-shutdown → uvicorn graceful HTTP drain → процесс завершается; wall clock = сумма активных фаз. Уложиться нужно в 60s минус preStop = 50s.
• Не помещается? — сократить batch (100 → 20 записей), не увеличивать terminationGracePeriodSeconds.
• --timeout-graceful-shutdown в uvicorn — без явного значения (20–30s) фреймворк рвёт in-flight запросы немедленно.
• Метрика app_shutdown_duration_seconds — prometheus_client Gauge + финальная запись в конце lifespan-shutdown.
• Лог факта SIGTERM — первым, до любого cleanup: logger.info("получили SIGTERM, начинаем graceful shutdown").
• Нормальное закрытие engine.dispose()/consumer.stop() — INFO, не ERROR; иначе каждый деплой генерирует ложный алерт.
• Без observability — первое падение под нагрузкой = чёрный ящик.

Graceful shutdown — это distributed coordination. Если он сломался в проде, нужно понять где именно: сколько секунд занял HTTP drain, сколько aiokafka, сколько фоновые asyncio-задачи? Без метрик и структурного лога каждый инцидент расследуется через kubectl logs и догадки. R-SHUT-OBS-* фиксирует минимум: один gauge + structured log как нижнюю планку.

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

R-SHUT-OBS-1: cumulative timeline для FastAPI/uvicorn.

70s > 60s — но в FastAPI/uvicorn последовательность детерминированная: если aiokafka укладывается в 15s и uvicorn HTTP drain — в 25s, а фоновые asyncio-задачи завершаются в 5s, реальный wall clock 35-40s. Бюджет 60s оставляет запас на нагруженный кластер.

T=0     SIGTERM
T=0     uvicorn.Server.should_exit = True
T=0     lifespan shutdown-блок начинается:
        ├── readiness_state.is_ready = False  → /health/ready 503
        ├── aiokafka consumer.stop() (timeout 15s)
        └── aiokafka producer.stop()
T=15s   uvicorn graceful drain (--timeout-graceful-shutdown 25s)
        ├── in-flight HTTP-запросы дожимаются
        └── новые соединения отклоняются
T=40s   asyncio-задачи отменяются с дожатием CancelledError
        ├── APScheduler shutdown(wait=True)
        └── engine.dispose()  (SQLAlchemy пул)
T=45s   process exit(0)

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

Не увеличивать budget до 90s, 120s — длинный shutdown = длинный rolling deploy, окно несовместимости схем растёт; kubelet drain зависает дольше.

Сократить scope операций:

• aiokafka max_poll_records=500 → 100; handler завершает batch за 5s вместо 25.
• APScheduler-задача с heavy-итерацией → batch 50 вместо 500.
• asyncio-задача с долгим cascade → asyncio.wait_for(task, timeout=15) и ранний выход.

Метрика app_shutdown_duration_seconds

R-SHUT-OBS-2: prometheus_client Gauge + структурный лог.

В FastAPI наблюдаемость shutdown удобно упаковать в отдельный класс, который lifespan-блок инстанцирует при старте и вызывает в двух точках: при получении сигнала и по завершении дренажа.

import logging
import time
from prometheus_client import Gauge, REGISTRY

logger = logging.getLogger(__name__)

_shutdown_duration = Gauge(
    "app_shutdown_duration_seconds",
    "Duration of graceful shutdown in seconds",
    ["service"],
    registry=REGISTRY,
)


class ShutdownObserver:
    def __init__(self, service_name: str) -> None:
        self._service = service_name
        self._start: float = 0.0

    def on_sigterm(self) -> None:
        self._start = time.monotonic()
        logger.info("получили SIGTERM, начинаем graceful shutdown")

    def on_complete(self) -> None:
        duration = time.monotonic() - self._start
        _shutdown_duration.labels(service=self._service).set(duration)
        logger.info("graceful shutdown завершён за %.1fs", duration)

Использование в lifespan:

from contextlib import asynccontextmanager
from fastapi import FastAPI

observer = ShutdownObserver(service_name="order-service")


@asynccontextmanager
async def lifespan(app: FastAPI):
    # startup
    yield
    # shutdown
    observer.on_sigterm()
    await consumer.stop()
    await producer.stop()
    observer.on_complete()


app = FastAPI(lifespan=lifespan)

on_sigterm() вызывается первым — до любого cleanup. on_complete() — после всех фаз, перед engine.dispose().

В Prometheus:

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

# Алерт: приближается к budget (50s из 60s)
max(app_shutdown_duration_seconds) > 50

Без gauge расследование «почему deploy timeout» — прокликивание логов десятков pod-ов вручную.

Лог причины SIGTERM

R-SHUT-OBS-3: где смотреть.

uvicorn не знает, почему получил SIGTERM — это информация инфраструктурного уровня:

• Rolling deploy (Sber-кластер выкатывает новую версию order-service)?
• HPA scale-down (нагрузка на product-service упала)?
• Manual kubectl delete pod?
• OOM killer?
• Node maintenance?

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

def on_sigterm(self) -> None:
    self._start = time.monotonic()
    logger.info("получили SIGTERM, начинаем graceful shutdown")

Контекст ищем через kubectl describe pod <pod-name>:

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

Или через k8s audit log для более глубокого расследования. Не пытаемся определить причину в коде — это infrastructure-info, не application-info.

Уровни логирования на shutdown

R-SHUT-OBS-X1: нормальное закрытие — INFO, не ERROR.

# АНТИПАТТЕРН — alert channel заспамлен каждым deploy
ERROR - SQLAlchemy engine disposed
ERROR - aiokafka consumer stopped
ERROR - APScheduler shut down

Это нормальные события завершения работы. Если они на ERROR — каждый деплой customer-service генерирует алерты в Slack/PagerDuty, команда привыкает их игнорировать, и реальный инцидент проходит незамеченным.

Правильный уровень:

async def _stop_kafka(consumer: AIOKafkaConsumer) -> None:
    await consumer.stop()
    logger.info("aiokafka consumer остановлен")


async def _dispose_db(engine: AsyncEngine) -> None:
    await engine.dispose()
    logger.info("SQLAlchemy engine закрыт")

ERROR на shutdown — только если что-то реально пошло не так: force-shutdown до завершения транзакций, потеря соединения в процессе дренажа, необработанное исключение в lifespan-shutdown.

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

Куда дальше

• Рантайм и конфигурация uvicorn — --timeout-graceful-shutdown, readiness-флаг в lifespan, раздельные /health/live и /health/ready.
• HTTP drain — uvicorn graceful, preStop 10s, долгие эндпоинты — 202 Accepted + polling.
• Kafka shutdown — consumer.stop() с таймаутом, manual commit, cascade в outbox.
• БД и persistence — engine.dispose() в правильной точке lifespan-shutdown.
• Scheduled / async / outbox — APScheduler shutdown(wait=True), CancelledError, draining-флаг в outbox-relay.
• Идемпотентность in-flight — retry-safe операции при SIGTERM, Idempotency-Key.
• Kubernetes — terminationGracePeriodSeconds: 60, probes, maxUnavailable: 0.