2024-11-15

모든 것을 의심하자. 삽질이후.. (feat. 부하테스트 툴)

2024.11.15 - 모든 것을 의심하자. 삽질이후.. (feat. 부하테스트 툴)

나는 동시성 테스트를 하기 위해 NGrinder 와 Apache Bench 를 사용했다. 대략적인 계획은 이러하다.

쿠폰 발급이라고 예시를 들면

수량이 1억개인 쿠폰이 있다고 가정하고, 1000명, 10000명 동시에 쿠폰 발급 요청을 했을 때 정확히 유저의 요청 수 만큼 쿠폰이 발급되었는 지를 확인한다.

문제는 실제 시간을 두고 계속해서 부하를 줬을 때(NGrinder 의 경우 3분동안 부하테스트 시행) 실제 총 실행 테스트를 했을 경우이다. 아래의 테스트 결과에서는 총 실행테스트가 22546 개의 요청을 날린 것으로 나와있지만, 실제로는 그보다 많은 23120 개의 요청이 들어온 것을 알 수 있다.

NGrinder

스크린샷 2024-09-11 오후 8 05 07
그림 1 - NGrinder 테스트 결과

Apache Bench

AB 테스트 역시 마찬가지 였다. 실제로 -t 옵션을 주지 않았을 때는 문제가 되지 않았지만, -t 옵션을 통해 시간을 두고 부하 테스트를 했을 경우도 마찬가지로 실제 요청 수와 차이가 있었다

스크린샷 2024-09-11 오후 8 05 07
그림 2 - Apache Bench 테스트 결과

AB 테스트 결과에는 1084 개의 완료된 요청이 있다고 했지만 실제로는 그 보다 9개 많은 1093 개의 요청이 들어온 것을 알 수 있다.

스크린샷 2024-09-11 오후 8 05 07
그림 3 - 실제 app 내에서 측정한 요청 카운트

확인 방법

접속 카운트를 저장하는 변수는 스레드에 안전해야 하기 때문에 Java 에서 제공하는 단일 연산 변수 AtomicLong 를 이용하여 요청 카운트를 저장했다.

  private final AtomicLong count = new AtomicLong(0L);	

  @GetMapping("/pay-result-v2")
  public ResponseEntity<String> payResultV2() {
    count.getAndIncrement();
    try {
      roomReservationService.reserve(1L);
    } catch (RuntimeException e) {
      return ResponseEntity.status(400).build();
    }
    return ResponseEntity.ok("ok");
  }

  @GetMapping("/result-request")
  public String totalRequestCount() {
    return "total request count : " + count.get();
  }

깨달은 점

사실 처음에는 동시성에 대한 코드가 잘못된 줄 알았다. 하지만 동시성을 제어하는 코드에는 아무런 이상이 없었다. 실제로 테스트 코드를 돌려봤을 때는 모두 통과했었다. 하지만 유독 시간을 두는 테스트에서만 문제가 생기는 것을 의심했고 직접 카운트를 찍었을 때 툴에서의 결과와 다른 것을 알 수 있었다.

툴에 나오는 요청 횟수를 그대로 믿었기에, 한 동안 나의 코드가 잘못되었는 지 계속 살펴보았다. 생각해보면 부하테스트는 정확한 요청 카운트가 중요하지 않을 수 있다. 특히 시간을 두고 점차적인 부하테스트를 할 때 1억건의 요청을 날리는 데 10, 100 정도 요청이 차이난다고 해서 시스템 병목을 파악하고 어느 정도 요청에 대한 Throughput 을 가지는 지를 파악못하는 것은 아니기 때문이다.

추가 수정(2024/11/15)

이와 관련된 글이 있는 지 찾아보고 수정함.

nGrinder 의 경우 log 파일의 test 수와 web 상에 나타나는 executed test 수가 다를 수 있다고 한다. 왜냐하면 별도의 샘플링이라는 데이터 수집 프로세스를 이용하여 결과가 합산되는 데, 이때 테스트 종료시에 샘플링이 일부 누락되어 조금의 차이가 발생할 수 있고 이는 알려진 이슈라고 한다.(링크참조)

테스트

참고로 nGrinder 는 에이전트당 1개의 프로세스 로그만 볼 수 있기 때문에 1agent, vuser 1000 (1process, 1000 thread) 로 테스트 했다(그림 1의 경우에는 로그파일을 보면 한개의 프로세스만 볼 수 있어서 전체 요청 수 확인 불가함.)
테스트 결과 실제 application 에서 측정한 요청 수 와 일치하는 것을 확인할 수 있었다!

스크린샷 2024-09-11 오후 8 05 07
그림 4 - 1agent, vuser 1000 (1process, 1000 thread), nGrinder 테스트 결과 log 파일 중 일부

스크린샷 2024-09-11 오후 8 05 07
그림 5 - 실제 application 에서 측정한 요청 수

참고

http://ngrinder.373.s1.nabble.com/exected-test-td2531.html