BullMQ 재실행과 정기 스윕이 겹쳐 중복된 PR 리뷰

PR 리뷰 자동화에서는 한 번 실패하는 것보다 두 번 성공하는 일이 더 위험할 때가 있어요. 2026년 10월 7일, 서버 재시작으로 멈췄던 BullMQ 작업을 stalled 상태에서 회수할 때 마침 다음 정기 스윕이 시작됐어요. 두 회차는 0.66초 간격으로 같은 PR을 골랐고 같은 리뷰를 두 번 게시했어요.

이 글에서는 실행 원장과 서버 로그를 맞춰 장애를 재구성하고 스윕 회차가 겹치지 않게 바꾸고, BullMQ 이벤트를 서버 로그에 연결한 과정을 다뤄요. 제공된 PR 자료만으로는 실행 중 표시의 원자성이나 전체 자동화 검증 결과를 확인할 수 없어요.

중복 코멘트보다 중복 실행을 먼저 의심했다

해당 PR에는 같은 지적을 담은 인라인 코멘트가 두 번 달렸어요. 처음에는 게시 단계에서 중복됐거나 하나의 리뷰 결과를 전송하다 재시도했을 가능성도 있었어요. 그런데 실행 원장과 서버 로그의 시각을 맞춰 보니 서로 다른 두 스윕 회차가 같은 PR을 각각 골라 따로 리뷰하고 있었어요.

실행 원장은 UTC, 서버 로그는 KST를 쓰고 있었어요. 시간대를 맞춘 다음 원장 기록과 BullMQ 잠금 만료 시각을 하나의 타임라인에 놓았어요.

서버가 재시작된 때부터 작업이 다시 시작되기까지 약 15분 34초가 걸렸어요. 재시작 직후 재시도한 게 아니라 기존 잠금이 만료된 뒤 stalled 검사가 작업을 회수한 거예요. 당시 공통 worker에는 stalled 이벤트를 기록하는 리스너가 없어서 원장 시각과 활성화 시각 + lockDuration을 대조하며 재실행 경로를 거꾸로 추론해야 했어요.

개별 PR보다 스윕 회차의 중첩을 막았다

중복 리뷰를 막으려면 PR별 잠금을 떠올릴 수 있어요. 특정 PR을 고를 때 잠금을 잡고 리뷰가 끝날 때까지 다른 작업이 처리하지 못하게 하는 방식이죠. 하지만 이번 사건에서 먼저 드러난 문제는 앞선 정기 PR 리뷰 스윕이 끝나기 전에 다음 회차가 시작될 수 있다는 점이었어요. 한 회차에서 여러 후보를 검사해 리뷰 대상을 고르는 구조라 회차가 겹치면 어느 PR에서든 같은 일이 반복될 수 있었어요.

스윕 task에 “현재 회차가 실행 중”이라는 표시를 두고 앞 회차가 끝나지 않았다면 다음 회차는 아무 작업도 하지 않고 끝나도록 바꿨어요. 흐름을 간단히 나타내면 다음과 같아요.

스윕 시작
├─ 앞 회차 실행 중 → 이번 회차 건너뛰기
└─ 실행 중 아님
├─ 실행 중 표시
├─ PR 탐색 및 리뷰
└─ 회차 종료 처리

건너뛴 회차에서 처리하지 못한 PR은 이후 정기 회차가 다시 찾아요. 모든 슬롯을 실행하기보다 회차가 동시에 돌지 않게 하는 쪽을 택한 셈이에요. 앞 회차가 길어지면 일부 PR의 리뷰 시작이 다음 회차까지 늦어질 수 있어요. 모든 슬롯을 병렬로 실행하려면 같은 후보를 고르지 않도록 PR 단위의 원자적 선점이나 멱등성 키가 따로 필요해요.

이번에는 회차 중첩이 실제 장애 원인이었고 건너뛴 대상도 다음 회차에서 처리할 수 있어 이 방식을 선택했어요. 회차마다 서로 다른 샤드를 처리하거나 정해진 슬롯 안에 반드시 끝내야 하는 시스템이라면 같은 방식으로 직렬화해서는 안 돼요. 여러 프로세스가 완전히 동시에 시작할 때 실행 중 표시를 원자적으로 획득하는지, 비정상 종료 후에는 그 표시를 어떻게 정리하는지도 별도로 검증해야 해요.

복구는 됐지만 복구됐다는 사실은 보이지 않았다

BullMQ는 작업이 잠금을 잃으면 회수해서 다시 실행할 수 있지만 당시 서버 로그에는 그 전환 과정이 남지 않았어요. 10월 7일 사건도 직접적인 stalled 로그 없이 다음 근거를 조합해 판정했어요.

• 서버가 09:37:26에 재시작됐어요.
• 작업의 첫 잠금 갱신은 시작 후 589초 뒤로 예정돼 있었지만 그 전에 프로세스가 종료됐어요.
• 잠금은 활성화 시각 09:33:00에서 1,178초가 지난 09:52:38에 만료됐어요.
• 새 프로세스가 09:53:00에 같은 작업을 처음부터 실행했어요.

