힙·고루틴·잠금: CPU 밖의 프로파일

목표

같은 pricing 에서 heap·goroutine·mutex·block 프로파일을 받아, 각 프로파일이 서로 다른 결함을 가리키는 것을 확인합니다. CPU 프로파일만 보는 습관이 무엇을 놓치는지 손으로 겪습니다.

왜 중요한가

「느리다」의 원인이 늘 CPU 는 아닙니다. 메모리를 붙잡아 GC 가 잦아질 수 있고, 고루틴이 쌓여 결국 OOM 으로 죽을 수 있고, 잠금을 기다리느라 CPU 는 놀고 있는데 응답은 느릴 수 있습니다. CPU 프로파일은 이 셋을 보여 주지 않습니다. 잠금을 기다리는 동안은 CPU 를 쓰지 않기 때문입니다(off-CPU).

Go 는 이 프로파일들을 표준 라이브러리로 내주지만 성격이 다릅니다. heap 은 「지금 붙잡고 있는 것(inuse)」과 「지금까지 할당한 것(alloc)」을 함께 담고, goroutine 은 지금 이 순간의 스냅숏이며, mutex·block 은 기본으로 꺼져 있어서 켜지 않으면 빈 파일이 나옵니다. 어느 프로파일이 무엇을 언제부터 모으는지 알아야 빈 결과를 「문제가 없다」로 잘못 읽지 않습니다.

단계

1. pricing 을 새로 띄우고 -c 4 -d 12s 부하가 끝난 뒤 heap 프로파일을 /root/prof/profiles/m4-heap.pb.gz 에 저장하세요.
2. inuse_space 와 alloc_space 각각의 flat 1위 함수를 /root/prof/answers/heap.json 에 적으세요.
3. 큰 주문을 늘린 부하(-big 0.3 -d 10s) 뒤 goroutine 프로파일을 /root/prof/profiles/m4-goroutine-1.pb.gz 에 받고, 고루틴이 가장 많이 멈춘 main 함수와 그 수를 /root/prof/answers/goroutine.json 에 적으세요.
4. 같은 부하를 한 번 더 준 뒤 /root/prof/profiles/m4-goroutine-2.pb.gz 를 받고 두 수를 /root/prof/answers/goroutine-growth.json 에 적으세요.
5. 지금 설정 그대로 mutex 프로파일을 /root/prof/profiles/m4-mutex-off.pb.gz 에 받고 표본 수를 /root/prof/answers/mutex-off.txt 에 적으세요.
6. PPROF_MUTEX_FRACTION=5 PPROF_BLOCK_RATE=100000 으로 pricing 을 다시 띄우고 -c 16 -coupon 0 -d 10s 부하 뒤 /root/prof/profiles/m4-mutex.pb.gz·/root/prof/profiles/m4-block.pb.gz 를 받으세요.
7. 프로파일마다 가장 큰 비중의 main 함수(잎에 가장 가까운 것)를 /root/prof/answers/m4-summary.json 에 적으세요.

참고

• 작업 자리는 /root/prof 입니다. prof-workspace 가 소스(src)를 복사하고 두 프로그램(bin/pricing·bin/loadgen)을 빌드합니다. 여러 번 불러도 이미 있는 것은 덮지 않습니다.
• 서비스는 prof-svc up pricing·prof-svc up api 로 띄우고 prof-svc status 로 봅니다. up 은 떠 있던 것을 내리고 다시 띄우므로, 앞에 적은 환경 변수가 그때 반영됩니다.
• 부하는 loadgen 입니다. -c(동시성)·-d(시간)·-coupon(쿠폰 비율)·-big(큰 주문 비율)·-seed 를 받고, -out 파일에 조건과 결과를 함께 적습니다.
• 이 파드는 네트워크가 막혀 있습니다. 필요한 것은 전부 이미지에 들어 있습니다.
• 프로파일 주소는 http://127.0.0.1:6060/debug/pprof/<종류> 입니다(heap·goroutine·mutex·block·allocs).
• go tool pprof -top -sample_index=inuse_space <파일> 처럼 heap 은 보고 싶은 값을 고릅니다. 기본은 inuse_space 입니다.
• 6단계에서 쿠폰을 끄는(-coupon 0) 이유: 쿠폰 주문의 CPU 가 두 코어를 다 쓰면 잠금 경합이 그 뒤에 가려집니다. 보고 싶은 것만 남기는 것도 측정 설계입니다.
• 「main 함수」는 main.quote·main.quote.func1(모든 요청이 지나는 입구)을 뺀 main 패키지 함수입니다.

