종료 훅이 두 번 돌고 있었다 - SIGTERM의 주인이 둘일 때

배포할 때마다 Sentry에 같은 에러가 하나씩 떨어졌다. Transaction already closed. Prisma가 트랜잭션이 이미 닫힌 뒤에 쿼리를 실행하려다 P2028로 죽는 에러다. 유저에게는 아무 피해가 없었다. BullMQ 재시도가 곧바로 다른 태스크에서 잡을 성공시켰고, 완료 로그는 끊김 없이 이어졌다. 그런데도 배포와 트래픽이 겹칠 때마다 조용히 재발하는 구조였다. 이 에러를 쫓다가, 나는 우리 서버의 종료 훅이 실은 매번 두 번씩 실행되고 있었다는 걸 알게 됐다.

1막: DB가 잡보다 먼저 죽는다

에러가 난 시각을 CloudWatch 로그와 맞춰보니 타임라인이 정확히 떨어졌다. 롤링 배포가 옛 태스크에 SIGTERM을 보낸다. 6초 뒤 app.close()가 정리를 시작하고, Prisma 엔진이 트랜잭션을 닫는다. 그 직후, 아직 돌고 있던 asset-processing 잡의 updateMany가 닫힌 트랜잭션 위에서 실행되며 P2028로 실패한다. 유저가 오디오를 연속 업로드 중이라 배포 순간에 활성 잡이 있었고, 그 잡의 쿼리가 죽었다.

원인은 종료 순서였다. NestJS는 종료할 때 라이프사이클 훅을 정해진 순서로 부른다. 문제는 BullMQ 워커를 닫는 일과 Prisma 연결을 끊는 일이 같은 종료 페이즈(onApplicationShutdown)에 있었다는 점이다. 같은 페이즈 안에서는 모듈 등록 순서가 실행 순서를 정하는데, 하필 Prisma가 먼저 끊기면 아직 잡을 처리 중이던 워커의 쿼리가 갈 곳을 잃는다.

