Go를 pprof로 프로파일링하기: CPU, 메모리, goroutine 병목 찾기
1. 개요
Go 서비스가 느리게 실행되거나 RAM을 많이 사용할 때, 추측만으로는 시간이 많이 걸리고 종종 잘못된 결론에 도달합니다. Go는 표준 라이브러리에 pprof 도구를 기본 제공합니다. 이 도구는 어느 함수가 CPU를 사용하는지, 어디서 메모리가 할당되는지, 어느 goroutine이 블로킹되어 있는지 정확하게 알려줍니다.
이 글을 읽고 나면, HTTP 서비스에서 pprof를 활성화하는 방법, 벤치마크와 CLI 프로그램에서 프로필을 수집하는 방법, go tool pprof로 결과를 읽는 방법, 그리고 두 프로필을 비교하여 최적화를 검증하는 방법을 알게 될 것입니다.
2. pprof란 무엇이고 어떤 종류의 프로필이 있는가
pprof는 두 부분으로 이루어져 있습니다:
- 수집 측면: 표준 라이브러리의
runtime/pprof와net/http/pprof패키지입니다. 이들은 protobuf 형식으로 프로필을 기록합니다. - 분석 측면:
go tool pprof명령입니다. 이 명령은 프로필 파일이나 URL을 읽고 테이블, 소스 코드 또는 웹 인터페이스 형태로 결과를 표시합니다.
자주 사용되는 프로필 종류:
| Profile | 측정 대상 | 기본 활성화? |
|---|---|---|
profile (CPU) |
함수별 CPU 시간, 초당 100번 샘플링 | 요청할 때만 |
heap |
현재 살아있는 메모리와 할당된 총 메모리 | 예 |
allocs |
heap과 같지만 기본적으로 총 할당량을 봅니다 |
예 |
goroutine |
현재 모든 goroutine의 스택 트레이스 | 예 |
block |
channel, select, sync.Cond에서의 대기 시간 |
아니오 |
mutex |
sync.Mutex/RWMutex에서의 경쟁 |
아니오 |
trace |
상세 이벤트 추적 (go tool trace 사용) |
요청할 때만 |
3. HTTP 서비스에서 pprof 활성화하기
가장 빠른 방법은 side effect를 얻기 위해 net/http/pprof를 import하는 것입니다. 이 패키지는 /debug/pprof/* 핸들러를 http.DefaultServeMux에 등록합니다.
package main
import (
"log"
"net/http"
_ "net/http/pprof" // DefaultServeMux에 /debug/pprof/* 등록
)
func main() {
// 별도의 pprof 서버, localhost에서만 수신
go func() {
log.Println(http.ListenAndServe("localhost:6060", nil))
}()
// 애플리케이션 서버는 별도의 mux를 사용하여 pprof 미노출
appMux := http.NewServeMux()
appMux.HandleFunc("GET /invoice", invoiceHandler)
log.Fatal(http.ListenAndServe(":8080", appMux))
}
주목할 점:
_ "net/http/pprof"줄은 핸들러만 등록하며, 이 패키지의 어떤 함수도 호출하지 않습니다.- pprof 서버는
nil을 핸들러로 전달하여DefaultServeMux를 사용하며, 여기에 pprof 라우트가 포함됩니다. - 메인 애플리케이션은 별도의
appMux를 사용하므로 포트8080에는/debug/pprof가 없습니다.
빠른 확인:
curl -s http://localhost:6060/debug/pprof/ | head -n 20
주의:
/debug/pprof를 절대 인터넷에 노출하지 마세요. 이 엔드포인트는 스택 트레이스와 코드 구조를 노출합니다. 악의적인 사용자가 이를 이용하여 서비스를 과부하시킬 수 있습니다 (30초 CPU 프로필링도 리소스를 소비합니다).localhost에 바인드하거나, 내부 네트워크 뒤에 두고 인증 계층을 추가하세요.
4. CPU 프로필 수집 및 읽기
서비스에 다음과 같은 인보이스 생성 함수가 있다고 가정합시다:
type Item struct {
SKU string
Price float64
Qty int
}
type Order struct {
ID int
Items []Item
}
func BuildInvoice(o Order) string {
s := ""
for _, it := range o.Items {
s += fmt.Sprintf("%s x%d = %.2f\n", it.SKU, it.Qty, it.Price*float64(it.Qty))
}
return s
}
각 반복에서 s += ...는 새 문자열을 만들고 기존 내용을 전부 복사합니다. 많은 항목을 가진 주문의 경우, 비용이 O(n²)로 증가합니다.
서비스가 부하를 받고 있는 동안 (예: hey 또는 wrk로 /invoice에 요청을 보내는 중), 30초 동안 CPU 프로필을 수집합니다:
go tool pprof "http://localhost:6060/debug/pprof/profile?seconds=30"
수집이 완료되면 대화형 모드로 들어갑니다. top을 입력하세요:
(pprof) top 8
Showing nodes accounting for 2.41s, 85.46% of 2.82s total
flat flat% sum% cum cum%
0.92s 32.62% 32.62% 0.92s 32.62% runtime.memmove
0.41s 14.54% 47.16% 1.38s 48.94% runtime.concatstrings
0.33s 11.70% 58.87% 0.33s 11.70% runtime.memclrNoHeapPointers
0.27s 9.57% 68.44% 0.71s 25.18% runtime.mallocgc
0.18s 6.38% 74.82% 0.52s 18.44% fmt.(*pp).doPrintf
0.13s 4.61% 79.43% 0.13s 4.61% strconv.fmtF
0.10s 3.55% 82.98% 2.47s 87.59% main.BuildInvoice
0.07s 2.48% 85.46% 0.21s 7.45% runtime.scanobject
가장 중요한 두 열 읽는 방법:
- flat: 함수 내에서 직접 소비되는 CPU 시간입니다.
- cum (누적): 함수 자체의 시간 더하기 호출하는 모든 함수의 시간입니다.
여기서 main.BuildInvoice는 flat은 작지만 cum이 거의 88%입니다. 대부분의 시간이 memmove와 concatstrings에서 소비되는데, 이는 문자열 연결 작업입니다. 각 줄의 세부 정보를 보려면 list를 사용하세요:
(pprof) list BuildInvoice
ROUTINE ======================== main.BuildInvoice in /app/invoice.go
100ms 2.47s (flat, cum) 87.59% of Total
. . 18:func BuildInvoice(o Order) string {
. . 19: s := ""
10ms 10ms 20: for _, it := range o.Items {
90ms 2.46s 21: s += fmt.Sprintf("%s x%d = %.2f\n", ...)
. . 22: }
21번 줄이 범인입니다. Flame graph를 보려면 웹 인터페이스를 열 수 있습니다:
go tool pprof -http=:8081 "http://localhost:6060/debug/pprof/profile?seconds=30"
브라우저에서 Top, Graph, Flame Graph 및 Source 뷰가 열립니다. Flame graph에서 블록이 넓을수록 더 많은 CPU를 소비합니다.
strings.Builder와 fmt.Fprintf를 사용한 수정 버전:
func BuildInvoiceFast(o Order) string {
var b strings.Builder
b.Grow(len(o.Items) * 32) // 미리 예상, 여러 번 grow 피하기
for _, it := range o.Items {
fmt.Fprintf(&b, "%s x%d = %.2f\n", it.SKU, it.Qty, it.Price*float64(it.Qty))
}
return b.String()
}
5. Heap 프로필: 누가 메모리를 보유하고 있는가?
go tool pprof http://localhost:6060/debug/pprof/heap
Heap 프로필은 네 가지 “샘플 인덱스”를 포함합니다. -sample_index 플래그로 인덱스를 선택합니다:
inuse_space(기본값): 마지막 GC 시점에 활성 바이트 수입니다. 메모리 누수를 찾는 데 사용합니다.inuse_objects: 현재 활성 객체 수입니다.alloc_space: 프로그램 시작 이후 할당된 총 바이트 수입니다. GC 압력을 유발하는 부분을 찾는 데 사용합니다.alloc_objects: 할당된 총 객체 수입니다.
go tool pprof -sample_index=alloc_space http://localhost:6060/debug/pprof/heap
(pprof) top 3
flat flat% sum% cum cum%
1.84GB 91.20% 91.20% 1.84GB 91.20% main.BuildInvoice
0.12GB 5.95% 97.15% 0.12GB 5.95% fmt.Sprintf
0.03GB 1.49% 98.64% 0.03GB 1.49% encoding/json.Marshal
결과는 BuildInvoice가 총 1.84GB를 할당했음을 보여줍니다. 비록 현재 살아있는 양은 적을 수 있지만, 이는 GC가 많은 작업을 해야 함을 의미합니다. 이 상황은 섹션 4의 CPU 프로필에서 본 runtime.mallocgc와 runtime.scanobject의 양과 일치합니다.
주의: Heap 프로필도 샘플링된 데이터입니다 (기본적으로 할당된 512KB마다 약 1개 샘플). 따라서 숫자는 추정치일 뿐입니다. 바이트 단위로 비교하지 말고 비율을 보세요.
6. Goroutine 프로필: goroutine 누수 감지
Goroutine 수가 계속 증가하면, go tool pprof를 사용하지 않고도 브라우저나 curl로 빠르게 확인할 수 있습니다:
curl -s "http://localhost:6060/debug/pprof/goroutine?debug=1" | head -n 15
goroutine profile: total 10432
10398 @ 0x43a5d6 0x4071c5 0x406d78 0x6b2f45 0x46c0e1
# 0x6b2f44 main.(*PaymentService).notify+0x64 /app/payment.go:57
10,398개의 goroutine이 모두 payment.go:57에서 블로킹되어 있습니다. 이는 거의 확실히 누수입니다. 누수를 유발하는 코드는 일반적으로 다음과 같은 형태입니다:
func (s *PaymentService) notify(ctx context.Context, p Payment) {
result := make(chan error) // unbuffered
go func() {
result <- s.gateway.Send(p) // 아무도 받지 않으면 영원히 블로킹
}()
select {
case err := <-result:
log.Println(err)
case <-ctx.Done():
return // 내부 goroutine이 버려짐
}
}
ctx가 먼저 만료되면, result를 읽을 수 없으므로 내부 goroutine이 송신 명령에서 영구적으로 블로킹됩니다. 간단한 수정은 make(chan error, 1)을 사용하여 송신이 절대 블로킹되지 않도록 하는 것입니다.
debug=2를 사용하면, 엔드포인트는 각 goroutine의 전체 스택 트레이스를 대기 시간과 함께 출력합니다 (예: [chan send, 42 minutes]). 이 정보는 deadlock을 조사할 때 매우 유용합니다.
7. Block 및 mutex 프로필
이 두 프로필은 비용이 들기 때문에 기본적으로 비활성화되어 있습니다. main에서 이들을 활성화할 수 있습니다:
import "runtime"
func init() {
// 5 중에 평균 1개의 mutex contention 이벤트 기록
runtime.SetMutexProfileFraction(5)
// 블로킹된 10µs마다 1개의 block 이벤트 샘플링
runtime.SetBlockProfileRate(10_000)
}
그 후 평소대로 프로필을 수집합니다:
go tool pprof http://localhost:6060/debug/pprof/mutex
go tool pprof http://localhost:6060/debug/pprof/block
Mutex 프로필은 어떤 lock으로 인해 goroutine들이 대기열을 형성하는지 보여줍니다. 예를 들어, 공유 cache map[int]Customer를 보호하는 sync.Mutex가 있습니다. Block 프로필은 어떤 channel이나 select에서 goroutine이 오래 대기하는지 보여줍니다.
주의:
SetBlockProfileRate(1)은 모든 block 이벤트를 기록합니다. 이 수준은 로컬 디버깅에만 적합합니다. 프로덕션에서는 더 큰 rate를 사용하거나 일시적으로만 활성화하세요.
8. 벤치마크에서의 프로파일링
특정 함수의 경우, 가장 간단한 방법은 벤치마크를 작성하고 go test가 프로필을 생성하도록 하는 것입니다. 다음 코드는 b.Loop()을 사용하므로 Go 1.24 이상이 필요합니다.
package main
import (
"fmt"
"testing"
)
func sampleOrder(n int) Order {
items := make([]Item, n)
for i := range items {
items[i] = Item{SKU: fmt.Sprintf("SKU-%04d", i), Price: 19.99, Qty: i%5 + 1}
}
return Order{ID: 1, Items: items}
}
func TestBuildInvoiceFastMatchesOriginal(t *testing.T) {
order := sampleOrder(200)
if got, want := BuildInvoiceFast(order), BuildInvoice(order); got != want {
t.Fatalf("출력이 다릅니다:\n got=%q\nwant=%q", got, want)
}
}
func BenchmarkBuildInvoice(b *testing.B) {
order := sampleOrder(500)
b.ReportAllocs()
for b.Loop() {
BuildInvoice(order)
}
}
func BenchmarkBuildInvoiceFast(b *testing.B) {
order := sampleOrder(500)
b.ReportAllocs()
for b.Loop() {
BuildInvoiceFast(order)
}
}
테스트 TestBuildInvoiceFastMatchesOriginal은 최적화된 버전이 원래 버전과 정확히 동일한 결과를 생성하는지 확인합니다. 이 단계를 건너뛰지 마세요: 최적화가 잘못된 결과를 생성하면 의미가 없습니다. 벤치마크를 프로필과 함께 실행하세요:
go test -run='^$' -bench=BuildInvoice -cpuprofile=cpu.out -memprofile=mem.out
BenchmarkBuildInvoice-8 1543 772410 ns/op 6342817 B/op 1002 allocs/op
BenchmarkBuildInvoiceFast-8 19821 60318 ns/op 36472 B/op 504 allocs/op
strings.Builder를 사용한 버전은 약 12배 빠르고 약 170배 적게 할당합니다. 플래그 -run='^$'는 일반 테스트를 건너뛰고 벤치마크만 실행합니다. 파일 cpu.out과 mem.out은 다음으로 열 수 있습니다:
go tool pprof -http=:8081 cpu.out
9. runtime/pprof을 사용한 CLI 프로그램 프로파일링
한 번 실행하고 종료되는 도구의 경우 (예: 주문 import 작업), runtime/pprof을 직접 사용하세요:
package main
import (
"log"
"os"
"runtime"
"runtime/pprof"
)
func main() {
cpuFile, err := os.Create("cpu.out")
if err != nil {
log.Fatal(err)
}
defer cpuFile.Close()
if err := pprof.StartCPUProfile(cpuFile); err != nil {
log.Fatal(err)
}
defer pprof.StopCPUProfile()
importOrders("orders.csv") // 메인 작업
memFile, err := os.Create("mem.out")
if err != nil {
log.Fatal(err)
}
defer memFile.Close()
runtime.GC() // 쓰기 전 inuse 통계 업데이트
if err := pprof.WriteHeapProfile(memFile); err != nil {
log.Fatal(err)
}
}
여기서 흔한 두 가지 실수:
StartCPUProfile후log.Fatal또는os.Exit을 호출하면defer가 무시됩니다. 그러면StopCPUProfile이 실행되지 않고 프로필 파일이 비어 있거나 손상됩니다.WriteHeapProfile전에runtime.GC()를 빠뜨리면,inuse_*통계는 각 GC 후에만 업데이트되므로 프로필이 오래된 상태를 반영할 수 있습니다.
10. 두 프로필 비교
최적화 후에는 느낌에 의존하지 말고 다시 측정해야 합니다. 플래그 -diff_base는 새 프로필에서 이전 프로필을 뺍니다:
go tool pprof -diff_base=cpu_before.out cpu_after.out
(pprof) top 3
flat flat% sum% cum cum%
-0.89s 31.56% 31.56% -0.89s 31.56% runtime.memmove
-0.40s 14.18% 45.74% -1.35s 47.87% runtime.concatstrings
-0.25s 8.87% 54.61% -0.66s 23.40% runtime.mallocgc
음수 값은 시간이 감소했음을 의미합니다. 결과가 의미 있으려면, 두 프로필을 동일한 조건에서 수집해야 합니다: 같은 부하, 같은 기간, 같은 머신.
또한 Go 1.21부터 CPU 프로필은 **Profile-Guided Optimization (PGO)**에도 사용됩니다. 프로덕션에서 대표적인 CPU 프로필을 수집하여 main 패키지 디렉토리에 default.pgo로 이름을 지으면, go build가 해당 프로필을 자동으로 사용하여 인라인과 hot code path 최적화를 수행합니다. 개선 수준은 보통 몇 퍼센트이며, 코드를 수정할 필요가 없습니다.
11. 흔한 실수와 사용하면 안 되는 경우
- 프로필이 너무 짧거나 부하가 없음. CPU 프로필은 100Hz로 샘플링합니다. 서비스가 유휴 상태일 때만 2초 동안 수집하면,
runtime과 노이즈만 볼 수 있습니다. flat을cum과 혼동.cum이 높은 함수가 반드시 범인인 것은 아니며, 단지 범인을 호출할 수도 있습니다.inuse_space을alloc_space과 혼동. 누수를 찾으려면inuse를 봅니다. GC 압력을 줄이려면alloc을 봅니다.- CPU 프로필로 I/O 측정. Goroutine이 데이터베이스나 HTTP를 기다리는 시간은 CPU를 소비하지 않으므로 CPU 프로필에 나타나지 않습니다. Block 프로필,
go tool trace또는 분산 추적을 사용하세요. - 애플리케이션 포트에서 pprof를 공개. 섹션 3을 다시 참조하세요.
주의: pprof는 “어디가 비용이 많이 드는가”에 답하지만, “최적화해야 하는가”에는 답하지 않습니다. 엔드포인트가 이미 SLA를 충족하고 함수가 CPU의 2%만 차지한다면, 더 복잡하게 작성하는 것은 보통 가치가 없습니다.
12. 결론
이 글에서 다룬 내용:
localhost의 별도 서버에서 안전하게net/http/pprof활성화;top과list로 CPU 프로필 읽기 및flat과cum구분;inuse_space와alloc_space를 사용한 heap 프로필;debug=1과debug=2로 goroutine 누수 감지;- block 및 mutex 프로필 활성화;
- 벤치마크 및 CLI 프로그램에서 프로필 생성;
-diff_base로 전후 비교.
가장 효과적인 프로세스는: 측정 → 핫스팟 찾기 → 수정 → 동작을 유지하는 테스트 작성 → 재측정입니다. pprof는 표준 라이브러리에 포함되어 있으므로, 시작하기 위해 추가 설치가 필요하지 않습니다.