매일 2,000건이 조용히 사라지던 배치를 고쳤다

배치 서비스에서 RejectedExecutionException이 계속 난다는 이야기를 들었다. 확인해 보니 매일 새벽 다섯 시 무렵 약 2,000건씩, 열흘 넘게 같은 자리에서 반복되고 있었다.

더 나빴던 것은 그 예외가 무엇을 의미하는지였다. 거부된 이벤트는 판매자 한 명의 신용평가였고, 거부되면 그날 그 판매자의 등급은 갱신되지 않았다. 그런데 예외는 로그에만 남고 화면에는 아무 표시도 없었으니, 실패한 것이 아니라 사라진 것이었다.

에러는 매일 났는데 아무도 몰랐다

신용평가는 매일 회수 잔액이 남아 있는 판매자 전체를 대상으로 돈다. 하루 처리량이 약 4만 건이고, 회수할 돈이 남았다는 것은 위험 관리에서 가장 먼저 봐야 할 모수라는 뜻이다. 그중 매일 2,000건 안팎이 며칠째 갱신되지 않고 있었다.

배치가 실패로 끝났다면 바로 알았을 텐데, 배치는 정상 종료했다. 발행은 전부 성공했고 소비 단계에서 일부가 거부됐을 뿐이라, 잡 실행 결과만 보는 관측 체계는 이걸 성공으로 읽었다.

거부 건수는 로그에만 있었다. 그것도 거부 한 건마다 풀스택이 찍혀서, 여드레치 로그가 1,800만 줄을 넘었다. 정보가 없어서 못 본 것이 아니라 너무 많아서 못 봤다.

풀 상태를 보고 나서야 그림이 보였다

예외가 난 시점의 스레드풀 상태를 찍어 보니 원인이 한 줄로 드러났다.

pool size    = 2
active       = 2
queued tasks = 3000
completed    = 40

워커 두 개가 모두 일하는 중이고, 대기 큐 3,000칸이 전부 찼고, 그때까지 끝낸 작업은 마흔 건이었다. 큐가 가득 찬 상태에서 들어온 작업은 기본 거부 정책에 걸려 그 자리에서 예외가 됐다.

여기서 큐가 두 개라는 것을 짚어야 한다. 배치가 발행한 이벤트는 먼저 Redis 큐에 쌓이는데, 이건 프로세스가 죽어도 남는 저장소다. 그다음 poll 루프가 하나씩 꺼내 스레드풀에 넘기는데, 스레드풀 앞에 붙은 대기 줄이 3,000칸짜리 두 번째 큐다.

flowchart LR
  A["배치 · 대상 전량 발행"] --> B[("Redis 큐 · 죽어도 남음")]
  B --> C["poll 루프"]
  C --> D["executor 큐 3,000 · 넘치면 버림"]
  D --> E["워커 2"]

두 큐의 성질이 정반대다. 앞의 것은 꺼내지 않으면 그대로 남고, 뒤의 것은 넘치면 버린다. 그러니 이 사고는 한 줄로 요약된다. 안전한 큐에 있던 이벤트를 꺼내 안전하지 않은 큐로 옮기다가 흘린 것이다.

poll 루프는 뒤쪽 사정을 묻지 않았다. 워커 둘이 외부 호출에 붙잡혀 있는 동안에도 계속 꺼내 넘겼고, 3,000칸이 차면 그때부터 넘긴 것이 그 자리에서 거부됐다. 하루 대상 4만 건 중 2,000건 안팎이 그렇게 사라졌다.

flowchart TD
  A["배치 · 대상 전량 발행"] --> B[("Redis 큐")]
  B --> C["poll 루프"]
  C --> D{"executor 큐에 자리 있나?"}
  D -- "있음" --> E["워커 2개 · 외부 신용조회"]
  D -- "없음" --> F["거부 · 재시도 없이 폐기"]

누락을 두 방향에서 셌다

거부 예외가 곧 누락이라고 단정하지 않았다. 예외가 났어도 다른 경로로 처리됐을 수 있고, 반대로 예외 없이 빠진 건이 있을 수도 있다. 그래서 로그와 데이터 양쪽에서 셌다.

로그 쪽은 거부 예외를 날짜별로 집계했다. 데이터 쪽은 그날 대상이 몇 건이었는지와 실제로 등급이 갱신된 행이 몇 건인지를 비교했다.

