Spring Batch 312만 건 소멸 배치, 절반만 처리되고 끝난 이유

2022년 12월, 연말 포인트 소멸 배치를 Spring Batch로 옮기는 일을 맡았다. 쇼핑몰 적립 포인트는 유효기간이 지나면 1월 1일 0시 기준으로 한꺼번에 소멸된다. 그전까지는 @Scheduled 메서드 하나가 대상 회원을 전부 읽어 for문으로 돌렸다. 대상이 40만 건이던 2021년에도 3시간이 걸렸다. 그런데 2022년 말에는 대상이 312만 건으로 늘었다. 그해 가입 이벤트로 뿌린 포인트가 한꺼번에 만료되기 때문이었다. 같은 방식이면 아침까지도 안 끝날 게 뻔했다. “청크 단위로 나눠 커밋하면 되겠지.” 그렇게 시작했는데, 리허설에서 한 번, 1월 1일 본 실행에서 한 번, 4월 월간 배치에서 또 한 번 문제가 났다. 이 글은 그 넉 달의 기록이다.

당시 환경은 Spring Boot 2.7, Spring Batch 4.3, MySQL 8.0이었다. 포인트는 point 테이블에 적립 건 단위로 쌓이고, 소멸하면 status를 EXPIRED로 바꾼 뒤 point_history에 소멸 이력을 한 줄씩 남겼다. 배치는 사내 Jenkins가 정해진 시각에 jar를 실행하는 구조였다.

리허설 — 312만 건 중 156만 건만 처리하고 “COMPLETED”

첫 버전은 예제 코드를 거의 그대로 따랐다. JpaPagingItemReader로 소멸 대상을 1,000건씩 읽고, 프로세서에서 상태를 바꾸고, JpaItemWriter로 저장했다. 청크 크기와 페이지 크기는 둘 다 1,000이었다.

// 2022.12 첫 버전
@Bean
@StepScope
public JpaPagingItemReader<Point> expireReader(
        @Value("#{jobParameters['targetDate']}") String targetDate) {
    return new JpaPagingItemReaderBuilder<Point>()
        .name("expireReader")
        .entityManagerFactory(emf)
        .queryString("SELECT p FROM Point p " +
                     "WHERE p.status = 'ACTIVE' AND p.expireAt < :targetDate " +
                     "ORDER BY p.id")
        .parameterValues(Map.of("targetDate", LocalDate.parse(targetDate).atStartOfDay()))
        .pageSize(1000)
        .build();
}

12월 20일, 운영 DB를 복제한 리허설 환경에서 처음 돌렸다. 배치는 오류 없이 COMPLETED로 끝났다. 그런데 확인 쿼리로 남은 소멸 대상을 세어 보니 155만 9천 건이 그대로 남아 있었다. 정확히 절반 정도만 처리된 셈이다. 한 번 더 돌렸더니 남은 것의 또 절반만 처리됐다.

원인은 페이징 방식이었다. JpaPagingItemReader는 페이지마다 OFFSET을 1,000, 2,000, 3,000으로 늘려 가며 다음 페이지를 읽는다. 그런데 나는 읽는 조건(status = 'ACTIVE')에 걸리는 바로 그 값을 청크마다 바꾸고 있었다. 첫 청크 1,000건이 EXPIRED가 되어 조건에서 빠지면, 원래 1,001번째였던 행이 1번째로 당겨진다. 이 상태에서 다음 페이지가 OFFSET 1000으로 읽으니 당겨진 1,000건을 통째로 건너뛰게 된다. 이게 매 페이지 되풀이되니 결국 절반만 처리됐다. 오류도 나지 않고 읽은 건수와 쓴 건수도 서로 맞았기 때문에, 배치 메타 테이블만 봐서는 알아챌 수 없었다.

해결은 오프셋 대신 마지막으로 읽은 ID 다음부터 읽는 방식이었다. JdbcPagingItemReader에 정렬 키를 주면 두 번째 페이지부터 WHERE id > 마지막ID 조건을 붙여 읽는다. 앞쪽 행이 조건에서 빠져도 위치가 밀리지 않는다. 이 방식은 커서 기반 페이징 vs OFFSET 글에서 화면 목록에 쓴 것과 원리가 같다.

