排查Go性能问题的思路当Go程序占用CPU过高、内存过大、接口太慢时，一般有三招：靠嗅觉和肉眼、靠打日志、靠pprof工

flowchart LR
r["排查Go<br/>性能问题的思路"]
r --> i["1.靠嗅觉和肉眼"]		
r --> ii["2.靠打日志"]
r --> iii["3.靠pprof工具<br/>"]

当程序占用CPU过高、内存过大、接口太慢时，一般有三招：

靠嗅觉和肉眼，大概率能看出哪里代码有问题
靠打日志，能排查到哪个环节耗时高，但内存和cpu过高不太好搞
靠pprof工具，本文着重演示一些问题代码，是如何被pprof定位到的

第一招：靠嗅觉和肉眼

大部分问题，都能被有经验的baby找到，线上出现问题时，一定要稳如老狗，梳理下思路：

并发请求是否增大?
检查日志，是否有磁盘满了、慢SQL等
最近是否有发版？改了哪些代码？环境是否有变动？
逐渐升高后不释放？协程泄漏？有本地map啥的未释放？
是否是升高后又释放？是否有大文件导出导入、大数据读取、定时长任务？
互斥锁？
循环里面有IO请求？

第二招：靠打日志

适用于某接口太慢，且肉眼看不出问题，在怀疑的地方添加耗时埋点

第三招：靠pprof工具

当不能快速定位问题时，pprof 便可上场了，pprof提供了几种采集工具：

allocs：查看所有内存分配的样本（包含历史）
block：分析 goroutine 阻塞事件（锁、通道、select、wait group 、IO 等），必须先开启采样 runtime.SetBlockProfileRate，支持seconds参数
cmdline：当前程序的命令行的完整调用路径（从程序一开始运行时决定）
goroutine：查看当前所有运行的 goroutines 堆栈跟踪（实时变化）。
heap：查看所有内存分配的样本（不包含历史，与allocs的唯一区别），不支持seconds参数，只能获取当前内存情况
mutex：分析互斥锁的竞争情况，必须先开启两个采样 runtime.SetMutexProfileFraction、runtime.SetBlockProfileRate，支持seconds参数
profile：查看CPU 使用情况，定位计算密集型热点，支持seconds参数
threadcreate：查看创建新 OS 线程的堆栈跟踪（一般没啥用）。
trace：当前程序的执行跟踪

真凶 1：协程泄漏，导致内存持续增涨

伪代码

package main

import (
	"net/http"
	_ "net/http/pprof" // 引入即可，包里的init会注册路由
)

func main() {
	http.HandleFunc("/test", func(w http.ResponseWriter, r *http.Request) {
		c := make(chan string)
		go doSomething(c)
		// 模拟忘记接收c的数据，导致协程未退退出

		w.WriteHeader(http.StatusOK)
		w.Write([]byte(`{"code":"ok"}`))
	})
	http.ListenAndServe(":8080", nil)
}
func doSomething(c chan string) {
	data := ""
	for i := 0; i < 100; i++ {
		data = data + "test"
	}
	c <- data // 由于c被阻塞，导致data内存无法被回收
}

pprof heap下的表现：

访问10次模拟业务地址：127.0.0.1:8000/test
获取内存分配情况127.0.0.1:8000/debug/pprof/heap?debug=1（分析此刻内存的分配情况，它没有seconds采集周期参数）

heap profile: 1: 139264 [1: 139265] @ heap/1048576 
// 1: 139264 表示当前活跃对象:当前活跃对象占用的字节数;
// [1: 139265] 包含历史活跃对象:包含历史活跃对象占用的字节数;
// heap/1048576 表示内存采样的频率：每分配1MB采样、在周期内累记1MB(高频率的小分配)
// 过环境变量 GODEBUG 调整 pprof 的堆采样率

1: 139264 [1: 139264] @ 0x1028414b0 0x1028414e1 0x10284ac28 0x10284abf1 0x1028af4ec 0x1028b3948 0x1028aa914 0x1028aa64c 0x1028a8d38 0x1028bdc24 0x1028be538 0x102886f08 0x102888b04 0x10288fb2c 0x102885d8c 0x1026effc4
// 1: 139264 [1: 139264]分别是：函数栈上当前活跃的对象个数：数栈上当前活跃的对象字节数 [包含历史的对象个数:包含历史的对象字节数]
// 0x 这些表示调用栈的内存地址

