腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查

作者:jasonzxpan , 腾讯 IEG 运营开发工程师
【腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查】本文排查一个Linux 机器 CPU 毛刺问题 , 排查过程中不变更进程状态、也不会影响线上服务 , 最后还对 CPU 毛刺带来的风险进行了分析和验证 。
本文中提到 CPU 统计和产生 core 文件的工具详见 simple-perf-tools 仓库 。
问题描述某服务所在机器统计显示 , 其 CPU 使用率在高峰时段出现毛刺 。
暂时未收服务调用方的不良反馈 。
腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查文章插图
初步排查查看 CPU 1 分钟平均负载 , 发现 1 分钟平均负载有高有低 , 波动明显 。 说明机器上有些进程使用 CPU 波动很大 。
腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查文章插图
登录机器排查进程 , 使用top指令 。 因为 CPU 会明显上升 , 重点怀疑使用 CPU 总时间高的进程 , 在打开 top 后 , 使用shift +t可以按照 CPU TIME 进行排序 。
腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查文章插图
直观的看 , 有几个 spp_worker 相关的进程使用 CPU TIME 相对较高 。
第一个进程因为启动的时间比较长 , 所以 CPU TIME 也比较大 。 可以使用下面的脚本 , 计算各个进程从各自拉起后 CPU 使用率:
uptime=`awk '{print $1}' /proc/uptime` # why is it too slow indocker?hertz=`zcat /proc/config.gz | grep CONFIG_HZ= |awk -F"=" '{print $2}'`awk -v uptime=$uptime -v hertz=$hertz -- '{printf("%d\t%s\t%11.3f\n", $1, $2, (100 *($14 + $15) / (hertz * uptime - $22)));}' /proc/*/stat 2> /dev/null | sort-gr -k +3 | head -n 20看到的也是这些 spp_worker 使用 CPU 相对要高一些:
腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查文章插图
选其中的一个 PID 为 45558 的 Worker 进程监控器 CPU 使用率:
腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查文章插图
可以发现其 CPU 大部分情况很低 , 但是在某一个时间点会升高 , 持续 1 秒左右 。 而且大部分时间是耗费在用户态 , 而非系统调用 。
而《Linux Agent 采集项说明 - CPU 使用率》中描述的 CPU 使用率的采样策略为:
Linux Agent 每分钟会采集 4 次 15 秒内的 CPU 平均使用率 。 为了避免漏采集 CPU 峰值 , 网管 Agent 取这一分钟内四次采集的最大值上报 。
因为采样可能采到高点或者低点 , 当 1 分钟内出现 CPU 飙升 , 则会表现为尖峰;如果四次都没有出现飙升 , 则表现为低谷 。
至此 , 已经能确认是这批 Worker 进程引起了这种毛刺 , 但具体是哪部分代码有问题还需要进一步排查 。
进一步排查前边确认了没有太多的系统调用 , 所以不必使用strace工具 。
使用perf工具使用perf工具进行查看 。 具体的命令是perf top -p 45558 , 在低 CPU 使用率的时候:
腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查文章插图
但是当 CPU 飚上去的时候 , perf采样的位置变成如下这样:
腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查文章插图
看一下红框的位置 , 可以发现可能是配置更新部分有问题 , 因为:

  • 这个地方 Protobuf 特别多的地方 , 在做更新的操作(有MergeFrom , 有Delete)
  • 有大量的用到了std::map(有std::_Rb_tree , 有字符串比较)
通过观察perf结果的方法 , 虽然能够猜测大计算量的位置 , 但是有两个不便之处:
  • 如果 CPU 高的情况发生概率很低 , 人为观察比较耗时
  • 不能明确的知道 , 具体在哪个文件的哪个函数
使用gcore最初统计的时候 , 发现 CPU 高的情况会出现 1 秒多的时间 , 如果发现 CPU 高负载时 , 直接调用gcore {pid}的命令 , 可以保留堆栈信息 , 明确具体高负载的位置 。
将使用 gcore 的指令 , 添加到统计工具中取 , 设置 CPU 上门先触发 。
通过gdb看了几个 coredump 文件 , 发现堆栈和函数调用基本一致 。 可以明确的看到 , 大量的耗时发生在了AddActInfoV3这一函数中:
腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查文章插图
到此位置 , 我们明确了高计算量发生的具体位置 。
风险点CPU 突然飙升是否存在风险呢?是不是计算资源充足的时候 , 就不会有问题呢?
这个例子中 , 使用的是 SPP 微线程功能 , 每个 Worker 进程只启用一个线程 。
腾讯游戏开发工程师:Linux 机器 CPU 毛刺问题排查文章插图