-- 그날 대상 (회수 잔액이 남은 판매자)
SELECT COUNT(DISTINCT user_id) FROM 회수원장 WHERE 남은금액 > 0;

-- 그날 실제로 갱신된 평가 결과
SELECT COUNT(*) FROM 신용평가 WHERE DATE(updated_at) = CURDATE();

-- 두 값의 차 = 갱신되지 않은 대상

두 방향의 숫자가 같은 크기로 나왔다. 로그의 거부 건수와 데이터의 미갱신 건수가 맞아떨어지면서, 예외가 곧 누락이라는 것이 확인됐다. 한쪽만 봤으면 거부가 정말 데이터에 영향을 줬는지는 추정으로 남았을 것이다.

왜 하필 그날부터였나

이상했던 것은 시작 시점이었다. 이 배치는 4년째 같은 구조로 돌고 있었는데 거부는 특정 날짜부터 갑자기 시작됐다. 그 전 아흐레는 0건이었다.

기간	거부 건수
발생 전 9일	0
첫날	1,862
이후 12일	매일 1,855~2,051

배포 이력을 거슬러 올라가니 사흘 전에 개인사업자의 신용 정보를 가져오는 경로가 바뀌어 있었다. 동기 외부 호출이 하나 늘었고, 응답이 비면 크롤로 한 번 더 확인하는 폴백이 붙었다. 작업 하나에 걸리는 시간이 올라간 것이다.

구조는 그대로였고 바뀐 것은 작업 단가뿐이었는데, 그것이 임계를 넘겼다. 워커 두 개가 더 오래 붙잡혀 있으니 같은 시간에 비우는 큐 칸이 줄었고, 발행량은 그대로여서 넘쳤다.

바꿔 말하면 4년 동안은 운이 좋았다. 작업 하나가 빨리 끝나는 동안에는 워커 두 개로도 발행량을 따라갈 수 있었고, 큐 3,000칸이 완충 역할을 했다. 결함이 없었던 것이 아니라 여유가 결함을 가리고 있었다.

처리 시간을 늘리는 변경은 그 자체로는 성능 이야기처럼 보인다. 그런데 소비 측 용량이 고정된 구조에서는 그것이 데이터 누락으로 나타난다. 이 연결을 미리 봤어야 했다.

결함은 하나가 아니라 셋이었다

원인을 하나로 적으려다 그만뒀는데, 셋 중 어느 하나만 없었어도 이 사고는 나지 않았기 때문이다.

결함	내용	단독으로는
풀 과소	워커 2개. 외부 I/O 대기형 작업인데 옆 배치는 10개였다	느릴 뿐 누락은 없다
무백프레셔 발행	대상 전량을 한 번에 큐로 투입	큐가 넉넉하면 넘지 않는다
거부 = 폐기	재시도 횟수가 0이라 거부된 이벤트는 즉시 버려졌다	재큐잉되면 늦어질 뿐이다

이 셋은 4년 동안 함께 있었다. 그동안 사고가 없었으니 문제없는 구조로 취급됐고, 그래서 아무도 다시 보지 않았다. 무사고 기간은 결함이 없다는 증거가 아니라 아직 임계에 닿지 않았다는 뜻이었다.

특히 세 번째가 이 사고를 조용하게 만들었다. 소비 코드 안에는 예외를 잡는 블록이 있었지만, 그건 작업이 실행되는 도중의 예외만 잡는다. 실행 자체를 거부당한 것은 그 블록에 들어가지도 못한다.

풀을 늘리는 것은 답이 아니었다

가장 빠른 조치는 워커를 2개에서 10개로 올리는 것이었고, 실제로 그렇게 했으면 그날은 넘어갔을 것이다.

그런데 그건 같은 사고를 다음 임계까지 미루는 일이었다. 대상 판매자가 늘거나 외부 응답이 다시 느려지면 똑같이 큐가 차고 똑같이 버려진다. 문제는 워커 수가 아니라 발행량과 소비 용량이 서로를 모른다는 것이었다.

기준을 이렇게 잡았다. 큐가 넘칠 수 있다는 사실을 받아들이되, 넘쳤을 때 데이터가 사라지지 않아야 한다. 늦어지는 것은 괜찮고 없어지는 것은 안 된다.

