Celery Beat 격자와 시간 윈도우 경계에서 생긴 버그 - 10분 전 알림이 항상 15분 전에 온 이유

예전에 django-celery-beat의 내부 구조를 정리한 적이 있는데, 이번에는 beat로 도는 주기 배치에서 겪은 실전 버그입니다.

시설 예약 시스템에는 "이용 시작 10분 전 입장 안내 푸시"가 있습니다.

그런데 QA에서 이런 제보가 왔습니다.

"10분 전 알림이 15분 전에 와요. 가끔이 아니라 항상요."

이 "항상"이라는 단어가 이 버그의 가장 큰 단서였습니다. 간헐적이면 타이밍 문제를 의심하게 되지만, 항상 5분이 밀린다는건 구조적인 원인이 있다는 뜻이기 때문입니다.

1. 구조: 모든 것이 5분 격자 위에 있다
2. 원인: beat는 정시에 돌지 않는다
3. 수정: 윈도우를 격자에서 띄운다
4. 회귀 테스트: ε을 파라미터로
5. 반대로, ε 덕분에 동작하는 코드도 있었다
참고 자료

1. 구조: 모든 것이 5분 격자 위에 있다

상황을 정리하면 이렇습니다.

예약 슬롯의 시작 시각은 5분 격자 위에 있습니다 (10:00, 10:20, 10:40 ...)
발송 배치는 celery beat로 매 5분마다 실행됩니다 (10:00, 10:05, 10:10 ...)
배치는 "시작 시각이 지금부터 10~15분 사이인 예약"을 찾아 푸시를 보냅니다

@app.task
def send_check_in_guide_task():
    """입장 안내 푸시 - 이용 시작 10분 전. 매 5분 실행."""
    now = timezone.localtime()
    from_dt = now + timedelta(minutes=10)
    to_dt = now + timedelta(minutes=15)
    # 시작 시각이 [from_dt, to_dt) 인 예약 조회 후 발송
    ...

윈도우 폭이 beat 간격과 같은 5분이라, 이론상 모든 슬롯이 정확히 한번씩만 윈도우에 잡힙니다. 중복 발송도 누락도 없는, 종이 위에서는 완벽한 설계입니다.

10:00에 beat가 돌면 윈도우는 [10:10, 10:15) 이고, 10:20 슬롯은 10:05나 10:10의 beat가 잡겠죠.

그런데 실제로는 10:20 슬롯의 푸시가 항상 10:05 부근에 발송되고 있었습니다. 15분 전 입니다.

2. 원인: beat는 정시에 돌지 않는다

핵심은 ε(엡실론)입니다. beat는 10:05:00.000에 돌지 않습니다.

이전 글에서 정리했듯 beat의 tick 루프는 스케줄 확인과 발행을 반복하는 구조라서, 실행 시각은 항상 정시보다 몇초씩 늦습니다. 10:05:03 같은 식입니다.

이 몇초가 격자에 정확히 걸쳐있는 윈도우 경계를 무너뜨립니다.

10:20 슬롯 기준으로 수직선을 그려보면 이렇게 됩니다.

슬롯: 10:20:00

[10분 전 beat] 정시 10:10, 실제 10:10+ε
  윈도우 = [10:20+ε, 10:25+ε)
  10:20:00 은 하한(10:20+ε)보다 작다 → 미포함!  (ε초만큼 밀려남)

