가끔 실패하는 테스트(flaky test) 잡기: 시계·난수·순서·스레드

시리즈: 테스트·디버깅 강좌 5/6 (고급). CI가 "대체로 초록불"이고, 이유를 묻지 않고 "재실행" 버튼을 누르기 시작한 개발자를 위한 글입니다. 이 강좌를 마치면 flaky 테스트를 원할 때 재현하고, 실패율을 재고, 증상이 아니라 원인을 없앨 수 있습니다.

신입 온보딩 때 받은 첫 과제를 머지했는데, 다음 주부터 그 테스트가 CI에서 가끔 빨간불이 됩니다. 코드 리뷰에서는 문제가 없었고, 재실행하면 통과합니다. 장애 대응 회고에서 "그 실패는 원래 가끔 나던 거라 무시했다"는 말이 나오면 이미 늦은 것입니다. 이것이 flaky 테스트, 즉 같은 코드인데 통과하기도 하고 실패하기도 하는 테스트입니다. 비용은 재실행 몇 번이 아닙니다. 팀이 빨간 빌드를 무시하는 습관을 들이고, 진짜 실패가 소음 속에 묻힙니다. 이 강좌에서는 현장에서 가장 흔한 다섯 가지 원인(시계, 난수, 테스트 순서, 스레드, 고정 sleep)을 일부러 일으키고, 몇 번에 한 번 실패하는지 세고, 고친 다음 다시 셉니다.

환경: Python 3.9.6(macOS 기본 Python), 플러그인 없이 unittest만, Apple Silicon Mac (M1 Pro), 8코어. 아래 비율은 모두 실제로 센 값이고 N을 함께 적었습니다. 난수 자체가 주제가 아닌 곳은 시드를 고정했습니다. 경로는 ~/demo/…로 줄였습니다. 이 강좌는 강좌 3: 첫 단위 테스트와 강좌 4: 테스트 더블·목·픽스처를 바탕으로 합니다.

flaky란 무엇이고, 고칠 때의 단 하나의 규칙

flaky 테스트에는 "숨은 입력"이 있습니다. 테스트 대상 코드는 매번 같아도, 테스트가 통제하지 않는 무언가, 즉 벽시계, 난수 생성기, 바로 앞에 돈 테스트, OS의 스레드 스케줄링, 기계가 얼마나 바쁜지가 실행마다 달라집니다. 고치는 생각은 늘 같습니다. 숨은 입력을 찾아 명시적인 입력으로 만든다.

스스로를 속이지 않기 위한 규칙은 하나입니다. 수정 전과 수정 후의 실패율을 같은 N으로 재기 전에는 고쳤다고 말하지 않는다. 원래 대부분 초록불이던 테스트라면 한 번 통과한 것은 증거가 되지 않습니다. 그래서 아래 각 절에는 "수정 전"과 "수정 후" 숫자가 반드시 있습니다.

가장 간단한 측정 도구는 재실행 루프이고, 어떤 테스트 러너에서도 쓸 수 있습니다.

fails=0
for i in $(seq 1 100); do
  python3 -m unittest -q test_coupon 2>/dev/null || fails=$((fails + 1))
done
echo "$fails/100 failed"

원인 1: 시드 없는 난수

쿠폰 코드 생성기입니다. 요구사항은 "숫자를 최소 1개 포함"이고, 테스트는 정확히 그것을 확인합니다.

# coupon.py
import random
import string

ALPHABET = string.ascii_letters + string.digits   # 62자

def make_code(length=8, rng=random):
    """쿠폰 코드를 반환한다. 요구사항: 숫자를 최소 1개 포함."""
    return "".join(rng.choice(ALPHABET) for _ in range(length))

# test_coupon.py
class CouponTest(unittest.TestCase):
    def test_code_has_a_digit(self):
        code = make_code()
        self.assertTrue(any(c.isdigit() for c in code), code)

8번 연속 돌리니 OK, FAILED, OK, FAILED, OK, OK, FAILED, OK였습니다. 실패한 회차의 출력입니다.

