신호 넷과 질문 넷: 프로파일은 무엇에 답하나
한 줄 요약
트레이스는 「어느 구간이 느렸나」, 메트릭은 「얼마나 자주, 얼마나 심하게」, 로그는 「그때 무슨 일이 있었다고 적혔나」, 프로파일은 「그 시간에 어느 함수가 무엇을 썼나」에 답합니다. 이 코스는 느린 요청 하나를 이 네 신호로 차례로 쫓아가 원인 함수까지 내려간 뒤, 고치고 나서 정말 고쳐졌는지를 숫자로 확인합니다.
왜 이게 필요했나
관측을 처음 붙인 팀이 흔히 겪는 장면이 있습니다. 대시보드의 p99 가 튀어서 트레이스를 열었더니 pricing.quote 구간이 길었습니다. 그런데 그 구간은 함수 수십 개를 부르는 Go 서비스 한 덩어리입니다. 트레이스에 스팬을 더 잘게 넣으면 될 것 같지만, 함수마다 스팬을 달면 비용이 감당되지 않고, 무엇보다 어디에 달아야 할지 모르는 것이 문제의 본질입니다.
프로파일이 이 빈틈을 메웁니다. 코드에 아무것도 미리 넣지 않고, 일정한 간격으로 「지금 어느 함수를 실행 중인가」를 표본으로 적어 모읍니다. 표본이 쌓이면 함수마다 시간이 얼마나 쓰였는지가 통계로 드러납니다. 그래서 트레이스가 가리킨 구간 안으로 한 단계 더 들어갈 수 있습니다.
어떻게 동작하나
프로파일러는 크게 두 방식이 있습니다.
| 방식 | 하는 일 | 장점 | 대가 |
|---|---|---|---|
| 표본(sampling) | 10ms 마다 스택 한 장을 찍는다 | 부담이 작고 늘 켜 둘 수 있다 | 짧은 일은 통계로만 보인다 |
| 계측(instrumentation) | 함수 들어가고 나올 때마다 잰다 | 호출 횟수까지 정확하다 | 작은 함수가 많으면 몇 배 느려진다 |
무엇을 재느냐도 갈립니다. on-CPU 프로파일은 CPU 를 쓰는 동안만 표본을 찍습니다. 잠금이나 네트워크를 기다리는 시간은 보이지 않습니다. 그 시간은 off-CPU 프로파일(Go 의 block·mutex 프로파일, JFR 의 잠금 이벤트)이 따로 봅니다. 메모리는 할당 프로파일과 힙(지금 붙잡고 있는 것) 프로파일로 봅니다.
이 코스의 실습 재료는 둘입니다. 파이썬 앞단 api 는 OpenTelemetry SDK 로 계측되어 스팬과 메트릭을 파일로 남기고, Go 가격 서비스 pricing 은 표준 라이브러리 net/http/pprof 로 자기 프로파일을 HTTP 로 내줍니다. 둘 다 프로그램이 스스로 신호를 내는 방식이라, 권한이 하나도 없는 실습 파드에서 그대로 돕니다. 이미 떠 있는 남의 프로세스에 붙는 도구(py-spy·perf·gdb·eBPF)는 커널 권한이 필요해 마지막 모듈의 VM 에서 다룹니다.
현장에서 만나는 모습
장애 회고에서 「CPU 사용률이 높았다」는 문장은 원인이 아니라 증상입니다. 같은 회고에 「CPU 의 79% 가 요청마다 정규식을 컴파일하는 데 쓰였다」가 적히면 그때부터 고칠 수 있습니다. 두 문장의 차이가 프로파일 한 장입니다. 그리고 고친 뒤에는 같은 조건에서 다시 받은 프로파일 한 장이 「고쳤다」의 증거가 됩니다. 이 코스의 마지막 실습들이 그 증거를 만드는 법입니다.
이 코스의 재료는 그 장면을 작게 줄여 놓은 것입니다. 쿠폰 주문 하나의 처리 시간이 일반 주문의 수십 배인데, 요청 수로는 다섯에 하나뿐이라 평균에는 잘 드러나지 않습니다.
흔히 틀리는 읽기
첫째, 「평균이 괜찮으니 괜찮다」입니다. 요청 100건 중 99건이 5ms 이고 1건이 2초면 평균은 25ms 남짓이라 그래프는 평온해 보입니다. 그 1건을 겪은 사용자에게는 서비스가 멈춘 것입니다. 그래서 이 코스는 평균 대신 가장 느린 요청과 p99 에서 출발합니다.
둘째, 「트레이스의 가장 긴 스팬이 원인이다」입니다. 가장 긴 스팬은 원인이 사는 구간일 뿐입니다. 그 안에서 CPU 를 썼는지, 잠금을 기다렸는지, 다른 서비스를 기다렸는지는 스팬만으로 모릅니다. 자식 스팬이 부모 시간의 대부분을 차지하면 다음 조사는 그 자식 쪽 서비스로 넘어가고, 자식이 없는데 길면 그 서비스 안을 프로파일로 봐야 합니다.
셋째, 「요청 하나에서 본 것이 전부다」입니다. 한 건은 우연일 수 있습니다. 느린 요청들을 묶어 속성(쿠폰 여부, 품목 수, 고객사)을 전체와 견줘야 공통점이라고 말할 수 있습니다. 이 실습의 마지막 단계가 그 비교입니다.
다음 실습에서 할 것
두 서비스를 띄우고 부하를 준 뒤, SDK 가 남긴 스팬 파일에서 가장 느린 요청 하나를 고릅니다. 그 요청의 시간이 어느 자식 구간에서 쓰였는지, 그리고 느린 요청들에 어떤 공통점이 있는지를 찾습니다. 그것이 이 코스가 끝까지 쫓아갈 첫 단서입니다.
English corner
공식 문서와 도구 출력에 그대로 나오는 표현입니다.
- sampling profiler: 표본 프로파일러. "A sampling profiler periodically records the call stack." 처럼 쓰입니다.
- overhead: 측정 때문에 더 드는 비용. "low overhead" 는 「부담이 작다」입니다.
- on-CPU / off-CPU: CPU 를 쓰는 시간과 기다리는 시간. 성능 글에서 짝으로 나옵니다.
- hot path: 가장 자주, 가장 오래 지나는 코드 길. "This function is on the hot path." 라고 씁니다.