RateLimitTest는 혼자 돌리면 늘 초록불이었다. 그런데 전체 스위트에서만 간헐적으로 429를 맞고 죽었다. 같은 시기에composer test는 타임아웃으로 완주조차 못 했다. 둘 다 "전체로 돌릴 때만" 나타나는 문제였고, 원인은 완전히 달랐다. 타임아웃 값을 세 번 올린 끝에 진짜 원인을 고친 기록이다.
0. 상황
AIFid(멀티테넌트 실시간 상담 시스템)의 백오피스는 CodeIgniter 4다. 푸시 전 게이트는 composer test(PHPUnit 전체 스위트)이고, pre-push 훅이 이걸 돌린다. 개별 테스트는 다 통과하는데 전체만 돌리면 사고가 나는 유형이 두 가지 겹쳤다.
- 특정 테스트(
RateLimitTest)가 전체 스위트에서만 간헐적으로 실패한다. - 스위트가 커지면서
composer test자체가 타임아웃으로 죽는다.
두 문제는 서로 원인이 아니다. 다만 둘 다 "개별 실행으로는 재현되지 않는다"는 점이 같아서, 처음에는 한 덩어리의 불안정으로 보였다.
1. 타임아웃 첫 번째: 300초 → 900초 (2026-07-27, #23)
푸시 직전 훅이 이런 메시지와 함께 실패했다.
The process "phpunit" exceeded the timeout of 300 seconds.
Composer의 process-timeout 기본값은 300초다. 테스트가 351개로 늘면서 실행 시간이 250~310초대까지 올라와 경계에 걸렸다. 어떤 날은 통과하고 어떤 날은 죽으니 플레이키처럼 보이지만, 실제로는 스위트가 느려진 것뿐이었다. backoffice/composer.json에 한 줄을 넣었다.
"config": {
"process-timeout": 900
}
이때는 이게 맞는 수정이라고 생각했다. 스위트가 커지면 시간이 늘고, 타임아웃은 그걸 허용해야 한다고.
2. RateLimitTest: 혼자는 초록, 전체에서는 429 (2026-07-28, #46)
다음 날 RateLimitTest::testMessageSendingIsLimitedPerVisitor가 전체 스위트에서만 실패했다. 이 테스트는 방문자 한 명이 메시지를 32번 보내서, 30번째까지는 통과하고 31번째부터 429가 나는지 본다.
$this->assertNotSame(429, $statuses[29]);
$this->assertSame(429, $statuses[30]);
실패는 "30번째가 이미 429"였다. 즉 버킷이 비어 있어야 할 시점에 이미 소진돼 있었다. 혼자 돌리면 항상 통과한다. 앞선 테스트의 상태가 새는 전형적인 증상이었다.
의심한 것
setUp()에는 이미 cache()->clean()이 있다. 토큰 버킷은 캐시에 사는데, 앞 테스트가 남긴 버킷이 넘어오면 첫 요청부터 429가 나므로 방어해 둔 것이다. 그런데도 새고 있었다. 청소가 닿지 않는 캐시가 어딘가 있다는 뜻이다.
또 하나 단서가 있었다. 테스트마다 DB를 비우면 AUTO_INCREMENT가 초기화되어, 서로 다른 테스트가 같은 방문자 id(예: 1)를 쓴다. 버킷 키는 방문자 id로 만들어지므로, 앞 테스트가 소진한 버킷을 다음 테스트가 같은 키로 이어받을 수 있다. 문제는 그 버킷이 왜 cache()->clean()으로 안 지워지느냐였다.
원인
CI4의 CIUnitTestCase는 매 테스트마다 cache 서비스를 새 MockCache로 교체한다. 그런데 RateLimiter가 쓰던 service('throttler')는 프로세스 전체에서 공유되는 싱글턴이다. throttler는 처음 만들어질 때 그 시점의 캐시 참조를 잡고 놓지 않는다.
테스트 A: cache = MockCache#1 → throttler 생성, MockCache#1 을 붙든다
테스트 B: cache = MockCache#2 로 교체, cache()->clean() 은 #2 를 비운다
하지만 throttler 는 여전히 #1 에 버킷을 쓰고 읽는다
그래서 cache()->clean()은 아무 효과가 없었다. 청소는 새 캐시를 비웠고, 버킷은 옛 캐시에 남아 있었다. 같은 방문자 id를 쓰는 다음 테스트가 그 버킷을 이어받아 조기 429를 받았다. 어떤 테스트가 먼저 throttler를 만드느냐, 어떤 순서로 도느냐에 따라 나타나서 간헐적이었다.
수정
service() 대신 single_service()를 쓴다. 공유 인스턴스가 아니라 매번 새로 만들어 항상 현재의 cache 서비스를 물게 한다.
$throttler = single_service('throttler');
RateLimiter와 같은 패턴을 쓰던 TenantQuota도 같이 고쳤다. 회귀 테스트(RateLimiterCacheIsolationTest)는 버킷을 소진시킨 뒤 cache 서비스를 새 MockCache로 갈아끼우고, 새 캐시 아래에서는 허용되는지를 확인한다. 공유 throttler가 옛 캐시를 붙든다면 이 테스트가 그 지점에서 막힌다.
돌아보면 "플레이키 테스트"가 아니었다. 프로덕션 코드가 테스트 하네스의 서비스 교체와 맞지 않는 방식으로 상태를 쥐고 있었다. 테스트가 약한 게 아니라 오히려 정확하게 그 결함을 짚고 있었다.
3. 타임아웃 두 번째: 900초 → 3600초 (2026-08-05, #103)
스위트는 계속 커졌다. 로컬 전체 실행이 약 913초가 되자 900초 타임아웃에 걸려 composer test가 매번 죽었다. CLAUDE.md가 dev 푸시 전 게이트로 정한 명령이 정작 완주하지 못하는 상태였다. phpunit을 직접 부르면 통과하니 스위트가 틀린 건 아니었다. 이번에는 여유를 두고 3600초로 올렸다.
돌이켜보면 이 수정은 증상 처리였다. 스위트가 5분에서 15분으로 늘었는데 "더 기다려 준다"로 대응했다. 같은 PR에서는 워크트리 두 곳이 같은 테스트 DB를 공유해서 서로 테이블을 드롭하던 문제도 같이 고쳤는데, 그쪽은 Table 'x' doesn't exist, Deadlock found처럼 매번 다른 에러가 나서 마이그레이션 문제로 오인하기 쉬웠다. 전체 스위트에서만 500건이 넘게 터졌다. 이 역시 "혼자 돌리면 통과"하는 유형이었다.
4. 타임아웃 세 번째: 3600초도 넘었다 (2026-09-04, #141)
CI의 백오피스 잡이 한 시간을 넘겨 죽었다. 메시지는 이랬다.
The process "phpunit" exceeded the timeout of 3600 seconds.
처음에는 DB를 의심했다. MySQL에 계측을 붙여 보니 한 시간 내내 멀쩡했다. 커넥션은 2~3개로 고정이었고, abort는 0이었고, 종료 시점에도 healthy였다. 테스트도 378개째까지 전부 통과 중이었다. DB 문제도 아니고 테스트 실패도 아니었다. 그냥 느린 것이었다.
진짜 원인
AuthTestCase는 $refresh = true다. CI4에서 이 설정은 테스트 클래스가 아니라 테스트 메서드마다 전체 regress → migrate를 돈다. 마이그레이션이 38개이고 DB를 쓰는 테스트가 수백 개라 DDL이 수만 건이다. InnoDB의 DROP/CREATE는 파일 조작이라 건당 수십 ms가 든다. 러너에서 측정하니 MySQL이 567초 동안 테이블을 4,707번 열었다. 맥에서도 같은 비용이었고, 디스크가 빨라서 덜 아팠을 뿐이다.
타임아웃을 올릴 때마다 이 비용이 가려졌다. 300초에서 900초로, 900초에서 3600초로 올리는 동안 스위트가 "더 느려지고 있다"는 신호가 매번 설정값 하나에 묻혔다.
수정
스키마는 프로세스당 한 번만 만든다($migrateOnce = true, $refresh = false). 그리고 새 트레이트 TruncatesTables가 테스트마다 데이터만 비운다. "빈 DB로 시작한다"는 기존 테스트의 전제는 그대로라 테스트 코드는 손대지 않았다.
DELETE가 아니라TRUNCATE를 쓴다. AUTO_INCREMENT까지 초기화되어 갓 만든 스키마와 같은 상태가 된다.- 행이 있는 테이블만 비운다. InnoDB에서는
TRUNCATE도 테이블스페이스를 다시 만드는 파일 조작이라 공짜가 아니다. 한 테스트가 실제로 건드리는 테이블은 보통 몇 개뿐이다. 판별은LIMIT 1조회로 한다.information_schema.TABLE_ROWS는 InnoDB에서 추정치라 믿을 수 없다. *MigrationTest두 개는 일부러$refresh = true로 남겼다. 스위트 안에regress → migrate사이클을 실제로 도는 자리가 하나쯤은 있어야 한다.
5. 정리
| 날짜 | 증상 | 한 일 | 성격 |
|---|---|---|---|
| 07-27 (#23) | 300초 타임아웃 | 900초로 상향 | 증상 처리 |
| 07-28 (#46) | RateLimitTest가 전체에서만 429 |
single_service('throttler') |
진짜 원인 수정 |
| 08-05 (#103) | 913초 > 900초 | 3600초로 상향 | 증상 처리 |
| 09-04 (#141) | 3600초 초과 | 스키마 1회 + 데이터만 TRUNCATE | 진짜 원인 수정 |
두 가지를 배웠다.
"전체에서만 터진다"는 격리가 깨졌다는 신호다. 개별로 통과하는 테스트가 전체에서만 실패하면 테스트가 아니라 공유 상태를 먼저 본다. 이번에는 프로세스 전역 싱글턴이 테스트 하네스가 교체한 캐시를 못 따라가는 경우였다. cache()->clean()을 더 넣는 건 답이 아니었다. 청소하는 쪽이 아니라 청소가 닿지 않는 쪽을 고쳐야 했다.
타임아웃을 올리는 수정은 두 번까지만 허용한다. 한 번은 정당했다. 스위트가 정말 커졌으니까. 하지만 세 번째에서는 실행 시간이 왜 이렇게 자라는지 먼저 물었어야 했다. 한도를 올릴 때마다 근본 비용이 보이지 않게 된다. 이번에는 "느린 게 아니라 DB가 죽은 건가"라는 의심이 계측으로 이어졌고, 그 계측 덕분에 DB가 아니라 DDL 횟수라는 답이 나왔다.
두 문제는 이어져 있지 않았다. 레이트 리밋 플레이키는 상태 누수였고 타임아웃은 비용 누적이었다. 둘이 같은 "전체 스위트 문제"처럼 보인 이유는 증상이 나타나는 자리가 같았기 때문이다. 증상의 위치로 원인을 묶으면 두 번 다 헛다리를 짚는다.
댓글 0개