밤에만 실패하는 테스트 — 같은 커밋이 낮에는 통과했습니다

CI 게이트가 밤 9시 42분에 실패했습니다. 제가 바꾼 것은 API 서버의 e2e 테스트 하네스뿐이었는데, 실패한 것은 다른 앱(worker)의 알림 테스트 8건이었습니다. 그리고 같은 테스트가 그날 오후에는 통과했습니다.

CI 테스트 시간 줄이기 연재의 다섯 번째 편이자 곁가지입니다. 시간을 줄이다가 시각에 걸린 이야기입니다. 원인을 찾은 과정보다, 원인을 «믿을 수 있게» 좁힌 실험과, 그 과정에서 드러난 더 조용한 문제를 중심으로 적습니다.

실패한 것은 건드리지 않은 테스트였습니다

측정을 위해 같은 브랜치로 CI 게이트를 두 번 차례로 돌렸습니다. 두 번 모두 마지막 단계인 worker DB 테스트에서 같은 8건이 실패했습니다. 제 변경이 걸린 e2e 단계는 두 번 다 통과했습니다.

실패한 8건은 모두 「알림을 대기열에 펼치고, 보낼 행을 잡고, 보낸다」를 기대하는 테스트였습니다. 실제 값은 이랬습니다.

- Expected
+ Received

  {
-   "batches": 1,
+   "batches": 0,
    "failed": 0,
    "lost": 0,
    "mode": "ENABLED",
-   "sent": 2,
+   "sent": 0,
  }

보낼 행이 하나도 잡히지 않았다는 뜻입니다. 같은 파일의 나머지 테스트는 통과했습니다. 오류도 예외도 없이, 그저 «보낼 것이 없었다»는 결과였습니다.

내 변경 때문인지부터 갈랐습니다

변경 파일은 API 쪽 테스트 하네스 두 개였고, worker 테스트는 그 하네스를 가져다 쓰지 않았습니다. 하지만 「관계없어 보인다」는 증명이 아닙니다. 그래서 질문을 바꿨습니다. 이 테스트는 «언제부터» 실패하는가.

기록을 거슬러 올라가니 그날 오후 5시 15분에 돈 dev 브랜치의 CI 에서는 이 파일이 전부 통과했습니다. 그 뒤로 dev 에 들어온 알림 관련 변경은 하나였습니다. 대기열 행을 잠그는 트랜잭션의 격리 수준을 바꾼 커밋입니다. 가장 그럴듯한 용의자였습니다.

결정적인 실험은 단순했습니다. 오후 5시 15분에 통과했던 «바로 그 커밋»을 별도 작업 트리로 꺼내, 밤 10시 16분에 로컬 전용 DB 로 같은 파일을 돌렸습니다.

시각	커밋	장소	결과
17:15	A	CI	전부 통과
21:42 · 21:56	A 이후 커밋들 + 내 변경	CI	8건 실패
22:16	A 그대로	로컬	같은 8건 실패

커밋 A 에는 용의자였던 격리 수준 변경이 없습니다. 그런데도 밤에는 실패했습니다. 그래서 원인은 코드의 차이가 아니라 시각의 차이라고 판단했습니다. 다만 이 실험이 확인한 것은 「같은 코드가 낮에는 통과하고 밤에는 실패한다」는 사실까지이며, «왜» 그런지는 알려 주지 않습니다. 이유는 코드를 읽어 찾았습니다.

원인 — 그날 들어온 야간 발송 대기

그날 오후, 밤 9시부터 아침 9시 사이에 대기열에 든 알림톡은 바로 보내지 않고 다음 날 아침 9시에 보내는 기능이 들어왔습니다. 대기열에 행을 넣을 때 「보낼 시각」을 함께 적고, 보내는 쪽은 보낼 시각이 지난 행만 집습니다. 보낼 시각은 애플리케이션의 시계가 아니라 DB 의 시계(NOW(3))로 계산합니다.

계산식을 일반화하면 아래와 같습니다. 순간 @at 은 UTC 이고, 한국 표준시는 UTC 에 9시간을 더한 값입니다. MySQL 에서 그대로 실행해 볼 수 있습니다.

SET @at = TIMESTAMP('2026-10-14 12:42:00'); -- UTC 순간 (KST 21:42)

SELECT CASE
  WHEN HOUR(DATE_ADD(@at, INTERVAL 9 HOUR)) >= 21
    THEN DATE_SUB(DATE_ADD(TIMESTAMP(DATE(DATE_ADD(@at, INTERVAL 9 HOUR))), INTERVAL 33 HOUR), INTERVAL 9 HOUR)
  WHEN HOUR(DATE_ADD(@at, INTERVAL 9 HOUR)) < 9
    THEN DATE_SUB(DATE_ADD(TIMESTAMP(DATE(DATE_ADD(@at, INTERVAL 9 HOUR))), INTERVAL 9 HOUR), INTERVAL 9 HOUR)
  ELSE NULL
