Why NextWhy Next
목록으로
💻 개발6분 읽기

테스트는 초록인데, 알림은 한 번도 발송된 적이 없었다

큐에 잡을 넣는 코드가 첫날부터 항상 실패하고 있었다. 에러는 삼켜졌고, 테스트는 목(mock) 덕분에 초록이었다. 콜론 한 글자가 기능 세 개를 조용히 죽인 이야기.

핵심 요약

BullMQ는 커스텀 jobId에 콜론을 금지한다. 이 규칙을 어긴 enqueue가 첫날부터 100% 실패하고 있었는데, 실패를 catch로 삼킨 탓에 알림 기능이 죽었다는 사실을 아무도 몰랐다. 테스트는 큐를 순수 목으로 대체해 실제 검증을 태우지 않았기 때문에 계속 초록이었다. 같은 결함이 큐 두 곳에 더 있었고, 하나는 12일간 무증상이었다. 고치는 길에 두 번째 함정도 나왔다 - 고정 jobId는 완료된 잡의 해시가 남아 있으면 재등록을 에러 없이 무시해서, 재시도 계약을 조용히 죽인다.

목차

Slack에 500 알림이 떴다. 에러 메시지가 낯설었다. Error: Custom Id cannot contain :. 관리자가 사용자 질문에 답변을 등록하는 API가 죽고 있었고, 스택 트레이스는 BullMQ의 Job.validateOptions를 가리켰다.

여기까지는 평범한 버그 리포트다. 이 이야기가 평범하지 않아지는 지점은 원인을 찾은 다음이다. 이 에러를 던지는 코드는 그날 배포에서 바뀐 게 아니었다. 기능이 처음 들어온 날부터 매번, 100% 실패하고 있었다. 그 말은 곧, 이 큐가 보내야 했던 푸시 알림이 지금껏 단 한 번도 발송된 적이 없다는 뜻이다. 그리고 그동안 테스트는 전부 초록이었다.

원인은 한 글자

문제의 코드는 이렇게 생겼다. 질문에 답변이 달리면 사용자에게 푸시를 보내는 잡을 큐에 넣는 자리다.

await this.queue.add(ANSWER_NOTIFY_JOB_NAME, data, {
  jobId: `answer-notify:${data.questionId}`, // ← 이 콜론
});

같은 질문에 잡이 두 번 들어가지 않도록 커스텀 jobId를 준 것인데, 구분자로 콜론을 썼다. BullMQ는 Redis 키를 콜론으로 조립하기 때문에 커스텀 jobId의 콜론을 금지한다. v5 기준 정확한 조건은 이렇다: jobId에 콜론이 있으면서, 콜론으로 나눈 토막이 3개가 아니면 던진다. 3토막 예외는 레거시 repeatable 잡 형식을 위한 카브아웃이라, answer-notify:123 같은 2토막은 무조건 Custom Id cannot contain :다. 참고로 순수 숫자 jobId도 Custom Id cannot be integers로 거부되기 때문에, 저 접두사를 지우는 것도 답이 아니다.

코드베이스의 다른 큐 수십 곳은 전부 하이픈을 쓰고 있었다. 이 파일만 콜론이었다.

버그는 첫날부터 있었다, 그런데 왜 오늘 터졌나

고치는 건 한 줄이다. 콜론을 하이픈으로 바꾸면 된다. 흥미로운 질문은 따로 있다. 항상 실패하던 코드가 왜 그동안 조용하다가 오늘 500이 됐나.

기능이 처음 배포됐을 때 enqueue는 이렇게 감싸여 있었다.

try {
  await this.queue.add(/* ... */);
  return true;
} catch (err) {
  this.logger.error("enqueue failed", err);
  return false; // ← 실패가 여기서 사라진다
}

실패를 로그로 남기고 false를 반환한다. 호출부는 반환값을 확인하지 않는다. 그래서 매번 던져지던 예외가 매번 삼켜졌고, API는 200을 반환했고, 알림만 조용히 증발했다.

그러다 같은 날 머지된 커밋이 이 계약을 바꿨다. enqueue가 실패하면 삼키지 말고 던져서, 트랜잭션에 찍어둔 "답변됨" 표시를 되돌리고 재시도할 수 있게 하자는 의도였다. 옳은 방향의 변경이다. 그 순간 항상 실패하던 enqueue가 처음으로 소리를 냈다. 500은 그 커밋이 만든 버그가 아니라, 원래 있던 버그가 처음 낸 비명이었다.