이미 옆 배치에 답이 있었다

같은 예외를 다른 배치에서 3주 전에 겪은 기록이 있었다. 거기서는 발행 측에 세마포어를 두고 워커가 빌 때만 다음 작업을 밀어 넣는 방식으로 해결했고, 그 뒤로 재발이 없었다.

새로 설계하지 않고 그 패턴을 그대로 가져오기로 했다. 같은 회사 안에서 같은 문제를 두 번 푸는 것만큼 낭비가 없고, 이미 운영에서 검증된 형태라는 점이 컸다.

세마포어를 submit 앞에 뒀다

핵심은 executor에 작업을 넣기 전에 자리를 확보하는 것이다. 자리를 못 잡으면 큐에서 꺼내는 동작 자체를 멈춘다.

semaphore.acquire();
try {
    executor.execute(() -> {
        try {
            process(event);
        } finally {
            semaphore.release();
        }
    });
} catch (RejectedExecutionException e) {
    semaphore.release();
    log.warn("submit 거부 - permit 반환, {}", executorState());
}

permit이 없으면 이 컨슈머의 poll 루프가 그 자리에서 대기한다. 꺼내지 않은 이벤트는 Redis 큐에 그대로 남는다. 큐가 저장소 역할을 하니 프로세스가 재시작돼도 대상이 사라지지 않는다.

반환을 finally에 둔 것은 실패해도 permit이 새지 않게 하기 위해서다. 작업이 예외로 끝나든 정상으로 끝나든 자리는 반드시 돌려준다. submit 자체가 거부되는 경로에도 반환을 넣었다.

flowchart TD
  A["poll 루프"] --> B{"permit 확보?"}
  B -- "실패" --> C["대기 · 이벤트는 큐에 남음"]
  C --> B
  B -- "성공" --> D["executor submit"]
  D --> E["외부 신용조회"]
  E --> F["permit 반환"]
  F --> A

풀 크기는 누락을 막는 장치가 아니다

백프레셔를 넣고 나서 풀 크기를 다시 봤다. 설계 때는 옆 배치와 맞춰 10으로 올리려 했는데 5에서 멈췄다.

이유는 외부 의존성이었다. 동시 호출을 갑자기 다섯 배로 올렸을 때 신용조회 기관과 크롤러가 버티는지 확인할 방법이 검증 환경에 없었다. 운영에서 한 번 돌려 보고 올리는 편이 안전했다.

이때 판단 기준이 정리됐다. 백프레셔가 있으면 풀 크기는 누락을 막는 값이 아니라 처리 속도를 정하는 값이어서, 작으면 느릴 뿐 데이터가 사라지지는 않는다. 그러니 보수적으로 시작해도 됐다.

동시성을 올리자 트랜잭션 경계가 걸렸다

풀을 키우면 동시에 도는 작업이 늘고, 그만큼 DB 커넥션도 더 잡는다. 기존 코드는 외부 호출 전체가 트랜잭션 안에 들어 있었다. 느린 외부 응답을 기다리는 내내 커넥션을 붙잡고 있었다는 뜻이다.

그대로 동시성만 올렸으면 이번에는 커넥션 풀이 말랐을 것이다. 그래서 외부 호출과 저장을 분리했다. 오케스트레이션은 트랜잭션 밖에서 돌고, 결과를 DB에 넣는 구간만 별도 서비스로 빼서 트랜잭션을 걸었다.

변경 전
  [ 트랜잭션 시작 ] 외부 조회 -> 폴백 크롤 -> 저장 [ 커밋 ]

변경 후
  외부 조회 -> 폴백 크롤
  [ 트랜잭션 시작 ] 저장 [ 커밋 ]

이건 이번 장애의 원인은 아니었다. 동시성을 올리는 변경이 만들어 낼 다음 장애를 미리 지운 것에 가깝다. 그렇게 판단한 근거는 이 글 끝에 따로 적었다. 비슷한 시기에 다른 서비스에서 정확히 그 일이 벌어졌기 때문이다.

재시도를 늘리지 않기로 했다

조치 후보 중에 재시도 횟수를 0에서 올리는 것도 있었는데, 거부된 이벤트를 다시 큐에 넣으면 누락은 막힌다.

