[Java] STW(Stop The World) 유도하기

목표 

Java의 가장 대표 격인 GC인 G1GC에서의 Stop The World를 빈번하게 유도해보고 초저지연 GC도 사용해보겠습니다.

얕게 배워본 초저지연 GC로 일단 테스트부터 해보며 어떤 상황일 때 ZGC를 사용해볼 법한지 알아보겠습니다.

배열에 큰 용량 할당 테스트

JDK 17에서의 G1GC 테스트

우선 JDK 17에서 아무 설정도 건드리지 않으면 G1GC로 선택이 되니 바로 테스트해 보겠습니다.

일단 10MB를 배열에 지속적으로 할당과 해제를 반복하는 것을 1000번 진행합니다.

private static final int SIZE = 10 * 1024 * 1024 * 10; // 100MB씩 할당

public void createMemoryPressure() {
  // 메모리를 빠르게 할당하고 해제하면서 GC를 유도
  for (int i = 0; i < 1000; i++) {
    byte[] memoryPressure = new byte[SIZE]; // 10MB씩 할당
    // 할당된 메모리를 사용하고 나서 즉시 참조를 끊음
    // 메모리 할당 후 바로 GC가 발생할 수 있게 만듦
    memoryPressure = null;
  }
}

프로젝트 실행 시 -Xlog:gc*:file=gc.log를 추가하면 아래 로그를 볼 수 있습니다.

[7.631s][info][gc] GC(3) Pause Young (Concurrent Start) (G1 Humongous Allocation) 955M->14M(2048M) 2.893ms
[7.631s][info][gc] GC(4) Concurrent Undo Cycle
[7.634s][info][gc] GC(4) Concurrent Undo Cycle 2.383ms
[7.689s][info][gc] GC(5) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->14M(2048M) 1.727ms
[7.689s][info][gc] GC(6) Concurrent Undo Cycle
[7.691s][info][gc] GC(6) Concurrent Undo Cycle 1.661ms
[7.747s][info][gc] GC(7) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->14M(2048M) 1.901ms
[7.748s][info][gc] GC(8) Concurrent Undo Cycle
[7.749s][info][gc] GC(8) Concurrent Undo Cycle 1.731ms
[7.805s][info][gc] GC(9) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->14M(2048M) 2.622ms
[7.805s][info][gc] GC(10) Concurrent Undo Cycle
[7.806s][info][gc] GC(10) Concurrent Undo Cycle 1.642ms
[7.863s][info][gc] GC(11) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->14M(2048M) 1.739ms
[7.863s][info][gc] GC(12) Concurrent Undo Cycle
[7.865s][info][gc] GC(12) Concurrent Undo Cycle 1.691ms
[7.921s][info][gc] GC(13) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->14M(2048M) 2.457ms
[7.921s][info][gc] GC(14) Concurrent Undo Cycle
[7.923s][info][gc] GC(14) Concurrent Undo Cycle 1.761ms
[7.981s][info][gc] GC(15) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->14M(2048M) 1.817ms
[7.981s][info][gc] GC(16) Concurrent Undo Cycle
[7.983s][info][gc] GC(16) Concurrent Undo Cycle 1.647ms
[8.039s][info][gc] GC(17) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->14M(2048M) 2.147ms
[8.039s][info][gc] GC(18) Concurrent Undo Cycle
[8.040s][info][gc] GC(18) Concurrent Undo Cycle 1.567ms
[8.097s][info][gc] GC(19) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->15M(2048M) 1.883ms
[8.097s][info][gc] GC(20) Concurrent Undo Cycle
[8.099s][info][gc] GC(20) Concurrent Undo Cycle 1.652ms
[8.156s][info][gc] GC(21) Pause Young (Concurrent Start) (G1 Humongous Allocation) 917M->14M(2048M) 2.039ms
[8.156s][info][gc] GC(22) Concurrent Undo Cycle
[8.158s][info][gc] GC(22) Concurrent Undo Cycle 1.643ms
[8.220s][info][gc] GC(23) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->14M(2048M) 1.825ms
[8.220s][info][gc] GC(24) Concurrent Undo Cycle
[8.222s][info][gc] GC(24) Concurrent Undo Cycle 1.610ms
[8.280s][info][gc] GC(25) Pause Young (Concurrent Start) (G1 Humongous Allocation) 916M->14M(2048M) 1.981ms
[8.280s][info][gc] GC(26) Concurrent Undo Cycle
[8.282s][info][gc] GC(26) Concurrent Undo Cycle 1.752ms

 

위의 STW를 포함해서 걸린 시간을 조회해 보면 전체 약 40ms 정도가 소요됩니다.

물론 Humogous Allocation(거대 할당)과 같은 상황은 일반적이지 않은 테스트 방식이긴 합니다.

JDK 17의 Shenandoah(셴언도우) GC

셴언도우는 미국의 강이고 평온한 GC라는 뜻으로 굉장히 빠른 GC로 World가 멈추지 않는 현상을 보입니다.

아래의 설정으로 셴언도우 GC를 실행시킬 수 있습니다.

-Xms2g -Xmx2g -Xlog:gc:file=gc.log.2025-02-11 -XX:+UseShenandoahGC

 

이렇게 해보면 JDK 17에서의 G1GC보다 5배 빠른 걸 확인할 수 있었습니다.

다만, 셴언도우는 동시성 처리를 위해 CPU, 메모리 소비 증가 하므로 해당 부분을 염두에 두어야 합니다.

일단 여기서는 로그를 가져오지 않았습니다.
어차피 2023년 9월 19일 프로덕션 릴리스로 Shenandoah 기능은 준비되지 않아 제거되고 있습니다.
세대별 Shenandoah용 JEP 작성자인 Amazon의 Roman Kennke는 JDK 21 또는 Java 21에서 해당 기능을 제거하기로 결정했으며 Oracle 이 명시한 대로 향후 JDK 릴리스가 준비되면 이를 평가할 계획이라고 합니다.