// 바꾼 뒤: 정렬 키 기반 페이징, 처리한 행이 빠져도 위치가 밀리지 않는다
return new JdbcPagingItemReaderBuilder<PointRow>()
    .name("expireReader")
    .dataSource(dataSource)
    .selectClause("SELECT id, member_id, amount, expire_at")
    .fromClause("FROM point")
    .whereClause("WHERE status = 'ACTIVE' AND expire_at < :targetDate")
    .sortKeys(Map.of("id", Order.ASCENDING))
    .parameterValues(Map.of("targetDate", targetDate))
    .pageSize(1000)
    .rowMapper(new PointRowMapper())
    .build();

이때부터 리허설이 끝나면 처리 건수 말고 남은 대상 건수가 0인지까지 세어 보기로 했다. 배치가 성공했다고 해서 일이 끝났다는 뜻은 아니었다.

7시간 걸리는 writer — 청크 하나에 9초

건너뛰는 문제를 고치고 다시 돌리자 이번에는 너무 느렸다. 청크 하나에 8~9초가 걸렸다. 청크가 3,120개이니 계산하면 7시간이 넘는다. 기존 for문보다는 낫지만 1월 1일 아침 고객센터 문의가 시작되기 전에 끝나야 한다는 조건에는 한참 못 미쳤다.

쿼리 로그를 켜 보니 JpaItemWriter가 엔티티마다 UPDATE 한 번, 소멸 이력 INSERT 한 번을 따로 날리고 있었다. 청크 하나에 쿼리가 2,000번 나간 셈이다. 이력 테이블은 ID를 IDENTITY로 생성해서 Hibernate의 JDBC 배치 설정을 켜도 INSERT가 묶이지 않았다.

writer를 JDBC로 바꿨다. 상태 변경과 이력 기록을 JdbcBatchItemWriter 두 개로 나누고 CompositeItemWriter로 묶었다. 그리고 MySQL 접속 URL에 rewriteBatchedStatements=true를 붙였다. 이 옵션이 없으면 MySQL 드라이버는 배치로 모은 쿼리도 한 줄씩 보낸다. 옵션을 켜야 INSERT 1,000건이 여러 행을 한 번에 넣는 쿼리로 합쳐진다.

@Bean
public CompositeItemWriter<ExpireResult> expireWriter() {
    JdbcBatchItemWriter<ExpireResult> update = new JdbcBatchItemWriterBuilder<ExpireResult>()
        .dataSource(dataSource)
        .sql("UPDATE point SET status = 'EXPIRED', expired_at = NOW() " +
             "WHERE id = :pointId AND status = 'ACTIVE'")
        .beanMapped()
        .build();   // assertUpdates 기본값 true: 0건 갱신이면 예외로 알려 준다

    JdbcBatchItemWriter<ExpireResult> history = new JdbcBatchItemWriterBuilder<ExpireResult>()
        .dataSource(dataSource)
        .sql("INSERT INTO point_history (point_id, member_id, type, amount, notified) " +
             "VALUES (:pointId, :memberId, 'EXPIRE', :amount, 'N')")
        .beanMapped()
        .build();

    return new CompositeItemWriterBuilder<ExpireResult>()
        .delegates(update, history)
        .build();
}

청크 하나가 0.7초로 줄었고, 전체 리허설은 41분 만에 끝났다. UPDATE 조건에 AND status = 'ACTIVE'를 남겨 둔 것은 일부러였다. 그사이 다른 경로로 상태가 바뀐 행은 0건 갱신이 되고, 그러면 예외가 나서 바로 알 수 있다.

1월 1일 0시 14분 — 잔액이 음수인 한 건에 전체가 멈췄다

본 실행은 1월 1일 0시에 시작했다. 나는 집에서 노트북으로 모니터링했다. 0시 14분, 진행률 34% 지점에서 잡이 FAILED로 끝났다. 프로세서에 넣어 둔 검증 로직이 금액이 음수인 적립 건을 만나 IllegalStateException을 던진 것이다. 12월 28일 고객센터가 수기로 보정하다 만든 데이터였다. 리허설은 12월 20일 복제본으로 했으니 그 데이터가 있을 리 없었다.

당직자가 Jenkins에서 재실행 버튼을 눌렀다. 나는 Spring Batch가 실패한 지점부터 이어서 처리해 줄 거라고 생각하고 있었다. 그런데 잡은 처음부터 새로 시작했다. 메타 테이블을 보니 새 JobInstance가 하나 더 생겨 있었다. 실행 스크립트가 잡 파라미터에 time=현재시각을 넣고 있었기 때문이다. 예제를 따라 하다 “같은 파라미터로는 재실행이 안 된다”는 오류를 피하려고 넣은 값이었다. Spring Batch는 잡 이름과 파라미터 조합으로 실행 단위를 구분한다. 파라미터가 매번 다르니 매번 처음 보는 잡으로 취급했던 것이다.

