[spring batch] faultTolerant.retry 횟수와 관련된 고찰

2024. 9. 27. 11:56

환경: spring batch 5.0.3, java 17

스프링 배치의 fault tolerant에는 크게 retry와 skip이 있다.

skip(): ItemReader, ItemProcessor, ItemWriter 모두에서 예외 발생 시 적용할 수 있으며, 예외를 스킵하고 다음 아이템으로 넘어감
retry(): ItemProcessor와 ItemWriter에만 적용되며, 예외 발생 시 설정된 횟수만큼 재시도. ItemReader에서는 retry()를 사용할 수 없음

이번 글에서는 writer의 retry에 대해 집중해 본다.

에러로 인한 재시도를 하고 싶을 경우. faultTolerant()와 함께. retry()와. retryLimit() 설정을 사용하면 Spring Batch에서 Step 또는 Chunk 단위로 처리 중 발생하는 예외에 대해 재시도 처리를 할 수 있다.

private Step getCommonStep(
    JobRepository jobRepository,
    PlatformTransactionManager transactionManager,
    String stepName,
    MyBatisCursorItemReader<GmahjongRankingRat> itemReader,
    ItemWriter<GmahjongRankingRat> itemWriter) {
  return new StepBuilder(stepName, jobRepository)
      .listener(deleteAllBeforeStep)
      .<GmahjongRankingRat, GmahjongRankingRat>chunk(CHUNK_SIZE, transactionManager)
      .reader(itemReader)
      .writer(itemWriter) ///-> 에러 발생
      .faultTolerant()
      .retry(RuntimeException.class)
      .retryLimit(2)   // -> 재시도 두번
      .listener(retryListener())
      .build();
}

1. .faultTolerant()

Fault Tolerant Step을 설정
Step이나 Chunk 처리 중 예외가 발생했을 때, 해당 예외를 허용하거나 재시도할 수 있도록 구성
retry, skip, noRollback, noRetry 등의 다양한 옵션을 적용할 수 있는 시작점

2. .retry(Class<? extends Throwable> exceptionClass)

재시도 대상 예외 타입을 지정
예외 타입은 특정 예외 클래스(예: RuntimeException.class) 또는 그 하위 클래스

예를 들어, .retry(RuntimeException.class)를 설정하면 RuntimeException과 그 하위 클래스에서 예외가 발생할 때마다 재시도가 이루어짐

3. .retryLimit(int retryLimit)

최대 재시도 횟수를 설정
retryLimit 값은 예외가 발생했을 때 최대 재시도 가능 횟수를 의미(총 횟수가 아닌 재시도 횟수)
- 예를 들어, retryLimit(2)로 설정하면 최대 2번 재시도함
retryLimit에 설정된 횟수는 최초 시도에는 영향을 주지 않으며, 최초 시도 후 추가로 재시도할 수 있는 횟수를 의미

4. .faultTolerant().retry(RuntimeException.class).retryLimit(2)의 의미

faultTolerant():
- 예외가 발생했을 때, 예외를 처리하거나 재시도할 수 있는 내구성 있는 단계로 설정
재시도 대상 예외 설정 (retry(RuntimeException.class)):
- RuntimeException과 그 하위 클래스에서 예외가 발생했을 때 재시도하도록 설정
최대 재시도 횟수 설정 (retryLimit(2)):
- 최초 시도 외에 최대 2번의 재시도를 허용
- 즉, 총 3번의 시도(초기 시도 1번 + 재시도 2번) <<<<<< 3일간 나를 고민에 빠트린 오늘의 주제...

재시도 테스트를 위해 3번 실행까지 에러를 발생시킨다.

  @Bean
  @StepScope
  public ItemWriter<GmahjongRankingRat> insertTotalRank(
      @Qualifier(DataSourceConfig.SESSION_FACTORY) SqlSessionFactory casualDb) {
    System.out.println(">>>>>>>>> insertTotalRank");
    return new ItemWriter<RankingRat>() {
      private final SqlSessionTemplate sqlSessionTemplate = new SqlSessionTemplate(casualDb);
      private int attempt = 0;

      @Override
      public void write(Chunk<? extends RankingRat> items) {
        attempt++;
        System.out.println("Attempt " + attempt + ": Writing items " + items);
        if (attempt < 3) { // 2번 이하로는 예외 발생
          throw new RuntimeException("Intentional error on attempt " + attempt);
        }
        for (RankingRat item : items) {
          sqlSessionTemplate.insert(
              Constant.GAME_MAPPER + "insertTotalRank", item);
        }
      }
    };
  }

