JVM Stacktrace Optimizing

HYK·2023년 8월 10일

❗❗환경에 따라 결과가 다를 수 있습니다.

개요

서비스 운영시 Log의 Stacktrace가 누락되는 원인과 함께 해결방안에 대해서 알아봅시다.

원인

JVM은 JIT 컴파일러를 통해서 성능을 최적화시킵니다.
JIT 컴파일러 tiered compilation 단계에서 C2 컴파일러를 사용할 때 Stacktrace가 최적화됩니다.
정확하게는 지속적으로 예외가 발생하면서 특정 임계치가 되면 해당 exception에 대한 Stacktrace를 누락시킵니다.

하지만 모든 Stacktrace를 누락시키는 것은 아닙니다.
특정 Exception에서만 Stacktrace 누락이 발생하며 코드상에서 직접 throw한 예외는 최적화되지 않습니다.

ex)throw new NullPointerException();

JVM에서 Stacktrace를 최적화하는 Exception 종류

NullPointerException
ArithmeticException
ArrayIndexOutOfBoundsException
ArrayStoreException
ClassCastException

open jdk jvm 17 hotspot https://github.com/openjdk/jdk17/blob/master/src/hotspot/share/opto/graphKit.cpp

테스트 환경

open JDK 17
spring boot
JVM optin : -Xmx4096m -Xms4068m
외부 부하 도구 : k6

테스트 방법

최적화 과정을 보는 것이기 때문에 warm up은 생략합니다.
엔드 포인트당 약 20000개의 request를 주어 exception을 발생시키면서 stacktrace가 초기화되는지 확인합니다. (테스트당 3번 진행)
위의 5가지 예외 중에 평소에 자주 만나는 예외 3가지 NullPointerException, ArrayIndexOutOfBoundsException, ClassCastException를 기준으로 테스트합니다.
또한 위에 해당되지 않는 예외인 NumberFormatException 테스트를 추가로 진행합니다.

그리고 예외 생성 방식에 따른 조건도 알아보기 위해 다음과 같이 두 가지 엔드 포인트로 나누어 진행합니다.

1번 예외를 직접 던지지 않는 케이스
2번 예외를 직접 던지는 케이스

마지막으로 최적화된 후에 엔드 포인트를 크로스 해서 각각 호출합니다.
ex) 1번이 최적화된 후 1번 재호출 및 2번 재호출
1번과 2번은 같은 Exception이지만 1번이 최적화돼도 2번이 함께 최적화되는지 확인하는 용도입니다.

테스트 컨트롤러


//java -jar -Xmx4096m -Xms4096m java17spring3-0.0.1-SNAPSHOT.jar

@RestController
@Slf4j
public class TestController {


	//================nullPointerException===================
    
    
	@GetMapping("null1")
	public void nullPointerException1() {
		String a = null;
		a.length();
	}

	@GetMapping("null2")
	public void nullPointerException2() {
		throw new NullPointerException();
	}
    
    

	//================arrayIndexOutOfBoundsException===================
    
    
	@GetMapping("/array1")
	public void arrayIndexOutOfBoundsException1() {
		int[] arr = {0, 1, 2, 3, 4};
		arr[5] = 4;
	}

	@GetMapping("/array2")
	public void arrayIndexOutOfBoundsException2() {
		throw new ArrayIndexOutOfBoundsException();
	}


	//================classCastException===================
    
    
	@GetMapping("/class1")
	public void classCastException1() {
		Object i = Integer.valueOf(42);
		String s = (String)i;
	}

	@GetMapping("/class2")
	public void classCastException2() {
		throw new ClassCastException();
	}


	//================numberFormatException===================
    
    
	@GetMapping("/number1")
	public void numberFormatException1() {
		String number = "12345O";
		Integer.parseInt(number);
	}

	@GetMapping("/number2")
	public void numberFormatException2() {
		throw new NumberFormatException();
	}
    
    
	//================번외 명시적 로그 사용===================
	@GetMapping("/log")
	public void logArrayIndexOutOfBoundsException() {
		try {

			int[] arr = {0, 1, 2, 3, 4};
			arr[5] = 4;
		} catch (ArrayIndexOutOfBoundsException e) {
			log.error("error", e);
		}
	}
}

부하 스크립트

import http from 'k6/http';
import { sleep } from 'k6';

export let options = {
    vus: 100,
    iterations: 6000,
};

export default function () {
    let res = http.get('http://{ip}:8017/log');
  	// http://{ip}:8017/null1, null2, class1, class2 ...
    sleep(5)
}