Хуки остановки срабатывали дважды - когда у SIGTERM два хозяина

После каждого деплоя в Sentry прилетала одна и та же ошибка. Transaction already closed. Prisma падала с P2028, пытаясь выполнить запрос уже после закрытия транзакции. Пользователи от этого никак не страдали - повтор от BullMQ тут же успешно подхватывал задачу в другой попытке, и лог завершений оставался непрерывным. Но при каждом совпадении деплоя с трафиком проблема тихо повторялась. Гоняясь за этой ошибкой, я обнаружил, что хуки завершения на нашем сервере на самом деле выполнялись дважды за раз.

Акт первый: база умирает раньше задачи

Сопоставив время ошибки с логами CloudWatch, я получил точную временную линию. Rolling-деплой отправляет старому таску SIGTERM. Через 6 секунд app.close() начинает очистку, и движок Prisma закрывает транзакцию. Сразу после этого updateMany из ещё выполняющейся задачи asset-processing запускается поверх уже закрытой транзакции и падает с P2028. Пользователь в момент деплоя как раз загружал аудио подряд несколькими файлами, поэтому активная задача была, и её запрос погиб.

Причина была в порядке завершения. При остановке NestJS вызывает хуки жизненного цикла в заданном порядке. Проблема в том, что закрытие воркеров BullMQ и разрыв соединения Prisma находились на одной и той же фазе завершения (onApplicationShutdown). Внутри одной фазы порядок выполнения определяется порядком регистрации модулей, и так вышло, что Prisma отключалась раньше, из-за чего запросам ещё работающего воркера было некуда деваться.

Направление исправления было очевидным: закрывать воркеры на более ранней фазе. У хуков завершения NestJS есть свой порядок, и beforeApplicationShutdown завершается раньше, чем onApplicationShutdown любого модуля. Я написал сервис, который находит все воркеры и дренирует их (ждёт завершения активных задач) уже на этой ранней фазе.

@Injectable()
export class WorkerDrainService implements BeforeApplicationShutdown {
  constructor(private readonly discovery: DiscoveryService) {}

  async beforeApplicationShutdown() {
    // Находим все зарегистрированные WorkerHost и ждём завершения активных задач.
    // Эта фаза заканчивается раньше onApplicationShutdown, на которой отключается Prisma.
    const workers = this.discovery
      .getProviders()
      .filter((p) => p.instance instanceof WorkerHost);
    await Promise.all(workers.map((w) => w.instance.worker.close()));
  }
}

Worker.close() при повторном вызове возвращает тот же самый promise, поэтому не конфликтует с уже существующим кодом закрытия воркеров, а в окружениях без Redis попросту ничего не делает. Теперь даже если деплой совпадает с задачей, сначала завершается задача, и только потом закрывается база. Я добавил юнит-тесты и открыл PR. На этом этапе всё выглядело как обычное исправление порядка выполнения.

Акт второй: у SIGTERM оказалось два хозяина

Поворот случился в ревью. Ревьюер, разбирая весь путь завершения, задал вопрос: а кто вообще обрабатывает SIGTERM?

Оказалось, хозяев было двое. В main.ts были отдельно эти две строки.

// ① Доверяем обработку сигнала завершения самому Nest (без аргументов регистрируются и SIGTERM, и SIGINT)
app.enableShutdownHooks();

// ② Отдаём завершение ещё и библиотеке http-graceful-shutdown
setupGracefulShutdown(server, {
  onShutdown: async () => {
    await app.close(); // здесь выполняются все хуки жизненного цикла целиком
  },
});

Оба ловят SIGTERM. Node при получении сигнала вызывает все зарегистрированные слушатели по порядку, не дожидаясь завершения друг друга. Поэтому в момент реального SIGTERM происходило следующее. Слушатель, зарегистрированный Nest, немедленно, даже не дожидаясь дренажа HTTP-соединений, один раз выполняет ту же самую последовательность завершения, что и app.close(). Параллельно с этим http-graceful-shutdown по-своему опустошает HTTP-соединения и уже потом, внутри onShutdown, вызывает app.close() ещё раз. Хуки завершения выполняются дважды.

Одних рассуждений было мало, поэтому я перечитал продакшн-логи завершения. Доказательство было налицо. Через 20 миллисекунд после отметки SIGTERM, ещё до окончания дренажа HTTP, уже начинался onModuleDestroy, а логи завершения SpeechService и QueueMonitorService были продублированы дважды. Единственная причина, по которой это не вылилось в инцидент, - хуки каждого сервиса были написаны так, чтобы безопасно переживать повторный вызов (идемпотентно). Благодаря этой защитной привычке двойное выполнение осталось просто запахом в логах, а не аварией, и именно этот запах в итоге позволил найти баг.

Удаляем одну строку

Исправление свелось к удалению одной строки.

// main.ts
- app.enableShutdownHooks();

Убрав enableShutdownHooks(), мы закрепляем за SIGTERM единственного хозяина - http-graceful-shutdown. Ничего при этом не теряется: app.close(), который вызывает её onShutdown, и так выполняет все хуки жизненного цикла целиком. Меняется только то, что хуки теперь выполняются не дважды, а один раз - причём уже после завершения дренажа HTTP.

Чем меньше правка, тем сильнее нужно измерение на реальных данных. Я собрал сервер и отправил ему настоящий SIGTERM, чтобы своими глазами увидеть последовательность.

Received SIGTERM → health check 503 → HTTP connections closed
→ shutdown hooks run only once, after HTTP close
→ Drained 56/56 BullMQ workers in 211ms → shutdown completed → clean exit

То, что в продакшене раньше выполнялось дважды ещё до дренажа HTTP, теперь выполняется один раз уже после дренажа. Проверка шла вместе с исправлением дренажа воркеров из первого акта, так что фактически подтвердилось совместное поведение обоих исправлений сразу.

Отдельно зафиксировал и одну ловушку. В NODE_ENV=development библиотека http-graceful-shutdown работает в режиме немедленного завершения и вообще не идёт по пути graceful, поэтому в режиме разработки эту проверку не воспроизвести. Реально измерить получилось только выставив NODE_ENV=staging с фиктивными секретами, чтобы код пошёл тем же путём, что и в продакшене. Проверяя путь завершения, в первую очередь нужно убедиться, что тестовое окружение действительно проходит по этому пути.

Что вынесено из кода завершения

Урок этой истории выходит за пределы узкой темы последовательности остановки.

У одного сигнала должен быть один хозяин. Если подключена библиотека graceful shutdown, нельзя одновременно включать автоматическую регистрацию хуков завершения от фреймворка. В момент, когда оба ловят один и тот же SIGTERM, последовательность завершения тихо начинает выполняться дважды. Подключая новый инструмент, в первую очередь нужно проверить, хозяином какого сигнала или события он становится, и нет ли уже существующего кода, который ловит то же самое.

У завершения тоже есть порядок. Код, который что-то очищает, должен запускаться уже после того, как всё зависящее от этого ресурса закончило работу. База должна закрываться после завершения использующих её задач, а для этого сами задачи нужно опустошать на более ранней фазе. Разделение хуков завершения фреймворка на фазы существует не для красоты, а именно для выражения такого порядка.

Защитно написанный код выигрывает время. Не будь хуки завершения написаны так, чтобы безопасно переживать двойной вызов, этот баг проявился бы не запахом в логах, а инцидентом с данными. Именно идемпотентность хуков позволила пережить двойное выполнение, и благодаря этому мы нашли проблему в логах, а не в результате аварии. Будь хуки написаны в расчёте на строго однократный вызов, история закончилась бы куда хуже.