Async Profiler案例

Async Profiler 实战案例详解

环境准备

# 安装 async-profiler
curl -L https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.9/async-profiler-2.9-linux-x64.tar.gz | tar xz
cd async-profiler-2.9-linux-x64
# 或者使用 jatt 简化版本
# jatt 是一个封装了 async-profiler 的 Docker 镜像，支持容器化使用

案例一：CPU 火焰图分析

场景：电商系统订单处理性能瓶颈

问题现象：订单创建接口响应时间从 100ms 增长到 5s

# 1. 启动 Java 应用（带 JVM 参数）
java -Xms2g -Xmx2g -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints \
     -jar order-service.jar
# 2. 获取进程 PID
jps -l
# 输出：12345 order-service.jar
# 3. 采集 CPU 火焰图（30秒）
./profiler.sh -d 30 -e cpu -f /tmp/cpu_analysis.html 12345
# 4. 采集并随时中断
./profiler.sh -d 30 -e cpu -o collapsed -f /tmp/cpu_analysis.txt 12345
# 5. 生成火焰图(如果使用 html 输出已包含火焰图，如果需要单独生成)
# 可使用 https://www.speedscope.app/ 打开或使用 FlameGraph 工具

查看火焰图关键节点：

• 顶部宽阔区域：OrderServiceImpl.createOrder()
• 从调用链中发现：OrderServiceImpl.calculatePrice() 占据 60% 采样

问题定位：

// 问题代码 - 计算价格逻辑
public BigDecimal calculatePrice(Order order) {
    // 问题：遍历所有历史订单来计算平均价格
    BigDecimal avgPrice = BigDecimal.ZERO;
    int count = 0;
    for (Order historyOrder : orderRepository.findAll()) { // 全表扫描！
        avgPrice = avgPrice.add(historyOrder.getPrice());
        count++;
    }
    return avgPrice.divide(BigDecimal.valueOf(count));
}

解决方案：

// 优化后：使用数据库聚合查询
public BigDecimal calculatePrice(Order order) {
    return orderRepository.getAveragePrice(); // 使用 AVG() SQL
}

结果：接口响应时间从 5s 降至 120ms

---

案例二：内存分配分析

场景：内存溢出（OOM）排查

问题现象：服务频繁 Full GC，内存占用持续上升

# 1. 采集内存分配火焰图
./profiler.sh -d 60 -e alloc -f /tmp/alloc_analysis.html 12345
# 2. 分析对象分配热点
./profiler.sh -d 60 -e alloc -o collapsed -f /tmp/alloc_analysis.txt 12345

发现内存泄漏来源： 火焰图显示 UserService.getUserInfo() 大量分配 byte[]

问题定位：

public class UserService {
    private static Map<String, byte[]> userCache = new HashMap<>();
    public byte[] getUserInfo(String userId) {
        // 问题：缓存永远不会被清除
        if (!userCache.containsKey(userId)) {
            byte[] userData = loadUserData(userId);
            userCache.put(userId, userData);
        }
        return userCache.get(userId);
    }
}

解决方案：

public class UserService {
    private static Cache<String, byte[]> userCache = Caffeine.newBuilder()
        .maximumSize(10000)
        .expireAfterWrite(30, TimeUnit.MINUTES)
        .build();
    public byte[] getUserInfo(String userId) {
        return userCache.get(userId, this::loadUserData);
    }
}

---

案例三：锁竞争分析

场景：高并发下线程阻塞

问题现象：系统吞吐量低，线程大量 BLOCKED

# 1. 采集锁竞争火焰图
./profiler.sh -d 30 -e lock -f /tmp/lock_analysis.html 12345
# 2. 查看线程状态
jstack 12345 > thread_dump.txt
grep -A 5 "BLOCKED" thread_dump.txt | head -20

锁竞争热点： 火焰图显示大量时间花在 synchronized (InventoryService.class)

问题代码：

public class InventoryService {
    private static final Object lock = new Object();
    public void deductStock(int productId, int quantity) {
        synchronized (lock) { // 问题：全局锁，所有商品共用
            int stock = getStockFromDB(productId);
            if (stock >= quantity) {
                updateStock(productId, stock - quantity);
            }
        }
    }
}

