GraalVM 소개

스레드 스택 덤프를 내장하는 방법

자바 응용프로그램의 장애는 크게 2가지로 분류됩니다. 첫번째는 과도한 힙 메모리 사용에 따른 잦은 GC 발생이고, 두번째는 I/O로 인한 블록 혹은 잠금으로 인한 스레드 대기 혹은 교착 문제입니다. 개발 환경에서는 디버거를 통해서 쉽게 WAS나 자바 애플리케이션의 내부 동작을 확인할 수 있지만, 운영 환경에서는 보안 문제로 터미널 접속조차 쉽지 않은 경우가 많습니다. 운영 환경에 JRE 대신 JDK를 설치한 경우라면, 잘 알려진대로 jstack 도구를 사용할 수 있습니다. 다음과 같이 현재 동작 중인 JVM 프로세스 PID를 매개변수로 넘겨서 실행합니다. ``` $ jstack <PID> ``` 그러면 아래와 같은 형식으로 스레드 스택이 출력됩니다. ``` 2017-02-01 23:01:35 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.51-b03 mixed mode): "[iPOJO] pool-5-thread-1" #53 prio=5 os_prio=0 tid=0x000000000428a000 nid=0x7dcd waiting on condition [0x00007f3b2cf74000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0000000080c04348> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) "FelixStartLevel" #36 daemon prio=5 os_prio=0 tid=0x000000000263d000 nid=0x7dbc in Object.wait() [0x00007f3b2d67b000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:283) - locked <0x0000000080f65660> (a java.util.ArrayList) at java.lang.Thread.run(Thread.java:745) ``` jstack 덤프는 스레드 이름, 스택, 동작 상태 뿐 아니라, 현재 각 스레드가 소유하고 있는 잠금 인스턴스, 대기하고 있는 인스턴스 정보까지 포함합니다. 이를 확인하면 현재 어떤 이유로 스레드가 대기하고 있는지 진단할 수 있습니다. 그러나 보안 문제로 운영 환경에서 jstack 도구를 실행하기 어렵거나, 진단 정보를 자동으로 수집하려는 경우에는 [ThreadMXBean](https://docs.oracle.com/javase/8/docs/api/java/lang/management/ThreadMXBean.html)을 사용해서 애플리케이션 자체에 잠금 상태를 포함한 스택 덤프 기능을 내장할 수 있습니다. [JstackHelper.java 전체 코드 보기](https://gist.github.com/logpresso/c7928aefac3f094bef5905c5284eb9cb) ```java ThreadMXBean bean = ManagementFactory.getThreadMXBean(); long[] tids = bean.getAllThreadIds(); writer.write("Thread dump (total=" + tids.length + ")" + LF); writer.write("------------------------------------------" + LF); for (ThreadInfo t : bean.getThreadInfo(tids, true, true)) { if (t == null) continue; writer.write("\"" + t.getThreadName() + "\" tid=" + t.getThreadId() + ": (state = " + t.getThreadState() + ")" + LF); writer.write(mergeStackTrace(t)); writer.write(LF); } ``` 그런데 스레드 풀을 활용하는 경우 보통 스레드 풀을 대표하는 이름만 부여되기 때문에 스택 덤프를 봐도 현재 실행 중인 작업의 맥락을 쉽게 식별하기 어려운 경우가 종종 있습니다. 많은 개발자들이 스레드 이름은 스레드를 생성할 때만 설정할 수 있다고 생각하지만 실제로는 실행 중에 스레드 이름을 임의로 변경할 수 있습니다. [Thread.setName(String name)](https://docs.oracle.com/javase/8/docs/api/java/lang/Thread.html#setName-java.lang.String-) 따라서 Runnable 혹은 Callable을 구현할 때, 시작 부분에 현재 컨텍스트에 해당하는 문자열을 스레드 이름으로 설정하고, finally 블록으로 원래 스레드 이름을 복구하도록 코딩하면 현장에서 빠르게 장애를 진단하고 대응할 수 있습니다. 로그프레소는 system threads 쿼리를 통해서 스레드 실행 상태를 진단할 수 있는 기능을 제공하며, 외부 시스템이 흔히 연동되는 스트림 엔진에서는 실행 중인 스트림 쿼리 이름을 스레드 이름으로 설정함으로써 필드 엔지니어의 장애 진단을 지원합니다. 예를 들어 인덱스되지 않은 외부 데이터베이스의 테이블을 dblookup 커맨드로 참조하는 경우 낮은 SQL 조회 성능으로 인해 스트림이 JDBC 드라이버 스택에서 소켓 수신을 대기하고 있는 모습을 쉽게 확인할 수 있고, 해당 스트림 쿼리에 설정된 SQL 쿼리를 확인한 후 즉시 대응할 수 있습니다.

2017-02-02

로깅 안티패턴 Top 10

로그 포맷을 설계할 때 피해야 할 안티패턴 10가지를 소개합니다.

2023-05-04

JMH로 알아보는 오토 박싱의 부하

쉽게 쓰여진 자바 코드에서는 일반적으로 정수 값의 목록을 List 클래스로 관리합니다. 자바 컬렉션 프레임워크는 구조적으로 잘 설계된 편이지만, 자바 언어의 한계로 프리미티브 타입을 자바 컬렉션으로 관리하는 경우 성능 상 많은 불이익을 받게 됩니다. 이는 자바 컬렉션이 설계적으로 Object 타입만 받아들일 수 있고, 프리미티브는 Object를 상속하지 않기 때문에 자동으로 객체 변환(Boxing)을 수행하기 때문입니다. 64비트 시스템에서 int 프리미티브는 8바이트를 차지하는 반면, Integer 객체는 포인터 8바이트, 객체 헤더 16바이트, 데이터 8바이트로 총 32바이트를 소모하므로 메모리량을 많이 차지할 뿐더러, GC 작업에 있어서도 하나의 프리미티브 배열에 비해 개별 Integer 객체를 모두 추적해야 하므로 많은 비용이 들어갑니다. 자바 컬렉션으로 인한 성능 페널티는 계산량이 많은 응용프로그램일수록 더욱 두드러지는데, 수십-수백 테라바이트의 역인덱스 포스팅 리스트를 스캔해야 하는 검색엔진이나, 대량의 연산을 수행해야 하는 데이터베이스에서도 마찬가지로 큰 성능 저하를 유발합니다. 오래된 예이지만, 루씬 3.5 시절의 아래 이슈는 객체 참조로 인한 메모리 사용량을 줄이고 프리미티브 배열로 처리하는게 어느 정도의 성능 향상 효과를 가져올 수 있는지 잘 보여줍니다: * [\[LUCENE-2205\] Rework of the TermInfosReader class to remove the Terms\[\], TermInfos\[\], and the index pointer long\[\] and create a more memory efficient data structure](https://issues.apache.org/jira/browse/LUCENE-2205) ### JMH: Java Microbenchmark Harness 이제 오토박싱으로 인한 부하를 실제 측정해보기에 앞서, JMH를 소개하도록 하겠습니다. JMH는 JDK에서 공식적으로 제공하는 마이크로 벤치마크 프레임워크입니다. JMH를 기반으로 벤치마크 테스트를 작성하는 것을 권장하는 이유는, 조심스럽게 테스트 코드를 작성하지 않으면 JVM에서 제공하는 다양한 최적화 기법 때문에 벤치마크 테스트가 의도한대로 동작하지 않고 왜곡된 결과를 내놓을 수 있기 때문입니다. 아래와 같이 몇 가지 잘못된 예를 생각해볼 수 있습니다: <ul><li>JIT 컴파일 여부: 핫스팟 컴파일러는 일정 횟수 이상 실행되는 메소드를 컴파일하는데, 만약 웜업 단계를 생략하게 되면 결과에 왜곡이 발생하게 됩니다.</li><li>데드코드 제거: 벤치마크 작성 시 성능 측정 대상 코드만 간단히 루프에 넣어 돌리는 경우가 흔한데, 핫스팟 컴파일러는 참조되지 않는 무의미한 코드를 자동으로 삭제하기 때문에 왜곡된 결과를 얻을 수 있습니다.</li><li>버추얼테이블 최적화: 인터페이스 구현체가 1개인 경우에는 실행 시 분기할 필요가 없기 때문에 네이티브 코드가 최적화됩니다. 그러나 코드 실행에 따라 동일 인터페이스를 구현하는 클래스가 추가로 로드되는 경우, 이전 실행과 달리 왜곡된 결과를 얻을 수 있습니다.</li></ul> ### JMH 벤치마크 프로젝트 만들기 Maven을 이용해서 새 JMH 프로젝트를 생성합니다. ``` $ mvn archetype:generate -DinteractiveMode=false -DarchetypeGroupId=org.openjdk.jmh -DarchetypeArtifactId=jmh-java-benchmark-archetype -DgroupId=com.logpresso -DartifactId=benchmark -Dversion=1.0 ``` 그러면 아래와 같이 샘플 코드가 생성됩니다. ```java package com.logpresso; import org.openjdk.jmh.annotations.Benchmark; public class MyBenchmark { @Benchmark public void testMethod() { // This is a demo/sample template for building your JMH benchmarks. Edit as needed. // Put your benchmark code here. } } ``` 아래와 같이 두 개의 벤치마크 테스트 코드를 작성합니다. ```java package com.logpresso; import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.runner.Runner; import org.openjdk.jmh.runner.RunnerException; import org.openjdk.jmh.runner.options.Options; import org.openjdk.jmh.runner.options.OptionsBuilder; public class MyBenchmark { private static final int MAX_SIZE = 10000000; @Benchmark public int[] testPrimitive() { int[] array = new int[MAX_SIZE]; for (int i = 0; i < MAX_SIZE; i++) array[i] = i; return array; } @Benchmark public Integer[] textBoxing() { Integer[] array = new Integer[MAX_SIZE]; for (int i = 0; i < MAX_SIZE; i++) array[i] = i; return array; } } ``` 컴파일 후 아래와 같이 실행합니다: ``` $ mvn clean package $ java -jar target/benchmark-1.0.jar ``` 이제 실행하면 아래와 같은 결과를 볼 수 있습니다: ``` # Run complete. Total time: 00:14:20 Benchmark Mode Cnt Score Error Units MyBenchmark.testPrimitive thrpt 200 166.054 ± 1.265 ops/s MyBenchmark.textBoxing thrpt 200 32.191 ± 0.484 ops/s ``` 프리미티브 배열의 처리량이 객체 배열에 비해 약 5배 정도 높은 것을 확인할 수 있습니다. 전체 실행 결과는 [이 링크](https://gist.github.com/xeraph/06cedd1054ad0ff3e9536e2b7115a537)에서 볼 수 있습니다. JMH 프레임워크에서 적용할 수 있는 옵션은 여러가지인데, 이번 글에서는 가장 간단한 테스트 구성만 알아보았습니다. 자세한 내용은 [OpenJDK: JMH](http://openjdk.java.net/projects/code-tools/jmh/) 페이지를 참고하시기 바랍니다.

2017-01-12