원장과 잠금 시간을 계산해 사건을 복원할 수는 있었지만 매번 같은 추론을 되풀이하기는 어려워요. 당시 Redis 이벤트 스트림도 약 2.4일치만 남아 있어서 조사가 늦어지면 큐 내부 이벤트로 과거 상황을 확인하기 어려웠어요.

모든 큐 consumer가 공통 worker 부모 클래스를 상속하게 하고 worker의 stalled와 error 이벤트를 서버 로그에 연결했어요.

error 이벤트는 리스너가 없으면 BullMQ 내부에서 console.error로만 흘러가 어느 큐에서 발생했는지 구분하기 어려웠어요. 공통 부모에서 큐 이름과 작업 식별자를 함께 기록하면 consumer마다 리스너를 반복해서 구현하지 않아도 사건의 범위를 좁힐 수 있어요. 메트릭이나 분산 추적을 새로 도입한 것은 아니지만 서버 로그에서 어느 큐의 어떤 작업을 회수했는지 확인할 출발점은 생겼어요.

stalled 뒤의 최종 실패도 기록했다

stalled 이벤트를 기록하면 작업이 잠금을 잃고 회수되는 과정은 볼 수 있어요. 그런데 BullMQ 5.73.1의 실패 경로를 따라가 보니 작업이 반복해서 stalled 되어 허용 한도를 넘을 때는 다른 빈틈이 있었어요.

1. moveStalledJobsToWait-8.lua가 작업에 job stalled more than allowable limit이라는 사유를 기록하고 wait 상태로 돌려보내면서 stalled 이벤트를 발생시켜요.
2. worker가 그 작업을 다시 가져오면 Worker.getUnrecoverableErrorMessage가 해당 사유를 반환해요. consumer의 처리 함수는 호출하지 않은 채 handleFailed로 이동한 뒤 failed 이벤트를 발생시켜요.

PR 설명에 따르면 기본 maxStalledCount는 1이었어요. 허용 한도를 넘긴 작업은 consumer 코드에 진입하지 않아서 consumer 내부의 try/catch나 실패 로그를 거치지 않아요. stalled 경고만 봐서는 작업이 결국 복구됐는지 최종 실패했는지 알 수 없었어요.

공통 worker 부모 클래스에 failed 리스너를 추가하고 실패 사유가 stalled 허용 한도 초과일 때만 error를 기록하게 했어요. 일반적인 처리 실패는 consumer가 이미 기록하므로 로그가 중복되지 않으면서도 잠금 상실부터 최종 실패까지 이어서 볼 수 있어요.

잠금 상실
→ stalled 감지 및 회수 경고
→ 재실행
→ 다시 stalled
→ 허용 한도 초과
→ consumer를 거치지 않은 최종 실패 로그

lockDuration은 그대로 두었다

중복 실행을 보면 잠금 시간을 늘리고 싶어져요. 작업이 오래 걸려 잠금이 풀렸다면 lockDuration을 늘리는 게 직접적인 처방일 수 있어요. 하지만 실측한 스윕 한 회차의 최대 소요 시간은 잠금 시간의 64%였고 측정 기간에는 잠금 만료로 다시 실행된 흔적도 찾지 못했어요. 2주 이상 쌓인 로그와 원장을 측정 대상으로 삼았지만 중앙값과 p95의 실제 값, 표본 수, 정확한 측정 시작일과 종료일은 확인되지 않았어요.

10월 7일 사건은 정상 실행 중인 스윕이 lockDuration을 초과한 사례가 아니었어요. 서버가 시작 후 589초인 첫 잠금 갱신 시점보다 먼저 재시작되면서 worker가 사라졌고, 남아 있던 잠금이 1,178초 뒤 만료되자 새 프로세스가 작업을 회수했어요. 잠금 시간을 늘렸다면 재실행을 늦출 수는 있었겠지만 장애 후 복구를 시작하기까지 기다리는 시간도 길어졌을 거예요. 정상 작업 시간이 잠금에 가까워졌다는 근거가 없어 lockDuration은 바꾸지 않았어요.

재시작과 동시 시작을 검증해야 한다

정상 완료만 확인해서는 이번 문제를 재현할 수 없어요. 한 스윕이 실행 중일 때 다음 정기 슬롯을 시작해 두 번째 회차가 PR을 고르지 않고 끝나는지 확인해야 해요. 작업 도중 서버를 종료하고 잠금이 만료된 뒤 다시 시작해 BullMQ가 작업을 회수할 때 큐 이름·job.name·job.id가 담긴 stalled 경고가 남는지도 살펴야 해요.

같은 작업이 허용 횟수를 넘어 반복해서 stalled 되면 consumer 처리 함수가 호출되지 않더라도 job stalled more than allowable limit에 해당하는 최종 실패를 error로 기록해야 해요. 일반적인 consumer 실패 로그가 공통 failed 리스너 때문에 두 번 남지 않는지도 확인해야 해요. 재시작과 동시 시작을 포함한 전체 자동화 검증은 아직 확인되지 않았어요.