Java/자바 최적화

[Java] 자바 최적화(8) - GC 모니터링

ready-go 2023. 4. 6. 21:35

GC 모니터링

가비지 컬렉션은 많은 Java 개발자들을 편하게 만들어 줬지만, 동시에 내부에서 일어나고 있는 일을 파악하기 어렵게 만들었다. 단독으로 실행하는 데스크탑 어플리케이션이나 사용자가 적은 백오피스 서버의 경우 문제가 되지 않지만, 사용자가 많은 서비스에서 성능을 극한까지 끌어올려야 하는 경우는 다르다. JVM 런타임 메모리에서는 어떤 일이 일어나고 있는지, 가비지 컬렉터는 어떻게 동작하는지 알고있어야 제대로 튜닝할 수 있다. 따라서 GC를 모니터링할 수 있는 도구가 필요하다.

 

GC 로그

가장 기본적인 방법이자, 가장 중요한 것은 GC 로그를 출력하는 것이다. GC 로그는 메모리 할당에 실패한다거나, Full GC가 일어나는 등 특정한 이벤트가 발생할 때마다 기록된다. 이렇게 로그를 기록하는 것은 어플리케이션 성능에 주는 영향이 거의 없기 때문에 운영 환경에서도 반드시 켜 두어야 한다.

 

GC 로그를 활성화하기 위해서는 실행시 옵션을 주면 된다. 아래와 같은 코드를 실행해보자.

import java.util.ArrayList;

public class Test {
    public static void main(String[] args) {
        ArrayList<Integer> list = new ArrayList<>();
        for (int i = 0; i < 10000000; i++) {
            list.add(i);
        }
        list.clear();
    }
}
java -verbose:gc Test (java 8 이전)
java -Xlog.gc Test (java 9 이후)

위와 같이 Java 8 이전까지는 -verbose:gc 옵션을, Java 9부터는 -Xlog:gc 옵션을 주면 아래와 같이 출력된다.

[0.014s][info][gc] Using G1
[0.208s][info][gc] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 46M->45M(130M) 64.876ms
[0.222s][info][gc] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 48M->48M(130M) 11.771ms
[0.230s][info][gc] GC(2) Pause Young (Concurrent Start) (G1 Humongous Allocation) 52M->53M(130M) 5.538ms
[0.231s][info][gc] GC(3) Concurrent Undo Cycle
[0.232s][info][gc] GC(3) Concurrent Undo Cycle 1.702ms
[0.278s][info][gc] GC(4) Pause Young (Normal) (G1 Evacuation Pause) 77M->77M(130M) 15.544ms
[0.285s][info][gc] GC(5) Pause Young (Concurrent Start) (G1 Humongous Allocation) 78M->80M(390M) 6.352ms
... 생략 ...

조금 더 자세한 내용이 보고싶으면 Java 8까지는 -XX:+PrintGCDetails 옵션, 9 이상에서는 -Xlog:gc* 옵션을 주면 된다.

java -XX:+PrintGCDetails Test (java 8 이전)
java -Xlog:gc* Test (java 9 이후)

로그를 파일로 저장하려면 Java 8 이전은 -Xloggc:test.log, Java 9 이상은 -Xlog:gc:test.log와 같이 파일 이름을 붙여주면 된다.

java -Xloggc:test.log Test (java 8 이전)
java -Xlog:gc:test.log Test (java 9 이후)

또한, GC 이벤트 발생 시간을 출력하는 옵션도 있다. 위 결과를 보면 맨 왼쪽에 VM 시작이후로 경과된 시간을 초단위로 보여주는데, 상대시간이 아닌 절대시간을 출력하고싶다면 파일이름 뒤에 time을 붙여주면 된다. Java 8 이전은 -XX:+PrintGCDateStamps, Java 9 이상은 -Xlog:gc::time 옵션을 주면 된다.

java -verbose:gc -XX:+PrintGCDateStamps Test (java 8 이전)
java -Xlog:gc::time Test (java 9 이후)

 

GC 로그 파서

1초에 50MB정도 메모리를 할당하는 어플리케이션을 30분간 실행하면 약 600KB정도의 로그가 쌓인다. 이것을 데이터 저장소에 저장한다고 생각하면 생각보다 작아보이지만, 사람이 직접 읽어서 분석한다면 밤을 새야 할 것이다. 따라서 이러한 로그를 파싱해서 필요한 결과를 보여주는 파서가 필요하다.

 