[15분 전 beat] 정시 10:05, 실제 10:05+ε
  윈도우 = [10:20+ε-5분... 정리하면 [10:15+ε, 10:20+ε)
  10:20:00 < 10:20+ε → 상한 안쪽 → 포함!

즉 ε이 0보다 크기만 하면,

슬롯은 원래 잡혀야 할 "10분 전 beat"의 윈도우에서 하한 밖으로 밀려나고
그 앞의 "15분 전 beat"의 윈도우 상한 안으로 들어옵니다

ε은 항상 양수이므로 매번, 항상, 정확히 5분 이른 beat에 잡힙니다. "가끔이 아니라 항상"의 정체가 이것이었습니다.

직접 시뮬레이션해본 결과입니다. beat 지연을 바꿔가며 슬롯이 몇분 전에 발송되는지 계산한 것 입니다.

ε= 0초 | 윈도우[10,15): 10.0분 전 발송   <- 이론
ε= 3초 | 윈도우[10,15): 14.9분 전 발송   <- 현실
ε=10초 | 윈도우[10,15): 14.8분 전 발송
ε=30초 | 윈도우[10,15): 14.5분 전 발송

ε=0일 때만 설계대로 동작합니다. 그리고 ε=0인 세상은 없습니다.

3. 수정: 윈도우를 격자에서 띄운다

수정은 코드 두 줄입니다. 윈도우를 [now+10, now+15)에서 [now+6, now+11)로 옮겼습니다.

    now = timezone.localtime()
    from_dt = now + timedelta(minutes=6)   # 10 -> 6
    to_dt = now + timedelta(minutes=11)    # 15 -> 11

숫자만 보면 임의로 보이지만 의도가 있습니다.

윈도우 경계(+6, +11)가 5분 격자(+5, +10, +15)에 걸치지 않습니다. 슬롯이 윈도우의 중앙 부근에 오게 됩니다.
슬롯(+10)과 경계 사이에 여유가 최소 1분 있으므로, ε이 수십초 흔들려도 판정이 바뀌지 않습니다.
윈도우 폭은 그대로 5분이라 무중복·무누락 성질은 유지됩니다.

같은 시뮬레이션을 새 윈도우로 돌리면 이렇게 됩니다.

ε= 0초 | 윈도우[6,11): 10.0분 전 발송
ε= 3초 | 윈도우[6,11):  9.9분 전 발송
ε=10초 | 윈도우[6,11):  9.8분 전 발송
ε=30초 | 윈도우[6,11):  9.5분 전 발송

ε과 무관하게 10분 전 beat가 정확히 한번 잡습니다.

4. 회귀 테스트: ε을 파라미터로

이런 버그는 고치는 것보다 "다시 안 생기게 만드는 것"이 중요해서, ε을 명시적으로 주입하는 회귀 테스트를 같이 넣었습니다.

from freezegun import freeze_time

class CheckInGuideWindowTest(TestCase):
    def _simulate_beats(self, slot_start, eps_seconds):
        """슬롯 이전 1시간 동안 5분 격자 + ε 지연으로 beat를 돌려 발송 횟수·시점 수집"""
        sends = []
        beat_time = slot_start - timedelta(hours=1)
        while beat_time <= slot_start:
            fired_at = beat_time + timedelta(seconds=eps_seconds)
            with freeze_time(fired_at):
                sent = send_check_in_guide_task()
            if sent:
                sends.append((slot_start - fired_at).total_seconds() / 60)
            beat_time += timedelta(minutes=5)
        return sends

    def test_sends_once_at_10_minutes_regardless_of_beat_delay(self):
        for eps in [0, 3, 10, 30]:
            sends = self._simulate_beats(self.reservation_start, eps)
            self.assertEqual(len(sends), 1)          # 정확히 1회
            self.assertAlmostEqual(sends[0], 10, delta=1)  # 10분 전 부근

포인트는 ε=0 케이스만 테스트하면 이 버그를 영원히 못잡는다는 것 입니다. 테스트의 시계도 현실처럼 조금씩 늦어야 합니다.

5. 반대로, ε 덕분에 동작하는 코드도 있었다

수정하면서 같은 파일의 다른 배치들도 점검했는데, 재미있는 것을 발견했습니다.

체크아웃 시간 초과 알림(종료 N분 후 발송)은 윈도우 상한이 격자에 걸쳐 있는데도 정상 동작하고 있었습니다.

이유를 따져보니, 상한이 제외(<) 경계라서 ε이 상한을 종료 시각보다 살짝 키워주는 덕분에 정확히 N분 후 beat에 잡히는 구조였습니다. 말하자면 ε 때문에 우연히 맞게 동작하는 코드입니다.

이 경우 누군가 "시간 비교를 깔끔하게 하자"며 now를 분 단위로 내림(floor)하는 순간 ε=0이 되어 알림이 5분씩 늦게 나가게 됩니다.

지금 당장 고칠 문제는 아니지만 침묵하고 있으면 미래의 누군가(아마도 저)가 밟을 지뢰라서, docstring으로 명시해뒀습니다.

    # 주의: 상한 now-stage 가 격자에 걸리지만 '제외(<)' 경계라, beat 실행 지연(ε>0)이
    # 상한을 종료 시각보다 살짝 키워 정확히 stage분 후 1회만 발송된다.
    # now 를 분/격자 단위로 내림(floor)하면 ε=0 이 되어 5분 늦게 발송되니 주의.

우연히 동작하는 코드는 고장난 코드와 문서화된 코드 사이 어딘가에 있습니다. 최소한 문서화 쪽으로 옮겨둬야 합니다.

이번 버그에서 정리하게 된 원칙은 두가지입니다.

시간 윈도우의 경계를 대상 시각의 격자에 걸치게 만들지 말 것. 경계와 격자가 겹치는 순간, 판정은 코드가 아니라 ε의 부호가 결정하게 됩니다.

그리고 주기 배치를 설계할때는 "beat는 항상 조금 늦는다"를 전제에 포함할 것. ε=0 가정으로 종이 위에서 완벽한 설계는, 현실의 몇초 앞에서 매번 같은 방향으로 틀립니다.

1. 구조: 모든 것이 5분 격자 위에 있다

2. 원인: beat는 정시에 돌지 않는다

3. 수정: 윈도우를 격자에서 띄운다

4. 회귀 테스트: ε을 파라미터로

5. 반대로, ε 덕분에 동작하는 코드도 있었다

참고 자료