고치는 방향은 분명했다. 워커를 더 이른 페이즈에서 닫으면 된다. NestJS의 종료 훅에는 순서가 있고, beforeApplicationShutdown은 어떤 모듈의 onApplicationShutdown보다도 먼저 완료된다. 모든 워커를 찾아 이 이른 페이즈에서 드레인(활성 잡이 끝날 때까지 대기)하는 서비스를 하나 만들었다.

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

  async beforeApplicationShutdown() {
    // 등록된 모든 WorkerHost 를 찾아, 활성 잡이 끝날 때까지 기다린다.
    // 이 페이즈는 Prisma 가 끊기는 onApplicationShutdown 보다 먼저 끝난다.
    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가 없는 환경에선 조용히 아무 일도 하지 않는다. 배포가 잡과 겹쳐도 이제 잡이 먼저 끝나고 나서 DB가 닫힌다. 단위 테스트를 붙이고 PR을 올렸다. 여기까지는 평범한 순서 버그 수정이었다.

2막: SIGTERM의 주인이 둘이었다

반전은 리뷰에서 나왔다. 이 수정을 검토하던 리뷰어가 종료 경로 전체를 훑다가 질문을 던졌다. SIGTERM은 대체 누가 처리하고 있나?

확인해보니 주인이 둘이었다. main.ts에 이런 두 줄이 따로 있었다.

// ① Nest 자신에게 종료 시그널을 맡긴다 (인자 없이 부르면 SIGTERM·SIGINT 전부 등록)
app.enableShutdownHooks();

// ② http-graceful-shutdown 라이브러리에도 종료를 맡긴다
setupGracefulShutdown(server, {
  onShutdown: async () => {
    await app.close(); // 여기서 라이프사이클 훅 전체가 실행된다
  },
});

둘 다 SIGTERM을 잡는다. Node는 시그널이 오면 등록된 리스너를 순서대로, 서로의 완료를 기다리지 않고 전부 호출한다. 그래서 실제 SIGTERM이 오는 순간 이런 일이 벌어진다. Nest가 등록한 리스너가 app.close()와 똑같은 종료 시퀀스를 HTTP 드레인을 기다리지도 않고 즉시 한 번 실행한다. 그와 별개로 http-graceful-shutdown은 자기 방식대로 HTTP 커넥션을 비운 뒤 onShutdown에서 app.close()를 또 한 번 부른다. 종료 훅이 두 번 도는 것이다.

머릿속 추론만으로는 확신할 수 없어서 프로덕션 종료 로그를 다시 읽었다. 증거가 그대로 있었다. SIGTERM이 찍힌 시각으로부터 20밀리초 뒤, HTTP 드레인이 끝나기도 전에 onModuleDestroy가 시작됐고, SpeechService와 QueueMonitorService의 종료 훅 로그가 각각 두 번씩 찍혀 있었다. 사고로 이어지지 않은 유일한 이유는 각 서비스의 훅이 두 번 불려도 안전하도록(idempotent) 짜여 있었기 때문이다. 방어적으로 짜둔 덕에 "두 번 실행"이 장애가 아니라 로그 냄새로 남아 있었고, 그 냄새가 결국 버그를 잡게 해줬다.

한 줄을 지운다

수정은 한 줄을 지우는 것이었다.

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

enableShutdownHooks()를 없애면 SIGTERM의 주인은 http-graceful-shutdown 하나로 정리된다. 잃는 것은 없다. 그쪽 onShutdown이 부르는 app.close()가 어차피 라이프사이클 훅 전체를 실행하기 때문이다. 달라지는 건 훅이 두 번이 아니라 한 번, 그것도 HTTP 드레인이 끝난 뒤에 돈다는 것뿐이다.

한 줄짜리 수정일수록 실측이 필요하다. 빌드한 서버에 실제로 SIGTERM을 보내 시퀀스를 눈으로 확인했다.

Received SIGTERM → 헬스체크 503 → HTTP connections closed
→ 종료 훅이 HTTP close "이후"에 한 번씩만 실행
→ Drained 56/56 BullMQ workers in 211ms → shutdown completed → 정상 exit

프로덕션에서는 훅이 HTTP 드레인 전에 두 번씩 돌던 것이, 이제 드레인 후에 한 번씩만 돈다. 1막의 워커 드레인 수정과 합쳐진 상태로 검증했으니, 두 수정이 함께 도는 통합 동작까지 확인한 셈이다.

한 가지 함정도 같이 기록해뒀다. NODE_ENV=development에서는 http-graceful-shutdown이 즉시 종료 모드로 동작해서 graceful 경로를 아예 타지 않는다. 그래서 이 검증은 개발 모드로는 재현되지 않는다. NODE_ENV=staging에 더미 시크릿을 넣어 프로덕션과 같은 경로를 타게 만든 뒤에야 실측할 수 있었다. 종료 경로를 검증할 때는 검증 환경이 그 경로를 실제로 타는지부터 확인해야 한다.

종료 코드에서 배운 것

이 이야기의 교훈은 종료 시퀀스라는 좁은 무대를 넘는다.

하나의 시그널에는 주인이 하나여야 한다. graceful shutdown 라이브러리를 붙였다면, 프레임워크가 제공하는 종료 훅 자동 등록을 동시에 켜두면 안 된다. 둘 다 같은 SIGTERM을 잡는 순간, 종료 시퀀스는 조용히 두 번 실행된다. 새 도구를 도입할 때는 그 도구가 어떤 시그널·이벤트의 주인이 되는지, 그리고 기존에 같은 것을 잡던 코드가 없는지부터 봐야 한다.

종료에도 순서가 있다. 무언가를 정리하는 코드는 그것에 의존하는 일이 다 끝난 뒤에 돌아야 한다. DB는 그 DB를 쓰는 잡이 끝난 뒤에 닫혀야 하고, 그러려면 잡을 더 이른 페이즈에서 비워야 한다. 프레임워크가 종료 훅에 페이즈를 나눠 둔 건 장식이 아니라 이런 순서를 표현하라고 있다.

방어적으로 짠 코드가 시간을 벌어준다. 종료 훅이 두 번 불려도 안전하게 짜여 있지 않았다면, 이 버그는 로그 냄새가 아니라 데이터 사고로 먼저 모습을 드러냈을 것이다. idempotent하게 짜둔 훅이 두 번 실행을 견뎌준 덕에, 우리는 사고 대신 로그에서 그것을 발견할 수 있었다. 반드시 한 번만 실행된다고 믿고 짠 훅이었다면 이야기는 훨씬 나빴을 것이다.