retry 할 때 로그를 보기 위해 retryListener도 만들어서 달아준다.

  @Bean
  public RetryListener retryListener() {
    return new RetryListener() {
      @Override
      public <T, E extends Throwable> void onError(
          RetryContext context, RetryCallback<T, E> callback, Throwable throwable) {
        // 재시도 중 발생한 예외를 로깅
        System.err.println(
            "Retry attempt "
                + context.getRetryCount()
                + " failed with exception: "
                + throwable.getMessage());
      }
    };
  }

예상 시나리오

최초 시도 -> 에러1 -> 재시도1 -> 에러2 -> 재시도2 -> 에러3 -> 재시도 횟수 2번이 지나서 종료처리

그래서 에러가 3번까지 발생하고, 재시도 로그 2번 남을 것이라 기대

10:54:24.210 [main] DEBUG o.s.b.c.s.i.FaultTolerantChunkProcessor - Attempting to write:   ////최초 시도
10:54:24.221 [main] DEBUG o.s.batch.core.scope.StepScope - Creating object in scope=step, name=scopedTarget.insertTotalRank
>>>>>>>>> insertTotalRank
Attempt 1: Writing items... //최초 적재
...
10:54:24.247 [main] DEBUG o.s.b.core.step.tasklet.TaskletStep - Rollback for RuntimeException: java.lang.RuntimeException: Intentional error on attempt 1
10:54:24.247 [main] DEBUG o.s.t.support.TransactionTemplate - Initiating transaction rollback on application exception
java.lang.RuntimeException: Intentional error on attempt 1
...
10:54:24.250 [main] DEBUG c.a.i.imp.CompositeTransactionImp - rollback() done of transaction 10.78.130.172.tm172740206400000010
...
10:54:24.250 [main] DEBUG o.s.b.c.s.i.SimpleRetryExceptionHandler - Handled non-fatal exception
java.lang.RuntimeException: Intentional error on attempt 1
...
10:54:24.251 [main] DEBUG o.s.b.repeat.support.RepeatTemplate - Repeat operation about to start at count=2
...
Retry attempt 1 failed with exception: Intentional error on attempt 1


10:54:24.265 [main] DEBUG o.s.b.c.s.i.FaultTolerantChunkProcessor - Attempting to write: ////재시도 1
...
Attempt 2: Writing items... //재시도1 적재
10:54:24.282 [main] DEBUG o.s.b.core.step.tasklet.TaskletStep - Rollback for RuntimeException: java.lang.RuntimeException: Intentional error on attempt 2
10:54:24.282 [main] DEBUG o.s.t.support.TransactionTemplate - Initiating transaction rollback on application exception
java.lang.RuntimeException: Intentional error on attempt 2
...
10:54:24.282 [main] DEBUG c.a.i.imp.CompositeTransactionImp - rollback() done of transaction 10.78.130.172.tm172740206425100011
...
10:54:24.283 [main] DEBUG o.s.b.c.s.i.SimpleRetryExceptionHandler - Handled non-fatal exception
java.lang.RuntimeException: Intentional error on attempt 2
...
10:54:24.283 [main] DEBUG o.s.b.repeat.support.RepeatTemplate - Repeat operation about to start at count=3
10:54:24.288 [main] DEBUG o.s.b.c.s.i.FaultTolerantChunkProcessor - Attempting to write: ////재시도 2
...
Retry attempt 2 failed with exception: Intentional error on attempt 2


