프로파일러는 다양한 난관에 봉착했을 때 앱이 이상하게 작동되는 근본 원인을 밝혀내는 강력한 도구다.
프로파일러는 실행 중인 JVM 프로세스를 가로채서 다음과 같이 유용한 세부 정보를 제공한다.
- CPU와 메모리 같은 리소스가 앱에서 어떻게 소비되는가?
- 실행 중인 스레드와 그 현재 상태는 어떤가?
- 실행 중인 코드 및 특정 조각에서 사용하는 리소스(예: 메서드별 실행 시간)는 무엇인가?
1. 프로파일러는 어떤 경우에 유용할까?
프로파일링 도구가 도움이 되는 상황을 세 가지 정도 꼽아보면 이렇다.
- 비정상적인 리소스 사용량 식별
- 코드의 어느 부분이 실행되는지 찾기
- 앱 실행 속도가 저하되는 문제 파악
1.1 비정상적인 리소스 사용량 식별
프로파일러는 대개 앱이 CPU와 메모리를 어떻게 소비하는지 파악하는 용도로 쓰인다.
앱이 리소스를 어떤 패턴으로 소비하는지 살펴보면 다음 두 가지 범주의 문제점이 발견된다.
- 스레드 관련 문제: 동기화가 결여되어 있거나 제대로 되지 않을 때 발생하는 동시성 문제
- 메모리 누수: 불필요한 데이터를 메모리에서 비우지 못하여 앱 실행 속도가 느려지고 결국 완전히 앱이 멈추게 되는 문제
1.2 실행되는 코드 찾기
프로파일러가 있으면 코드를 직접 들여다보지 않아도 어느 코드가 백그라운드에서 실행 중인지 쉽게 찾을 수 있다.
이런 기능을 샘플링이라고 한다.
코드가 너무 복잡해서 무엇이 호출되는지 파악하기 어려울 때 매우 유용한 기능이다.
1.3 앱 실행 속도가 느려지는 원인을 파악
프로파일러는 실행 중인 코드를 가로채서 각 코드가 소비하는 리소스를 계산하는 마법을 부린다.
2. 프로파일러 사용 방법
책과 동일하게 VisualVm 설치를 진행했다. 필자는 JDK 17을 사용하고 있다.
https://visualvm.github.io/download.html
VisualVM: Download
First Steps Unzip the downloaded archive. The archive already contains the top-level visualvm directory. Start VisualVM by invoking the binary appropriate for your OS:visualvm\bin\visualvm.exe or visualvm/bin/visualvm You may provide additional options to
visualvm.github.io
간단하게 스프링 부트로 웹서버를 띄우고 VisualVm을 사용해보겠다.
접속하면 왼쪽에 메인 프로세스가 표시되는데, 우리가 프로세스를 명명하지 않아 메인 클래스명으로 표시된다.
또한 다양한 세부정보를 명시한 탭들을 볼 수 있다.
Monitor 탭으로 들어가면 다음과 같은 화면을 확인할 수 있다.
본격적으로 실습을 진행해보겠다.
CPU와 메모리 사용량 관찰
실행 중인 앱을 프로파일러로 들여다보면 비정상적인 앱 동작을 쉽게 발견할 수 있다.
좀비스레드 등을 바로 확인할 수 있다는 뜻이다.
아래는 예제 코드다.
간단히 설명하면 두 스레드는 자바 리스트에 계속 값을 추가하고, 다른 두 스레드는 이 리스트에서 계속 값을 추가한다.
먼저 프로듀서 스레드다.
public class Producer extends Thread {
private Logger log = Logger.getLogger(Producer.class.getName());
@Override
public void run() {
Random r = new Random();
while(true) {
if(App.list.size() < 100) {
int x = r.nextInt();
App.list.add(x);
log.info("Producer " + Thread.currentThread().getName() + " added value " + x);
}
}
}
}
다음은 컨슈머 스레드다.
public class Consumer extends Thread {
private Logger log = Logger.getLogger(Consumer.class.getName());
@Override
public void run() {
while(true) {
if(App.list.size() > 0) {
int x = App.list.get(0);
App.list.remove(0);
log.info("Consumer " + Thread.currentThread().getName() + " removed value " + x);
}
}
}
}
프로듀서 및 컨슈머 스레드를 만들어 시작하는 App 클래스다.
public class App {
public static List<Integer> list = new ArrayList<>();
public static void main(String[] args) {
new Producer().start();
new Producer().start();
new Consumer().start();
new Consumer().start();
}
}
이 앱은 잘못되어있다.
다수의 스레드가 리스트에 달려들어 변경하지만 ArrayList 타입은 동시성 컬렉션 구현체가 아니기 때문에 스레드의 액세스 자체는 관리하지 않는다.
따라서 여러 스레드가 이 컬렉션에 액세스하면 경쟁 상태에 빠질 공산이 크다.
경쟁 상태는 이렇게 여러 스레드가 동일한 리소스에 서로 다투어 액세스하려고 할 때 발생한다.
이 앱은 스레드 동기화 기능이 아예 빠졌다.
그래서 어떤 스레드는 경쟁 상태에 빠져 예외가 발생하며 잠깐씩 중단되는 동안 다른 스레드는 영원히 살아남아 아무 일도 하지 않는다.
VisuamVm으로 문제를 식별한 뒤, 스레드 동기화 기능이 추가된 앱을 살펴보자.
위 예제를 실행하면 앱은 멈춘 것 같지만 백그라운드에서 흥미로운 단서가 보인다.
- 프로세스의 CPU 사용량을 확인한다.
- 프로세스의 메모리 사용량을 확인한다.
- 실행 중인 스레드를 시각화하여 조사한다.
CPU 위젯이 시스템 처리 파워의 약 37%를 프로세스가 사용하고 있었다.
GC가 전체 CPU 사용량에서 차지하는 비중이 없다는 부분은 매우 흥미롭다.
이는 일반적으로 동시성 문제로 발생하는 좀비 스레드를 나타내는 이상 징후에 해당한다.
컨슈머/프로세스 스레드가 제대로 일을 하지 못하고 있지만 계속 실행 상태로 남아 시스템 리소스를 소모하는 듯하다.
여러 스레드가 비동시성 컬렉션에 액세스하여 변경을 시도하다 보니 경쟁 상태가 발생했기 때문이다.
이미 우리는 이 앱이 잘못됐다는 사실을 알고 있지만, 실무에서도 이런식으로 어떤 문제로 인한 증상을 관찰하면 해결의 실마리를 얻을 수 있다.
GC의 CPU 사용량은 앱의 메모리 할당에 문제가 있음을 암시하는 중요한 정보다.
GC가 CPU 할당량을 많이 차지하고 있다면 메모리 누수가 발생한 징후일지도 모른다.
이 예제는 GC가 CPU 리소스를 전혀 사용하지 않는다.
앱이 많은 처리 능력을 소비하면서도 실제로 아무것도 처리하지 않고 있다는 뜻이므로 이 역시 반가운 신호는 아니다.
이러한 현상은 일반적으로 좀비 스레드를 나타내는 징후로서 동시성 문제가 생긴 결과다.
추가적으로 이 앱은 메모리를 거의 사용하지 않고 있다.
이것은 '앱이 아무 일도 하지 않는다'는 것을 의미하므로 좋은 신호는 아니다.
이렇게 두 위젯만 보아도 동시성이 문제의 근원일 가능성이 높다고 결론 내릴 수 있다.
다음은 Threads 탭 화면이다.
예재 앱은 모두 4개의 스레드를 시작했고 현재 모두 실행중이다.
앱이 아무것도 안하는 것 같지만 앱이 생성한 스레드 4개는 계속 실행 중이다.
이렇게 아무 일도 안하면서 계속 실행상태로 남은 스레드를 좀비 스레드라고 한다.
이들은 그저 CPU 리소스를 축내고 있을 뿐이다.
이제 동기화 블록(synchronized) 블록을 추가해 정상적인 앱을 모니터링해보자.
정상적으로 작동되는 앱은 CPU 리소스를 많이 소비하지 않는다.
또한 앱이 메모리를 사용한다는 것은 실제로 어떤일을 하고 있다는 의미다.
코드를 올바르게 동기화하면 CPU 소비는 줄고 앱은 메모리를 약간 사용하는 형태로 리소스 소비 패턴 자체가 달라진다.
스레드가 더 이상 연속적으로 실행되지 않고 모니터에 의해 차단되거나, 대기하거나, 잠든 것으로 표기된다.
동기화 블록을 벗어난 커맨드 때문에 스레드가 동시 실행될 수는 있다.
두 프로듀서 스레드가 동시에 음영처리된 부분이 바로 그런 부분이다.
메모리 누수 현상 식별
메모리 누수는 앱이 사용하지 않는 객체 레퍼런스가 메모리에 계속 남아 있는 현상을 말한다.
메모리에서 불필요한 데이터를 비우는 GC도 이런 레퍼런스가 남아 있기 때문에 삭제할 수가 없다.
점점 더 많은 데이터가 쌓이면 결국 메모리는 가득 차고, 더 이상 새 데이터를 추가할 공간이 없으면 OOM 에러가 나면서 앱이 중단될 것이다.
아래는 예시 코드다.
public class OOM {
public static void main(String[] args) {
List<Cat> list = new ArrayList<>();
while(true) {
list.add(new Cat(new Random().nextInt(20)));
}
}
static class Cat {
private int age;
public Cat(int age) {
this.age = age;
}
public int getAge() {
return age;
}
public void setAge(int age) {
this.age = age;
}
}
}
OOM 스택 트레이스를 살펴보면 반드시 문제를 일으킨 코드를 가리키는 것이 아닐 수 있다.
앱에 할당된 힙 메모리 공간은 하나뿐이므로 어떤 스레드라도 문제를 일으킬 수 있다.
실제로 메모리 공간을 마지막으로 차지하려고 시도하다가 에러를 낸, 운이 나쁜 스레드일 수 있다.
메모리 누수가 없는 정상적인 앱은 그래프에 피크와 밸리가 분명하다.
앱에 필요한 메모리가 할당되고 GC가 불필요한 데이터를 삭제하는 일이 반복되는 것이다.
하지만 메모리가 점점 채워지는데도 GC가 메모리를 청소하지 않는 모습이면 메모리 누수일 가능성이 있다.
메모리 누수가 의심될 경우, 힙 덤프를 보면서 추가 조사를 시작해야 한다.
힙 공간 외에도 모든 자바 앱은 메타스페이스를 사용한다.
참고로 메타스페이스는 클래스 메타 데이터(리플렉션)를 저장하는 공간이다.
이 공간에서도 OOM이 발생할 수 있다.
예시로는 자바 리플렉션을 사용한 프레임워크의 잘못된 사용이다.
하이버네이트는 인스턴스의 콘텍스트를 관리하고 콘텍스트의 변경 사항을 DB에 매핑하는 역할을 한다.
큰 콘텍스트에 사용하기는 적합하지 않다. 즉 DB에서 한 번에 너무 많은 레코드를 작업하면 안된다.
너무 많은 레코드를 가져오면 메타스페이스가 꽉 찰 수 있어 메타스페이스에서도 OOM이 발생할 수 있다.
참고 자료
댓글