부하 뒤의 힙

prof-svc up pricing 으로 새로 띄우고 loadgen -c 4 -d 12s -out /root/prof/runs/m4-load.json 이 끝난 뒤 /debug/pprof/heap 을 /root/prof/profiles/m4-heap.pb.gz 에 저장하세요.

heap 프로파일은 받는 순간의 상태입니다. 새로 띄운 서비스는 아직 아무것도 붙잡지 않았으니, 부하를 준 뒤에 받아야 붙잡힌 메모리가 보입니다.

붙잡은 것과 할당한 것

같은 heap 파일에서 -sample_index=inuse_space 와 -sample_index=alloc_space 의 flat 1위 함수를 각각 inuse_top·alloc_top 으로 /root/prof/answers/heap.json 에 적으세요.

inuse 는 GC 뒤에도 살아 있는 것, alloc 은 프로세스가 뜬 뒤 할당한 모든 것입니다. 많이 할당하고 곧 버리는 함수와 조금씩 영원히 붙잡는 함수는 서로 다른 칸에서 1위가 됩니다.

멈춰 있는 고루틴

loadgen -big 0.3 -d 10s -out /root/prof/runs/m4-big1.json 뒤 /debug/pprof/goroutine 을 /root/prof/profiles/m4-goroutine-1.pb.gz 에 저장하고, 고루틴이 가장 많이 멈춰 있는 main 함수와 그 수를 leak_function·count 로 /root/prof/answers/goroutine.json 에 적으세요.

goroutine 프로파일의 값은 시간이 아니라 「그 스택에 지금 있는 고루틴 수」입니다. 잎은 대개 runtime.gopark 이니, 그 아래에서 main 패키지 함수를 찾으세요(-top -cum).

누수의 증거는 두 장이다

같은 부하를 한 번 더(-out /root/prof/runs/m4-big2.json) 준 뒤 /root/prof/profiles/m4-goroutine-2.pb.gz 를 받고, 같은 함수의 고루틴 수를 before·after 로 /root/prof/answers/goroutine-growth.json 에 적으세요.

고루틴이 많다는 것만으로는 누수가 아닙니다. 일이 끝났는데도 줄지 않고 부하에 비례해 쌓여야 누수입니다. 스냅숏 두 장을 견줍니다.

켜지 않은 프로파일은 비어 있다

지금 떠 있는 pricing(기본 설정)에서 /debug/pprof/mutex 를 /root/prof/profiles/m4-mutex-off.pb.gz 에 받고, 표본 수(contentions 합)를 /root/prof/answers/mutex-off.txt 에 숫자로 적으세요.

Go 는 잠금 경합을 기본으로 모으지 않습니다. runtime.SetMutexProfileFraction 으로 켜야 합니다. 빈 프로파일은 「경합이 없다」가 아니라 「보고 있지 않다」입니다.

잠금을 기다린 시간

PPROF_MUTEX_FRACTION=5 PPROF_BLOCK_RATE=100000 prof-svc up pricing 으로 다시 띄우고 loadgen -c 16 -coupon 0 -d 10s -out /root/prof/runs/m4-locks.json 뒤 /root/prof/profiles/m4-mutex.pb.gz 와 /root/prof/profiles/m4-block.pb.gz 를 받으세요.

mutex 프로파일은 잠금을 놓는 쪽(Unlock)에서 「다른 고루틴을 얼마나 기다리게 했나」를, block 프로파일은 기다린 쪽에서 「얼마나 막혔나」를 적습니다. 같은 경합을 두 방향에서 봅니다.

프로파일마다 다른 범인

heap(inuse_space)·goroutine(두 번째 스냅숏)·mutex·block 프로파일 각각에서 가장 큰 비중을 가진, 잎에 가장 가까운 main 함수를 inuse·goroutine·mutex·block 키로 /root/prof/answers/m4-summary.json 에 적으세요.

표본마다 잎에서 뿌리 쪽으로 올라가며 처음 만나는 main 함수(main.quote 계열 제외)에 값을 더합니다. 3단계에서 쓴 방법을 네 파일에 그대로 적용하면 됩니다.