一次Go程序CPU占用过高的排查经历

2023 年 09 月 30 日

649 次浏览

2800字数

block巭是从selfhelp-iptables修改过来的巭对抗程序，原理是当用户访问订阅链接时获取客户端IP，然后把客户端IP加入服务器白名单中，从而阻断巭主动探测。也正是因为block巭需求变化很大，selfhelp-iptables中的很多地方都需要定制化开发。

作为一个技术宅，我很快就给block巭加上了订阅功能，还细心地支持vXX节点订阅和claXX规则订阅两种类型，顺手修复了几个安全问题。因为block巭需要一直运行，来长期阻断巭主动探测，所以我又给它增加了systemd配置，避免巭在机器重启/进程奔溃时乘虚而入。一直到这里，事情都进展的相当顺利，我也美滋滋地在服务器上部署完睡觉去了。

发现问题

第二天我习惯性打开邮箱，发现AWS居然给我发封CPU使用率过高的邮件，心里第一反应是被黑了。但是一想自己只开放了22,443端口，平时用的秘钥登录，443上也只部署了block巭服务，看起来都不像容易被黑的样子。登录服务器输入top命令，查看CPU占用情况：

发现block巭的CPU占用率达到99%。这里怀疑是端口上流量太大，block巭实时读取iptables的日志造成的。先把端口上的流量停止，再top看下，发现CPU占用依然是99%，说明CPU占用过高的问题和流量负载无关。到这里问题比较明确了，block巭和业务无关的代码占用了太多CPU。

开发环境

排查过程

pprof是分析Golang程序的利器，它可以监控以下四种资源：

CPU profile：报告程序的 CPU 使用情况，按照一定频率去采集应用程序在 CPU 和寄存器上面的数据
Memory Profile（Heap Profile）：报告程序的内存使用情况
Block Profiling：报告 goroutines 不在运行状态的情况，可以用来分析和查找死锁等性能瓶颈
Goroutine Profiling：报告 goroutines 的使用情况，有哪些 goroutine，它们的调用关系是怎样的

block巭使用了自定义的Mux，所以我们需要先导入pprof，

import _ "net/http/pprof"

再手动注册一下路由规则

r.HandleFunc("/debug/pprof/", pprof.Index)
r.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline)
r.HandleFunc("/debug/pprof/profile", pprof.Profile)
r.HandleFunc("/debug/pprof/symbol", pprof.Symbol)
r.HandleFunc("/debug/pprof/trace", pprof.Trace)

重新编译部署到生产环境后，可以访问：

/debug/pprof/: 汇总数据
/debug/pprof/profile：访问这个链接会自动进行 CPU profiling，持续 30s，并生成一个文件供下载
/debug/pprof/heap： Memory Profiling 的路径，访问这个链接会得到一个内存 Profiling 结果的文件
/debug/pprof/block：block Profiling 的路径
/debug/pprof/goroutines：运行的 goroutines- 列表，以及调用关系

在开发环境执行：

go tool pprof http://生产环境IP:生产环境PORT/debug/pprof/profile -seconds 60

获取最近60秒程序运行的cpuprofile,-seconds参数不填默认为30。命令执行完后会在开发环境生成pprof/pprof.samples.cpu.001.pb.gz文件。注意此时需要CPU压力比较高时操作，要不然可能获取到的信息太少可能不足以后续生成火焰图。

接着在开发环境上生成火焰图，并向外提供http服务

go tool pprof -http=:8081 ~/pprof/pprof.samples.cpu.001.pb.gz

因为我的开发环境没有UI界面，只好在PC上打开浏览器访问以下地址来查看火焰图

http://开发环境IP:8081/ui/flamegraph?si=cpu

可以看出CPU的绝大部分时间都在执行Fmt.Scan操作，这是一个和控制台输入相关的函数，那么我们打开代码看看

// 开启http服务
go server.StartServer()
// 主协程读取用户输入并执行命令
for {
    var cmdIn string
    fmt.Scan(&cmdIn)
    cmdlineHandler(cmdIn)
}

这就很明显了，selfhelp-iptables作者是在命令行下使用的，所以他不断读取控制台的输入信息，但我们使用的是service方式运行，这里的读取会耗尽CPU资源。

最后block巭在api里提供了相关白名单操作，不再需要从terminal中读入信息，这里导致CPU占用过高的“罪魁祸首”也被删除。这一段流程走下来，除了感觉Golang自带的pprof工具非常强大，使用非常方便外，也警醒自己在性能测试上做的不足，即使是这样自用的小工具，性能测试也是不可忽略的部分。