넣지 않았다. 백프레셔로 거부 자체가 사라졌으니 거부에 대비한 재시도는 죽은 코드가 된다. 그리고 개별 이벤트가 일시적으로 실패했을 때 몇 번 다시 시도할지는 이번 문제와 다른 판단이라, 같은 변경에 섞으면 어느 쪽 때문에 동작이 달라졌는지 설명하기 어려워진다.

대신 후속 과제로 분리해 남겨 뒀고, 지금도 개별 실패의 재시도 정책은 정해지지 않은 채다.

거부를 세는 것으로 바꿨다

로그도 같이 손봤다. 거부마다 풀스택을 찍던 것을 카운터 집계로 바꾸고, 그때의 풀 상태를 함께 남겼다.

같은 사고가 다시 나면 이번에는 줄 수가 아니라 숫자로 보인다. 1,800만 줄을 훑는 대신 하루 거부 몇 건이라는 값을 본다.

포화 상태를 테스트로 고정했다

백프레셔는 큐가 가득 찬 상황에서만 동작하므로, 그 상황을 테스트에서 만들어야 했다. 처음에는 대기를 넣어 재현하려 했는데 실행 환경에 따라 결과가 흔들렸다. 워커를 래치로 붙잡아 두고 풀 용량을 넘는 이벤트를 밀어 넣는 방식으로 바꿨다. 포화 시점이 시간에 의존하지 않고 확정된다.

풀 크기 = N
래치 = CountDownLatch(1)

워커가 하는 일: 래치를 기다린다        // N개가 전부 잡힌 상태로 고정

이벤트 N + 20건을 밀어 넣는다
  -> 백프레셔가 없으면: 3,000칸을 넘는 순간 거부 예외
  -> 백프레셔가 있으면: permit이 없어 poll이 멈추고 대기

래치를 푼다
워커가 비워지면서 남은 20건이 순서대로 처리된다

검증: 처리된 건수 == N + 20,  거부 0

변경 전 코드로 같은 시나리오를 돌리면 초과분이 거부로 떨어진다. 그 대조가 있어야 이 테스트가 백프레셔를 검증한다고 말할 수 있다. 통과만 확인하면 원래도 통과했을 수 있다.

같은 형태를 다른 서비스에서 봤다

이 배치를 고치기 며칠 전, 전혀 다른 서비스에서 커넥션 풀이 마르는 일이 있었다. 처음에는 관계없는 사건으로 봤는데 원인을 따라가 보니 구조가 닮아 있었다. 신용평가 배치에서 트랜잭션 경계를 미리 손본 것도 이 사건을 보고 나서였다.

요청 하나가 커넥션을 두 개 쓰고 있었다

외부 연동을 조회하는 엔드포인트에서 커넥션 풀이 1분 남짓 말랐다. 그 사이 요청 열 몇 건이 5초 타임아웃으로 실패했고, 그다음에는 저절로 회복됐다. 배포도 없었고 조치도 하지 않았다.

풀 크기는 열이었는데 대기하는 요청이 열일곱이었고, 동시 요청이 열을 넘지 않는 시간대였는데도 그랬다. 숫자가 맞지 않아서 호출 경로를 따라갔다.

바깥 메서드가 트랜잭션을 열고 첫 조회에서 커넥션 하나를 잡는다. 메서드가 끝날 때까지 그 커넥션은 반납되지 않는다. 그 안에서 부르는 다른 메서드에 새 트랜잭션을 요구하는 설정이 붙어 있었고, 그러면 바깥 트랜잭션을 잠시 멈춰 세운다. 멈춰 세우는 것이지 반납하는 것이 아니어서, 그 상태로 두 번째 커넥션을 추가로 요구한다.

요청 1건
  바깥 트랜잭션   -> 커넥션 #1 점유 (메서드 끝까지)
    안쪽 새 트랜잭션 -> 커넥션 #2 추가 요구

풀 크기 10 -> 이 경로의 실효 동시 처리 한도는 5

즉 이 엔드포인트는 처음부터 풀의 절반밖에 못 쓰는 상태였다. 여섯 번째 요청부터는 자기 앞의 요청이 끝나기를 기다리는데, 그 요청도 두 번째 커넥션을 기다리고 있다. 자기 자신과 교착한다.

1년 넘게 멀쩡했던 이유

이 구조는 1년도 더 전에 들어온 것인데 그동안 아무 일도 없었다.