Redis에서 큰 용량의 데이터 조회하기

JDK 21의 ZGC

-Xms2g -Xmx2g -Xlog:gc:file=gc.log.2025-02-11 -XX:+UseZGC

 

위의 코드 케이스는 강제 할당이라 일반적이지 않다고 했으니 일반적인 상황을 가정해 보겠습니다.

Redis에서 업데이트 정보를 가져가면서 Gzip 압축도 하고 암복호화도 하는 테스트를 해보겠습니다.

  public String getUpdate(String updateId) {
    try {
      String base64EncryptedData = (String) redisTemplate.opsForHash().get("update:" + updateId, "content");
      if (base64EncryptedData == null) {
        return null; // Redis에 데이터가 없을 경우 null 반환
      }

      // 1. Base64 디코딩
      byte[] encryptedData = Base64.getUrlDecoder().decode(base64EncryptedData);

      // 2. 복호화
      byte[] decryptedData = ARIAUtil.decryptWithCBC(encryptedData);

      // 3. GZIP 압축 해제
      ByteArrayOutputStream out = new ByteArrayOutputStream();
      try (GZIPInputStream gzipInputStream = new GZIPInputStream(new ByteArrayInputStream(decryptedData))) {
        byte[] buffer = new byte[1024];
        int len;
        while ((len = gzipInputStream.read(buffer)) != -1) {
          out.write(buffer, 0, len);
        }
      }

      // 4. 복호화된 데이터 반환
      return out.toString("UTF-8");

    } catch (Exception e) {
      e.printStackTrace();
      return null; // 예외 발생 시 null 반환
    }
  }

 

이렇게 설정하고 레디스에 약 4kb 데이터를 Hash로 넣어두고 k6로 1000명의 사용자가 조회하는 테스트 해봤습니다.

[59.105s][info][gc] GC(10) Pause Young (Normal) (G1 Evacuation Pause) 462M->53M(2048M) 11.602ms
[117.056 s][info][gc] GC(11) Pause Young (Normal) (G1 Evacuation Pause) 1252M->60M(2048M) 13.200ms

G1GC는 GC에 걸리는 시간이 약 10ms가 나옵니다.

100만 분의 10초로 굉장히 적은 숫자지만 사용자가 더 많아진다면 더 오랜 시간 멈출 겁니다.

JEP 439: Generational ZGC
These benefits should come without significant throughput reduction compared to non-generational ZGC. The essential properties of non-generational ZGC should be preserved:Pause times should not exceed 1 millisecond,

 

ZGC에 대한 공식 문서를 보면 STW는 1 millisecond를 초과하면 안 된다고 설명되어 있습니다.

그러므로 ZGC 측면에서는 G1GC를 사용하는 것은 비효율적이라는 의미가 될 수 있습니다.

물론 G1GC의 기본 GC 처리 지연 시간은 200ms인데, 그 정도 시간 이내로 처리되는 것이 안전한 애플리케이션이라면 G1GC를 그대로 사용해도 상관없습니다.

 

그럼 G1GC가 부하가 오는 정도는 어떻게 파악하면 좋을까요?

테스트를 하기 위해서는 일단 G1GC의 처리 시간을 보면 안됩니다.(어차피 GC의 처리시간은 200ms이하로 고정일테니)결국에 Heap이 꽉차는지 안차는지만 체크를 하면 됩니다.

-XX:+PrintGCDetails같은 설정으로 빈번하게 Heap이 꽉차는걸 볼 수 있다면 G1GC의 문제가 생기는 것으로 간주할 수 있습니다.
G1GC는 작은 Region 영역으로 분리해서 GC를 처리하는데 그 영역이 꽉차있다면 분명히 문제가 생기는 것일 테니까요.

 

ZGC를 사용하면 백그라운드에서 애플리케이션이 구동하는 도중에 GC를 처리하기 때문에 아래와 같은 로그가 나옵니다.

[27.805s][info][gc] GC(3) Garbage Collection (CodeCache GC Threshold) 144M(7%)->50M(2%)
[34.122s][info][gc] GC(4) Garbage Collection (Warmup) 208M(10%)->74M(4%)
[39.141s][info][gc] GC(5) Garbage Collection (Warmup) 414M(20%)->96M(5%)

 

동시 처리로 1 millisecond 이하로 유지하기 때문에 굳이 시간을 뽑을 필요가 없는 건지 GC에 걸리는 시간에 대한 로그가 노출되지 않았습니다.(추후에 찾으면 넣겠습니다.)

 

ZGC는 대부분의 작업을 애플리케이션 실행(application threads)과 동시에(concurrently) 수행합니다.

이를 통해 애플리케이션의 일시 중지(Stop-The-World) 시간을 최소화합니다. 
다만, 완전히 stop-the-world를 피할 수는 없고, 매우 짧은 시간(1ms 이하) 동안의 일시 중지는 발생합니다.
예를 들어, 객체 포인터를 이동시키거나, 메모리 영역을 정리하는 등의 작업을 할 때는 잠깐 애플리케이션 스레드가 멈출 수 있습니다. 그러나 이러한 정지 시간은 몇 밀리초에 불과하며, STW 시간은 매우 짧고 대부분은 백그라운드에서 GC가 진행됩니다.
동시 처리하기 때문에 애플리케이션의 CPU나 Concurrent 작업을 위한 추가 메모리 overhead가 필요하기 때문에 최소 권장 힙 크기는 8GB고 최대는 16TB로 설정한다고 합니다.
작은 힙에서는 GC의 오버헤드가 상대적으로 커질 수 있습니다.