背景用户发现自己的 flink程序出现多个TaskManager cpu使用率相差 10%的现象。他们排除了数据差异TaskManager基本都是相似结构的数据程序处理起来不会有这么大的区别。期待我找出原因这样方便用户规划规模和扩量。排查历程60 秒快速扫描用户做了基本的自查但是并不能作为排查进行的证据先把 flink 的运行指标汇聚到一起进行快速了解。可以看到如下的内容。多个TaskManager cpu使用率出现恒定高低变化。高的一直高低的一直低。高 cpu使用率的heap 内存占用比低cpu 使用率的高。高 cpu使用率的gc 次数比低cpu 使用率的多。两者线程数相同。这里看到内存和 gc 有差异flink 本身没有心跳超时表现直接忽略 gc 时延的影响。转换成gc吞吐两者都是 90 左右影响不大不存在吞吐太低拉长运行时长的情况说明这个现象是状态下的结果不是原因。gc 吞吐的公式如下GC吞吐量 (总时间 - GC总耗时) / 总时间 × 100%jmx 和 gc日志都可以计算出吞吐量只是精度问题日常用jmx 即可并不是只有 gc日志才能计算。profiling经过快速扫描排除了简单的问题场景。cpu 的使用率变化还可能是程序代码本身带来的例如不同的分支处理逻辑不一样。用户代码也是多人开发可能存在理解和实际运行不一致的情况。我们用 jdk 自带的 jfr 进行 oncpu 采集分析看看高cpu和低 cpu 使用率堆栈上的差异。jcmd pid JFR.start duration2m filename/tmp/my.jfr上面是一个采集 2min 的命令。拿到文件先快速统计一下事件差异。这里可以利用jdk 自带的 jfr命令统计。jfr summary my.jfrcpu使用率高的进程采样次数为jdk.ExecutionSample 4261cpu 使用率低的进程采样次数为jdk.ExecutionSample 3773jdk.ExecutionSample只会采集 java代码的堆栈也就是说 cpu 使用率高的程序采样到的 oncpu 的java 代码多。我们需要分析代码上的差异。jfr 的可视化不好可以使用我的火焰图转换工具。# JFR转化火焰图工具经过做火焰图的差分对比发现没有代码路径上的差异堆栈调用基本是等比率增长。排查 jit等比率增长的情况下说明问题已经不是编写出的 java 代码本身了。怀疑热点的代码是否是编译出了相同的机器码。可能是 jit 出来的代码效率不高导致代码跑起来性能不好相同的 cpu 使用率下执行的代码处理的数据少。没有提前开启打印 jit 的参数我们选择 jcmd 导出正在运行的编译情况。jcmd pid Compiler.codelist这里导出的数据很多需要保存到一个文件中。我们可以看到如下内容33566 3 2 org.jsoup.parser.HtmlTreeBuilderState$7.inBodyStartTag(Lorg/jsoup/parser/Token;Lorg/jsoup/parser/HtmlTreeBuilder;)Z [0x00007f55b3ba7190, 0x00007f55b3ba8d60 - 0x00007f55b3bb9e58]这里需要重点看的是第二列表示编译等级。Level编译器特点0解释器无编译纯解释执行1C1无 profiling快速轻量编译2C1轻量 profiling收集基本调用信息3C1完整 profiling收集方法计数、类型统计等4C2最高优化级别基于 level 3 收集的 profiling 数据做激进优化通过对比火焰图的热点方法发现热点方法的编译等级基本是一样的。jdk 也是相同版本及时编译出的代码区别不大。排查cpu虚拟机层已经排除完了最大可能就是 2 个机器上 cpu 执行相同的代码本身有差异。我们使用 perf stat 快速统计。可以看到如下的结果cpu 使用率高的cycles如下频率是2.545 GHz1,809,708,584 cycles # 2.545 GHzcpu 使用率低的cycles如下频率是3.055 GHz2,003,433,272 cycles # 3.055 GHz可以发现两个机器的频率差异比较大。这里破案了频率高的机器执行的速度快从 cpu 使用率低角度看on cpu 的时间少使用率低。这里协调了运维把低频机器剔除TaskManager的表现基本一致了。总结回头看这个排查过程从 Flink 指标面板一路追到 CPU 频率。堆内存和 GC 次数的差异是「高频低利用率」和「低频高利用率」的副产品不是原因。很多人走到这里就会开始调 GC 参数试图让两边的内存曲线对齐。但方向已经错了。火焰图差分显示热点代码等比率增长说明不是某条分支路径在拖后腿。JIT 编译等级一样JDK 版本一样应用层和 JVM 层已经排除。最后两行perf stat的输出摆在面前——2.545 GHz vs 3.055 GHz差距接近 20%。频率低的机器跑同样的指令要花更多的 CPU 时间。我们看到的10% 的 CPU 使用率差异根因就在这里。CPU 使用率本质上是一段时间内 CPU 处于非空闲状态的时间占比无法表达程序处理的快慢。相关链接