7일치 로그 640만 줄을 훑어 커넥션 타임아웃이 언제 났는지 셌다. 그 1분 구간에만 있었고 나머지는 0이었다. 같은 시각의 요청량을 보니 평소 분당 한 자릿수이던 것이 세 번에 걸쳐 스물넷씩 몰려 있었다. 전날 같은 시간대는 평탄했다.

여기서도 잠재 결함과 버스트의 결합이었다. 실효 한도가 절반이라는 사실은 평소 요청량에서는 드러나지 않는다. 요청이 한 번 몰릴 때만 임계를 넘고, 넘으면 몇십 초 만에 저절로 풀린다. 그래서 남는 흔적이 거의 없다.

웹 쪽 동시성에 상한이 없어진 것도 겹쳤다. 가상 스레드를 쓰면서 요청을 받는 쪽은 얼마든지 늘어나는데, 그 앞에 대기를 걸어 주는 장치가 없으니 부하가 그대로 DB 풀로 몰린다. 병목이 풀 하나로 좁혀져 있었다.

새 트랜잭션은 지울 수 없었다

가장 단순한 수정은 안쪽의 새 트랜잭션 설정을 빼는 것이었다. 그러면 커넥션은 하나만 쓴다.

이력을 찾아보니 그건 의도적으로 넣은 것이었다. 안쪽에서 로그인 예외가 나면 바깥 트랜잭션까지 롤백 대상으로 오염되는 문제가 있었고, 그걸 막으려고 경계를 분리해 둔 것이었다. 빼면 그 문제가 돌아온다.

그래서 반대쪽을 봤다. 바깥 메서드의 트랜잭션이 실제로 무엇을 지키고 있는지 확인했더니, 함께 커밋돼야 할 쓰기가 없었다. 조회하고 외부를 부르는 것이 전부였다. 지켜 주는 정합성이 없는 트랜잭션이 커넥션만 붙잡고 있었던 것이다.

바깥 트랜잭션을 지우니 안쪽 경계는 그대로 둔 채 이중 점유만 사라졌다.

두 사건을 나란히 놓고 보니 형태가 같았다. 오래된 구조가 조용히 버티고 있다가, 그 위에 얹힌 작은 변화가 임계를 넘긴다. 앞의 것은 작업 단가가 올라서였고 뒤의 것은 요청이 한 번 몰려서였다. 둘 다 그 변화 자체는 잘못이 없었다.

배포 뒤 거부가 0으로 떨어졌다

다음 실행부터 거부 예외가 나오지 않았다. 로그의 거부 건수와 데이터의 미갱신 건수를 같은 기준으로 다시 셌고, 양쪽 다 0이었다. 대상 수와 갱신 건수가 일치했다.

한 번 확인하고 끝내지 않았다. 이 배치는 매일 도는데 문제는 처음 열흘 가까이 0이다가 갑자기 나타났었다. 한 번의 0은 임계에 안 닿았다는 뜻일 뿐이라, 이후 실행에서도 같은 값을 이어서 봤다.

고친 뒤에도 열사흘은 남았다

가장 큰 한계는 이미 누락된 기간이다. 열사흘 동안 갱신되지 않은 등급은 배치를 고친다고 채워지지 않는다. 대상을 뽑아 다시 돌려야 했고, 그 작업은 구조 개선과 별개로 손이 갔다.

풀 크기 5도 잠정값이다. 운영에서 한 배치를 관찰한 뒤 올리기로 했는데, 올릴 근거가 되는 처리 시간 지표를 아직 정식으로 두지 않았다.

그리고 이 배치 하나만 고쳤다. 같은 구조로 도는 컨슈머가 더 있는지, 발행량과 소비 용량이 어긋난 곳이 또 있는지는 전수로 확인하지 않았다. 새 컨슈머를 추가할 때 백프레셔를 기본으로 두자는 합의만 남겼다.

고치는 데는 코드 몇십 줄이면 됐다. 어려웠던 것은 해결이 아니라 발견이었고, 그 몇십 줄이 4년 동안 없었다는 사실보다 없다는 것을 알아챌 방법이 그동안 하나도 없었다는 쪽이 더 오래 남았다. 열사흘 내내 매일 2,000건이 사라지는데도 배치는 계속 성공으로 보고되고 있었다.