TT Lab
블로그 시작하기
배우기 러닝패스 코스

프로파일링: 느린 요청 하나를 함수까지

런타임 안의 기록기: 자바 JFR, 파이썬, 그리고 async-profiler

TT Lab 에서 이어서 보기

한 줄 요약

언어 런타임에는 저마다 안에서 켜는 기록기가 있습니다. 자바는 JFR(JDK Flight Recorder)이 JDK 에 들어 있고, 파이썬은 표준 라이브러리 cProfile 이 있습니다. 런타임 안의 기록기는 권한이 없어도 돌지만 보지 못하는 곳이 있어, 그 빈틈은 async-profiler 나 py-spy 같은 도구가 채웁니다.

왜 이게 필요했나

Go 에서 익힌 읽는 법(잎에서 가장 가까운 내 코드, inuse 와 alloc, 잠금 대기)은 런타임이 바뀌어도 그대로입니다. 바뀌는 것은 「표본을 누가 어떻게 찍느냐」입니다. 그리고 그 방식이 무엇을 볼 수 있는지를 정합니다. 도구의 한계를 모르고 쓰면 빈 결과를 「문제가 없다」로 읽게 됩니다.

어떻게 동작하나

JFR. JVM 안에서 돕니다. -XX:StartFlightRecording 으로 시작부터 켜거나, 떠 있는 JVM 에 jcmd <pid> JFR.start 로 켭니다. jcmd 는 ptrace 가 아니라 JVM 이 스스로 여는 attach 통로(같은 사용자의 소켓 파일과 신호)를 씁니다. 그래서 권한이 없는 컨테이너에서도 됩니다. 녹화 하나에 CPU 표본(jdk.ExecutionSample), 할당 표본(jdk.ObjectAllocationSample), 잠금 대기(jdk.JavaMonitorEnter, profile 설정에서 10ms 넘게 기다린 것), GC, 그리고 그 JVM 의 인자(jdk.JVMInformation)가 함께 담깁니다. JDK 21 의 jfr view hot-methods·allocation-by-site·contention-by-site 가 표를 바로 보여 줍니다.

JFR 의 CPU 표본은 자바 코드를 실행 중인 스레드만 찍습니다. 네이티브 코드, 잠금을 기다리는 시간, 표본을 찍을 수 없는 지점에 있던 순간은 빠집니다. 이 코스의 자바 재료에서도 잠금을 오래 기다리는 구간은 CPU 표본이 아니라 잠금 이벤트로만 보입니다.

async-profiler. JVM 의 비공식 API(AsyncGetCallTrace)와 리눅스 perf_events 를 함께 써서 자바 프레임과 네이티브·커널 프레임을 한 스택에 이어 붙입니다. 표본을 찍을 수 없는 지점에 치우치는 문제(safepoint bias)를 피하는 것이 이 도구가 만들어진 이유입니다. perf_events 를 쓰는 모드는 커널 설정(perf_event_paranoid)과 권한이 필요하고, 권한이 없으면 itimer 모드로 물러나 자바 쪽만 봅니다.

파이썬. cProfile 은 함수 호출마다 재는 계측 방식이라 호출 횟수가 정확한 대신, 작은 함수가 많으면 몇 배 느려지고 그 느려짐이 결과를 왜곡합니다. py-spy 는 표본 방식이고 대상 프로세스에 아무것도 넣지 않은 채 밖에서 메모리를 읽어 파이썬 스택을 다시 짓습니다. 그래서 운영 중인 프로세스에 쓰기 좋지만, 남의 메모리를 읽는 권한(ptrace 계열)이 필요합니다. 이 실습 파드에서 재 보니 py-spy 가 자식으로 띄운 프로그램에는 그 권한이 열렸고, 이미 떠 있는 남의 프로세스에는 막혔습니다.

현장에서 만나는 모습

자바 서비스의 장애 대응 절차에 「jcmd 로 60초 JFR 을 받아 첨부한다」가 들어 있는 팀이 많습니다. 다시 띄우지 않고 받을 수 있고, 녹화 안에 JVM 인자와 GC 기록까지 있어 다른 사람이 같은 장면을 다시 열 수 있기 때문입니다. 파이썬 서비스라면 같은 자리에 py-spy dump 와 record 가 들어갑니다.

흔히 틀리는 읽기

jfr view hot-methods 의 첫 줄을 그대로 범인으로 적는 실수가 흔합니다. 그 줄은 대개 JDK 내부 메서드(정규식 파서, 배열 복사)라서 고칠 수 없습니다. Go 실습과 같은 방식으로 스택을 따라 올라가 처음 만나는 이 프로그램의 메서드를 찾습니다.

녹화를 너무 짧게 받는 것도 흔합니다. JVM 은 처음 몇 초 동안 인터프리터와 JIT 컴파일러로 코드를 데우므로, 그 시간에는 실제 운영과 다른 모양이 찍힙니다. 녹화는 데워진 뒤의 구간을 충분히 덮어야 합니다. 이 실습에서 주문 수를 넉넉히 주는 이유입니다.

할당 표본을 개수로 세는 것도 틀립니다. 작은 객체 수천 개와 큰 배열 한 번이 같은 표본 하나로 보일 수 있으니, weight 로 더해야 실제 할당량이 됩니다.

다음 실습에서 할 것

Go 서비스와 같은 결함을 넣은 자바 정산 배치를 JFR 로 녹화해 CPU·할당·잠금 대기의 1위를 각각 찾고, 떠 있는 JVM 에 jcmd 로 녹화를 켭니다. 원인을 고친 뒤 같은 인자로 다시 녹화해 두 녹화를 견줍니다.

English corner