msprof 性能分析工具实战 一看就会！

前言

做 Qwen2.5-7B 推理优化，吞吐只有 34 tokens/s，不知道瓶颈在哪。跑了一下 msprof，发现 Attention 占 42%、LayerNorm+残差占 21%、MoE Router 占 15%。针对性优化这三个算子，吞吐涨到 89 tokens/s（+162%）。

很多人以为性能优化就是"改算子"，其实 80% 的性能问题不在算子，在调度开销、HBM 读写、通信瓶颈。msprof 能精确定位这些问题，不需要猜。

msprof 的定位

msprof 是 CANN 内置的性能分析工具，能采集 NPU 的硬件计数器（Cube/Vector/Scalar 利用率、HBM 带宽、ACL 调用次数等），生成性能报告。

CANN 工具链： ├─ msprof（性能分析工具）← 你在这 ├─ AOE（调优引擎） ├─ cann-smi（NPU 状态监控） ├─ npu-smi（NPU 设备管理） ├─ msacc（精度分析工具） └─ cann-qualify（兼容性检查工具）

核心能力：

工程经验：不复用 msprof 手动加计时（torch.cuda_event那套），只能算算子耗时，算不到硬件计数器、HBM 读写、ACL 调用。msprof 能采集全栈数据，定位更精准。

msprof 的核心功能

1. 算子耗时统计

采集：

# 1. 准备待分析的程序cat>infer_qwen.py<<EOF import torch from transformers import AutoModelForCausalLM, AutoTokenizer model = AutoModelForCausalLM.from_pretrained("qwen2.5-7b").npu() tokenizer = AutoTokenizer.from_pretrained("qwen2.5-7b") inputs = tokenizer("Hello, ", return_tensors="pt").input_ids.npu() outputs = model.generate(inputs, max_new_tokens=50) print(tokenizer.decode(outputs[0], skip_special_tokens=True)) EOF# 2. 用 msprof 采集msprof--application"python infer_qwen.py"\--output./msprof_output\--taskop# 3. 等待程序跑完# 输出：# [INFO] msprof start collecting...# Hello, how are you doing today? I hope you're having a great day!# [INFO] msprof collection completed.# [INFO] Report saved to ./msprof_output/op_summary.csv

分析报告（op_summary.csv）：

op_name,op_type,avg_time(us),call_count,total_time(us) FlashAttention,Attention,1250,30,37500 LayerNorm,LayerNorm,320,60,19200 FFN,GEMM,890,30,26700 MoERouter,Routing,180,30,5400 Softmax,Activation,45,60,2700 ...

解读：

• FlashAttention 平均耗时 1250μs，占比最大（42%），优先优化。
• LayerNorm 平均耗时 320μs，次数多（60 次），考虑跟其他算子融合。
• MoERouter 平均耗时 180μs，占比 15%，考虑用融合算子。

2. 硬件计数器采集

采集：

# 用 msprof 采集硬件计数器msprof--application"python infer_qwen.py"\--output./msprof_output\--taskhardware# 输出：# [INFO] msprof start collecting...# Hello, how are you doing today? I hope you're having a great day!# [INFO] msprof collection completed.# [INFO] Report saved to ./msprof_output/hardware_summary.csv

分析报告（hardware_summary.csv）：

unit,utilization(%),bandwidth(GB/s) Cube,91,890 Vector,67,340 Scalar,12,45 HBM,78,910 L1,89,1200 UB,92,1500

解读：

• Cube 利用率 91%（高），没有瓶颈。
• Vector 利用率 67%（中），可能有优化空间（比如 Vector 算子融合）。
• HBM 带宽利用率 78%（中），可能 HBM 读写多（考虑算子融合，减少 HBM 读写）。

工程经验：Cube 利用率 < 70%，说明 Tiling 不对（tile 大小没装满 MAC 阵列）。要调大 tile_m/tile_n。Vector 利用率 < 50%，说明 Vector 算子没融合（小算子多，调度开销大）。

3. HBM 读写统计

采集：

# 用 msprof 采集 HBM 读写msprof--application"python infer_qwen.py"\--output./msprof_output\--taskhbm# 输出：# [INFO] msprof start collecting...# Hello, how are you doing today? I hope you're having a great day!# [INFO] msprof collection completed.# [INFO] Report saved to ./msprof_output/hbm_summary.csv

分析报告（hbm_summary.csv）：

op_name,op_type,hbm_read(GB),hbm_write(GB),total_hbm(GB) FlashAttention,Attention,2.1,1.2,3.3 LayerNorm,LayerNorm,0.8,0.8,1.6 FFN,GEMM,1.5,0.9,2.4 MoERouter,Routing,0.3,0.2,0.5 ... Total,,,14.2

解读：

• FlashAttention HBM 读写 3.3GB（占 23%），优化空间大（用 FlashAttention 替代标准 Attention，省 70% HBM 读写）。
• Total HBM 读写 14.2GB，优化后应该 < 4.3GB（省 70%）。