에러를 삼키는 코드의 비용이 이것이다. 신호가 사라지고, 버그는 그대로 남아 기능 하나를 통째로 데려간다.

테스트는 왜 초록이었나

이 큐에는 테스트가 있었다. enqueue를 호출하면 queue.add가 올바른 인자로 불리는지 확인하는, 흔한 형태의 스펙이다. 그리고 그 테스트의 queue.add는 무조건 성공하는 목이었다.

실제 BullMQ의 add는 jobId를 검증하고 콜론을 거부한다. 목의 add는 아무거나 받는다. 목이 실제 계약과 다르게 관대한 만큼, 테스트는 현실에서 절대 통과할 수 없는 입력을 초록으로 통과시켰다. 목이 실제 계약과 다르면, 초록 테스트는 살아 있는 코드가 아니라 죽은 코드를 보증한다.

수정하면서 이 구멍부터 메웠다. 큐 목의 add가 BullMQ의 실제 Job.validateOptions를 태우게 바꿨다. 이 함수는 Redis 없이 도는 순수 검증이라 테스트에 그대로 얹을 수 있다. 그리고 가드가 진짜 가드인지 변이 테스트로 확인했다. 콜론을 되돌려 보고, 테스트가 정확히 그 지점에서 빨개지는 걸 본 다음에야 커밋했다. 버그를 되돌렸는데 테스트가 여전히 초록이라면 그 테스트는 없는 것과 같다.

한 건이 아니었다

여기서 멈췄다면 절반만 고친 것이다. 같은 실수가 한 곳에 있다면 다른 곳에도 있을 가능성이 높다. 결함의 "부류"를 정의하고 - 콜론이 들어간 커스텀 jobId - 코드베이스를 전수 수색했고, 리뷰 에이전트를 여럿 붙여 교차 검증까지 걸었다. 두 건이 더 나왔다.

하나는 사용자가 올린 음성을 텍스트로 전사하는 큐였다. jobId: "stt:${id}". 이쪽은 에러를 여전히 삼키고 있어서 500조차 나지 않았다. 확인해 보니 12일 전부터 전사 잡이 단 한 건도 큐에 들어가지 않고 있었다. 음성 파일은 정상적으로 저장되고, 실패는 로그에만 남고, 사용자 화면에는 텍스트가 영영 비어 있는 상태. 완전한 무증상이었다.

다른 하나는 예약된 일정의 안내 이메일 큐였다. jobId가 콜론 4토막이라 리마인더도 취소 안내도 큐에 아예 들어가지 않았다.

세 큐의 producer를 공용 jobId 빌더 하나로 통일했다. 하이픈으로 조인하고, 콜론이 섞이면 치환하고, 순수 숫자를 거부하는 함수다. 재발 방지로 콜론 리터럴이 jobId에 들어가는 패턴만 정확히 잡는 린트 룰도 추가했다. 기존의 하이픈 jobId 50여 곳을 억지로 새 빌더로 마이그레이션하지는 않았다. repeatable 잡의 jobId가 바뀌면 cron이 중복 등록될 위험이 있어서, 결함 부류만 겨냥하는 쪽을 택했다.

두 번째 함정: 고정 jobId는 재시도를 조용히 죽인다

이야기가 여기서 끝나면 좋았겠지만, 리뷰 검증 중에 더 근본적인 문제가 나왔다. 콜론을 고치고 나면 answer-notify-123 같은 고정 jobId가 살아나는데, 이 고정 jobId 자체가 같은 날 세운 재시도 계약과 모순이었다.

BullMQ는 같은 jobId의 잡 해시가 Redis에 남아 있으면, 새 add를 에러 없이 무시하고 기존 jobId를 반환한다. 검증자가 BullMQ의 Lua 스크립트까지 읽어 확인한 동작이다. 그런데 이 큐는 removeOnComplete: { count: 100 }이라 방금 완료된 잡의 해시도 그대로 남는다. 조합하면 이런 시나리오가 된다. 알림 잡이 한 번 실패한다. 계약대로 "답변됨" 표시를 되돌리고, 관리자가 재시도한다. 새 enqueue는 남아 있는 잡 해시에 걸려 아무것도 하지 않고 성공처럼 반환한다. 알림은 영영 나가지 않는데, 이번에는 에러도 DLQ도 없다.

