GC Logging

애플리케이션 실행 중 트래픽이 몰릴 때 사용자의 요청에 응답을 해 주지 못하거나 오류가 발생하는 원인은 다양하지만, 동적 메모리 할당에서 문제가 발생할 소지가 많다. 이러한 동적 메모리 할당은 GC에 의해 자동으로 메모리가 해제되는데 이러한 과정에서 GC가 적절히 동작하는지를 살펴보려면 GC 로그를 확인해 보는 것이 좋다.

GC Logging Options

플래그 설명
-Xloggc:gc.log GC 이벤트에 로깅할 파일을 지정한다
-XX:+PrintGCDetails GC 이벤트 세부 정보를 로깅한다
-XX:+PrintTenuringDistribution 툴링에 꼭 필요한, 부가적인 GC 이벤트 세부 정보를 추가한다
-XX:+PrintGCTimeStamps GC 이벤트 발생 시간을 VM 시작 이후 경과시간을 기준으로 sec 단위로 출력한다
-XX:+PrintGCDateStamps GC 이벤트 발생 시간을 wall-clock 기준으로 출력한다

: 위 옵션을 사용할 때 성능적인 관점에서 주의해야할 사항들이다.

  • verbose:gc는 지우고 PrintGCDetails를 사용한다.
  • PrintTenuringDistribution 옵션을 사용함으로써 이 플래그가 제공하는 정보를 사람이 사용하기에는 어렵다. 하지만 중요한 memory pressure, premature promotion 등의 이벤트 계산시 필요한 기초 데이터를 제공해 줍니다.
  • PrintGCDateStampsPrintGCTimeStamps는 둘 다 사용해 주는것이 좋은데, 전자는 GC 이벤트와 로그파일을 연관짓는 용도, 후자는 GC와 다른 내부 JVM이벤트를 연관짓는 용도로 쓸 수 있다.


JVM 모니터링 툴과 GC 로그

VisualVM

  • VisualVM은 NetBeans 플랫폼 기반의 시각화 툴로 JRE에 포함되어 있다.(Java 9 부터는 배포 파일에서 빠져있으므로 다음의 경로에서 내려받아 디폴트 경로에 visualvm 바이너리 경로를 추가해 주어야 한다.)
  • JMX(Java Management eXtension) 이 적용된 기술이라 볼 수 있는데, 이는 JVM과 그 위에서 동작하는 애플리케이션을 제어하고 모니터링하는 범용 툴로 클라이언트 애플리케이션처럼 메소드를 호출하고 매개변수를 바꿀 수 있다.
  • VisualVM은 attach mechanism을 이용해 실행 프로세스를 실시간 모니터링한다. 원격 프로세스에 연결하려면 원격지에 JMX를 통해 인바운드 접속이 허용되어야 한다(== 원격 호스트에 jstatd가 실행되어야 한다.)
  • 이 툴을 이용하면 CPU, 힙 사용량, 로드/언로드 된 클래스 갯수, 실행중인 스레드 갯수, 스레드별 상태와 짧은 변화추이(with 스레드 덤프), CPU & 메모리 사용률에 대한 단순 샘플링 결과를 볼 수 있다.


JMX vs GC 로그

  • GC 로그 데이터는 실제 가비지 수집 이벤트가 발생해 쌓이지만, JMX는 데이터를 샘플링하여 얻는다.
  • GC 로그 데이터는 캡쳐 영향도가 거의 없으나, JMX는 프록시 및 원격 메소드 호출(Remote Method Invocation) 과정에서 비용이 발생한다.
  • GC 로그 데이터는 자바 메모리 관리에 연관된 성능 데이터가 50가지 이상이지만, JMX는 10가지도 안된다.
    JMX는 스트리밍된 데이터를 즉시 제공하지만 위와 같은 이유에서 GC 로그가 성능 관점에서 조금 더 좋아보일 수 있다. 추가로 요즘은 jClarity 센섬같은 툴도 GC 로그 데이터를 스트리밍하는 API를 제공하므로 큰 차이는 없다.


JMX의 단점

  • JMX를 이용해 애플리케이션을 모니터링하는 클라이언트는 대부분 런타임을 샘플링해 현재 상태를 업데이트 한다. 클라이언트는 데이터를 계속 넘겨받기 위해 런타임에있는 JMX 빈을 폴링한다. 문제는 GC가 언제 실행될지 클라이언트는 알 수 없으므로, GC 전후의 메모리 상태 역시 알 수 없으며 따라서 GC 데이터를 깊이있게 정확히 분석하기 힘들다.
  • JMXConnector를 구현한 코드는 내부적으로 RMI에 의존하는데, RMI기반 통신은 방화벽에 포트를 열어야하므로 secondary socket connection이 발생하며, 프록시 객체를 이용해 remove() 메소드 호출을 대행하고 Java finalization에 의존한다는 고질적인 문제점이 존재한다. (다음에 추가적으로 더 알아보자..)
  • 접속을 해제하는 작업은 finalize에 의존하는데 이는 GC를 돌려 객체를 회수해야하므로 종료화가 GC에 미치는 영향을 고려하지 않을 수 없다.
  • RMI를 사용하는 애플리케이션은 기본 1시간에 한번씩 full GC가 발생하는데, JMX를 사용하는 순간부터 추가적인 부하는 피할수 없을 것이다.

+ Recent posts