...
10:54:24.295 [main] DEBUG o.s.b.core.step.tasklet.TaskletStep - Rollback for RuntimeException: org.springframework.retry.ExhaustedRetryException: Retry exhausted after last attempt in recovery path, but exception is not skippable.
10:54:24.295 [main] DEBUG o.s.t.support.TransactionTemplate - Initiating transaction rollback on application exception
org.springframework.retry.ExhaustedRetryException: Retry exhausted after last attempt in recovery path, but exception is not skippable.
...
10:54:24.295 [main] DEBUG c.a.i.imp.CompositeTransactionImp - rollback() done of transaction 10.78.130.172.tm172740206428300012
...
10:54:24.298 [main] DEBUG o.s.b.repeat.support.RepeatTemplate - Handling fatal exception explicitly (rethrowing first of 1): org.springframework.retry.ExhaustedRetryException: Retry exhausted after last attempt in recovery path, but exception is not skippable.
10:54:24.299 [main] ERROR o.s.batch.core.step.AbstractStep - Encountered an error executing step gmahjongTotalRankingStep in job gmahjongDailyRankingJob

writer.write() 함수 두 번 호출됨. 3번째 시도를.. 하는 것 같긴 한데.. write 호출은 안 하고.. 횟수 초과로 전체 롤백을 하는 듯한 로그만 남음..

정확하게 세 번 시도를 하는 건지는 모르겠으나..(10:54:24.288과 10:54:24.295 사이에 실행 로그가 있어야 하지 않나)

"Rollback for RuntimeExceptioin", "rollback() done"의 로그가 세 번씩 남으므로 프로그램의 입장에선 에러를 세 번 감지한 것 같긴 하다..

참고로 rollback을 한다고 했지만 해당 chunk대한 부분만 rollback이라, beforeStep에서 한 deleteAll은 이미 적용되어 있고(테이블이 비어 있고) writer의 첫 chunk부터 에러 발생이라 결국 빈 테이블이 유지된다.

이 상태에서(retryLimit = 2; writer에서 첫 2번만 에러 발생)

retryLimit만 2 -> 3으로 올리면, 에러는 그대로 두 번, 총 시도는 최초 + 재시도 3번 = 4번이라 마지막에 성공해야 한다.

실행해보면, 위와 같은 에러가 두 번나고 마지막 쪽 로그가 아래처럼 바뀌면서 insert가 된다..

14:38:12 DEBUG [main] o.s.b.repeat.support.RepeatTemplate - Repeat operation about to start at count=3
14:38:12 DEBUG [main] o.s.b.c.s.i.FaultTolerantChunkProcessor - Attempting to write: ...
14:38:12 DEBUG [main] org.mybatis.spring.SqlSessionUtils - Creating a new SqlSession
...// insert logs

뜻대로 되긴 하는데.. 아직도 왜 마지막 시도에 대한 로그가 제대로 안 찍혔는지 모르겠다.. write을 세 번 부르는 게 아닌가?

테스트 코드로 확인

@Test
  void testRetryLimit() throws Exception {
    // 첫 번째, 두 번째, 세 번째 호출에서 예외 발생
    JobParameters jobParameters = getJobParameters();
    given(totalRankingReader.read()).willReturn(userRats().get(0), userRats().get(1), null);
    doNothing().doNothing().doNothing().when(deleteAllBeforeStep).beforeStep(any());
    doAnswer(
            invocation -> {
              System.out.println("First write attempt");
              throw new RuntimeException("error! 1");
            })
        .doAnswer(
            invocation -> {
              System.out.println("Second write attempt");
              throw new RuntimeException("error! 2");
            })
        .doAnswer(
            invocation -> {
              System.out.println("Third write attempt");
              throw new RuntimeException("error! 3");
            })
        .when(insertTotalRank)
        .write(any(Chunk.class));

    // Step 실행
    JobExecution jobExecution =
        jobTestUtils
            .getJobTester(GmahjongRankingJobConfig.JOB_NAME)
            .launchJob(jobTestUtils.makeJobParameters(jobParameters));

    verify(totalRankingReader, times(3)).read();
    // write 메서드가 총 3번 호출되었는지 확인
    verify(insertTotalRank, times(3)).write(any(Chunk.class));

    // Job이 실패했는지 확인 (최대 재시도 후 실패)
    assertThat(jobExecution.getStatus()).isEqualTo(BatchStatus.FAILED);
  }

retryLimit = 2 일 때 writer를 3번 부르는지 테스트 코드이다. 시도한 로그를 남기기 위해 doThrow가 아닌 doAnswer을 사용하였다.

