生产环境总是会遇到一些奇怪的问题，比如 Go 服务时不时地响应非常慢甚至完全没有响应，Go 服务的内存占用总是居高不下等。遇到这些问题该如何排查与分析呢？Go 语言其实为我们提供了一些非常有用的工具，如 ppprof、Trace,这两种工具可以帮助我们分析和解决 Go 服务的性能问题。另外，学习 C 语言的读者可能知道 GDB 可以用来调试 C 程序，那么 Go 语言有没有对应的调试工具呢？ Go 语言专用的调试工具叫作 dlv。
1. Go 程序分析利器 ppprof
pprof 是 Go 语言提供的一款非常强大的性能分析工具，它可以收集 Go 程序的各项运行时指标数据，包括内存、CPU、锁等。有了这些指标数据，大部分的 Go 服务性能问题也就可以迎刃而解了。
1.1 pprof 概述
为什么 pprof 可以帮助我们分析 Go 程序的性能呢？因为它可以采集 Go 服务的运行时数据，比如协程调用栈、内存分配情况等。这样一来，我们就能清楚地知道 Go 服务在哪里阻塞，在哪里消耗内存。当然，要想通过 pprof 分析程序性能，需要引入一点代码，如下所示：
package main
import (
"net/http"
_"net/http/pprof"
)
func main(){
go func(){
http.ListenAndServe("0.0.0.0:6060",nil)
}()
}参考上面的官方说明，可以看到，pprof 工具可以用来分析内存溢出问题、协程溢出问题、锁/阻塞问题等。那么如何应用这些数据指标呢？举一个例子，指标 goroutine 可以采集所有协程的调用栈，通常可以用来分析 Go 服务的阻塞情况，比如当大量协程阻塞在获取锁的代码时，那是不是有可能是因为锁没有被释放？再比如当大量协程阻塞在写管道的代码时，那是不是有可能是因为读管道的协程太慢或者异常退出了？goroutine 指标的输出内容如下所示：
http://127.0.0.1:8888/debug/pprof/goroutine?debug=1
//第一个数字表示协程数
1 @ 0x10390d6 0x1032357 0x1063929 0x10d0372 0x10d16da 0x10d16c8 0x1126c29 0x1135d85 0x131dc9f 0x1069921
# 0x1063928 internal/poll.runtime_pollWait+0x88 /go1.23/src/runtime/netpoll.go:302
# 0x10d0371 internal/poll.(*pollDesc).wait+0x31 /go1.23/src/internal/poll/fd_poll_runtime.go:83
# 0x10d16d9 internal/poll.(*pollDesc).waitRead+0x259 /go1.23/src/internal/poll/fd_poll_runtime.go:88
# 0x10d16c7 internal/poll.(*FD).Read+0x247 /go1.23/src/internal/poll/fd_unix.go:167
# 0x1126c28 net.(*netFD).Read+0x28 /go1.23/src/net/fd_posix.go:55
# 0x1135d84 net.(*conn).Read+0x44 /go1.23/src/net/net.go:183
# 0x131dc9e net/http.(*connReader).backgroundRead+0x3e /go1.23/src/net/http/server.go:672
......最后思考一个问题：为什么只需要引入 net/http/pprof 就能采集这些运行时数据指标呢？回顾一下上面的程序示例，我们还启动了一个HTTP服务，但是我们没有设置 HTTP 请求的处理器，那么当我们在浏览器中输入地址 “/debug/pprof" 时，该请求由谁处理了呢？其实在引入 net/http/pprof包的时候，其声明的 init 函数就默认注册好了 HTTP 请求处理器，所以我们才能通过这些接口获取到运行时数据指标，如下所示：
func init() {
//前缀匹配，包含allocs、heap、goroutine等
http.HandleFunc("/debug/pprof/", Index)
http.HandleFunc("/debug/pprof/cmdline", Cmdline)
http.HandleFunc("/debug/pprof/profile", Profile)
http.HandleFunc("/debug/pprof/symbol", Symbol)
http.HandleFunc("/debug/pprof/trace", Trace)
}
1.2 内存指标分析
内存指标可以通过地址 “/debug/pprof/heap" 或者 “/debug/pprof/allocs" 查看，这两种指标采样的数据基要上是一样的，只是指标 heap 可以用来采样存活对象的内存分配情况（可通过参数 gc=1 在采样前运行 GC, 这样剩下的都是存活对象了）。以指标 heap 为例，其输出结果如下所示：
//访问地址
http://127.0.0.1:6060/debug/pprof/heap?debug=1&gc=1
//heap profile 汇总数据:
//3: 29728 [16: 54144] 含义如下：
//inuse对象数目（已分配的，去除了已释放的）: inuse字节 [已分配对象数目: 已分配字节]
//heap/1048576 平均采样频率1048576字节
heap profile: 10: 29728 [16: 54144] @ heap/1048576
//1: 18432 [1: 18432] 含义同上面；该调用栈内存分配情况
1: 18432 [1: 18432] @ 0x1363bc9 0x1365cce 0x13660f8 0x1366c51 0x1366c46 0x1669517 0x1045c06 0x1045b51 0x1045b51 0x1045b51 0x1045b51 0x1045b51 0x1038c33 0x1069881
# 0x1363bc8 regexp.onePassCopy+0x48 /go1.18/src/regexp/onepass.go:226
# 0x1365ccd regexp.compileOnePass+0x14d /go1.18/src/regexp/onepass.go:498
......
//其他调用栈
//总的内存统计指标
# runtime.MemStats
# Alloc = 1311912 //已分堆内存字节数，不包含已释放内存，与一致（分配时累加，释放减）
# TotalAlloc = 5007040 //总的分配堆内存字节数，包含已释放内存
# Sys = 16598024 //从操作系统申请的内存总数（包括栈，堆，还有Go的一些原生对象等）
# Mallocs = 34063 //内存分配数（分配的mspan内存块数目之和）
# Frees = 25879 //内存释放数（释放也就是回收的mspan内存块数目之和）
# HeapAlloc = 1311912 //同Alloc
# HeapSys = 7602176 //从操作系统申请的，仅用于堆
# HeapIdle = 4104192 //mspan没被分配就是idle状态，HeapIdle等于这些状态的mspan内存之和
# HeapInuse = 3497984 //mspan部分内存被分配了就是inuse状态，HeapInuse等于这些状态的mspan内存之和
# HeapReleased = 2449408 //归还给操作系统的堆内存
# HeapObjects = 8184 //堆对象数目，等于Mallocs-Frees
# Stack = 786432 / 786432 //inuse的栈内存/向操作系统申请的栈内存
# NextGC = 4194304 //下次GC结束后的堆内存目标大小
# LastGC = 1663660279482080000 //上次GC结束时间
# PauseNs = [42600 .......] //stopTheWorld暂停时间，单位纳秒；256大小的循环数组
# PauseEnd = [1663582175653806000 ......] //GC结束时间；256大小的循环数组
# GCCPUFraction = 2.6664927576867443e-06 //GC耗费CPU时间占整体的比例
# MaxRSS = 14467072 //进程分配的常驻内存大小
//省略了部分1.3 CPU 指标分析
假设有这样一个业务场景，某一时刻线上机器的 CPU 利用率突然飙升并且居高不下。通过简单的定位发现是 Go 服务耗费了太多 CPU 资源，但是接下来该如何排查呢？为什么 Go 服务会耗费这么多 CPU 资源呢？这里我们可以使用 pprof 工具中的 CPU profile, 它可以用来分析程序的热点，使用方式如下：
go tool pprof http://127.0.0.1:8888/debug/pprof/profile?debug=1
(pprof)
1.4 锁与阻塞指标分析
我们已经知道，指标 block 用于采集因为同步原语而阻塞的协程调用栈，默认不开启，需要通过函数 runtime.SetBlockProfileRate 开启；指标 mutex 采集持有锁的协程调用栈，同样默认不开启，需要通过函数 runtime.SetMutexProfileFraction 开启。以指标 block 为例，其输出的结果如下所示：
//cycles取的是cputick，这里的值是平均每秒钟cputick递增多少；
cycles/second=1996821317
// 第一个值是协程阻塞的cputick数，第二个值是阻塞次数，根据cycles/second就可以计算平均阻塞时间了
161357271645546 364 @ 0x1048768 0x13a4014 0x1069921
# 0x1048767 runtime.selectgo+0x407 /go1.18/src/runtime/select.go:509
# 0x13a4013 github.com/go-redis/redis/v8/internal/pool.(*ConnPool).reaper+0xd3 /xxx/vendor/github.com/go-redis/redis/v8/internal/pool/pool.go:485最后，当指标 block 或者指标 mutex 的输出结果非常多的时候，同样可以使用 pprof 工具帮助我们分析，如下所示：
[root@pass ~]# go tool pprof http://127.0.0.1:8888/debug/pprof/block?debug=1
(pprof) top
Dropped 102 nodes (cum <= 0.20hrs)
flat flat% sum% cum cum%
40.97hrs 100% 100% 40.97hrs 100% runtime.selectgo
0 0% 100% 23hrs 56.13% github.com/go-redis/redis/v8/internal/pool.(*ConnPool).reaper
0 0% 100% 17.97hrs 43.85% github.com/go-sql-driver/mysql.(*mysqlConn).startWatcher.func1
0 0% 100% 40.97hrs 100% runtime.goexit
2. 性能分析工具 Trace
除了 pprof 之外，Go 语言还提供了另外一款性能分析工具 Trace,它可以跟踪 Go 程序的运行时数据，包括协程调度、系统调用、锁、垃圾回收等。我们可以通过函数 trace.Start 开启 Trace 追踪，实际上接口 “/debug/pprof/trace" 也是基于该函数实现的。Trace 的使用方式如下：
3. 使用 dlv 调试 Go 程序
3.1 Go 语言调度工具 dlv
dlv 全称 delve,其目标是为 Go 语言提供一款简单的、全功能的调试工具。通过 dlv,我们可以控制 Go 进程的执行，查看任意变量，查看协程或线程状态等。不过需要说明的是，dlv 并非官方提供的调试工具，所以需要额外安装，安装方式如下所示：
[root@pass ~]# git clone https://github.com/go-devel/delve
[root@pass ~]#cd delve
[root@pass ~]#go install github.com/go-delve/delve/cmd/dlvdlv 支持以多种方式跟踪 Go 进程，我们可以通过子命令 help 查看，结果如下所示：
[root@daolian ~]#dlv help
//参数传递
Pass flags to the program you are debugging using `--`, for example:
`dlv exec ./hello -- server --config conf/config.toml`
Usage:
dlv [command]
Available Commands:
//常用来调试异常进程
attach Attach to running process and begin debugging.
//启动并调试二进制程序
exec Execute a precompiled binary, and begin a debug session.
debug Compile and begin debugging main package in current directory, or the package specified.
......dlv 与 C 语言调试工具 GDB 还是比较类似的，都可以设置断点，可以输出任意变量的值，可以单步执行，可以输出调用栈等，这些常用功能（命令）如下所示：
Running the program:
//运行到断点处，或者直到程序终止
continue (alias: c) --------- Run until breakpoint or program termination.
//单步执行
next (alias: n) ------------- Step over to next source line.
//重新启动进程
restart (alias: r) ---------- Restart process.
//进入函数，普通的n函数调用是一行代码，会直接跳过
step (alias: s) ------------- Single step through program.
//退出函数执行
stepout (alias: so) --------- Step out of the current function.
Manipulating breakpoints:
//设置断点
break (alias: b) ------- Sets a breakpoint.
//查看所有断点
breakpoints (alias: bp) Print out info for active breakpoints.
//删除断点
clear ------------------ Deletes breakpoint.
//删除所有断点
clearall --------------- Deletes multiple breakpoints.
Viewing program variables and memory:
//输出函数参数
args ----------------- Print function arguments.
//输出局部变量
locals --------------- Print local variables.
//输出某一个变量
print (alias: p) ----- Evaluate an expression.
//输出寄存器内存
regs ----------------- Print contents of CPU registers.
//修改变量的值
set ------------------ Changes the value of a variable.
Listing and switching between threads and goroutines:
//输出协程调用栈或者切换到指定协程
goroutine (alias: gr) -- Shows or changes current goroutine
//输出所有协程
goroutines (alias: grs) List program goroutines.
//切换到指定线程
thread (alias: tr) ----- Switch to the specified thread.
//输出所有线程
threads ---------------- Print out info for every traced thread.
Viewing the call stack and selecting frames:
//输出调用栈
stack (alias: bt) Print stack trace.
Other commands:
//输出程序汇编指令
disassemble (alias: disass) Disassembler.
//显示源代码
list (alias: ls | l) ------- Show source code.参考上面的输出结果，每一个调试功能都对应一个命令，看起来 dlv 的调试命令还是挺多的，但是常用的也就几个，一般只需要设置断点（b)、单步执行（n)、输出变量（p)、输出调用栈(bt) 等有限命令就能满足基本的调试需求。
3.2 dlv 调试实战
package main
import (
"fmt"
"time"
)
func main() {
queue := make(chan int, 1)
go func() {
for {
data := <- queue
fmt.Print(data, " ")
}
}()
for i := 0; i < 10; i ++ {
queue <- i
}
time.Sleep(time.Second * 1000)
}//编译标识注意 -N -l ，禁止编译优化
[root@daolian ~]#go build -gcflags '-N -l' test.go
dlv exec test
Type 'help' for list of commands.
(dlv)如下所示：
//有些时候只根据函数名无法区分，设置断点可能需要携带包名，如runtime.chansend
(dlv) b chansend
Breakpoint 1 set at 0x1003f0a for runtime.chansend() /go1.23/src/runtime/chan.go:159
(dlv) b chanrecv
Breakpoint 2 set at 0x1004c2f for runtime.chanrecv() /go1.23/src/runtime/chan.go:455
(dlv) b schedule
Breakpoint 3 set at 0x1037aea for runtime.schedule() /go1.23/src/runtime/proc.go:3111
(dlv) b main.main
Breakpoint 4 set at 0x1089a0a for main.main() ./test.go:8接下来使用调试命令c (continue) 执行到断点处，如下所示：
(dlv) c
> runtime.schedule() /go1.18/src/runtime/proc.go:3111 (hits total:1) (PC: 0x1037aea)
=>3111: func schedule() {
3112: _g_ := getg()
3113:
3114: if _g_.m.locks != 0 {
3115: throw("schedule: holding locks")
3116: }参考上面的代码，符号 “=>" 指向了当前执行的代码行。第一个遇到的断点竟然是调度器主函数 runtime.schedule,不应该是入口函数 main.main吗？如下所示：
(dlv) bt
0 0x0000000001037aea in runtime.schedule
at /go1.23/src/runtime/proc.go:3111
1 0x000000000103444d in runtime.mstart1
at /go1.23/src/runtime/proc.go:1425
2 0x000000000103434c in runtime.mstart0
at /go1.23/src/runtime/proc.go:1376
3 0x00000000010585e5 in runtime.mstart
at /go1.23/src/runtime/asm_amd64.s:368
4 0x0000000001058571 in runtime.rt0_go
at /go1.23/src/runtime/asm_amd64.s:331那接下来怎么办呢？我们可以通过命令 restart 重新执行程序，删除其他所有断点，重新在入口函数 main.main 处设置断点，并通过命令 c 执行到断点处，如下所示：
(dlv) r
Process restarted with PID 57676
(dlv) clearall
(dlv) b main.main
Breakpoint 5 set at 0x1089a0a for main.main() ./test.go:8
(dlv) c
> main.main() ./test.go:8 (hits goroutine(1):1 total:1) (PC: 0x1089a0a)
=> 8: func main() {
9: queue := make(chan int, 1)
10: go func() {由上面的输出结果可知，程序终于执行到入口函数 main.main 了。接下来我们可以在管道的读写函数处设置断点，并通过命令 c 执行到断点处，如下所示：
dlv) b chansend
Breakpoint 1 set at 0x1003f0a for runtime.chansend() /go1.23/src/runtime/chan.go:159
(dlv) b chanrecv
Breakpoint 2 set at 0x1004c2f for runtime.chanrecv() /go1.23/src/runtime/chan.go:455
(dlv) c
> runtime.chansend() /go1.23/src/runtime/chan.go:159 (hits goroutine(1):1 total:1) (PC: 0x1003f0a)
=> 159: func chansend(c *hchan, ep unsafe.Pointer, block bool, callerpc uintptr) bool {
160: if c == nil {
161: if !block {
162: return false
163: }参考上面的输出结果，程序执行到了函数runtime.chansend,对应的应该是“queue<-i" 一行代码，我们可能通过命令 bt 查看函数调用栈来确认，如下所示：
(dlv) bt
0 0x0000000001003f0a in runtime.chansend
at /go1.23/src/runtime/chan.go:159
1 0x0000000001003edd in runtime.chansend1
at /go1.23/src/runtime/chan.go:144
2 0x0000000001089aa9 in main.main
at ./test.go:18
上面的输出结果与我们的预期一致。另外，我们也可以通过命令args 查看输入参数，通过命令x查看向管道写入的数据，如下所示：
//查看参数
(dlv) args
c = (*runtime.hchan)(0xc00005a070)
ep = unsafe.Pointer(0xc000070f58)
block = true //会阻塞协程
callerpc = 17341097
~r0 = (unreadable empty OP stack)
//循环第一次写入管道的数值应该是0，x命令可查看内存
(dlv) x 0xc000070f58
0xc000070f58: 0x00接下来可以单步执行，验证管道写操作的执行步骤，这一过程比较简单，重复较多，这里就不再赘述了，下面只是列出了单步执行的一个中间过程：
(dlv) n
1 > runtime.chansend() /go1.23/src/runtime/chan.go:208 (PC: 0x10040e0)
Warning: debugging optimized function
203: if c.closed != 0 {
204: unlock(&c.lock)
205: panic(plainError("send on closed channel"))
206: }
207:
=> 208: if sg := c.recvq.dequeue(); sg != nil {
209: // Found a waiting receiver. We pass the value we want to send
210: // directly to the receiver, bypassing the channel buffer (if any).
211: send(c, sg, ep, func() { unlock(&c.lock) }, 3)
212: return true
213: }我们在函数 runtime.schedule以及函数 runtime.gopark 处再设置断点，观察协程切换情况，如下所示：
(dlv) b schedule
Breakpoint 8 set at 0x1037aea for runtime.schedule() /go1.23/src/runtime/proc.go:3111
(dlv) b gopark
Breakpoint 9 set at 0x1031aca for runtime.gopark() /go1.23/src/runtime/proc.go:344
(dlv) c
> runtime.gopark() /go1.23/src/runtime/proc.go:344 (hits goroutine(1):2 total:2) (PC: 0x1031aca)
=> 344: func gopark(unlockf func(*g, unsafe.Pointer) bool, lock unsafe.Pointer, reason waitReason, traceEv byte, traceskip int) {
345: if reason != waitReasonSleep {
346: checkTimeouts() // timeouts may expire while two goroutines keep the scheduler busy
347: }
348: mp := acquirem()
349: gp := mp.curg函数runtime.gopark 主要用于暂停当前协程，并切换到调度器主函数 runtime.schedule。所以，再次执行命令 c 程序会暂停到函数 runtime.schedule 处，如下所示：
(dlv) c
> [b] runtime.schedule() /go1.23/src/runtime/proc.go:3111 (hits total:19) (PC: 0x1037aea)
=>3111: func schedule() {
3112: _g_ := getg()
(dlv) bt
0 0x0000000001037aea in runtime.schedule
at /Users/lile/Documents/go1.23/src/runtime/proc.go:3111
1 0x000000000103826d in runtime.park_m
at /Users/lile/Documents/go1.23/src/runtime/proc.go:3336
2 0x0000000001058663 in runtime.mcall
at /Users/lile/Documents/go1.23/src/runtime/asm_amd64.s:425从上面的输出结果可知，通过bt查看函数调用栈时，会发现栈底函数是 runtime.mcall,并且函数调用栈非常短。为什么在函数调用栈中看不到函数 runtime.gopark 呢？因为已经从用户协程栈切换到了调度栈，所以就看不到用户协程的函数调用栈了。函数 runtime.mcall 就是用来切换栈帧的，所以函数调用栈的第一个函数也就是 runtime.mcall了。
1309
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
