注意: 本文内容于 2025-03-16 01:13:24 创建,可能不会在此平台上进行更新。如果您希望查看最新版本或更多相关内容,请访问原文地址:火焰图分析Java程序瓶颈。感谢您的关注与支持!
最近手撕的tcp-reverse-proxy,相比nginx来说,高并发时整体吞吐量太差了,需要定位具体的性能损耗点。因此特意了解了下火焰图。
一、火焰图
1.1 概念
火焰图(Flame Graph) 是一种用于可视化性能分析数据的图形化工具,它通过直观的方式展示程序在运行时的资源使用情况(如 CPU 时间、内存分配、I/O 时间等),帮助开发者快速定位性能瓶颈。
1.2 基本构成
火焰图由一个二维坐标系构成
- x轴
- 含义:表示某种资源的占比,如CPU时间、内存大小、IO时间等。
- 说明:宽度越大、表示该函数消耗的资源越多。
- y轴
- 含义:表示调用栈的深度。
- 说明:顶层是实际执行函数,下层是调用顶层的函数。
二、async-profiler
针对Java程序,如果想要生成火焰图,通过JDK自带的jstack与fastthread即可生成。但是这个过程太过麻烦。
在实际中,更推荐使用轻量工具async-profiler
2.1 安装
配置bash脚本,直接运行
#!/usr/bin/env bash
set -e# 日志打印函数
function log() {echo "$(date +"%Y-%m-%d %H:%M:%S"): $1"
}function downloadAsyncProfiler() {log "正在下载..."curl -k -L -o async-profiler.tgz "https://github.com/async-profiler/async-profiler/releases/download/v3.0/async-profiler-3.0-linux-x64.tar.gz"log "下载完成"
}function decompressAsyncProfiler() {if [ ! -f "$1" ]; thenlog "错误:未找到 $1"exit 1filog "正在解压..."mkdir -p async-profilertar -zxvf "$1" --strip-components=1 -C async-profilerlog "解压完成"
}function configAsyncProfiler() {log "开始配置环境变量..."mv async-profiler /usr/local/async-profilercat > /etc/profile.d/async-profiler.sh <<EOF
export PATH=\$PATH:/usr/local/async-profiler/bin
EOF# 刷新环境变量source /etc/profile.d/async-profiler.shlog "配置环境变量结束"
}downloadAsyncProfiler
decompressAsyncProfiler async-profiler.tgz
configAsyncProfiler
运行asprof -v
2.2 解读火焰图
该内容摘自async-profiler/docs/FlamegraphInterpretation.md at master · async-profiler/async-profiler
1.) 首先是示例代码
main() {// 一些业务逻辑func3() {// 一些业务逻辑func7();}// 一些业务逻辑func4();// 一些业务逻辑func1() {// 一些业务逻辑func5();}// 一些业务逻辑func2() {// 一些业务逻辑func6() {// 一些业务逻辑func8(); // 这里是 CPU 密集型工作}
}
2.) asprof进行采样。每秒采样一次样本,每次采样时,都会保存其当前调用堆栈,如下图。
3.) 对采样数据进行分类。由上图采样结果可得。
- func3()->func7():3 样本
- func4(): 1 样本
- func1()->func5():2 样本
- func2()->func6()->func8():4 样本
- func2()->func6(): 1 样本
4.) 排序,由按照字母排序,排序优先级由底层到上层。
5.) 聚合。将深度相同的函数拼成一块,获得聚合视图。
6.) 解读。在此示例中
- func4、func5、func6、func7、func8都是实际消耗资源的函数。
- 在实际开发中,像func4这类是比较接近底层的函数。这种底层的优化,我们可以暂时忽略。主要关注顶层优化,也就是像func8这种。
另外asprof生成的火焰图,也有颜色说明。如下
2.3 生成火焰图
以下火焰图的生成,是基于我手撕的tcp-reverse-proxy。
运行java程序后,执行命令ps -ef|grep java
可以获取PID。
详细的分析模式,可以自行查阅官方文档Profiling modes。
下面只记录常用的分析模式。
2.3.1 CPU
运行命令,采集30秒目标进程(PID为111)的CPU占用情况
asprof -d 30 -f cpu.html 111
搜索我的包名top.meethigehr
,通过火焰图,呈现为紫色,可以定位到以下两个函数还是可以进一步优化的。
分别是如下这两个函数
/*** 判断是否是逐跳标头。* hopByHopHeaders是固定值,我在此处使用的是数组* 可以考虑改用Set.contains,但是忽略大小写呢?*/
protected boolean isHopByHopHeader(String headerName) {for (String hopByHopHeader : hopByHopHeaders) {if (hopByHopHeader.equalsIgnoreCase(headerName)) {return true;}}return false;
}
/*** 获取代理后的完整proxyUrl,不区分代理目标路径是否以/结尾。* 处理逻辑为删除掉匹配的路径,并将剩下的内容追加到代理目标路径后面。*/
protected String getProxyUrl(RoutingContext ctx, HttpServerRequest serverReq, HttpServerResponse serverResp) {String targetUrl = getContextData(ctx, P_TARGET_URL).toString();// 不区分targetUrl是否以/结尾,均以targetUrl不带/来处理if (targetUrl.endsWith("/")) {targetUrl = targetUrl.substring(0, targetUrl.length() - 1);}// 在vertx中,uri表示hostPort后面带有参数的地址。而这里的uri表示不带有参数的地址。final String uri = serverReq.path();final String params = serverReq.uri().replace(uri, "");// 若不是多级匹配,则直接代理到目标地址。注意要带上请求参数if (!getContextData(ctx, P_SOURCE_URL).toString().endsWith("*")) {return targetUrl + params;}String matchedUri = ctx.currentRoute().getPath();if (matchedUri.endsWith("/")) {matchedUri = matchedUri.substring(0, matchedUri.length() - 1);}String suffixUri = uri.replace(matchedUri, "");// 代理路径尾部与用户初始请求保持一致if (uri.endsWith("/") && !suffixUri.endsWith("/")) {suffixUri = suffixUri + "/";}if (!uri.endsWith("/") && suffixUri.endsWith("/")) {suffixUri = suffixUri.substring(0, suffixUri.length() - 1);}// 因为targetUrl后面不带/,因此后缀需要以/开头if (!suffixUri.isEmpty() && !suffixUri.startsWith("/")) {suffixUri = "/" + suffixUri;}return targetUrl + suffixUri + params;
}
2.3.2 内存
运行命令,采集30秒目标进程(PID为111)的内存分配情况
asprof -d 30 -e alloc -f mem.html 111
搜索我的包名top.meethigher
,通过火焰图,呈现为紫色,矛头还是直指top.meethigher.proxy.http.ReverseHttpProxy#getProxyUrl
,他居然平分了我一个函数的一半内存,比vertx内存占用还要高。
2.3.3 锁消耗/锁等待
运行命令,采集30秒目标进程(PID为111)的锁占用的状态
asprof -d 30 -e lock -f lock.html 111
2.3.4 I/O时间
运行命令,采集30秒目标进程(PID为111)的运行延时状况
asprof -d 30 -e wall -f lock.html 111
可以看到更多的时间,还是花在write上了。
三、参考
async-profiler/async-profiler: Sampling CPU and HEAP profiler for Java featuring AsyncGetCallTrace + perf_events
async-profiler/docs/FlamegraphInterpretation.md at master · async-profiler/async-profiler
如何读懂火焰图? - 阮一峰的网络日志