위 테스트는 실패한다. 아래 부분에서 실제로 2번 호출했다고 검증된다.

verify(insertTotalRank, times(3)).write(any(Chunk.class));

관련 로그.. 본 로그와 크게 다르지 않다 세 번째 writer를 호출하는지 잘 모르겠는.. 로그다.

14:58:57.449 [Test worker] DEBUG o.s.b.c.s.i.FaultTolerantChunkProcessor - Attempting to write:
14:58:57.449 [Test worker] DEBUG o.s.retry.support.RetryTemplate - Retry: count=0
First write attempt
Retry attempt 1 failed with exception: error! 1
14:58:57.451 [Test worker] DEBUG o.s.retry.support.RetryTemplate - Checking for rethrow: count=1

14:58:57.459 [Test worker] DEBUG o.s.b.c.s.i.FaultTolerantChunkProcessor - Attempting to write:
14:58:57.460 [Test worker] DEBUG o.s.retry.support.RetryTemplate - Retry: count=1
Second write attempt
Retry attempt 2 failed with exception: error! 2
14:58:57.460 [Test worker] DEBUG o.s.retry.support.RetryTemplate - Checking for rethrow: count=2

14:58:57.466 [Test worker] DEBUG o.s.b.c.s.i.FaultTolerantChunkProcessor - Attempting to write:
14:58:57.466 [Test worker] DEBUG o.s.b.core.step.tasklet.TaskletStep - Rollback for RuntimeException: org.springframework.retry.ExhaustedRetryException: Retry exhausted after last attempt in recovery path, but exception is not skippable.
14:58:57.466 [Test worker] DEBUG o.s.t.support.TransactionTemplate - Initiating transaction rollback on application exception

파고들기..(w GPT)

1. retryLimit의 동작 원리

retryLimit은 최대 재시도 가능 횟수를 의미합니다. 이는 "초기 시도 횟수를 제외한" 재시도 횟수입니다.
예를 들어, retryLimit = 2로 설정한 경우, 최초 시도 1번 + 재시도 2번 = 총 3번의 시도가 이루어집니다.
- 시도 1: 최초 시도
- 재시도 1: retryLimit에 의해 허용된 첫 번째 재시도
- 재시도 2: retryLimit에 의해 허용된 마지막 재시도

2. 로그 분석

2.1. 첫 번째 시도 (count=0)

First write attempt 로그가 나타난 후 RuntimeException이 발생하여 재시도가 필요합니다.
retry()가 적용되어 재시도 1이 시작됩니다.

2.2. 첫 번째 재시도 (count=1)

Second write attempt 로그가 나타난 후 두 번째 예외가 발생합니다.
retry()에 의해 마지막 재시도가 필요합니다.

2.3. 두 번째 재시도 (count=2)

이 시도에서도 실패하여 RetryTemplate의 ExhaustedRetryException이 발생합니다.
세 번째 재시도에서 예외 발생 후, 더 이상 재시도가 이루어지지 않습니다.

3. 실제 호출과 예외 발생 횟수 차이

위 로그에서 write() 메서드가 총 3번 호출된 것을 확인할 수 있습니다. 하지만 예외가 명시적으로 두 번만 발생하는 이유는 다음과 같습니다:

첫 번째 시도와 첫 번째 재시도: 첫 번째 시도와 첫 번째 재시도에서 예외가 발생하여 retry()가 작동했습니다. 이때 retryLimit에 따라 재시도가 시도됩니다.
두 번째 재시도: 두 번째 재시도에서 예외가 발생하면 retryLimit을 모두 소진하게 됩니다. 이 시점에서 ExhaustedRetryException이 발생합니다.
재시도 실패 후 처리: ExhaustedRetryException이 발생하면 더 이상 재시도가 이루어지지 않으며, 마지막 재시도 실패 후에는 예외가 발생한 상태로 처리됩니다.

4. ExhaustedRetryException의 의미

ExhaustedRetryException은 설정된 재시도 한도(retryLimit)를 모두 소진한 후에도 예외가 해결되지 않았다는 의미입니다. 이 예외는 마지막 시도에서 예외가 발생했다는 것을 의미하며, 재시도가 더 이상 이루어지지 않음을 나타냅니다.