4. ACL 调用统计

采集：

# 用 msprof 采集 ACL 调用msprof--application"python infer_qwen.py"\--output./msprof_output\--taskacl# 输出：# [INFO] msprof start collecting...# Hello, how are you doing today? I hope you're having a great day!# [INFO] msprof collection completed.# [INFO] Report saved to ./msprof_output/acl_summary.csv

分析报告（acl_summary.csv）：

op_name,op_type,acl_call_count,acl_total_time(us) FlashAttention,Attention,30,450 LayerNorm,LayerNorm,60,900 FFN,GEMM,30,350 MoERouter,Routing,30,200 ... Total,,,360,5000

解读：

• Total ACL 调用 360 次，总耗时 5000μs（5ms）。
• 调度开销大（5ms），考虑算子融合（把多个算子融合成 1 个，ACL 调用降到 30 次，调度开销降到 0.45ms）。

工程经验：ACL 调用次数 > 100 次，调度开销 > 2ms，必做算子融合。不复用算子融合，调度开销吃掉 20-30% 性能。

msprof 的使用流程

1. 安装 msprof

# msprof 已内置在 CANN 里，不需要单独安装# 确认 msprof 可用msprof--version# 输出：# msprof 6.0.0# Copyright (C) 2024 Huawei Technologies Co., Ltd.

2. 采集性能数据

# 1. 准备待分析的程序（infer_qwen.py）# ...（见上文）# 2. 用 msprof 采集（全量采集）msprof--application"python infer_qwen.py"\--output./msprof_output\--taskall# 采集所有数据（op/hardware/hbm/acl）# 3. 等待程序跑完# 输出：# [INFO] msprof start collecting...# Hello, how are you doing today? I hope you're having a great day!# [INFO] msprof collection completed.# [INFO] Report saved to ./msprof_output/

3. 分析性能报告

# 1. 查看算子耗时cat./msprof_output/op_summary.csv|sort-k4-nr|head-10# 输出（按 total_time 降序）：# FlashAttention,Attention,1250,30,37500# FFN,GEMM,890,30,26700# LayerNorm,LayerNorm,320,60,19200# ...# 2. 查看硬件计数器cat./msprof_output/hardware_summary.csv# 输出：# Cube,91,890# Vector,67,340# ...# 3. 查看 HBM 读写cat./msprof_output/hbm_summary.csv|tail-1# 输出：# Total,,,14.2# 4. 查看 ACL 调用cat./msprof_output/acl_summary.csv|tail-1# 输出：# Total,,,360,5000

4. 定位瓶颈并优化

瓶颈 1：FlashAttention 慢（1250μs）

• 原因：HBM 读写多（3.3GB）。
• 优化：用 FlashAttention 替代标准 Attention（ops-transformer 提供）。
• 预期收益：HBM 读写省 70%，耗时降到 375μs。

瓶颈 2：LayerNorm 调用次数多（60 次）

• 原因：没跟其他算子融合，每次单独调 ACL。
• 优化：LayerNorm + 线性投影 + 激活 + 残差融合（ATB 提供）。
• 预期收益：ACL 调用从 60 次降到 30 次，耗时降到 160μs。

瓶颈 3：ACL 调用次数多（360 次）

• 原因：没做算子融合，每个小算子单独调 ACL。
• 优化：用 graph-autofusion 自动融合。
• 预期收益：ACL 调用从 360 次降到 30 次，调度开销降到 0.45ms。

性能对比

优化前 vs 优化后（Qwen2.5-7B，910B 单卡，FP16，seq=2048）：

工程经验：msprof 定位瓶颈 + 针对性优化，吞吐涨 162%。不复用 msprof 手动猜瓶颈，优化方向容易错，耗时 2-3 周还不一定有这效果。

踩坑实录

坑 1：msprof 采集时程序变慢（性能干扰）

原因：msprof 采集硬件计数器有开销（~5% 性能损失）。

解决：只采集必要数据。--task op（只采算子耗时），不要--task all。

坑 2：msprof 报告没数据（空 CSV）

原因：程序跑完前 msprof 被 kill 了，数据没写入。

解决：等程序完全跑完再 Ctrl+C。或者设--timeout 600（10 分钟超时）。

坑 3：msprof 报告数据不对（跟手动计时差 20%）

原因：msprof 采的是 NPU 硬件计数器（精确），手动计时（time.time()）包含 Python 开销（不精确）。

解决：以 msprof 数据为准。手动计时只做参考。

坑 4：msprof 在多卡环境下只采到 1 张卡的数据

原因：没设--device-id all（默认只采 device 0）。

解决：多卡环境必加--device-id all。

msprof--application"python infer_qwen.py"\--output./msprof_output\--taskall\--device-id all# 采集所有卡

https://atomgit.com/cann/asc-devkit

https://atomgit.com/cann/cann-samples

https://atomgit.com/cann/opbase