#	0x1028414af	compress/flate.newDeflateFast+0x33f		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/compress/flate/deflatefast.go:64
#	0x1028414e0	compress/flate.(*compressor).init+0x370		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/compress/flate/deflate.go:586
#	0x10284ac27	compress/flate.NewWriter+0x287			/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/compress/flate/deflate.go:668
#	0x10284abf0	compress/gzip.(*Writer).Write+0x250		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/compress/gzip/gzip.go:191
#	0x1028af4eb	runtime/pprof.(*profileBuilder).build+0x48b	/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/runtime/pprof/proto.go:390
#	0x1028b3947	runtime/pprof.writeHeapProto+0x457		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/runtime/pprof/protomem.go:66
#	0x1028aa913	runtime/pprof.writeHeapInternal+0x233		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/runtime/pprof/pprof.go:631
#	0x1028aa64b	runtime/pprof.writeHeap+0x2b			/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/runtime/pprof/pprof.go:590
#	0x1028a8d37	runtime/pprof.(*Profile).WriteTo+0x147		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/runtime/pprof/pprof.go:374
#	0x1028bdc23	net/http/pprof.handler.ServeHTTP+0x443		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/net/http/pprof/pprof.go:272
#	0x1028be537	net/http/pprof.Index+0xc7			/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/net/http/pprof/pprof.go:388
#	0x102886f07	net/http.HandlerFunc.ServeHTTP+0x37		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/net/http/server.go:2220
#	0x102888b03	net/http.(*ServeMux).ServeHTTP+0x1b3		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/net/http/server.go:2747
#	0x10288fb2b	net/http.serverHandler.ServeHTTP+0xbb		/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/net/http/server.go:3210
#	0x102885d8b	net/http.(*conn).serve+0x4fb			/Users/gangan/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.6.darwin-arm64/src/net/http/server.go:2092

# runtime.MemStats
# Alloc = 2738240 // 已分堆内存字节数，减去了已释放内存，等同于HeapAlloc
# TotalAlloc = 4249928 // 总的分配堆内存字节数, 未减去了已释放内存
# Sys = 12666120 // 从操作系统申请的内存总数，包括栈、堆
# Lookups = 0 // 运行时执行的指针查找次数（通常为0，除非使用 runtime.SetFinalizer）
# Mallocs = 2584 // 累计分配的对象数
# Frees = 1729 // 累计释放的对象数
# HeapAlloc = 2738240  // 等同于Alloc
# HeapSys = 7847936 // 从系统获取的总内存,只有堆内存
# HeapIdle = 4317184 // 空闲的堆内存
# HeapInuse = 3530752 // 正在使用的堆内存
# HeapReleased = 3358720 // 已释放回操作系统的内存
# HeapObjects = 855 // 当前堆上存活的对象数
# Stack = 491520 / 491520 // 当前使用的栈内存 / 从系统申请的栈内存
# MSpan = 64160 / 65280 // 结构使用的内存 / 从系统申请的内存
# MCache = 14400 / 15600 // 正在使用的 mcache 内存（每个 P 的本地缓存）/ 从系统申请的 mcache 总内存
# BuckHashSys = 1443966 // 存储 profiling 哈希表的系统内存（字节）
# GCSys = 2012192 // GC 元数据占用的内存（如标记位图等）
# OtherSys = 789626 // 未分类的系统内存（如调度器、信号栈、CGO 分配等）
# NextGC = 4194304 // 下次触发 GC 的堆大小阈值（字节）
# LastGC = 1751100745471233000 // 上次 GC 完成时间（Unix 纳秒时间戳）
# PauseNs = [130625 0 0 0 0 0 0 0 0 ...] // 最近 GC 暂停时间的环形缓冲区（纳秒）
# PauseEnd = [1751100745471233000 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]
# NumGC = 1 // 累计 GC 次数
# NumForcedGC = 0 // 由 runtime.GC() 或 debug.FreeOSMemory() 触发的强制 GC 次数
# GCCPUFraction = 4.698349298211649e-06 // GC占用CPU的比例（0.0~1.0），大于0.2 表示 GC 占用过多 CPU
# DebugGC = false // 是否启用调试 GC
# MaxRSS = 12042240 // 物理内存峰值,单位KB

为什么没有咱们模拟的doSomething方法？这是因为没有触发1MB的采样条件，再访问10次127.0.0.1:8000/test 后出现了，统计到了问题函数doSomething，不过奇怪的是活跃对象数是0？

heap profile: 0: 0 [3: 403200] @ heap/1048576
0: 0 [0: 0] @ 0x1026ccc6d 0x1026cc7f4 0x1026cc978 0x1028bf188 0x1026effc4
#	0x1028bf187	main.doSomething+0x57	/Users/gangan/www/lsxd/testgo/test4/main.go:24

0: 0 [0: 0] @ 0x1026ccc6d 0x1026cc7f4 0x1026cc978 0x1028bf188 0x1026effc4
#	0x1028bf187	main.doSomething+0x57	/Users/gangan/www/lsxd/testgo/test4/main.go:24

再刷10次127.0.0.1:8000/test发现活跃对象不为0了…

0: 0 [1: 112] @ 0x1026ccc6d 0x1026cc7f4 0x1026cc978 0x1028bf188 0x1026effc4
#	0x1028bf187	main.doSomething+0x57	/Users/gangan/www/lsxd/testgo/test4/main.go:24

