←Quay lại Blog
✦

pprof trong Go — tìm thủ phạm ngốn CPU và RAM

•Phong Hy
engineeringgo

Chuyện thật trước đã

Service Go của em — một API gateway nhỏ, tầm 1.2k req/s — tự dưng latency p99 nhảy từ 40ms lên 300ms. CPU 8 core chạm trần, mà DB thì idle, Redis cũng nhàn. Cả team nghi "chắc tại DB connection". Sai bét. Thủ phạm nằm trong code Go, và cách lôi nó ra nhanh nhất là pprof.

Nếu anh chưa từng xài pprof, đây là công cụ built-in của Go, không cần cài gì thêm. Nó lấy mẫu CPU, heap, goroutine, block, mutex — đủ để biết service đang chết vì cái gì.

Bật pprof trong 10 dòng

import (
	"log"
	"net/http"
	_ "net/http/pprof" // tự đăng ký handler vào DefaultServeMux
)

func main() {
	go func() {
		// Bind localhost hoặc cổng nội bộ. TUYỆT ĐỐI đừng hở ra internet.
		log.Println(http.ListenAndServe("127.0.0.1:6060", nil))
	}()
	// ... app chính
}

Bẫy đầu tiên: nếu app xài router riêng (chi, gin, echo) thì DefaultServeMux không được dùng, import trên chả có tác dụng gì. Phải mount tay:

mux := http.NewServeMux()
mux.HandleFunc("/debug/pprof/", pprof.Index)
mux.HandleFunc("/debug/pprof/profile", pprof.Profile)
mux.HandleFunc("/debug/pprof/heap", pprof.Handler("heap").ServeHTTP)
mux.HandleFunc("/debug/pprof/trace", pprof.Trace)

Lấy profile và đọc đúng chỗ

# CPU: lấy mẫu 30 giây
go tool pprof -http=:8081 http://127.0.0.1:6060/debug/pprof/profile?seconds=30

# Heap
go tool pprof -http=:8081 http://127.0.0.1:6060/debug/pprof/heap

# Goroutine đang block ở đâu
go tool pprof -http=:8081 http://127.0.0.1:6060/debug/pprof/goroutine

Mở lên thì xem tab top trước, rồi tới flame graph. Đừng nhảy thẳng vào flame graph — nó đẹp nhưng dễ bị lạc.

Đọc heap cho đúng là chỗ nhiều anh em hiểu sai:

  • -inuse_space: bộ nhớ đang giữ thật → tăng đều mãi không xuống = leak thật.
  • -alloc_space: tổng đã cấp phát trong lúc lấy mẫu (mặc định) → cao mà inuse thấp nghĩa là GC churn, không phải leak. Fix bằng cách giảm allocation, không phải đi tìm leak.

Thêm cờ -diff_base để so trước/sau khi sửa:

go tool pprof -diff_base before.pb.gz after.pb.gz

Bug của em: defer trong vòng lặp

Flame graph chỉ thẳng vào một hàm build cache key. Trong đó có đoạn:

// TRƯỚC
for _, id := range ids {
	resp, _ := client.Get(url + "/" + id)
	defer resp.Body.Close() // 5.000 vòng lặp = 5.000 body chưa đóng
	key := fmt.Sprintf("k:%s:%d", id, time.Now().UnixNano())
	_ = cache.Set(ctx, key, resp.Body)
}

Ba lỗi chồng nhau:

  1. defer trong loop → body không đóng tới khi hàm return, connection pool cạn, goroutine kẹt.
  2. fmt.Sprintf cho mọi key → cấp phát string mới mỗi lần, GC churn.
  3. time.Now().UnixNano() trong key → cache hit rate gần bằng 0, nên mỗi request đều đâm xuống downstream.

Sau khi sửa:

// SAU
var buf []byte
for _, id := range ids {
	func() {
		resp, err := client.Get(url + "/" + id)
		if err != nil {
			return
		}
		defer resp.Body.Close() // đóng ngay sau mỗi vòng
		_, _ = io.Copy(io.Discard, resp.Body)
	}()

	key := append(buf[:0], "k:"...)
	key = append(key, id...)
	_ = cache.Set(ctx, string(key), nil)
}

p99 về lại 45ms. Một dòng defer đặt sai chỗ.

Mấy cái bẫy vặt nhưng tốn thời gian

  • Đừng tin mặc định là heap. URL /debug/pprof/heap trả inuse_space; muốn xem tổng cấp phát phải thêm ?alloc_space=1.
  • Escape analysis miễn phí: go build -gcflags="-m" ./... in ra biến nào bị đẩy lên heap. Nhiều khi khỏi cần pprof.
  • Goroutine profile là vàng khi service treo mà CPU thấp. Nó chỉ luôn chỗ đang block: channel, mutex, hay network.
  • Đừng để pprof hở internet. Đây là lỗ hổng scan phổ biến — có endpoint là có người gọi, kèm luôn khả năng DoS vì CPU profile ăn tài nguyên.
  • Profile production được, overhead khoảng vài phần trăm, nhưng lấy 30s là đủ. Đừng để chạy 10 phút giữa giờ cao điểm.

Kết

pprof không phải đồ chơi của mấy ông performance engineer. Nó là công cụ debug bình thường, và khi service đã chạy production thì flame graph là thứ duy nhất không đoán mò. Bật nó lên ở cổng nội bộ ngay từ đầu — lúc cần thì không kịp thêm đâu.

←Xem các bài viết khác
✦