무료로 사용할 수 있는 대표적인 파서로 IBM의 Garbage Collection and Memory Visualizer, HPE의 HPjmeter 등이 있다. 이들은 GUI도 지원하기 때문에 필요한 정보를 쉽게 얻을 수 있다. 또한, Microsoft의 GCToolKit은 원하는 정보를 직접 가공할 수 있는 라이브러리를 제공한다.

 

[IBM Garbage Collection and Memory Visualizer] https://www.ibm.com/docs/en/mon-diag-tools?topic=monitoring-diagnostic-tools-garbage-collection-memory-visualizer 

[HPjmeter] https://myenterpriselicense.hpe.com/cwp-ui/product-details/HPJMETER/4.8.00/sw_free

[Microsoft GCToolKit] https://github.com/microsoft/gctoolkit

 

jstat

jstat은 OpenJDK의 기본으로 포함되어있는 JVM 모니터링 CUI 도구다. GC를 위해 만들어진 것은 아니지만, GC와 관련된 통계를 많이 제공한다. 서버를 실행시킨 후, vmid(Virtual Machine ID)를 이용해 아래와 같이 실행할 수 있다. vmid는 실행중인 Java 어플리케이션의 목록을 보여주는 jps 명령어로 찾을 수 있다.

jstat -gc 17835

jstat 실행 결과

각 컬럼이 의미하는 것은 아래와 같다.

S0C (Survivor 0 Capacity) Survivor 0영역의 크기(kB)
S1C (Survivor 1 Utilization) Survivor 1영역의 크기(kB)
S0U (Survivor 0 Used) Survivor 0영역에서 사용중인 메모리의 크기(kB)
S1U (Survivor 1 Utilization) Survivor 1영역에서 사용중인 메모리의 크기(kB)
EC (Eden Capacity) Eden 영역의 크기(kB)
EU (Eden Utilization) Eden 영역에서 사용중인 메모리의 크기(kB)
OC (Old Capacity) Old 영역의 크기(kB)
OU (Old Utilization) Old 영역에서 사용중인 메모리의 크기(kB)
MC (Metaspace Capacity) Metaspace 영역의 크기(kB)
MU (Metaspace Utilization) Metaspace 영역에서 사용중인 메모리의 크기(kB)
CCSC (Compressed Class Space Capacity) CCS 영역의 크기(kB)
CCSU (Compressed Class Space Utilization) CCS 영역에서 사용중인 메모리의 크기(kB)
YGC (Young GC) Young GC 횟수
YGCT (Young GC Time) Young GC에 걸린 총 시간
FGC (Full GC) Full GC 횟수
FGCT (Full GC Time) Full GC에 걸린 총 시간
CGC (Concurrent GC) Concurrent GC 횟수
CGCT (Concurrent GC Time) Concurrent GC에 걸린 총 시간
GCT (GC Time) 전체 GC 시간

jstat은 -gc 옵션 이외에도 -gcutil, -gccause 등의 다른 옵션들도 제공한다.

 

VisualVM

VisualVM도 JVM을 모니터링하기 위한 도구다. GUI를 제공하기 때문에 실시간으로 변하는 정보들을 쉽게 확인할 수 있다. 로컬에서 실행중인 JVM 프로세스를 클릭해서 모니터링을 시작할 수 있다. 기본적으로 CPU 사용률이나 Heap의 사이즈, 클래스와 스레드의 개수 등을 볼 수 있다.

 

GC와 관련하여 자세한 정보를 알고싶으면 VisualGC 플러그인을 설치하면 된다. 각 영역의 크기와 할당된 메모리의 크기, GC에 걸린 시간 등 jstat을 실행해서 알 수 있는 정보들을 그래프로 표현해주기 때문에 편리하다.

 

3줄 요약

  1. GC 로그를 남기는 것이 중요하다
  2. GC 로그 파서를 사용하면 편리하게 로그를 분석할 수 있다
  3. 실행중인 JVM은 jstat, VisualVM 등의 도구로 모니터링 할 수 있다