Go语言程序的状态监控 via 达达

时间:2023-01-03 04:19:09

Go语言程序的状态监控

Go是很实在的编程语言,从一开始就提供了很详细的运行状态信息。产品上线后的调优和排查疑难杂症都得靠这些状态信息。这边总结一些我们项目里用到的状态监控手段。

pprof

Go自带了一个pprof工具,这个工具可以做CPU和内存的profiling,官方的博客有一篇文章介绍用法:《Profiling Go Programs》

官方的文章讲了怎么用自带的pprof工具分析数据,但是获得分析数据的部分比较单一,我在很长一段时间一直误以为cpuprof和memprof必须在程序启动时打开,其实cpuprof和memprof是可以在线打开和关闭的。

并且pprof模块其实不只是cpuprof和memprof这两个功能,其中还提供了Lookup功能用于获取堆状态信息、线程状态信息、 goroutine状态信息等。

以下是我在项目中用到的pprof功能(代码片段):

case "lookup heap":
p := pprof.Lookup("heap")
p.WriteTo(os.Stdout, 2)
case "lookup threadcreate":
p := pprof.Lookup("threadcreate")
p.WriteTo(os.Stdout, 2)
case "lookup block":
p := pprof.Lookup("block")
p.WriteTo(os.Stdout, 2)
case "start cpuprof":
if cpuProfile == nil {
if f, err := os.Create("game_server.cpuprof"); err != nil {
log.Printf("start cpu profile failed: %v", err)
} else {
log.Print("start cpu profile")
pprof.StartCPUProfile(f)
cpuProfile = f
}
}
case "stop cpuprof":
if cpuProfile != nil {
pprof.StopCPUProfile()
cpuProfile.Close()
cpuProfile = nil
log.Print("stop cpu profile")
}
case "get memprof":
if f, err := os.Create("game_server.memprof"); err != nil {
log.Printf("record memory profile failed: %v", err)
} else {
runtime.GC()
pprof.WriteHeapProfile(f)
f.Close()
log.Print("record memory profile")
}

其中"lookup goroutine"和"lookup heap"都曾经帮我实际的解决过问题。有一次内网测试服务器因为一个功能逻辑陷入死锁,通过"lookup goroutine"获取到当前所有正在运行的goroutine的调用栈信息,可以快速的排查出是哪些goroutine的调用发生了死锁。

通过"lookup heap"可以看出堆的分存分配情况,可以快速的定位到内存泄漏的地方。"lookup heap"还提供了对象数量和每次GC执行的暂停时间,这些信息对Go程序的GC调优很有用。

"start cpuprof"和"start memprof"可以在线的动态启用cpuprof和memprof,这里有个细节需要注意,我的程序一开始是自己实现daemon模式来做后台运行,刚加上"start cpurprof"的时候,在线动态启用cpuprof会让进程停止响应,不用daemon模式启动就不会,最后我没办法只好去掉自己实现的daemon模式启动,改为nohup让程序在后台运行。

如果有自己实现daemon模式运行的通讯,请留意。

cpuprof和memprof有还有一个细节需要注意,做cpuprof的程序需要给最后交给pprof做分析的程序是一致的,至少编译时候使用的代码和代码路径需要是一致的,这跟程序里带的调试信息有关系,否则生成出来的profile报表是不准的。

GOGCTRACE

Go提供了一些很有用的环境变量,可以让程序在不修改代码的情况下,做一些运行时的设置调整,比如GOMAXPROC,即可以通过环境变量设置,也可以通过代码设置,我倾向于用环境变量设置,更为灵活。

其中GOGCTRACE环境变量在我做GC调优的时候起了很关键的作用,将GOGCTRACE设置为1,Go程序就会在每次GC的时候输出GC的相关信息。

用法类似这样:

GOGCTRACE=1 ./my_go_program 2>log_file

GOGCTRACE这个变量已经被禁用了,现在得这么用了 GODEBUG=gctrace=1 ./my_go_program 2>log_file

这是Linux的shell支持的语法,这样设置环境变量只会作用于当前启动的这个进程。

信息是输出到标准错误的,所以需要用 2> 把输出重定向到文件里。

输出的内容像这样:

gc16(8): 34+6+5 ms, 367 -> 365 MB 817253 -> 782045 (18216892-17434847) objects, 64(2182) handoff, 72(22022) steal, 553/244/51 yields

其中gc16表示第16次进行GC,后面的(8)表示由8个线程执行,这个线程数对应GOMAXPROCS环境变量,34+6+5 ms分别代表一系列GC动作消耗的时间,这三个时间加起来45ms,就是这个程序在这次GC过程中暂停的时间。

apiprof

apiprof不是Go自带的功能,而是我在项目里自己做的,这个功能可以让我在实时的观测到程序的所有通讯接口的运行情况。

apiprof监控的是所有通讯接口的执行时间,每次请求处理完,就给apiprof进程发送一个信息,其中包含请求的类型以及请求的执行时间。

apiprof进程汇总所有请求发来的数据,做进一步统计,比如某种请求的平均执行时间、最长执行时间等,然后输出成一份表格,按请求执行时间排序,这样就很容易抓到程序的性能瓶颈。

目前我们游戏的总体请求执行时间在30微秒左右,其中从单个请求类型看,比较高耗时的请求执行时间是200微秒左右,其余的大多在几十微秒。这些数据可以给正在用Go开发游戏的同学参考一下。

根据个人经验,建议尽量把请求时间保持在微秒级别,到了毫秒级别就要提高警惕想办法优化了,到了几十微秒应该就有很大的优化空间了。当然这些数据要根据项目类型和实时性要求来,如果是一个分布式系统,自身节点间通讯就要花掉几毫秒,如果请求处理时间要求在微秒级别就不实际了。

本文来自:达达的主页

感谢作者:达达

查看原文:Go语言程序的状态监控