ARTICLE DETAIL

资讯详情

深耕郑州网站建设与运营推广的一线实战洞察。

Linux火焰图实战:从原理到Java性能排查

Linux火焰图实战:从原理到Java性能排查 1. 为什么学了这么多年Linux我还是强烈建议你掌握火焰图大概半年前我接手一个Java线上服务高峰期CPU直接飙到300%以上top命令里看到的是java进程占满但具体是哪段代码在烧CPU完全抓瞎。按老套路先top -Hp 找到线程PID再jstack打印线程栈来回对比十几层调用关系折腾了两个小时定位到的居然是一个已经在凌晨三点修复过的历史问题。那一刻我意识到靠线程栈手工翻堆栈效率太低而且非常依赖经验换一个复杂点的调用链眼睛根本看不过来。后来我才系统地把火焰图这套方法用起来。所谓Linux火焰图是Brendan Gregg发明的一种性能分析可视化方式它把采样到的函数调用堆栈画成一张横向的、像火焰一样的SVG图。每一条火苗就是一个调用栈火苗越宽说明这个函数在采样周期里出现的次数越多也就是CPU时间占比越高。相比vmstat、top这种系统级指标火焰图能直接告诉你CPU时间到底烧在哪个函数、哪条调用链上而且不需要在代码里埋任何点不需要重启进程对线上服务几乎零侵入。如果你日常工作涉及Linux服务性能排查、JVM应用调优、容器化部署后的疑难杂症定位或者是做SRE、运维、后端开发的我强烈建议你把火焰图纳入自己的排查工具箱。它除了能看CPU还能看内存分配、锁竞争、Off-CPU阻塞时间同一个思路能解决好几类问题。这篇文章不是那种贴一堆命令就结束的教程我会把为什么这个参数这么写图上这个形状到底什么含义生成之后怎么看全部讲透最后附上我在真实环境中踩过的坑希望能帮你少走弯路。2. 火焰图的原理其实很简单采样堆栈然后按占比横向堆叠2.1 从一个愚蠢的计时问题说起要理解火焰图先理解它的数据来源。它不需要像很多APM工具那样在代码里埋桩而是用系统的性能计数器周期性地打断CPU记录当前正在执行的函数调用栈。打个比方你在一个工厂里随机按快门拍照拍一万张然后统计每个工位被拍到的次数。哪个工位在照片里出现的频次高就说明哪个工序最耗时。这个思路听上去很简单但非常有效。Linux里干这件事的主角是perf由内核的perf_event子系统提供支持。核心命令是perf record它会按照你指定的频率去采样调用栈。火焰图的横轴不是时间而是采样到的次数占比。注意整个图从头到尾没有时间先后顺序只有占比这一个语义维度。这一点经常被刚接触的人误解老觉得火苗从左到右是时间流动其实不是它是把所有采样到的栈按调用路径做了归类、排序和堆叠。2.2 为什么采样频率喜欢用99Hz你可能在很多教程里看到过perf record -F 99。第一次看的时候我就在想为什么不是100、不是1000偏偏是99。当时觉得这些博主肯定是在装深沉后来查了Brendan Gregg的原话才搞明白这里有个非常隐蔽的坑很多内核的采样定时器或者某些操作系统的心跳本身就是100Hz。如果你也把采样频率设成100Hz就有可能与系统自身的事件产生频率共振beat造成采样结果周期性偏差。比如说你的程序每10毫秒刚好做一次特定操作而采样器恰好也每10毫秒打一次点那这次操作就可能被反复采样或完全漏掉数据严重失真。于是99Hz就成了一种经验默认值它和100Hz错开一点尽量避免整倍数共振。当然如果你的场景需要更细粒度可以提高到499Hz甚至997Hz但没有特殊必要不用上几千赫兹因为采样本身有开销频率越高对目标进程的干扰越大。一般排查CPU问题时99Hz、持续30到60秒已经能拿到足够的样本。2.3 从perf record到SVG的完整链路整个生成过程可以分成三步# 第一步采样采集目标进程的调用栈 perf record -F 99 -p 12345 -g -- sleep 30 # 第二步把perf的原始数据导出成文本格式 perf script out.perf # 第三步把文本堆栈折叠成一行一行的路径 ./stackcollapse-perf.pl out.perf out.folded # 第四步用折叠后的数据生成火焰图SVG ./flamegraph.pl out.folded flamegraph.svg第二步里的out.perf长什么样里面每一行记录是一条采样样本包含进程名、PID、时间戳、以及从内核到用户态的一系列函数符号。第三步的折叠是关键它把每个采样点记录的完整堆栈从栈底到栈顶用分号拼接成一行然后在行尾统计出现次数。比如某个调用路径start_thread;JavaMain;main;run;run0出现了42次最后文件里就是这行加上数字42。第四步的flamegraph.pl会读取每一行和对应的次数按次数比例画横条。整个流程脚本都在Brendan Gregg的GitHub仓库FlameGraph里直接git clone下来就能用不需要编译依赖的只是Perl环境几乎每台Linux都有。2.4 如果没有root权限怎么办这是很多线上环境会遇到的问题。perf record采集全系统调用栈通常需要perf_event_paranoid允许内核默认值往往是2或3普通用户只能采样自己的进程。很多同学第一步就卡在permission denied上。解决办法有三条一是如果你们公司运维可以调内核参数把/proc/sys/kernel/perf_event_paranoid改成-1但这种改动在银行、政企类环境很难申请下来二是用sudo perf直接跑采集完生成的文件归root所有随后chown给普通用户再执行perf script三是用perf record配合--uid或者干脆让当前用户在容器外以root身份跑然后到容器内去分析这个后文讲容器场景时会展开。如果连perf命令都不存在多半是linux-tools-common这类包没装在Ubuntu/Debian上apt install linux-tools-common linux-tools-$(uname -r)能解决。3. 一张图摆在面前到底该看什么3.1 火苗的宽度、高度和颜色分别代表什么火焰图长得很像一场正在燃烧的山火底部是根顶部是叶。底部通常是进程入口或者内核的入口函数比如start_thread、entry_SYSCALL_64_after_hwframe越往上越接近你实际业务代码。每个横条的宽度代表它在总采样样本中出现次数占的比例所以看宽度就知道CPU时间的主要去向。颜色默认是暖色调从黄到红再到紫但它和性能没有直接关系更多是一种视觉分组。比如在Java场景里颜色深浅经常用来区分用户态代码和内核态代码或者按函数名哈希取色方便肉眼区分不同的调用栈。不建议根据颜色深浅来判断热点要看宽度。高度代表调用栈深度。如果整张图看起来是一座又高又窄的塔说明某个路径上函数嵌套很深这种形状经常出现在递归或者层层封装的框架代码里如果是一座又矮又胖的平顶山说明热点集中在少数几层往往可以直接定位到一个函数。3.2 先看顶部再看底部拿到一张火焰图我自己的阅读习惯是从上往下看那些顶部横条特别宽的函数。因为顶部意味着栈顶也就是CPU真正执行到的函数。如果顶部的热点是一个Native Method或者GC相关的函数那瓶颈大概率在JVM内部而不是业务代码如果顶部热点是你自己项目的类恭喜你直接打开源码改就完事了。然后看底部和整体形态。底部如果特别宽说明大量采样都是从底层框架发起的例如Tomcat的Http11Processor处理连接这时候业务代码的优化空间已经被框架主导重点要检查线程模型。再看横向的峡谷火焰图里那些明显的凹陷往往意味着两个热点路径之间存在过渡比如锁等待结束、IO返回具体是哪种得结合Off-CPU火焰图一起判断。3.3 典型形态速查形态特征大概率的含义进一步动作顶部有一个又宽又平的横条某个函数吃掉了大部分CPU打开源码看实现确认是否自旋或者做了大量计算图上出现大量锯齿状细条采样样本偏少或函数符号解析不全提高采样时长或安装符号表某条调用栈像针一样细长该路径只执行了很短时间但嵌套很深可忽略或在Off-CPU图上确认是否和IO阻塞有关整图呈现多个烟囱多个线程并发执行类似逻辑检查线程数与任务切分可能存在锁竞争底部非常宽且顶部很快变窄大范围调用集合到少数热点函数典型的框架封装的聚合优势重点查热点函数入参3.4 一个最容易忽略的细节点击和搜索如果你用浏览器打开生成的SVG你会发现火焰图是可以交互的。点击任意一个横条它会以这个横条为底重新放大看它的完整调用链这个功能在排查多层框架问题时极其好用。要回到完整视图直接点击左上角的Reset Zoom。另外浏览器里按CtrlF搜索函数名SVG会高亮所有带这个名字的横条这个技巧在确认某个工具类是否被大量调用时特别高效。我记得第一次实操时SVG文件有十几MB浏览器一度卡爆后来才反应过来火焰图在采样量很大的情况下SVG节点非常庞大建议先用grep过滤只包含目标关键字的调用栈再生成图。比如只关注某个包下的堆栈grep com.example out.folded out-filter.folded ./flamegraph.pl out-filter.folded filtered.svg4. 一次Java服务CPU飚高的完整定位实例4.1 现场情况和采集参数选择那是一个典型的Spring Boot应用部署在8核16G的容器里流量高峰期CPU超过300%。我先用top确认是java进程拿到PID为11221然后执行perf record -F 99 -p 11221 -g -- sleep 30注意命令最后的-- sleep 30它的意思是让perf record作为采样器sleep 30作为采样持续时间的载体。很多人写成perf record -F 99 -p 11221 -g sleep 30如果sleep放在-p后面会被解析成对进程11221发起sleep信号而不是指定时长这是个容易踩的命令顺序坑。perf record前还有一个-o参数可以指定输出文件名我习惯命名成perf.data.$(date %s)方便保留多份历史数据对比。采样完成后接着走标准流程perf script out.perf ./stackcollapse-perf.pl out.perf out.folded ./flamegraph.pl out.folded flamegraph.svg当时生成的火焰图里顶部出现了一个非常扎眼的宽条com.github.benmanes.caffeine.cache.BoundedLocalCache$BoundedLocalLoadingCache下的一个方法。我第一反应是本地缓存怎么成了CPU热点继续沿火苗往下看发现调用源头是某个定时任务在批量刷新缓存时对单个key执行了成千上万次get每次get又走了Caffeine的异步刷新的复杂分支。优化方案很简单把批量操作改成getAll并且在更新时只向缓存触发一次invalidate落库操作合并成批次。这个修改不到半小时但定位到这一步如果不用火焰图光靠jstack不知道要翻多少遍线程栈。4.2 用Arthas做交叉验证火焰图不背锅这里必须说一个很实际的场景Java应用跑在JVM里很多调用栈扒到JVM内部后函数名是_ZN2...这一类C符号非常难读。如果光看火焰图很容易在JVM内部函数里迷失。我在那次排查里同步用Arthas的thread -n 3看了CPU占用最高的几个线程再对应火焰图的顶部热点两边一交叉确认问题就在缓存刷新线程上不是JVM的GC或者编译器导致的伪热点。这种交叉验证很有必要。火焰图是统计采样它只能说明这段代码大部分时间在被采样不能说明这段代码是因为等待还是计算占的CPU。要区分是计算密集还是阻塞等待可以用Arthas看线程的状态如果是RUNNABLE但火焰图又宽说明纯计算如果是TIMED_WAITING还有其他线索那火焰图顶部的宽条可能只是反映线程反复被唤醒的现场真正的瓶颈在阻塞点这就要用到下一节要讲的Off-CPU火焰图。4.3 修复后对比怎么确认优化有效代码改完之后我重新采样30秒生成一张新的火焰图对比修复前后两版。对比时的标准不是肉眼看图觉得好像窄了一点而是看热点函数的采样占比修复前某个热点函数占大概38%修复后直接降到5%以下整张图的主峰形状都变了。同时配合top看实时CPU使用率确认从300%左右回落到120%以内再观察业务侧请求RT曲线。三份数据一起看才能确定这次优化不是噪声波动而是真实收益。这里建议所有排查性能问题的同学都养成保留前后对比图的习惯。被怀疑的性能问题修复后必须重新出图验证否则就是在盲人摸象有可能你改的代码根本没被采到。以前我就干过这种事优化完自我感觉良好第二天发现同一类问题换个接口又冒出来了就是因为根本没复测。5. 工具链不是只有perf一家的不同语言和场景的选型5.1 一张表看清常见方案火焰图的采集方式非常多很多方案不止能采CPU还能采内存、锁等其他资源。我把常用的列出来工具适用场景采集能力上手难度关注点perf通用LinuxC/C/Java/Go均可CPU、硬件事件、tracepoint中命令原生但Symbol解析需额外处理async-profilerJVM系服务CPU、内存分配、锁竞争低自带Java符号解析能直接生成火焰图ArthasJava服务在线诊断CPU、线程、方法调用耗时低命令行交互不落盘适合临时排查py-spyPython进程CPU低无需修改代码采样性能开销可忽略bpftrace内核定制分析动态追踪高适合深度内核问题不适合日常业务pstack/gdb轻量看线程栈当前时刻栈极低无法生成真正的火焰图只能做瞬间快照再补充一个和网络热词很相关的点很多人搜索arthas火焰图其实Arthas本身不直接输出和flamegraph.pl一样的SVG它是通过profiler命令调用了async-profiler的采集能力。比如在Arthas里执行profiler start -e cpu # 等几十秒 profiler stop --format svg --file /tmp/cpu.svg这个命令生成的SVG和直接用async-profiler生成的大同小异。好处是你不用离开现有的Arthas环境对已经喜欢用Arthas做Java诊断的同学非常友好。5.2 Java服务为什么要优先考虑async-profiler当目标进程是Java时我强烈不建议直接用perf去采而推荐async-profiler。原因是JVM内部有JIT编译、类卸载、栈帧优化纯perf采样到的栈经常是一堆JavaMain、Interpreter的符号根本看不懂。async-profiler自己实现了Java线程栈的获取它通过JVMTI和AsyncGetCallTrace拿到Java层的真实方法名能直接输出方法级别的火焰图。它的命令也非常简洁./profiler.sh -d 30 -o svg -f /tmp/java-cpu.svg 11221-d 30表示采样30秒-o svg指定输出格式-f指定输出文件。async-profiler还支持alloc事件来采样内存分配热点格式是-e alloc支持锁竞争事件-e lock。草根养成的习惯是先看CPU火焰图CPU没问题再看锁火焰图这个顺序基本能覆盖大多数Java线上问题。5.3 大数据场景里的Flink为什么也能用网络热词里出现了flink火焰图其实Flink集群里的性能分析思路和单机Linux没有本质区别只是采样对象从单个PID变成了TaskManager的JVM进程。Flink的TaskManager往往一个节点上跑多个Slot如果你拿top看到某个TaskManager进程CPU飙高先找到进程PID然后在节点上用async-profiler或perf采样定位到具体算子方法。我见过很多Flink作业延迟变大的问题到最后发现是反压导致的死循环式重试火焰图上会有非常典型的宽而高的调用栈形态。再往下追溯就到了AsyncWaitOperator这类异步等待点结合Off-CPU火焰图看阻塞时间基本就能还原完整链路。6. Off-CPU火焰图和连续火焰图CPU之外的另一半故事6.1 为什么只盯着CPU火焰图会漏掉一大半问题CPU火焰图回答的问题是CPU时间花在哪里但线上服务大量问题其实是线程在等待等待IO、等待锁、等待网络返回。这些等待过程CPU几乎为零perf record -F 99根本采不到有效样本因此CPU火焰图会表现为白茫茫一片或者只看到稀稀拉拉几条栈。这时候需要的是Off-CPU火焰图它基于追踪线程被调度出CPU的事件把线程为什么被移出CPU、阻塞了多久画出来。Brendan Gregg的原话是如果只画On-CPU火焰图你只看到了一棵树上的叶子看不到树根的腐烂。常用的采集方法是用perf的sched事件或者offcputime脚本。FlameGraph仓库里自带的offcputime工具可以一条命令生成./offcputime -K -p 11221 -d 30 off.folded ./flamegraph.pl --colorio --titleOff-CPU Time Flame Graph off.folded off.svgOff-CPU图横轴的语义不是CPU时间占比而是线程离开运行的等待时间占比。图上宽的横条代表某段阻塞路径累计等待时间最长。你会清楚看到是卡在FileInputStream.readBytes这种文件IO还是Object.wait这种锁等待还是SocketInputStream.read这种网络IO。接入层服务出问题时这张图往往比CPU图更一针见血。6.2 连续火焰图适合看什么还有一种连续火焰图Flame Graph Over Time本质上是在横轴上加了时间维度把不同时间段的火焰图拼成一张热图纵轴是调用栈横轴是时间颜色深浅表示该时刻的占用强度。它适合看CPU超时段的波形变化比如流量高峰每隔多久波动一次、某个热点函数是不是周期性出现。FlameGraph仓库里有flamegraph.pl --timeline参数可以做简单版本或者用perf timechart导出数据再转换。实际生产中我一般不会一上来就用连续图而是先在单张图上定位了热点函数再用连续图看它的出现规律确认它是持续占CPU还是周期性突发。6.3 在容器环境里的采集姿势现在服务基本都是容器化部署。容器里跑perf record常常因为缺少权限而失败一个非常实用的思路是在宿主机上直接以root运行perf record -g -p 容器内java进程的宿主PID。容器内进程的PID在宿主机上依然可见perf采集到的是这个进程的真实调用栈不会受容器隔离影响。但要注意如果在容器镜像里缺了perf工具在宿主机上用perf采完数据可以把perf.data拷贝到容器内或者用annotate、script在宿主机上分析两者等价。另外在容器里跑Java应用时JIT编译器产生的可执行文件位于临时文件系统里perf找不到符号时会把栈显示成一段地址而不是方法名。解决办法是让JVM禁用Anonymous Classes相关优化或者用async-profiler带上-i参数和--all-user。最省事的方法还是节里写过的在容器内直接用Arthas的profiler命令它不需要额外的系统权限也不依赖宿主机perf。7. 火焰图使用中那几个让我折腾到深夜的坑7.1 采样时长不是越长越好而是越有代表性越好最早用火焰图的时候我犯过一个经典错误为了采样充分直接采10分钟结果图是出了但SVG大得打开都要半分钟而且顶部热点反而被拉平了。原因是长时间采样会把多个阶段的CPU行为混在一起比如前2分钟在做正常业务、后8分钟出现GC风暴混合后的火焰图会呈现出两条热点路径看不出单一阶段的真实瓶颈。我的经验是先观察top里目标进程的CPU占用率是否稳定如果稳定采30-60秒足够如果CPU是周期性波峰就挑波峰出现时同步启动采样用top抓到波峰后立即执行perf record。最好是分多次采样分别覆盖波峰、波谷、常态三个区间生成三张图分别分析。这个习惯帮我解决过不少间歇性问题比一张超长采样图信息量大多了。7.2 函数符号解析看到的全是地址怎么办很多刚上手的朋友会碰到一个更普遍的坑生成的火焰图上大量横条的函数名是一串十六进制地址或者如0x7f34a1d2b8这种。原因很简单采样到进程调用栈时需要把指令地址翻译成函数名翻译靠的是符号表。Linux原生环境下C/C程序编译时如果没有加-g或者没保留符号或者Java的JIT代码没有上报给perf就会出现一堆地址。C/C场景的解法是安装debuginfo包或者编译时打开-g -fno-omit-frame-pointer后者比前者重要得多。很多C项目为了性能优化会默认开-fomit-frame-pointer导致perf采不到栈帧寄存器只能看到零星几条栈。火焰图仓库里有一名专门讲这个的文档如果栈都很浅且全是地址第一反应就应该是检查编译选项别急着怀疑perf工具坏了。Java场景的解法是我前面反复强调的用async-profiler或者Arthasprofiler。实在要用perf可以在启动Java时加上-XX:PreserveFramePointer这样perf能抓到JVM内部C栈和部分Java栈。注意这个参数对性能有微小影响测试环境验证没问题再上生产。7.3 折叠脚本对sh脚本的处理细节stackcollapse-perf.pl对不同的调用栈字符有细微处理比如当进程和线程名里带空格时折叠后的行可能错位。遇到过一两次grep过滤后栈变成乱数据后来才知道perf script输出里第一列是进程名/PID如果进程名里有空格整个行解析就乱了。稳妥的做法是先grep掉以空格开头的行再跑stackcollapse-perf.plperf script | grep -E ^[^ ] [0-9] \[[0-9]\] clean.perf这个过滤可以去掉那些不完整的采样记录让折叠脚本更稳定。另外如果你用容器环境perf script输出里进程名经常是一长串UUID或者哈希值折叠后对不齐这时候可以加一句sed把进程名统一替换成目标名保证折叠脚本正常计数。7.4 误以为自己已经定位到根因的时候先抽根烟这是我最想说的一条经验。火焰图最危险的地方在于它看起来太直观了——一个又宽又亮的横条在图上很容易让人立刻打开源码开始改。但火焰图告诉你的只是热点在这里它没有告诉你为什么在这里。举个例子有一次我定位到一个ConcurrentHashMap.put的热点整个横条宽到霸屏。正常人第一反应是改数据结构或者降低并发度。但我去看了日志后才发现真正的问题是上游调用方在循环里反复调这个接口每次传参都不一样导致缓存失效热点只是个结果。也就是Brendan Gregg说的那句名言采样只能告诉你函数占了多少时间不能告诉你它为什么占这么多时间。每次定位到热点函数后应该做两件事一是读源码看有没有明显的计算浪费二是看调用方是谁为什么在这个时间点调这么频繁。两件事都做了再动手改代码。8. 写在最后我现在的火焰图排查姿势上面这些内容写下来算是把自己折腾火焰图的过程复盘了一遍。如果让我用一句话总结现在的工作流就是先用top和Arthas确认现场再分场景采样优先用async-profiler看Java CPU用perf看系统级调用和内核态热点函数太多或CPU不高但排障无头绪时立刻补一张Off-CPU火焰图找阻塞源最后用前后对比图验证优化效果。日常使用中我最依赖的两个习惯一是每张火焰图都按时间命名并保留原始perf.data方便以后回溯二是看到横条宽度异常时先双击放大看完整调用路径再按CtrlF搜业务关键字确认不是符号乱掉的假数据。这套流程看起来朴素但已经帮我处理过不下几十个线上性能问题成功率相当高。如果你是第一次接触火焰图建议不要一次性学完全部工具先用perf record跑通一张CPU火焰图然后对照本机的一个明显热点函数看几遍。等你对宽条热点建立了直觉再遇到性能问题就会自然地想到这个工具。剩下的就是多踩几次坑、多积累几个案例的事。
返回列表