火焰图分析Java程序瓶颈

发布于:2025-03-17 ⋅ 阅读:(11) ⋅ 点赞:(0)

注意: 本文内容于 2025-03-16 01:13:24 创建,可能不会在此平台上进行更新。如果您希望查看最新版本或更多相关内容,请访问原文地址:火焰图分析Java程序瓶颈。感谢您的关注与支持!

最近手撕的tcp-reverse-proxy,相比nginx来说,高并发时整体吞吐量太差了,需要定位具体的性能损耗点。因此特意了解了下火焰图。

一、火焰图

1.1 概念

火焰图(Flame Graph) 是一种用于可视化性能分析数据的图形化工具,它通过直观的方式展示程序在运行时的资源使用情况(如 CPU 时间、内存分配、I/O 时间等),帮助开发者快速定位性能瓶颈。

1.2 基本构成

火焰图由一个二维坐标系构成

  1. x轴
    • 含义:表示某种资源的占比,如CPU时间、内存大小、IO时间等。
    • 说明:宽度越大、表示该函数消耗的资源越多。
  2. 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/async-profiler: Sampling CPU and HEAP profiler for Java featuring AsyncGetCallTrace + perf_events

async-profiler/docs/FlamegraphInterpretation.md at master · async-profiler/async-profiler

如何读懂火焰图? - 阮一峰的网络日志


网站公告

今日签到

点亮在社区的每一天
去签到