END AS send_after_utc;
-- 2026-10-15 00:00:00 (= KST 10-15 09:00)

낮에 대기열에 든 행은 NULL 이라 바로 잡힙니다. 밤에 든 행은 다음 날 아침 9시가 박혀, 그 전까지는 잡히지 않습니다.

문제의 테스트들은 이 기능보다 먼저 쓰였고, 「펼치면 곧바로 보낼 수 있다」는 가정을 하고 있었습니다. 기능을 넣은 변경은 낮에 검증되고 병합됐고, 그 뒤로 CI 도 낮에만 돌았습니다. 그래서 아무도 몰랐습니다. 낮에 도는 CI 가 테스트의 숨은 전제가 되어 있었다는 생각이 들었습니다.

영향은 작지 않았습니다. 밤 9시부터 아침 9시 사이에 도는 모든 게이트, 즉 릴리스 게이트와 수동 게이트, 로컬 push 훅의 DB 테스트가 이 8건 때문에 빨갛게 됩니다. 릴리스를 밤에 자르는 날이 많았기 때문에, 그날 밤 릴리스도 막힐 뻔했습니다.

더 조용한 문제 — 밤에는 초록인데 아무것도 재지 않던 테스트

고치는 과정에서 같은 원인이 다른 테스트에서도 발견됐습니다. 「메일 발송은 알림톡 행을 건드리지 않는다」는 테스트입니다. 메일을 잡는 쿼리에서 채널 조건을 일부러 지우는 결함을 넣어 보면, 낮에는 이 테스트가 빨갛게 결함을 잡았습니다. 밤에는 초록이었습니다.

밤에는 알림톡 행이 「보낼 시각 전」이라, 채널 조건이 없어도 시각 조건이 먼저 그 행을 걸러 주었기 때문입니다. 채널 조건이 망가져도 결과가 같으니, 테스트는 통과하면서 아무것도 재지 않고 있었습니다.

실패하는 테스트는 적어도 소리를 냅니다. 이 테스트는 밤마다 조용히 통과하며 회귀를 놓칠 자리에 있었습니다. 결함을 일부러 넣어 보지 않았다면 발견하지 못했을 것입니다. 예전에 쓴 「결함 주입으로 방어선 24곳을 망가뜨려 봤습니다」에서 두 겹의 방어 중 한 겹만 재는 테스트를 다뤘는데, 이번에는 그 두 번째 겹이 「시각」이었던 셈입니다.

고친 방법 — 시각에 기대는 시험과 기대지 않는 시험을 나눴습니다

원인을 좁힌 쪽과 고친 쪽은 달랐습니다. 이번 작업은 Claude Code 세션 여러 개가 나눠 맡았는데, 수정은 그 기능을 만든 세션이 맡았습니다. 수정은 테스트 파일만 고쳤고, 접근은 네 갈래였습니다.

1. 야간 대기와 무관한 시험은 「낮에 든 행」으로 만듭니다

펼치기 직후 보낼 시각을 비우는 도우미를 두었습니다. 그러면 몇 시에 돌든 낮에 든 행과 같은 모양이 됩니다. 이 시험들이 재려는 것은 야간 대기가 아니라 펼치기와 잡기, 보내기이기 때문입니다.

import { isNotNull } from 'drizzle-orm';

// 펼친 행의 야간 대기를 푼다 — 이 파일의 시험은 대기와 무관한 경로를 잰다
async function expandAsDaytime(): Promise<void> {
  await expander.runOnce();
  await db.update(outbox).set({ scheduledAt: null }).where(isNotNull(outbox.scheduledAt));
}

2. 도우미를 우회하지 못하게 합니다

새 시험이 도우미를 거치지 않고 펼치기를 직접 부르면 같은 문제가 돌아옵니다. 그래서 이 파일에서 펼치기를 직접 부르는 자리가 도우미 안뿐인지, 소스를 읽어 세는 시험을 하나 더했습니다. 조금 낯선 방식이지만, 규칙을 기억에 맡기지 않고 테스트에 맡기는 쪽을 택했습니다.

3. 대기 동작 자체는 실제 시각과 무관하게 잽니다

「대기 중인 행은 잡히지 않고, 대기를 풀면 잡힌다」는 동작은 보낼 시각을 «지금 + 12시간»으로 직접 박아서 확인합니다. 지금이 몇 시든 그 행은 미래에 보낼 행이므로, 결과가 시각에 따라 달라지지 않습니다.

