CANN Profiling 与性能分析：定位训练与推理瓶颈

一、为什么需要 Profiling1.1 性能问题的来源深度学习训练和推理的性能瓶颈可能来自多个环节数据准备慢导致 GPU 空闲、模型算子计算慢成为瓶颈、内存拷贝频繁拖累整体、通信带宽受限拖慢分布式训练。不同瓶颈的优化方法完全不同错误的优化方向不仅浪费 effort还可能引入新的问题。Profiling 的目的是先定位再优化用数据说话而非凭直觉猜测。1.2 CANN Profiling 工具链┌──────────────────────────────────────────────────┐ │ CANN Profiling 工具链 │ ├──────────────────────────────────────────────────┤ │ ascend-snCLI工具 │ │ ├── report生成性能报告 │ │ ├── analyze分析瓶颈 │ │ └── compare对比两次运行 │ │ │ │ ProfilerPython接口 │ │ ├── start/stop控制采集 │ │ ├── export导出数据 │ │ └── view可视化 │ └──────────────────────────────────────────────────┘1.3 Profiling 能解决什么问题问题场景Profiling 能发现训练速度低于预期数据加载瓶颈、算子耗时分布多卡训练加速比低通信时间占比、负载均衡问题推理延迟高哪些算子最耗时、显存拷贝开销显存占用异常哪些算子占用最多显存新优化效果不明显优化前后对比量化差异二、基础 Profiling 配置2.1 环境变量配置Profiling 通过环境变量控制采集范围和输出路径8.1 及之前基础配置# 启用 Profiling只采集算子执行时间exportASCEND_PROFILING_ENABLE1exportASCEND_PROFILING_OUTPUT_PATH/workspace/profiling_data# 运行训练python train.py8.2 新增精细化配置# 启用完整 Profiling算子通信内存exportASCEND_PROFILING_ENABLE1exportASCEND_PROFILING_OUTPUT_PATH/workspace/profiling_data# 采样配置exportASCEND_PROFILING_FREQ1000# 采样频率exportASCEND_PROFILING_TRACE_LEVEL3# 跟踪级别1-3# 关键算子采集减少数据量exportASCEND_PROFILING_OP_LISTMatMul,Conv2d,LayerNorm# 通信 ProfilingexportASCEND_HCCL_PROFILING_ENABLE1# 内存 ProfilingexportASCEND_MEMORY_PROFILING_ENABLE1python train.py2.2 Profiler Python 接口基础采集fromascend.profilerimportProfiler,ProfilerConfig# 配置 ProfilerconfigProfilerConfig(output_path/workspace/profiling,trace_ops[MatMul,Conv2d,LayerNorm,Softmax],enable通信True,# 8.2 新增enable_memoryTrue,# 8.2 新增sample_interval100# 采样间隔微秒)profilerProfiler(config)# 采集训练forepochinrange(num_epochs):profiler.start()forbatchindataloader:outputmodel(batch)lossloss_fn(output,target)loss.backward()optimizer.step()profiler.stop()# 每个 epoch 采集一次profiler.save()print(fProfiling data saved to{config.output_path})2.3 关键指标解读Profiling 输出的核心指标指标含义健康范围GPUTime算子实际执行时间-HostTime数据准备时间应远小于 GPUTimeCalls算子调用次数-AvgTime平均单次执行时间-InputSize输入数据大小-OutputSize输出数据大小-算子级别耗时分布示例算子 调用次数 总耗时 平均耗时 占比 MatMul 1,024 2,048ms 2.0ms 38.2% Conv2d 512 1,024ms 2.0ms 19.1% LayerNorm 512 768ms 1.5ms 14.3% Softmax 256 512ms 2.0ms 9.5% ReLU 1,024 256ms 0.25ms 4.8%三、训练 Profiling 分析3.1 数据加载瓶颈诊断训练中数据加载常成为瓶颈使用 Profiler 区分计算和数据准备时间fromascend.profilerimportProfiler profilerProfiler(output_path/workspace/profiling)forbatch_idx,batchinenumerate(dataloader):data_starttime.time()# 数据传输到 NPUdata,targetbatch[input].npu(),batch[label].npu()data_timetime.time()-data_start# 模型计算profiler.start_op(forward)outputmodel(data)lossloss_fn(output,target)profiler.stop_op(forward)profiler.start_op(backward)loss.backward()profiler.stop_op(backward)profiler.start_op(optimizer)optimizer.step()profiler.stop_op(optimizer)# 记录数据加载时间profiler.log_metric(data_time,data_time)ifbatch_idx%1000:print(profiler.summary())8.1 vs 8.2 数据加载瓶颈对比配置数据时间计算时间瓶颈8.1 单线程 DataLoader45ms55ms数据8.2 num_workers812ms55ms计算8.2 prefetch28ms55ms计算3.2 算子耗时分析定位最耗时的算子是优化的第一步# 运行 Profiling 并生成报告python train.py--profile# 生成算子级分析报告ascend-sn analyze\--input/workspace/profiling\--output/workspace/profiling/report.html\--op_time_threshold1.0# 只显示耗时 1ms 的算子# 打开报告open/workspace/profiling/report.html8.2 新增算子融合分析# 分析算子融合效果ascend-sn analyze\--input/workspace/profiling\--fusion_reportTrue# 生成融合分析报告# 输出示例算子融合分析: Conv2d BiasAdd ReLU → fused_ops 融合率:78% 融合前耗时: 512ms 融合后耗时: 410ms 节省: 102ms(19.9%)3.3 显存瓶颈分析8.2 新增显存 Profiling追踪各算子的显存占用exportASCEND_MEMORY_PROFILING_ENABLE1python train.py# 生成显存分析报告ascend-sn analyze\--input/workspace/profiling\--memory_reportTrue显存分析报告示例算子 保留显存 峰值显存 申请次数 MatMul 1.2 GB 1.5 GB 1,024 Embedding 0.8 GB 0.8 GB 1 LayerNorm 0.4 GB 0.6 GB 512 总显存 2.4 GB 2.8 GB显存热点定位# 代码中添加显存追踪forname,moduleinmodel.named_modules():ifisinstance(module,nn.Linear):# 追踪某一层的显存占用memory_beforetorch.npu.max_memory_allocated()outputmodule(input)memory_aftertorch.npu.max_memory_allocated()print(f{name}:{memory_after-memory_before:.2f}MB)四、通信 Profiling多卡训练4.1 HCCL 通信分析多卡训练中通信往往是性能瓶颈需要 Profiling 区分计算和通信时间8.1 及之前粗粒度# 只能看到总时间无法区分计算和通信exportHCCL_TRACE_LEVEL1python train.py8.2 新增细粒度通信分析# 开启 HCCL 详细 ProfilingexportHCCL_TRACE_LEVEL3exportHCCL_PROFILING_OUTPUT/workspace/hccl_profiling python train.py# 生成通信分析报告ascend-sn analyze\--input/workspace/hccl_profiling\--comm_reportTrue通信分析报告通信原语 调用次数 总耗时 平均耗时 通信占比 AllReduce 512 1,024ms 2.0ms 32.5% Broadcast 128 256ms 2.0ms 8.1% AllGather 64 128ms 2.0ms 4.1% 总通信时间 44.7%4.2 通信瓶颈诊断流程# 在训练循环中添加时间戳记录importtimeforbatchindataloader:step_starttime.time()# 数据加载data_loading_timetime.time()-step_start# 前向forward_starttime.time()outputmodel(data)lossloss_fn(output,target)forward_timetime.time()-forward_start# 反向backward_starttime.time()loss.backward()backward_timetime.time()-backward_start# 通信同步comm_starttime.time()torch.distributed.all_reduce(gradients)comm_timetime.time()-comm_start# optimizeroptimizer_starttime.time()optimizer.step()optimizer_timetime.time()-optimizer_start total_timetime.time()-step_startiflocal_rank0:print(f Step{batch_idx}: Data:{data_loading_time:.3f}s ({data_loading_time/total_time*100:.1f}%) Forward:{forward_time:.3f}s ({forward_time/total_time*100:.1f}%) Backward:{backward_time:.3f}s ({backward_time/total_time*100:.1f}%) Comm:{comm_time:.3f}s ({comm_time/total_time*100:.1f}%) Optimizer:{optimizer_time:.3f}s ({optimizer_time/total_time*100:.1f}%) )通信占比诊断标准通信占比结论优化方向 15%正常计算瓶颈优化算子15-30%轻微通信瓶颈梯度压缩 30%严重通信瓶颈通信优化或并行策略调整 50%极严重重新设计并行策略五、推理 Profiling 分析5.1 推理延迟分解推理优化前需要知道时间花在哪里importtimeclassInferenceProfiler:def__init__(self,model):self.modelmodel self.timings{}defprofile(self,input_data,num_runs100):# 预热for_inrange(10):_self.model.predict(input_data)# 正式测试for_inrange(num_runs):starttime.time()# 数据拷贝copy_starttime.time()input_npuinput_data.npu()copy_timetime.time()-copy_start# 模型推理infer_starttime.time()outputself.model.predict(input_npu)infer_timetime.time()-infer_start# 结果拷贝output_copy_starttime.time()output_cpuoutput.cpu()output_copy_timetime.time()-output_copy_start totaltime.time()-start self.timings[copy]self.timings.get(copy,0)copy_time self.timings[inference]self.timings.get(inference,0)infer_time self.timings[output_copy]self.timings.get(output_copy,0)output_copy_time# 统计nnum_runsprint(f 推理延迟分解{n}次平均: 数据拷贝:{self.timings[copy]/n*1000:.2f}ms ({self.timings[copy]/self.timings[copy]*100:.1f}%) 模型推理:{self.timings[inference]/n*1000:.2f}ms ({self.timings[inference]/(self.timings[copy]self.timings[inference]self.timings[output_copy])*100:.1f}%) 结果拷贝:{self.timings[output_copy]/n*1000:.2f}ms ({self.timings[output_copy]/(self.timings[copy]self.timings[inference]self.timings[output_copy])*100:.1f}%) 总延迟:{(self.timings[copy]self.timings[inference]self.timings[output_copy])/n*1000:.2f}ms )profilerInferenceProfiler(model)profiler.profile(test_input)5.2 推理吞吐量分析defmeasure_throughput(model,input_shape,batch_sizes[1,4,8,16,32]):测量不同 batch size 的吞吐量results[]forbsinbatch_sizes:test_inputnp.random.randn(bs,*input_shape).astype(np.float32)# 预热for_inrange(10):_model.predict(test_input)# 测量latencies[]for_inrange(100):starttime.time()_model.predict(test_input)latencies.append(time.time()-start)avg_latencynp.mean(latencies)throughputbs/avg_latency results.append({batch_size:bs,avg_latency:avg_latency*1000,# msthroughput:throughput})print(fBatch{bs:2d}: latency{avg_latency*1000:6.2f}ms, throughput{throughput:7.1f}img/s)returnresults resultsmeasure_throughput(model,(3,224,224))# 找最优 batchbestmax(results,keylambdax:x[throughput])print(f\n最优配置: batch_size{best[batch_size]}, throughput{best[throughput]:.1f}img/s)5.3 算子级推理分析# 推理 Profiling 命令atc--model/path/to/model.onnx\--framework5\--output/path/to/model\--soc_versionAscend310\--profiling_modememory# 内存 Profiling--profiling_output/workspace/infer_profiling# 查看瓶颈算子ascend-sn analyze\--input/workspace/infer_profiling\--top_k20# 显示 Top 20 耗时算子六、Profiling 报告解读6.1 报告结构CANN Profiling 报告包含以下部分Profiling Report ├── 执行概览 │ ├── 总耗时 │ ├── 算子总数 │ └── 时间分布饼图 ├── 算子分析 │ ├── Top 耗时算子 │ ├── 算子融合分析 │ └── 算子调用分析 ├── 通信分析多卡 │ ├── AllReduce 统计 │ └── 通信占比 ├── 显存分析 │ ├── 峰值显存 │ └── 显存热点 └── 优化建议 ├── 优先级高 ├── 优先级中 └── 优先级低6.2 关键优化建议Profiling 报告会自动生成优化建议问题建议预期收益数据加载占比高增加 num_workers使用 pin_memory提升 20-30%AllReduce 占比高启用梯度压缩或调整通信拓扑提升 15-40%小算子多开启算子融合提升 10-25%显存接近上限启用混合精度或 gradient checkpointing显存 -50%单算子耗时长检查是否使用最优 core_type提升 10-30%七、自动化 Profiling 脚本7.1 训练 Profiling 脚本#!/usr/bin/env python3 CANN 训练 Profiling 自动脚本 importosimportargparsefromascend.profilerimportProfiler,ProfilerConfigdefmain():parserargparse.ArgumentParser()parser.add_argument(--output,default/workspace/profiling)parser.add_argument(--ops,nargs,default[MatMul,Conv2d,LayerNorm])parser.add_argument(--epochs,typeint,default1)argsparser.parse_args()# 创建 ProfilerconfigProfilerConfig(output_pathargs.output,trace_opsargs.ops,enable_memoryTrue,enable通信True)profilerProfiler(config)# 构建模型modelbuild_model().npu()# Profiling 训练forepochinrange(args.epochs):profiler.start()forbatch_idx,batchinenumerate(dataloader):data,targetbatch[input].npu(),batch[label].npu()outputmodel(data)lossloss_fn(output,target)loss.backward()optimizer.step()ifbatch_idx%1000:profiler.save(intermediateTrue)profiler.stop()profiler.save()print(fProfiling complete. See{args.output})if__name____main__:main()7.2 使用方法# 基础 Profilingpython profiling.py--output/workspace/my_profile# 指定要追踪的算子python profiling.py--opsMatMul Conv2d LayerNorm Softmax# 多 epoch Profilingpython profiling.py--epochs3# 生成报告ascend-sn report--input/workspace/my_profile--output/workspace/my_report.html八、常见问题问题原因解决方案Profiling 数据为空环境变量未设置检查 ASCEND_PROFILING_ENABLE1报告生成失败数据损坏重新运行 Profiling显存溢出Profiling 本身占用大量显存减小采样频率或关闭 memory profiling性能反而下降Profiling 开销生产环境关闭 Profiling报告无法打开路径中文或特殊字符改用纯英文路径相关仓库ascend-toolkit- Profiling 工具和报告生成器 https://gitee.com/ascend/ascend-toolkitatc- 模型转换工具含 Profiling 配置 https://gitee.com/ascend/atctorch_npu- PyTorch Profiler 接口 https://gitee.com/ascend/torch_npu