这个是之前做的笔记,有些地方可能有错误或者outdated,大体思路应该没错。


Go Profiling and Debug

Contents

1. MemStat & GC

首先先获得一些基本的信息,内存使用和GC情况。

MemStats:

// read mem stats
var m runtime.MemStats
runtime.ReadMemStats(&m)

GC:

// disable gc when start
GOGC=off go run main.go
 
 
// disable gc and manually trigger gc
debug.SetGCPercent(-1)
runtime.GC()
 
// read gc stats
var g debug.GCStats
debug.ReadGCStats(&g)

MemStats中我们关注的是Alloc/HeapAlloc,这个值代表了当前heap的大小,另外就是HeapObjects,代表了当前heap中有多少个对象,同时应该关注一下Frees,这个值代表了一共释放过多少的对象,可能当前内存使用已经降下来了但过去某个时间曾经升高过。

同时可以结合GCStats查看一下GC的情况, LastGC代表了上次GC时间,NumGC代表了一共GC过多少次,PauseTotal总暂停时间以及Pause暂停历史。

2. pprof

MemStats和GCStats可以给我们一个大概的情况,但是更具体的信息,例如哪里耗内存最多,哪里耗CPU更多,我们需要更准确的情况,可以使用自带的pprof。

// CPU
pprof.StartCPUProfile(os.Stdout)
defer pprof.StopCPUProfile()
go run main.go > cpu.profile
go tool pprof cpu.profile
 
// Mem
pprof.WriteHeapProfile(os.Stdout)
go run main.go > cpu.profile
go tool pprof cpu.profile

同理,memory.profile给我们的也是当前的内存使用情况,有些时候并不适合debug,如果想知道全部的分配情况:

go tool pprof --alloc_space memory.profile

除了问题原因比较明确或者比较容易复现的情况,上面输出memory和cpu profile的情况有些时候并不那么实用,这个时候一方面我们可以结合上面的MemStats使用,如果达到某个值就输出一份profile,或者直接使用下面的通过web ui把profile信息实时输出:

// In time
import _ "net/http/pprof"
func main(){
  go func() {
    log.Println(http.ListenAndServe("localhost:6060", nil))
  }()
}
 
// http://localhost:6060/debug/pprof/
// - allocs: 这个跟上面的--alloc_space是一样的,同时还可以查看到MemStats
// - block: 没有在运行的时间,例如等待channel,等待mutex等。
// - cmdline: 当前程序的启动命令
// - goroutine: goroutine的信息
// - heap: 等同于上面的memory profle
// - mutex: Stack traces of holders of contended mutexes
// - profile: 等同于上面的CPU Profile
// - threadcreate: 线程
// - trace: 见下面trace部分

依旧可以使用工具来查看:

go tool pprof --alloc_space http://localhost:6060/debug/pprof/heap

除了实时分析外,还可以导出调用栈的图表:

go tool pprof -web/pdf/gif/dot/png... cpu.profile

或者直接在浏览器实时查看:

go tool pprof -http [host]:[port] [options] [binary] <source>

3. trace

profile go程序可以给我们一些直观的输出,例如时间用在哪里,内存用在哪里,但是更加深层次的原因,例如一个web服务器为什么响应时间总是很久,pprof和trace主要的区别还是维度不太一样,一个更像是代码栈层面的,一个是更横向的。trace更关注与latency。

比如说一个请求在client观察从发送到完成经过了5s,做profile可能发现这个请求的CPU时间只有2s,那剩下的3s就不是很清楚了,profile更侧重的是我们代码执行了多久,至于其他的,例如网络io,系统调用,goroutine调度,GC时间等,很难反映出来。

生成trace可以通过下面的代码:

trace.Start(os.Stdout)
defer trace.Stop()
go run main.go > app.trace
go tool trace app.trace

或者上面的pprof的web ui也支持下载trace。

在trace上可以清楚的看到每个goroutine的起始,怎么生成的,每个cpu内核在做什么这些。

4. gdb & delve

对于百分之80的情况,上面的工具就已经足够了,有些极端的情况依旧无法避免,例如说我们的程序已经无响应了,那么即使开了实时的web ui,也是打不开的,这个时候就需要经典的gdb了。

gdb --pid=pid [executable]
gcore pid // 保存core dump

GDB是很大的一个topic,而且也有很多资源是介绍GDB的,关于GDB+go的使用可以直接查看官方文档:https://golang.org/doc/gdb, 而更多GDB的使用直接Google。

GDB比较通用,不是很能直接反映出go语言的特点,例如goroutine。所以也可以使用delve,delve可以理解为go版本的gdb:

dlv debug // 以dlv方式运行,跟go run一致
dlv test // 以dlv方式运行测试 跟go test一致
dlv exec [executable]// 以attach方式运行一个编译好的binary
dlv attach pid [executable] // attach到一个运行中的进程 貌似会暂停进程?

同时,delve也可以查看gdb保存的core文件:

dlv core [executable] [core file]

对比GDB来说,比较有特色的命令有两个(gdb也有这个):

(dlv) goroutines
(dlv) goroutine [goroutine-id]

可以用来查看具体的goroutine信息。