优化方案：

public class InventoryService {
    private final ConcurrentHashMap<Integer, Object> locks = new ConcurrentHashMap<>();
    public void deductStock(int productId, int quantity) {
        Object productLock = locks.computeIfAbsent(productId, k -> new Object());
        synchronized (productLock) { // 按商品粒度加锁
            int stock = getStockFromDB(productId);
            if (stock >= quantity) {
                updateStock(productId, stock - quantity);
            }
        }
    }
}

---

案例四：I/O 等待分析

场景：数据库调用频繁

问题现象：应用 CPU 使用率低，但请求响应慢

# 1. 分析 I/O 等待
./profiler.sh -d 30 -e wall -f /tmp/io_analysis.html 12345
# 2. 对比 CPU 和 Wall 时间
./profiler.sh -d 30 -e cpu -f /tmp/cpu_profile.html 12345
./profiler.sh -d 30 -e wall -f /tmp/wall_profile.html 12345

问题定位：

• CPU 火焰图：显示 run() 使用 CPU 不多
• Wall 火焰图：大量时间在 UserRepository.findById() 等待 I/O

解决方案：添加 Redis 缓存

@Cacheable(value = "user", key = "#userId")
public User getUserById(String userId) {
    // 减少数据库查询次数
    return userRepository.findById(userId);
}

---

案例五：JVM 启动阶段分析

场景：应用启动慢

# 1. 启动时采集
./profiler.sh -d 30 -e cpu -f /tmp/startup_cpu.html -p $JAVA_PID
# 2. 分析启动过程中的热点
./profiler.sh -e class -d 30 -f /tmp/class_load.html 12345

启动优化点：

• 类加载瓶颈：找到加载时间最长的类
• XML/Properties 解析：Spring 配置加载优化
• 数据库连接池初始化：延迟初始化

---

最佳实践总结

常用命令组合

# CPU 性能分析
./profiler.sh -d 60 -e cpu -f /tmp/cpu.html 12345
# 内存分配分析（找到垃圾回收的根源）
./profiler.sh -d 60 -e alloc -f /tmp/alloc.html 12345
# 锁竞争分析
./profiler.sh -d 60 -e lock -f /tmp/lock.html 12345
# Wall 时间分析（包含等待 I/O 的时间）
./profiler.sh -d 60 -e wall -f /tmp/wall.html 12345
# 多种事件联合分析
./profiler.sh -d 60 -e cpu,alloc,lock -f /tmp/multi.html 12345

解读技巧

火焰图形状	含义	建议
顶部平坦且宽	该函数占用大量时间	优先优化
"烟囱"形状	存在深度递归	检查算法复杂度
底部连续分区	等待锁或 I/O	检查并发设计
不规则锯齿	GC 或类加载	检查内存使用

性能优化优先级

1. 数据库查询（N+1 问题，缺少索引）
2. 序列化/反序列化（JSON/XML 大对象）
3. 同步块（减小锁粒度）
4. 内存分配（避免频繁创建大对象）

避免常见误区

• ❌ 只分析生产环境：尽量在压测环境模拟
• ❌ 只看 CPU 场景：需要结合内存、锁、I/O
• ❌ 过度优化：优先优化明显的瓶颈
• ❌ 忽略 GC 日志：结合 -Xlog:gc 分析

---

实战排查清单

# 当性能问题发生时，按此顺序排查：
1. jps -l # 确认进程PID
2. top -Hp $PID # 查看线程CPU使用
3. ./profiler.sh -d 30 -e cpu -f /tmp/cpu.html $PID  # CPU分析
4. ./profiler.sh -d 30 -e alloc -f /tmp/alloc.html $PID  # 内存分析
5. jstack $PID # 线程状态快照
6. jstat -gcutil $PID 1000 # GC 实时监控
7. ./profiler.sh -d 30 -e lock -f /tmp/lock.html $PID  # 锁分析

关键提示：Async Profiler 是性能分析利器，但数据解读和业务理解才是解决问题的核心，遇到性能问题，先假设，用数据验证，再优化，最后回归测试验证效果。