注意: 本文内容于 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" ]; then
log "错误:未找到 $1"
exit 1
fi
log "正在解压..."
mkdir -p async-profiler
tar -zxvf "$1" --strip-components=1 -C async-profiler
log "解压完成"
}
function configAsyncProfiler() {
log "开始配置环境变量..."
mv async-profiler /usr/local/async-profiler
cat > /etc/profile.d/async-profiler.sh <<EOF
export PATH=\$PATH:/usr/local/async-profiler/bin
EOF
# 刷新环境变量
source /etc/profile.d/async-profiler.sh
log "配置环境变量结束"
}
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/docs/FlamegraphInterpretation.md at master · async-profiler/async-profiler