0: 0 [1: 384] @ 0x1026ccc6d 0x1026cc7f4 0x1026cc978 0x1028bf188 0x1026effc4
#	0x1028bf187	main.doSomething+0x57	/Users/gangan/www/lsxd/testgo/test4/main.go:24

此时我们使用图形工具：go tool pprof -http=:8080 http://127.0.0.1:8000/debug/pprof/heap

flat：当前函数直接分配的内存
flat%:  内存占总内存的百分比
sum%: 当前行及之前行的 flat% 累计值,如图中的第二行52.25=27.88+24.57
cum: 当前函数及其调用的所有子函数累计分配的内存，如无子函数调用，则cum和flat相等
cum%: 内存占总内存的百分比
name: 函数名称

使用Grapa视图能看到调用路径，且各路径下产生的内存大小

真凶 2：因锁导致接口变慢，监控CPU、内存正常

package main

import (
	"net/http"
	_ "net/http/pprof" // 引入即可，包里的init会注册路由
	"runtime"
	"sync"
	"time"
)

func main() {
	// 设置锁采集率，默认是0，参数表示每多少次锁采集一次，如：1表示每次都采集，100表示每100次采集一次，即1%
	runtime.SetMutexProfileFraction(1) // 开启mutex采样
	runtime.SetBlockProfileRate(1)     // 也需要开启block，否则无法生效，参数意义同上

	http.HandleFunc("/test", func(w http.ResponseWriter, r *http.Request) {
		doSomething()
		w.WriteHeader(http.StatusOK)
		w.Write([]byte(`{"code":"ok"}`))
	})
	http.ListenAndServe(":8000", nil)
}

var lock = sync.Mutex{}

func doSomething() {
	lock.Lock()
	defer lock.Unlock()
	time.Sleep(3 * time.Second) // 模拟耗时操作
}

刷几次模拟路由 127.0.0.1:8000/test，使其阻塞被采集
获取block采样结果：go tool pprof -http=:8080 http://127.0.0.1:8000/debug/pprof/mutex**（不给seconds参数表示历史所有，如果指定10表示获取最近10秒的阻塞采集情况）**
观察采集结果

平均耗时 = delay / contentions，示例中的平均每次耗时为4.97s

真凶 3：因某io操作导致接口变慢，监控CPU、内存正常

使用block类型：它能发现很多阻塞操作，如数据库连接池不足，数据库执行过慢，外部接口过慢等等

// 伪代码
package main

import (
	"fmt"
	"net/http"
	_ "net/http/pprof" // 引入即可，包里的init会注册路由
	"runtime"
)

func main() {
	// 设置阻塞采集率，默认是0，rate表示每多少次阻塞采集一次，如：1表示每次都采集，100表示每100次阻塞采集一次，即1%
	runtime.SetBlockProfileRate(1)

	http.HandleFunc("/test", func(w http.ResponseWriter, r *http.Request) {
		doSomething()
		w.WriteHeader(http.StatusOK)
		w.Write([]byte(`{"code":"ok"}`))
	})
	http.ListenAndServe(":8000", nil)
}

func doSomething() {
	// 模拟有IO的操作
	do, err := http.Get("<https://juejin.cn/>")
	fmt.Println(do, err)
}

刷几次模拟路由 127.0.0.1:8000/test，使其阻塞被采集
获取block采样结果：go tool pprof -http=:8080 http://127.0.0.1:8000/debug/pprof/block （不给seconds参数表示历史所有，如果指定10表示获取最近10秒的阻塞采集情况）
观察采集结果

平均阻塞时间 = delay 总阻塞时长 / contenions 阻塞次数 = 2.08s / 12 = 0.17s

通过命令行模式，能找到具体的代码，运行：

go tool pprof http://127.0.0.1:8000/debug/pprof/block

真凶4: 密集计算，导致CPU过高

package main

import (
	"net/http"
	_ "net/http/pprof" // 引入即可，包里的init会注册路由
)

func main() {
	http.HandleFunc("/test", func(w http.ResponseWriter, r *http.Request) {
		doSomething()
		w.WriteHeader(http.StatusOK)
		w.Write([]byte(`{"code":"ok"}`))
	})
	http.ListenAndServe(":8000", nil)
}

func doSomething() {
	var sum int
	for i := 0; i < 9999999999; i++ { // 模拟计算密集型任务
		sum += i
	}
}

访问地址：curl http://127.0.0.1:8000/test
使用top观察到CPU占用99.8%
我们通过命令行模式运行：go tool pprof -http=:8080 http://127.0.0.1:8000/debug/pprof/profile?seconds=10，这里指定secods采集10秒，然后我们再去访问下localhost:8000/test等待采集完成，如下图，图中看到大部分都消耗在doSomething方法