다행히 읽는 조건이 ACTIVE였기 때문에 이미 처리한 106만 건이 다시 소멸되지는 않았다. 하지만 잡은 같은 음수 데이터에서 같은 예외를 내고 0시 47분에 다시 멈췄다. 결국 내가 그 한 건을 HOLD 상태로 직접 빼고 세 번째로 실행해서 2시 5분에 끝냈다. 고객센터에 공유할 소멸 안내 문구는 예정보다 두 시간 늦게 나갔다.

1월 둘째 주에 두 가지를 고쳤다. 첫째, 잡 파라미터에서 time을 빼고 업무 기준값인 targetDate=2023-01-01만 넘기도록 바꿨다. 이렇게 하면 실패한 잡을 같은 파라미터로 다시 실행했을 때 같은 JobInstance가 재시작된다. reader가 실행 컨텍스트에 저장해 둔 마지막 정렬 키부터 이어서 읽는다. 이미 COMPLETED된 날짜를 누가 실수로 한 번 더 실행하면 JobInstanceAlreadyCompleteException으로 막힌다. Jenkins 자동 재시도 때문에 생길 수 있는 중복 실행을 프레임워크가 대신 막아 주는 셈이었다. 둘째, 데이터 한 건 때문에 312만 건 전체를 세우지 않도록 skip을 넣었다.

4월 월간 배치 — skip을 넣었더니 소멸 안내 푸시가 두 번 나갔다

연간 소멸 뒤로는 매월 1일에 월간 소멸이 돌았다. 대상은 9만 건 안팎이었다. 1월에 넣은 skip 설정은 이랬다. 지금 보면 문제가 두 군데 있다.

// 2023.1 — 문제가 된 설정
.<PointRow, ExpireResult>chunk(1000)
.reader(expireReader)
.processor(expireProcessor)     // 여기서 pushClient.sendExpireNotice() 호출
.writer(expireWriter)
.faultTolerant()
.skip(Exception.class)           // "일단 다 건너뛰자"
.skipLimit(100)

4월 1일 0시, 마침 만우절 행사로 0시 정각에 포인트 결제가 몰렸다. 실시간 결제 트랜잭션과 배치의 UPDATE가 같은 회원의 적립 건을 반대 순서로 잡으면서 데드락이 두 번 났다. 데드락 자체는 데드락은 왜 생기나에서 정리한 흔한 패턴이었다. 문제는 그다음이었다. skip(Exception.class) 때문에 데드락 예외도 건너뛸 대상이 됐다. writer에서 건너뛸 수 있는 예외가 나면 Spring Batch는 그 청크를 롤백하고, 어느 건이 문제인지 찾으려고 청크를 한 건씩 다시 처리한다. 이때 프로세서도 다시 실행된다.

프로세서 안에는 소멸 안내 푸시를 보내는 호출이 있었다. DB 트랜잭션은 롤백돼도 이미 나간 푸시는 되돌릴 수 없다. 청크 두 개가 한 건씩 다시 처리되면서 회원 1,930명이 같은 소멸 안내를 두 번 받았다. 게다가 한 건씩 다시 처리하는 중에 데드락이 또 걸린 3건은 정상 데이터인데도 그대로 건너뛰어져, 소멸되지 않고 남았다. 아침에 “푸시가 두 번 왔다”는 문의가 들어오고 나서야 알았다.

고친 방향은 세 가지였다.

  1. 프로세서는 계산만 한다. 푸시 호출을 빼서 별도 스텝으로 옮겼다. 소멸 스텝이 끝나면 알림 스텝이 point_history에서 notified = 'N'인 행을 읽어 보내고, 보낸 행을 'Y'로 바꾼다. 소멸 스텝을 몇 번 다시 처리해도 알림은 이력 기준으로 한 번만 나간다. DB 변경과 외부 발송을 떼어 놓는 발상은 Outbox 패턴과 같다.
  2. 건너뛸 예외와 다시 시도할 예외를 나눈다. 데이터 자체가 잘못된 경우에만 던지는 InvalidPointException을 만들어 그것만 skip하고, 잠금 충돌은 retry로 다시 시도하게 했다.
  3. 건너뛴 건은 반드시 남긴다. SkipListener로 건너뛴 적립 건 ID와 사유를 별도 테이블에 쌓고, 아침에 담당자가 보도록 했다.