: 말이 애매하다. 총 3번의 시도를 하지만 writer를 부르는 시도는 아니고,, writer를 2번 부르고 재시도 횟수가 고갈되면 마지막 시도를 하기 전에 예외가 발생한다고 이해해야 할 것 같다.

참고로 첫 번째, 두 번째는 실패 세 번째에서 성공시키는 테스트 코드를 짜도 writer는 2번 불리고 전체 배치는 실패처리 된다.

최초 시도 -> 에러1 -> 재시도1 -> 에러2 -> 재시도2 -> 성공 -> ..전체 성공?이라고 생각하기 쉬운데..

이미 에러2에서 재시도 횟수(2)가 소비되어 에러가 발생하는 플로우다..

 @Test
  void testRetryLimit() throws Exception {
    JobParameters jobParameters = getJobParameters();
    given(totalRankingReader.read()).willReturn(userRats().get(0), userRats().get(1), null);
    doNothing().doNothing().doNothing().when(deleteAllBeforeStep).beforeStep(any());
    // 첫 번째, 두 번째 호출에서 예외 발생
	doAnswer(
            invocation -> {
              System.out.println("First write attempt");
              throw new RuntimeException("error! 1");
            })
        .doAnswer(
            invocation -> {
              System.out.println("Second write attempt");
              throw new RuntimeException("error! 2");
            })
        .doNothing()
        .when(insertTotalRank)
        .write(any(Chunk.class));

    // Step 실행
    JobExecution jobExecution =
        jobTestUtils
            .getJobTester(GmahjongRankingJobConfig.JOB_NAME)
            .launchJob(jobTestUtils.makeJobParameters(jobParameters));

    verify(totalRankingReader, times(3)).read();
    // write 메서드는 2번 호출
    verify(insertTotalRank, times(2)).write(any(Chunk.class));

    // Job이 실패했는지 확인 (최대 재시도 후 실패)
    assertThat(jobExecution.getStatus()).isEqualTo(BatchStatus.FAILED);

흐름 설명:

첫 번째 시도 (Write attempt 1):
- write() 호출 → RuntimeException 발생 → 재시도 1로 진입.
첫 번째 재시도 (Write attempt 2):
- write() 호출 → 다시 RuntimeException 발생 → 재시도 2로 진입.
두 번째 재시도 (Write attempt 3):
- write() 호출 → 성공적으로 처리됨.
결과 처리:
- 비록 세 번째 시도에서 성공했더라도, 재시도 한도인 retryLimit 2번을 모두 소진했으므로, 전체 Step이 실패로 처리됩니다.
- ExhaustedRetryException이 발생하여, 더 이상의 재시도 없이 실패로 간주됩니다.

재시도 한도 소진과 처리 방식

재시도 한도 소진:
- retryLimit에 따라 재시도 횟수가 소진되면 RetryTemplate은 더 이상 ItemWriter를 호출하지 않습니다.
- 재시도 중 실패한 예외를 처리할 수 없는 상태가 되면 ExhaustedRetryException을 발생시킵니다.
최종 예외 처리:
- 최종적으로 발생한 예외가 스킵 가능하지 않거나, 재시도 후에도 처리되지 않은 경우 전체 Step이 실패로 종료됩니다.
마지막 시도가 성공하더라도:
- 마지막 재시도에서 성공하더라도 재시도 한도가 모두 소진된 상태에서는 더 이상 재시도 없이 Step이 실패로 처리됩니다.

이.. 말싸움 때문에 3일 정도 매진한 것 같다..ㅠㅠ

결국, 재시도 횟수 차감되는 시점이 중요.....!

728x90

'개발 > spring-batch' 카테고리의 다른 글

[spring-batch] mocking item reader/writer in test code (0)	2024.08.27
[spring-batch] job parameter와 관련된 수난기 (0)	2024.08.23
[spring-batch] springboot3 mybatis 설정 그리고 mapper (0)	2024.08.16
[spring-batch] 소개 (0)	2023.12.04
[spring-batch] simpleJob (0)	2022.05.26

기억 파편