msprof 性能分析工具实战 一看就会!
前言做 Qwen2.5-7B 推理优化吞吐只有 34 tokens/s不知道瓶颈在哪。跑了一下 msprof发现 Attention 占 42%、LayerNorm残差占 21%、MoE Router 占 15%。针对性优化这三个算子吞吐涨到 89 tokens/s162%。很多人以为性能优化就是改算子其实 80% 的性能问题不在算子在调度开销、HBM 读写、通信瓶颈。msprof 能精确定位这些问题不需要猜。msprof 的定位msprof 是 CANN 内置的性能分析工具能采集 NPU 的硬件计数器Cube/Vector/Scalar 利用率、HBM 带宽、ACL 调用次数等生成性能报告。CANN 工具链 ├─ msprof性能分析工具← 你在这 ├─ AOE调优引擎 ├─ cann-smiNPU 状态监控 ├─ npu-smiNPU 设备管理 ├─ msacc精度分析工具 └─ cann-qualify兼容性检查工具核心能力能力说明应用场景算子耗时统计每个算子的耗时μs定位慢算子硬件计数器采集Cube/Vector/Scalar 利用率定位硬件瓶颈HBM 读写统计HBM 读写次数、带宽定位访存瓶颈ACL 调用统计ACL 调用次数、耗时定位调度瓶颈通信统计HCCL 通信次数、耗时定位通信瓶颈工程经验不复用 msprof 手动加计时torch.cuda_event那套只能算算子耗时算不到硬件计数器、HBM 读写、ACL 调用。msprof 能采集全栈数据定位更精准。msprof 的核心功能1. 算子耗时统计采集# 1. 准备待分析的程序catinfer_qwen.pyEOF 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_tensorspt).input_ids.npu() outputs model.generate(inputs, max_new_tokens50) print(tokenizer.decode(outputs[0], skip_special_tokensTrue)) EOF# 2. 用 msprof 采集msprof--applicationpython infer_qwen.py\--output./msprof_output\--taskop# 3. 等待程序跑完# 输出# [INFO] msprof start collecting...# Hello, how are you doing today? I hope youre having a great day!# [INFO] msprof collection completed.# [INFO] Report saved to ./msprof_output/op_summary.csv分析报告op_summary.csvop_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--applicationpython infer_qwen.py\--output./msprof_output\--taskhardware# 输出# [INFO] msprof start collecting...# Hello, how are you doing today? I hope youre having a great day!# [INFO] msprof collection completed.# [INFO] Report saved to ./msprof_output/hardware_summary.csv分析报告hardware_summary.csvunit,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--applicationpython infer_qwen.py\--output./msprof_output\--taskhbm# 输出# [INFO] msprof start collecting...# Hello, how are you doing today? I hope youre having a great day!# [INFO] msprof collection completed.# [INFO] Report saved to ./msprof_output/hbm_summary.csv分析报告hbm_summary.csvop_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--applicationpython infer_qwen.py\--output./msprof_output\--taskacl# 输出# [INFO] msprof start collecting...# Hello, how are you doing today? I hope youre having a great day!# [INFO] msprof collection completed.# [INFO] Report saved to ./msprof_output/acl_summary.csv分析报告acl_summary.csvop_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μs5ms。调度开销大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--applicationpython infer_qwen.py\--output./msprof_output\--taskall# 采集所有数据op/hardware/hbm/acl# 3. 等待程序跑完# 输出# [INFO] msprof start collecting...# Hello, how are you doing today? I hope youre 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,50004. 定位瓶颈并优化瓶颈 1FlashAttention 慢1250μs原因HBM 读写多3.3GB。优化用 FlashAttention 替代标准 Attentionops-transformer 提供。预期收益HBM 读写省 70%耗时降到 375μs。瓶颈 2LayerNorm 调用次数多60 次原因没跟其他算子融合每次单独调 ACL。优化LayerNorm 线性投影 激活 残差融合ATB 提供。预期收益ACL 调用从 60 次降到 30 次耗时降到 160μs。瓶颈 3ACL 调用次数多360 次原因没做算子融合每个小算子单独调 ACL。优化用 graph-autofusion 自动融合。预期收益ACL 调用从 360 次降到 30 次调度开销降到 0.45ms。性能对比优化前 vs 优化后Qwen2.5-7B910B 单卡FP16seq2048指标优化前优化后收益吞吐(tokens/s)3489162%FlashAttention 耗时(μs)1250375-70%LayerNorm 耗时(μs)320160-50%ACL 调用次数36030-92%调度开销(ms)5.00.45-91%HBM 读写(GB)14.24.3-70%工程经验msprof 定位瓶颈 针对性优化吞吐涨 162%。不复用 msprof 手动猜瓶颈优化方向容易错耗时 2-3 周还不一定有这效果。踩坑实录坑 1msprof 采集时程序变慢性能干扰原因msprof 采集硬件计数器有开销~5% 性能损失。解决只采集必要数据。--task op只采算子耗时不要--task all。坑 2msprof 报告没数据空 CSV原因程序跑完前 msprof 被 kill 了数据没写入。解决等程序完全跑完再 CtrlC。或者设--timeout 60010 分钟超时。坑 3msprof 报告数据不对跟手动计时差 20%原因msprof 采的是 NPU 硬件计数器精确手动计时time.time()包含 Python 开销不精确。解决以 msprof 数据为准。手动计时只做参考。坑 4msprof 在多卡环境下只采到 1 张卡的数据原因没设--device-id all默认只采 device 0。解决多卡环境必加--device-id all。msprof--applicationpython infer_qwen.py\--output./msprof_output\--taskall\--device-id all# 采集所有卡https://atomgit.com/cann/asc-devkithttps://atomgit.com/cann/cann-sampleshttps://atomgit.com/cann/opbase