4. 야간 대기 식의 경계는 DB 세션 시계를 옮겨서 잽니다

식이 9시 정각, 21시 정각, 자정, 월말, 연말에서 맞는 값을 내는지는 시계를 옮겨야만 잴 수 있습니다. 여기서 중요한 점은 옮겨야 하는 시계가 애플리케이션의 시계가 아니라는 것입니다. 식은 DB 의 NOW(3) 를 읽으므로, 테스트 러너의 가짜 타이머로는 옮겨지지 않습니다.

MySQL 의 SET timestamp 는 그 연결(세션)의 NOW() 를 지정한 순간으로 고정합니다. 옮긴 뒤에는 NOW(3) 을 다시 읽어 실제로 옮겨졌는지 확인합니다. 옮기기가 조용히 실패하면 이후의 시험이 전부 「지금」 위에서 돌기 때문입니다.

import mysql from 'mysql2/promise';

// 세션 시간대가 UTC 라는 전제 — UNIX_TIMESTAMP 는 세션 시간대로 문자열을 읽는다
async function setSessionClock(conn: mysql.Connection, utc: string): Promise<void> {
  await conn.query('SET timestamp = UNIX_TIMESTAMP(?)', [utc]);
  const [rows] = await conn.query('SELECT CAST(NOW(3) AS CHAR) AS now');
  const now = (rows as Array<{ now: string }>)[0]?.now ?? '';
  if (!now.startsWith(utc.slice(0, 19))) {
    throw new Error(`세션 시계가 옮겨지지 않았다: ${now}`);
  }
}

async function resetSessionClock(conn: mysql.Connection): Promise<void> {
  await conn.query('SET timestamp = DEFAULT');
}

경계 시험은 KST 20:59:59.999, 21:00, 23:59:59, 00:00, 08:59:59.999, 09:00 과 월말·연말에서 식을 돌립니다. 이 시험들이 실제로 무언가를 재는지도 결함을 넣어 확인했습니다.

넣은 결함	빨개진 시험
창 시작 조건 >= 를 > 로(21시 정각 제외)	21건 중 3건
창 끝 조건 < 를 <= 로(9시 정각 포함)	21건 중 2건
DB 시계 대신 애플리케이션 시계로 계산	21건 중 5건

주의할 점도 둘 있습니다. SET timestamp 는 그 연결에만 적용되므로, 커넥션 풀의 다른 연결로 쿼리가 나가면 시계가 옮겨지지 않습니다. 그래서 시계를 옮기는 시험은 전용 연결 하나로 돕니다. 또 MySQL 문서에 따르면 SYSDATE() 는 SET timestamp 의 영향을 받지 않습니다. 코드가 NOW() 대신 SYSDATE() 를 쓴다면 이 방법은 통하지 않습니다.

검증 — 실패하던 그 시각에 통과했습니다

수정은 밤 11시 28분에 push 훅 전량을 밤 시각 그대로 돌려 통과한 뒤 병합됐습니다. 병합 직후 그 커밋으로 CI 게이트를 다시 돌렸고, 밤 11시 46분에 worker DB 테스트 45개 파일, 906건이 통과했습니다. 알림 대기열 파일의 48건도 모두 통과했습니다.

낮에 통과하는 것은 이번 문제에서 아무것도 증명하지 못합니다. 실패하던 그 시각대에 통과했다는 점이 이 검증의 의미였다는 생각이 들었습니다.

남긴 것

시각에 기대는 테스트에서는 「언제 도는가」도 입력입니다. CI 가 낮에만 돌면, 그것이 아무도 적지 않은 전제가 됩니다. 그리고 그 전제는 밤의 첫 실행에서 깨집니다.

시계는 하나가 아닙니다. 애플리케이션의 시계와 DB 의 시계가 따로 있고, 코드가 어느 시계를 읽는지 알아야 그 시계를 옮길 수 있습니다. 가짜 타이머로 시간을 멈춰 놓고 안심했던 테스트가 사실은 DB 의 진짜 시계 위에서 돌고 있을 수 있습니다.

통과하는 테스트가 무엇을 재는지는 결함을 넣어 봐야 압니다. 이번에 가장 오래 남는 교훈은 실패한 8건이 아니라, 밤마다 조용히 통과하던 1건이었습니다.

이 수정이 다룬 범위도 적어 둡니다. 고친 것은 문제가 드러난 두 테스트 파일입니다. 같은 저장소에 시각대에 기대는 다른 테스트가 없다는 것을 전수로 확인하지는 않았습니다. 밤에 도는 게이트가 계속 초록으로 남는지가 앞으로의 확인 방법입니다.