// 2023.4 이후
.<PointRow, ExpireResult>chunk(1000)
.reader(expireReader)
.processor(expireProcessor)                 // 외부 호출 없음, 계산과 검증만
.writer(expireWriter)
.faultTolerant()
.retry(PessimisticLockingFailureException.class)  // 데드락·락 대기: 다시 시도
.retryLimit(3)
.skip(InvalidPointException.class)          // 데이터 자체가 틀린 것만 건너뜀
.skipLimit(100)
.listener(skippedPointListener)             // 건너뛴 건은 expire_skip 테이블로
.build();

5월부터 월간 배치에서 건너뛴 건은 매달 0~2건이었고, 전부 expire_skip 테이블에서 사유와 함께 확인할 수 있었다. 그해 말 연간 소멸(대상 287만 건)은 한 번도 멈추지 않고 38분 만에 끝났고, 건너뛴 17건은 1월 2일에 수기로 처리했다. skip 로그를 남기는 형식은 운영 로깅 체크리스트에서 정한 기준을 따랐다.

넉 달 동안 바꾼 것 한눈에 보기

항목처음바꾼 뒤이유
readerJpaPagingItemReader (OFFSET)JdbcPagingItemReader + 정렬 키읽는 조건을 바꾸면 OFFSET이 밀려 절반을 건너뜀
writerJpaItemWriterJdbcBatchItemWriter 2개 + rewriteBatchedStatements건당 쿼리 2,000번 → 청크 9초에서 0.7초로
잡 파라미터targetDate + time(현재 시각)targetDate만같은 실행 단위로 재시작, 완료된 날짜는 중복 실행 차단
skip 대상Exception 전체InvalidPointException만잠금 충돌까지 건너뛰면 정상 데이터가 누락됨
잠금 충돌skipretry 3회잠시 뒤에 다시 하면 성공하는 오류
외부 호출프로세서에서 푸시 발송별도 알림 스텝(이력 기준)한 건씩 다시 처리할 때 프로세서도 다시 실행됨
검증잡 상태 COMPLETED남은 대상 0건 + skip 테이블 확인성공 상태가 곧 다 처리했다는 뜻은 아님

다시 한다면

돌아보면 넉 달 동안 낸 사고는 전부 “청크로 나누면 끝”이라는 생각에서 빠뜨린 부분이었다. 처음으로 돌아간다면 코드를 쓰기 전에 이것부터 정하겠다.

  1. 읽는 조건에 쓰인 컬럼을 같은 스텝에서 바꾸는지부터 확인한다. 바꾼다면 OFFSET 페이징은 처음부터 쓰지 않는다.
  2. 잡 파라미터는 “같은 일인지”를 판단하는 기준이다. 업무 기준값만 넣고, 재시작과 중복 실행 방지를 리허설에서 일부러 실패시켜 확인한다.
  3. 프로세서와 writer 안에 되돌릴 수 없는 외부 호출이 있는지 목록을 뽑는다. 있으면 별도 스텝으로 뺀다.
  4. 예외를 “데이터가 틀렸다”와 “잠깐 실패했다”로 나눠 skip과 retry를 따로 정한다. skip(Exception.class)는 쓰지 않는다.
  5. 리허설은 본 실행 직전 데이터로 한 번 더 한다. 12월 28일에 생긴 데이터는 12월 20일 복제본에 없다.

대상이 지금보다 몇 배 늘면 단일 스레드로는 한계가 온다. 멀티스레드 스텝은 reader 상태를 저장할 수 없어 방금 고친 재시작 기능을 포기해야 한다. 그래서 다음 단계로는 ID 범위로 나눠 스텝을 여러 개 띄우는 파티셔닝을 보고 있다. 청크·재시작·skip·retry가 정확히 어떻게 동작하는지는 Spring Batch 4.3 공식 문서의 Step 설정 장에 나와 있다. 특히 writer에서 skip이 나면 청크를 한 건씩 다시 처리한다는 설명은 꼭 읽어 보길 권한다. 나는 4월 1일 아침에야 그 문단을 읽었다. 배치가 DB에 부담을 줄 때 같이 볼 만한 내용은 MySQL 쿼리 지연 해결 3개월 분투기에 정리해 두었다.

댓글 남기기