실패를 삼키는 catch를 없앴더니, 라이브러리의 dedupe가 같은 자리를 이어받는 셈이다. 결국 이 큐에서는 커스텀 jobId를 아예 뺐다. 중복 발송 방지는 소비자 쪽으로 옮겨서, 프로세서가 "알림 발송됨" 표시를 조건부 갱신으로 원자적으로 선점하게 했다. 잡이 두 번 들어와도 표시를 먼저 잡은 한쪽만 푸시를 쏜다.

커스텀 jobId로 중복을 막고 있고 실패 시 재enqueue하는 설계가 함께 있다면, 두 장치가 서로를 죽이지 않는지 확인해 볼 만하다. 우리처럼 "재시도가 조용히 no-op이 되는" 조합일 수 있다.

피해는 얼마였나

12일간 죽어 있던 기능이라니 피해가 클 것 같지만, 실측 결과는 달랐다. 답변 알림은 해당 기능이 아직 프로덕션에서 실사용 전이라 유실이 0건이었다. 이메일 큐도 지난 일정뿐이라 재발송할 대상이 없었다. 실제 회수 대상은 전사되지 않은 음성 2건. 남은 음성 파일로 재전사해서 복구했다.

운이 좋았다. 그리고 이 운은 반복되지 않는다. 실사용 중인 기능이었다면 12일치 알림과 전사가 그대로 날아갔을 것이고, 잡이 애초에 큐에 만들어진 적이 없으니 배포로는 아무것도 회수되지 않았을 것이다. 백필 스크립트를 짜는 일은 부차적이었다. 죽은 기능이 12일간 죽은 줄 몰랐다는 사실을 고치는 게 본질이라고 판단했다. 그래서 전사 실패가 더 이상 로그에만 남지 않고 알림 채널로 올라오게 했고, 답변 알림 경로는 트랜잭션과 함께 커밋되는 아웃박스로 옮겨 "DB에는 성공이 기록됐는데 잡은 없는" 상태 자체를 없앴다.

남긴 것

이번 일에서 코드보다 오래 남을 세 가지.

첫째, catch에서 로그만 남기고 정상 반환하는 코드는 그 경로가 100% 실패해도 아무도 모르게 만든다. 삼킬 거면 최소한 실패를 세는 지표나 알림이 함께 있어야 하고, 그게 없다면 던지는 게 낫다. 던져진 에러는 시끄럽지만 고쳐지고, 삼켜진 에러는 12일을 산다.

둘째, 목은 실제 계약만큼 엄격해야 한다. 무조건 성공하는 목 위에서는 어떤 입력도 검증되지 않는다. 라이브러리에 순수 검증 함수가 있다면 목에 태우고, 버그를 되돌려 테스트가 빨개지는지까지 확인해야 가드다.

셋째, 결함은 부류로 잡는다. 같은 코드베이스에서 같은 실수는 한 번만 일어나지 않는다. 하나를 찾았으면 부류를 정의해 전수 수색하고, 린트 룰이든 공용 빌더든 그 부류가 다시 못 들어오게 막는 데까지 가야 한 번의 발견이 값을 한다.

자주 묻는 질문

BullMQ에서 'Custom Id cannot contain :' 에러가 나요. 왜 그런가요?

BullMQ v5는 커스텀 jobId에 콜론(:)을 금지합니다. 콜론이 Redis 키를 조립할 때 쓰는 구분자이기 때문입니다. 정확한 조건은 'jobId에 콜론이 있으면서 콜론으로 나눈 토막이 3개가 아닐 때'이며, 3토막 예외는 레거시 repeatable 잡 형식을 위한 것입니다. 순수 숫자 jobId도 'Custom Id cannot be integers'로 거부됩니다. 구분자는 하이픈을 쓰세요.

목(mock)을 쓴 테스트가 이런 버그를 왜 못 잡나요?

목이 실제 구현의 계약과 다르게 동작하면, 테스트는 실제로는 죽어 있는 코드를 초록으로 보증합니다. 큐의 add를 무조건 성공하는 목으로 대체하면 라이브러리의 입력 검증이 아예 실행되지 않아, 항상 거부되는 jobId도 테스트를 통과합니다. 목이 최소한 실제 라이브러리의 검증 함수는 태우게 만들고, 버그를 되돌렸을 때 테스트가 빨개지는지(변이 테스트)까지 확인해야 가드가 됩니다.

관련 글

댓글 0