FAIL: test_code_has_a_digit (test_coupon.CouponTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "~/demo/flaky/test_coupon.py", line 8, in test_code_has_a_digit
    self.assertTrue(any(c.isdigit() for c in code), code)
AssertionError: False is not true : ZYRtMYHA

테스트가 맞고 코드가 틀렸습니다. 숫자가 들어간다는 보장이 어디에도 없습니다. 8글자가 모두 영문자 52개에서 뽑힐 확률은 (52/62)^8 = 24.48%. 실측은 10,000번 중 2,509번(25.09%), 두 번째는 2,487번(24.87%)이었습니다.

흔한 실수 → 실제로 일어나는 일 → 해결. 가장 먼저 떠오르는 건 테스트 맨 앞에서 random.seed(1)을 부르는 것입니다. 시드 1이면 코드는 iK2ZWeqh로 숫자가 있어서 테스트는 영원히 통과합니다. 시드 4면 ptgUzEjf로 영원히 실패합니다. 시드 고정은 버그를 고치지 않고 동전 던지기를 얼려 버릴 뿐입니다. 쓸모 있는 형태는 여러 시드로 돌리고, 실패할 때마다 재현용 시드를 출력하는 것입니다.

SEED = int(os.environ.get("TEST_SEED", "2026"))

class CouponTest(unittest.TestCase):
    def check_many(self, fn):
        master = random.Random(SEED)
        for i in range(200):
            seed = master.randrange(2**32)
            code = fn(rng=random.Random(seed))
            with self.subTest(seed=seed):
                self.assertTrue(any(c.isdigit() for c in code), f"{code} (seed={seed})")

이제 버그는 매번 결정적으로 실패합니다. TEST_SEED=2026에서는 200케이스 중 FAILED (failures=54), 첫 실패는 uzfmpThT (seed=2637987308)이고, REPL에서 make_code(rng=random.Random(2637987308))을 부르면 같은 uzfmpThT가 나옵니다. 진짜 수정은 코드 쪽입니다. 숫자 하나를 일부러 넣습니다.

def make_code_fixed(length=8, rng=random):
    chars = [rng.choice(ALPHABET) for _ in range(length - 1)]
    chars.insert(rng.randrange(length), rng.choice(string.digits))
    return "".join(chars)

수정 후: 시드 10,000개에서 실패 0. 여기서 얻을 습관은 두 가지입니다. 난수 생성기를 인자로 받게 만들 것(rng=random), 그리고 시드를 항상 출력할 것.

원인 2: 시계, 자정, 서머타임

이건 밤에 실패하기 때문에 당직자를 가장 괴롭힙니다. 마감일 라벨 함수입니다.

# due.py
from datetime import date, datetime, timedelta, timezone

def due_label(due: date, today: date) -> str:
    if due == today:
        return "today"
    if due == today + timedelta(days=1):
        return "tomorrow"
    return "later" if due > today else "overdue"

def label_for_now_flaky(due: date) -> str:
    return due_label(due, datetime.now().date())          # 로컬 벽시계

def label_for(due: date, now_utc: datetime) -> str:       # 시계 하나, 인자로 받음
    return due_label(due, now_utc.astimezone(timezone.utc).date())

flaky 테스트는 "내일"을 UTC로 만들고 로컬 날짜와 비교합니다.

def test_tomorrow(self):
    due = (datetime.now(timezone.utc) + timedelta(days=1)).date()   # UTC 날짜
    self.assertEqual(label_for_now_flaky(due), "tomorrow")          # 로컬 날짜

TZ=UTC에서는 통과합니다. UTC 06:00 무렵, UTC보다 8시간 늦은 시간대(TZ=XST8, 지어낸 시간대 이름)로 기계 시계를 돌리면 로컬에서는 아직 "어제"라 실패했습니다.

AssertionError: 'later' != 'tomorrow'
- later
+ tomorrow

얼마나 자주 실패할까요? 시각에 달렸으니 기다리는 대신 고정한 시계로 UTC 하루 1,440분을 전부 훑어 분마다 같은 로직을 평가했습니다.

"CI 서버에서 특정 시간대에만 실패한다"는 전형적인 보고가 이 표로 설명됩니다. CI는 UTC로, 개발자 노트북은 다른 시간대로 돌고, 실패 구간의 길이는 정확히 시차와 같습니다.

고친 테스트는 시계를 인자로 넘기고 경계를 고정합니다. 몇 시에 돌려도 의미가 같습니다.

class FixedDueTest(unittest.TestCase):
    def check(self, now):
        due = (now + timedelta(days=1)).date()
        self.assertEqual(label_for(due, now), "tomorrow")

    def test_tomorrow_one_second_before_midnight(self):
        self.check(datetime(2026, 11, 14, 23, 59, 59, tzinfo=timezone.utc))

    def test_tomorrow_at_midnight(self):
        self.check(datetime(2026, 11, 15, 0, 0, tzinfo=timezone.utc))

    def test_month_and_year_end(self):
        self.check(datetime(2026, 12, 31, 23, 30, tzinfo=timezone.utc))

서머타임(DST). 하루가 늘 86,400초는 아닙니다. 지어낸 서머타임 시간대(TZ="XST5XDT,M3.2.0,M11.1.0", 3월 둘째 일요일과 11월 첫째 일요일에 전환)에서 로컬 자정을 타임스탬프로 바꾸고 86,400으로 나눴습니다.

2026-03-08 -> 2026-03-09 23 h int(seconds/86400) = 0 | date subtraction = 1
2026-11-01 -> 2026-11-02 25 h int(seconds/86400) = 1 | date subtraction = 1

int(seconds / 86400)는 3월 8일과 9일의 차이를 0일이라고 합니다. TZ=UTC에서는 네 쌍 모두 24시간이었습니다. date 끼리의 뺄셈은 항상 맞습니다. 시각은 UTC로 저장·비교하고, 로컬 시각 변환은 화면에 보여 줄 때만 합니다.

흔한 실수: datetime.now 패치. 가장 직관적인 mock은 내장 타입에서 실패합니다.

  File "…/python3.9/unittest/mock.py", line 1502, in __enter__
    setattr(self.target, self.attribute, new_attr)
TypeError: can't set attributes of built-in/extension type 'datetime.datetime'

자기 모듈 안의 datetime이라는 이름을, now()가 고정값을 돌려주는 하위 클래스로 바꿔 끼울 수는 있습니다(해 보니 flaky 함수가 23:59:59에서 tomorrow를 반환했습니다). 하지만 시계를 인자로 넘기는 편이 더 단순하고, 의존성이 함수 시그니처에 드러납니다.

원인 3: 테스트 순서와 공유 상태

"혼자서는 통과, 전체로는 실패"는 거의 확실히 공유 상태입니다. 원화 가격 계산 모듈로 재현합니다.

# pricing.py
DEFAULTS = {"tax_rate": 0.10, "currency": "KRW"}
config = DEFAULTS            # 버그 1: 복사본이 아니라 별칭

def set_option(key, value):
    config[key] = value

def price_with_tax(amount):
    return round(amount * (1 + config["tax_rate"]), 0)

class PricingTest(unittest.TestCase):
    def test_default_tax(self):
        self.assertEqual(pricing.price_with_tax(10000), 11000)

    def test_zero_tax_promo(self):
        pricing.set_option("tax_rate", 0.0)       # 버그 2: 되돌리지 않음
        self.assertEqual(pricing.price_with_tax(10000), 10000)

    def test_rounding(self):
        self.assertEqual(pricing.price_with_tax(12900), 14190)

unittest는 메서드를 알파벳 순으로 실행하므로 test_zero_tax_promo가 우연히 마지막에 돌고, 전체는 초록불입니다. 이름이 뒤로 가는 테스트를 하나 추가하거나, 병렬 워커로 테스트를 나누면 깨집니다. Python 3.9의 python3 -m unittest에는 순서를 섞는 옵션이 없어서, 테스트를 불러와 random.Random(seed)(시드 0~199)로 섞고, 매번 모듈을 다시 import해 상태를 깨끗하게 만드는 25줄짜리 러너를 썼습니다. 결과는 200가지 순서 중 139가지 실패(이론값 2/3, promo 테스트가 마지막이어야 통과). 첫 실패는 시드 0의 순서였습니다.

first failing order (seed 0): ['test_default_tax', 'test_zero_tax_promo', 'test_rounding']
AssertionError: 12900.0 != 14190

수정은 버그마다 하나씩입니다. 코드 쪽은 config = dict(DEFAULTS)와 reset() 함수. 테스트 쪽은 assertion이 실패해도 반드시 도는 정리 코드입니다.

class PricingTest(unittest.TestCase):
    def setUp(self):
        self.addCleanup(pricing.reset)          # 테스트가 실패해도 실행된다

    def test_zero_tax_promo_patch_dict(self):
        with mock.patch.dict(pricing.config, {"tax_rate": 0.0}):
            self.assertEqual(pricing.price_with_tax(10000), 10000)

수정 후: 섞은 순서 200가지에서 실패 0. config = DEFAULTS를 그대로 두면 "기본값" 자체가 바뀌므로 reset()을 만들어도 소용없었다는 점에 주의하세요.

원인 4: 스레드 사이의 경쟁 상태

스레드 4개가 공유 카운터에 각각 50,000번 더합니다.

class HitCounter:
    def __init__(self):
        self.value = 0
    def hit(self):
        self.value += 1            # 읽기, 더하기, 쓰기: 세 단계

기대값은 200,000. 6번 돌리니 194148, 156216, 199794, OK, 104471, OK였습니다. GIL이 있어도 +=는 원자적이지 않아서, 읽은 뒤 쓰기 전에 스레드가 바뀔 수 있습니다. 전환은 대략 sys.getswitchinterval()초마다(이 기계에서는 0.005) 일어나고, 이것이 아래의 의외의 결과를 설명합니다.

작은 테스트(스레드당 10,000번)는 한 번도 실패하지 않았습니다. 각 스레드가 5 ms 타임 슬라이스 안에 일을 끝내기 때문입니다. 경쟁 상태 버그가 코드 리뷰와 단위 테스트를 통과하고 운영 부하에서야 터지는 구조가 바로 이것입니다. 기억할 것은 여섯째 줄입니다. 전환 간격을 아주 작게 하면 드문 경쟁이 2 ms짜리 테스트에서 100% 재현됩니다. 확실히 실패하게 만든 다음 락을 넣고, 같은 가혹한 설정으로 고쳐졌음을 확인합니다.

class SafeHitCounter:
    def __init__(self):
        self.value = 0
        self._lock = threading.Lock()
    def hit(self):
        with self._lock:
            self.value += 1

락 때문에 200,000번 더하기 비용이 약 2배(30.4 ms → 59.9 ms)가 됐습니다. 카운터라면 괜찮지만 자주 도는 경로라면 재 볼 가치가 있습니다. GIL이 스레드를 어떻게 바꾸는지는 스레드·프로세스·asyncio를, 단일 스레드 이벤트 루프의 순서 함정은 JavaScript Promise와 이벤트 루프를 참고하세요.

원인 5: sleep으로 기다리는 테스트

백그라운드 워커가 결과를 계산하고, 테스트는 "충분히 기다립니다".

class ThumbnailWorker:
    def __init__(self):
        self.result = None
        self.done = threading.Event()

    def submit(self, n):
        def run():
            self.result = sum(i * i for i in range(n))   # CPU로 약 16 ms
            self.done.set()
        threading.Thread(target=run, daemon=True).start()

w = ThumbnailWorker(); w.submit(400_000)
time.sleep(0.02)                      # "이 정도면 되겠지"
assert w.result is not None

기계가 한가하면 200번 중 실패 0. 여기에 실제 테스트 스위트에서 흔한 상황, 다른 테스트가 끄지 않고 남긴 CPU를 쓰는 스레드 하나를 더했습니다. 200번씩 4세트에서 17, 9, 19, 21번 실패했습니다(평균 8.3%). 바쁜 스레드가 GIL을 절반쯤 쥐고 있어서 16 ms짜리 일이 거의 두 배 걸립니다. 흥미롭게도 OS 수준의 부하(8코어에 CPU를 쓰는 프로세스 12개)로는 200번 중 1번만 실패했습니다. 진짜 방아쇠는 같은 프로세스 안의 스레드였습니다.

긴 sleep은 모든 실행을 느리게 만드는 대가로 flaky를 "고칩니다". 이벤트 대기는 일이 끝나는 순간 돌아오므로 확실하고 가장 빠릅니다. timeout은 진짜 버그일 때 멈춰 있지 않고 실패하게 하려고 있을 뿐입니다.

남겨진 스레드에는 전용 검사를 붙이세요. 다음 기반 클래스는 스레드를 남긴 테스트를 실패시킵니다.

class NoLeakedThreads(unittest.TestCase):
    def setUp(self):
        before = set(threading.enumerate())
        def check():
            leaked = [t.name for t in threading.enumerate() if t not in before and t.is_alive()]
            self.assertEqual(leaked, [], "test left threads running")
        self.addCleanup(check)

poller 스레드를 띄우고 끄지 않은 테스트는 AssertionError: Lists differ: ['poller'] != []로 실패했고, 게다가 FAILED를 출력한 뒤 프로세스 전체가 멈췄습니다. 데몬이 아닌 스레드가 Python을 계속 살려 두기 때문이고, 5초 뒤 alarm으로 끝냈습니다(종료 코드 142). CI 잡이 "테스트는 끝났는데 안 끝난다"면 먼저 이것을 의심하세요.

수정 전후를 한 표로

격리할까, 지울까? 오늘 고칠 수 없는 flaky 테스트는 잰 실패율과 함께 분명히 표시합니다(예: @unittest.skip("flaky: issue-123, 54/100")). 그래야 팀이 빨간 빌드를 무시하도록 길들여지지 않습니다. "3번 재시도"를 영구 해결책으로 삼으면 안 됩니다. 강좌 6에서는 10% 확률로 실패하는 테스트가 git bisect에 엉뚱한 커밋을 지목하게 만드는 모습을 잽니다.

솔직한 한계와 버전 메모

• 모두 Python 3.9.6에서만 실행했습니다. sys.setswitchinterval은 Python 3.2부터 있습니다. free-threaded Python(3.13 이상)이나 다른 버전에서는 경쟁 빈도가 다를 수 있지만 돌려 보지 않았습니다.
• 3.9의 python3 -m unittest에는 무작위 순서 기능이 없습니다. pytest-randomly 같은 플러그인이 있지만 여기서는 설치도 실행도 하지 않았습니다.
• 서머타임 데모는 지어낸 POSIX 시간대 문자열이며 실제 지역이 아닙니다. 실제 시간대 규칙은 tz 데이터베이스에서 오고 법이 바뀌면 달라집니다.
• 실패율은 기계에 따라 다릅니다. 숫자는 "이만큼 커질 수 있다"는 감으로 읽고, 위의 루프로 자기 환경을 재세요.
• flaky 실패를 쫓을 때는 시드, 시계 값, 테스트 순서를 로그에 남기면 다음 발생을 재현할 수 있습니다. 감이 아니라 로그가 진짜 원인을 찾은 사례는 AI 에이전트의 오진을 로그로 잡아낸 이야기에 있습니다. 시리즈 전체 위치는 프로그래밍 학습 로드맵에서 볼 수 있습니다.

연습 문제

1. shuffle_deck()이 같은 카드를 두 번 내지 않는지 확인하는 테스트가 지난주 CI에서 딱 한 번 실패했습니다. 가장 먼저 무엇 두 가지를 추가하나요?
2. "전날" 파일을 고르는 리포트 작업이 date.today()를 씁니다. CI는 UTC, 사내 서버는 다른 시간대입니다. 테스트에서 어떤 값을 고정하나요?

정답

1. 난수 생성기를 shuffle_deck(rng=...)로 넘길 수 있게 하고, subTest로 여러 시드를 돌려 실패 시 시드를 출력합니다. 그다음 코드를 건드리기 전에 루프로 실패율을 잽니다. 한 번이라도 본 실패는 측정이 아니라고 할 때까지 진짜입니다.
2. now(UTC)를 인자로 넘기고 최소한 UTC 23:59:59와 00:00:00, 월초, 1월 1일을 테스트합니다. 로컬 시각을 써야 한다면 고정한 시간대로 서머타임 전환일도 테스트합니다.

---

이전: 테스트·디버깅 강좌 4: 테스트 더블·목·픽스처 · 다음: 테스트·디버깅 강좌 6: git bisect로 회귀 찾기