最近在做文本处理的时候遇到一个很奇怪的现象。串行执行脚本可能只需要几秒钟，但是如果想给每行开个协程并发处理的话，执行时间却从几十秒到几十分钟不等，关键是执行的过程中cpu的占用并不高。经过一系列的分析之后确认是gc导致的。所以想讲一下排查gc问题的一些小技巧，之后也会给出一些case：
一。如何查看程序运行过程中的GC信息呢？
设置gctrace的变量值为1即可，这个既可以设置成环境变量，也可以选择按如下方式执行：
GODEBUG=gctrace=1 go run main.go
//GODEBUG=gctrace=1 ./mainGODEBUG=gctrace=1 代表只针对这个进程开启gc追踪功能。程序输出如下：
对于上面每一行每一列的具体含义：
gc 1 @0.038s 1%: 0.55+0.12+0.081 ms clock, 2.2+0/0.42/1.1+0.32 ms cpu, 4->4->0 MB, 5 MB goal, 4 P。
1 表示第一次执行
@0.038s 表示程序执行的总时间
1% 垃圾回收时间占用总的运行时间百分比
0.018+1.3+0.076 ms clock 垃圾回收的时间，分别为STW（stop-the-world）清扫的时间, 并发标记和扫描的时间，STW标记的时间
0.054+0.35/1.0/3.0+0.23 ms cpu 垃圾回收占用cpu时间
4->4->3 MB 堆的大小，gc后堆的大小，存活堆的大小
5 MB goal 整体堆的大小
4 P 使用的处理器数量打开了GCTRACE之后对于gc执行的时间点、执行次数以及耗时可能已经有了初步的了解，但是对什么地方耗用大量内存并造成大量延迟可能并不清除。
二。如何定位gc问题所在？
这一点主要使用pprof来实现。开启pprof也特别简单，用net/http/pprof包可以快速实现。只需要在之前的代码中加下面三行就可以：
import (
"net/http"
_ "net/http/pprof"
)
go func() {
log.Println(http.ListenAndServe("localhost:8081", nil))
}()
在程序启动之后，只需要在命令行或者浏览器输入以下命令即可：
go tool pprof http://127.0.0.1:8081/debug/pprof/heap //查看堆的使用，即内存使用情况
go tool pprof http://127.0.0.1:8081/debug/pprof/profile //查看cpu耗时，会详细列出每个函数的耗时
go tool pprof http://127.0.0.1:8081/debug/pprof/goroutine //当前在运行的goroutine情况以及总数可以看下profile的输出信息， flat代表单个函数的运行时间，而cum则是累加的时间，也会包括这个函数下面的子函数的累加时间，所以main.main肯定是100%：
如果想看具体的图示的话，可以使用png命令将结果存成图片看，比如：
可以看下生成图片的样子， 有具体的箭头以及每个函数占用的时间或者内存：
基本目前笔者用到的工具就这两个了，感觉有收获的读者可以自己实验一下。接下来，我会不定期的分享一些遇到的GC问题的case，欢迎一起交流哈。
有疑问加站长微信联系（非本文作者）
