ARTICLE DETAIL

资讯详情

深耕郑州网站建设与运营推广的一线实战洞察。

CANN开发调试全攻略:从日志分析到性能瓶颈定位

CANN开发调试全攻略:从日志分析到性能瓶颈定位 跑起来容易调起来想哭——这是我在CANN开发这条路上最深的体会。无论是自定义算子、模型迁移还是框架适配只要代码能在昇腾NPU上编译通过、跑出第一个正确结果就算完成了一半但一旦遇到精度对不上、显存爆掉、或者在某个shape下性能突然掉一半的情况很多开发者就卡住了日志从哪看报错怎么解性能差在哪一层这些问题网上资料零散官方文档又偏原理介绍按图索骥很容易绕远路。这篇攻略想解决的就是三件事CANN开发调试前的环境与版本配套问题、日志分析的正确姿势、以及性能瓶颈的定位思路与实操方法。我尽量把每一个环节都写成可以直接照着做的程度该设什么环境变量、该看哪个目录下的哪个日志文件、该用哪条命令把profile数据扒出来、扒出来之后又该看哪几个指标。内容面向两类人刚上手CANN、第一次在昇腾环境里调算子的新手以及在CANN下写过算子或做过优化、但调试效率一直提不上去、总在重复踩坑的同学。1. 调试前的准备工作环境与版本是一切问题的基础1.1 CANN开发调试到底在调什么CANN全称是Ascend Computing Language是昇腾AI处理器上的核心软件栈承担着算子开发、图编译、运行时调度、应用开发等多层职责。从开发者的视角看CANN从上到下大致可以分成四层AscendCL应用开发接口层、GE图引擎层负责构图和整图优化、Runtime运行时层负责资源管理和任务下发、以及最底层的驱动与固件。算子开发者常用的TBE和Ascend C则位于更底层负责把算子的计算逻辑编译成能够直接在AI Core上运行的指令序列。为什么开篇要先讲这个分层因为我发现很多调试问题其实都出在层次之间。同一个“算子执行报错”可能是应用层传参传错了可能是图引擎构图时shape推导失败也可能是设备侧算子执行时发生内存越界访问。不同层次的错误日志出现的位置和格式都不一样排查路径也完全不同。所以拿到一个报错不要上来就瞎猜先判断它属于哪一层方向对了才能少走弯路。举个例子AscendCL接口返回ACL_ERROR_INVALID_PARAM这类错误时大概率是应用层传参的问题比如数据指针为空、tensor描述符没初始化而如果日志里出现device not ready或者task failed这一类运行时错误问题就可能出在驱动、设备状态或者算子本身。把错误按层次归类排查思路一下子就清晰了。1.2 CANN/PyTorch/torch_npu版本配套关系怎么确认如果你是用PyTorch在昇腾NPU上做模型迁移那版本配套是第一个雷区。CANN内部各组件对版本有严格要求CANN toolkit、驱动固件、PyTorch、torch_npu适配层这四个版本必须满足配套关系否则最容易出现的现象就是“pip install都成功了跑起来就报算子不存在”或者“加载模型直接coredump”。我的通用做法是先确认CANN toolkit版本然后根据版本去找对应的torch_npu版本。torch_npu的安装说明和版本配套表在官方社区和维护仓库里都有通常是一个版本矩阵表格会明确写出CANN版本、PyTorch版本、Python版本、torch_npu版本四者之间的对应关系。Python版本一般建议选3.8到3.11这个区间具体要以配套表为准不要无脑用最新版Python否则很容易在编译torch_npu扩展时失败。检查当前机器上版本信息的命令我常用这几条# 查看CANN toolkit版本 cat /usr/local/Ascend/ascend-toolkit/latest/version.cfg # 查看驱动和固件版本npu-smi输出中的Version字段 npu-smi info # 查看PyTorch版本 python -c import torch; print(torch.__version__) # 查看torch_npu版本 python -c import torch_npu; print(torch_npu.__version__)把这四个输出放在一起对照配套表只要发现某一个不在推荐的配套范围内就要先把版本拉齐再继续调试。这一步看起来很简单但能解决大量“莫名其妙”的报错。我见过太多同学拿着一个旧驱动配新CANN跑模型时算子编译报出一堆看不懂的底层错误最后才发现是版本不匹配。1.3 用npu-smi做第一轮设备体检很多性能问题其实不是代码问题而是设备本身就没有处于健康状态。比如NPU温度过高触发降频、某张卡显存不足导致算子频繁申请临时内存、或者HBM的ECC错误持续增长这些硬件层面的异常都会让算子速度突然变慢甚至执行失败。所以我在调试之前一定会先跑一句npu-smi info做设备体检。这个命令的输出类似GPU下的nvidia-smi能看到每张NPU卡的芯片型号、温度、功耗、HBM使用情况、显存占用率以及当前是否处于健康状态。重点关注这么几列Temp如果长时间高企不下可能是散热问题HBM-Usage如果接近100%说明显存吃紧Health状态如果不是OK基本可以判定是设备硬件或驱动层面的问题不用再纠结代码逻辑。这里分享一个我自己踩过的坑某次性能压测结果一直波动查了Allreduce通信时间忽高忽低后来发现是设备温度过高触发降频导致AI Core运行频率不稳定。所以先体检设备能避免把硬件问题当成软件问题排查很久。把环境基础打牢之后再往下走后面所有的日志分析和性能定位才是有意义的。2. 日志体系拆解从环境变量到错误码定位2.1 Ascend日志体系plog与slog的区别CANN的日志体系最初上手时会觉得有点绕因为日志分散在不同的目录和文件里搞不清该看哪个。简单来说Ascend日志分成两大通路进程日志plog和系统日志slog。plog记录的是每个进程内CANN各模块的运行信息主要包含AscendCL、GE、算子编译等信息用进程维度区分slog则是设备侧和系统侧运行时的日志记录的是Runtime、任务下发、设备状态等信息由NPU平台的日志服务统一收集。默认情况下日志根目录在$HOME/ascend/log下普通用户或/root/ascend/log下root用户里面通常会有plog和slog两个子目录。plog下面按照进程PID再细分目录每个进程一个目录里面是该进程从启动到退出期间产生的所有日志slog则按照device id和时间分文件存储每个NPU设备一个目录。另外还有一个debug目录主要放一些事件记录和错误处理时需要的额外信息。我记得第一次调一个多进程分布式训练任务时在plog里翻了半天都没找到某个错误后来发现那个错误根本不在plog里而是设备侧运行时抛出来的去slog里才定位到真正原因。所以调试时要先判断错误的归属如果是应用启动阶段、参数校验、图编译期的错误去plog找如果是运行期设备侧执行异常、任务下发失败重点看slog。这个区分能省掉大量无效查找时间。2.2 日志级别怎么配调试用0线上用2或3Ascend日志级别通过环境变量ASCEND_GLOBAL_LOG_LEVEL控制取值从0到40是DEBUG1是INFO2是WARNING3是ERROR4是NONE关闭。默认级别一般是1也就是INFO级别但这会在高性能计算场景下产生大量冗余日志拖慢运行速度在排查深层次问题时可能又需要打开DEBUG级别。我自己的习惯是分场景切换日常调试阶段比如算子程序刚写完还没跑通时直接把级别设成0宁可日志多、跑得慢也要把详细的执行流程看清楚等代码功能验证通过、要开始做性能测试时我会把级别改回3ERROR同时打开性能剖析工具避免日志写入成为性能瓶颈之外也让输出的日志更干净、更容易抓到真正的异常。设置方法很简单export ASCEND_GLOBAL_LOG_LEVEL0 # 调试阶段输出DEBUG级日志 export ASCEND_GLOBAL_LOG_LEVEL3 # 性能/线上验证阶段只输出ERROR除了全局级别还有一个环境变量ASCEND_GLOBAL_EVENT_ENABLE可以打开事件日志记录默认是0。在需要排查运行期设备事件的场景下可以临时设为1打开它但同样要注意性能和存储开销。有一个很容易踩的坑调试完忘记把日志级别改回去。级别一直停在0的话日志会在后台飞速增长跑一个大模型训练任务半天就能把磁盘写满。我在生产环境遇到过两次因为日志盘写满导致任务卡死的情况后来养成了习惯每次调试完马上把环境变量切回3并在脚本里写上注释提醒自己。2.3 日志内容怎么读一条日志一行拆解拿到一个日志文件很多人习惯直接CtrlF搜“ERROR”关键词这没错但有时候搜出来的错误信息并不指向根因真正的线索往往在它上面几行甚至几十行的WARNING或DEBUG日志里。所以我建议先把一条日志的结构看明白。一条典型的Ascend日志长这样[ERROR] GE(142857,rtp_spawn_work):2025-06-11-10:21:33.765.321 [tid: 139832123456] [ERROR] GE:0xE30009: GE tensor memory malloc failed, size1073741824拆开来看方括号里的是日志级别GE是产生日志的模块名括号里的数字第一个是进程ID第二个是进程别名后面跟着的是时间戳[tid]是线程ID再后面的GE:0xE30009是错误码最后冒号后面的才是真正的错误描述。模块名非常关键——GE代表图引擎RT或RUNTIME代表运行时AICPU代表AI CPU侧HCCL代表集合通信链路。看到错误码和描述后先按模块名判断在哪一层再去看那个模块的上下文日志。定位错误时我的阅读顺序是先看最后一条ERROR然后把日志向上翻大约50到100行重点看是否有WARNING或者“failed”“error”开头的蛛丝马迹。很多时候比如一个显存分配失败的错误根因是前面某一步算子申请了超大空间但没释放或者某个tensor的shape推导异常这些线索往往藏在ERROR出现之前的几行里。如果你不习惯直接开文件翻日志也可以用简单的grep组合快速过滤grep -n ERROR ~/ascend/log/plog/*/plog-*.log | tail -50 grep -n memory malloc failed ~/ascend/log/plog/*/plog-*.log日志分析这套方法论其实和做Java服务日志分析是相通的先按级别过滤再按模块聚合最后看上下文窗口。养成这种分层检索的习惯不管是排查CANN还是日常后端服务都能少走弯路。2.4 常见错误码分类与排查思路CANN的错误码体系在不同版本里会有微调但整体分类思路是稳定的。下面这张表是我平时排查问题时最常用的一组错误码分类按模块前缀和错误区间划分可以帮你快速缩小排查范围错误码区间常见模块典型含义优先排查方向E10010/E10012等驱动/运行时设备初始化、设备状态异常npu-smi体检检查驱动固件、容器设备映射E19999通用未知异常兜底错误翻上下文日志配合core dump定位E30009/E39001运行时/内存管理显存分配失败、资源不足检查显存占用、模型规模、是否内存碎片E40005等算子编译TBE/Ascend C算子编译失败检查算子源码、编译日志、shape类型推导E80008等模型管理OM模型转换或加载失败检查模型转换工具版本、输入输出shape匹配拿E19999举例这个错误码本身基本不携带有效信息就是告诉你“出事了但具体是什么事要看别的证据”。遇到它我的做法是打开同时间段plog里级别在WARNING以上的所有日志按时间线逐条阅读如果还定位不到再把core dump文件用gdb加载看崩溃调用栈在哪个模块。实操下来E19999大多数时候是显存越界或算子内部非法访问导致。还有一类高频问题容器里跑CANN报设备初始化失败。这种情况八成不是CANN本身的问题而是容器启动时没有映射NPU设备节点。手动检查一下/dev下面是否有davinci设备文件没有的话要在容器启动参数里把设备加进去。这种问题用npu-smi info一看就能判断——设备列表为空或者报错和驱动层关系不大。2.5 慢日志和超时日志性能问题的第一线索除了错误日志还有一类日志经常被忽略就是运行期的慢日志和超时日志。比如GE侧会记录图编译耗时如果某张图编译突然花了很长时间日志里通常会有“Compile graph xxx cost xxx ms”之类的信息运行时如果某个task执行超时slog里也会出现task timeout相关的记录。性能卡顿往往不是凭空出现的它会先以WARNING或者超时记录的形式暴露在日志里。我调试过一个模型前几次迭代都很正常跑到第200步左右突然每个step都慢了一倍去看slog发现存在周期性的“watchdog timeout”记录进一步排查是某个同步点等AICPU任务等了太久。这个线索如果不翻日志直接上性能工具反而不容易发现因为它是偶发性的。所以我的建议是做性能优化之前先把日志过一遍优先处理有明显timeout、retry、failed字样的记录。把日志层面的“慢性病”先治掉再谈profile数据里的算子瓶颈。如果日志干干净净再把精力集中到下一步的profiling上。3. 性能瓶颈定位从msprof到算子级优化3.1 为什么先看profile再动手优化很多开发者一遇到性能不达标第一反应是“这个算子是不是实现得不够好”然后就开始手写优化、调整tiling策略甚至换算法。这个思路不能说错但效率太低。性能瓶颈的分析应该像漏斗一样逐层收敛先看整张图的耗时分布再看单个算子的执行时间最后才深入到算子内部去分析访存、计算和调度情况。一上来就钻进某个算子细节很可能优化了半天才发现瓶颈根本不在那里。CANN提供的官方性能剖析工具是msprof当然现在也有更上层的ait等工具链。它们做的事情本质上是一样的在任务运行期间采集算子执行时间、AI Core利用率、带宽利用率、通信耗时等指标最后输出成结构化文件方便开发者分析。用一句话来概括profile数据的作用是告诉你“时间到底花在了哪里”而不是“应该怎么改”。定位到真正瓶颈之后优化才有方向。3.2 msprof常规用法一条命令拿到全部性能数据msprof作为CANN的全局性能分析工具在安装CANN toolkit之后一般位于/usr/local/Ascend/ascend-toolkit/latest/bin或tools目录下也可以直接通过命令行调用。最基础的用法是在启动目标程序时由msprof包裹起来msprof --application/home/user/my_project/test.py --output/home/user/profiling_data这条命令会在目标程序运行期间采集性能数据把结果输出到指定目录。跑完之后输出目录里会生成一个PROF_XXX_XXX格式的文件夹里面包含多个子文件。我最常看的有两类一类是op_summary.csv里面按算子维度列出每个算子的执行耗时、AI Core上计算时间、AIVector时间等另一类是timeline.json可以直接用chrome://tracing或Perfetto打开看整个时间线上CPU下发、NPU执行、通信同步的并发关系。如果是针对PyTorch训练脚本做分析更推荐在脚本里直接手工采集import torch_npu with torch.autograd.profiler.profile(use_npuTrue) as prof: run_training_step() print(prof.key_averages().table(sort_byself_cpu_time_total))或者直接用msprof裹住训练命令因为msprof可以同时采集到框架层和硬件层的指标数据更全。我个人建议两者结合框架侧的profiler负责看算子调度、CPU侧的预处理开销msprof负责看NPU设备侧的AI Core利用率和带宽指标。3.3 四个关键指标AI Core利用率、HBM带宽、拷贝耗时、算子耗时占比拿到msprof报告后不要眉毛胡子一把抓先看下面这四个指标就够了。第一个是AI Core利用率。这个指标衡量的是整个profiling窗口内AI Core实际执行计算指令的时间占比。我的经验判断标准是如果整体利用率在85%以上说明计算侧几乎没有空闲瓶颈大概率在带宽或者通信上如果低于60%就要怀疑是不是算子之间调度空隙太大、任务下发不连续或者kernel启动频率太高导致执行间隙过长。第二个是HBM带宽利用率。昇腾NPU的HBM带宽是片上数据传输的主动脉访存密集型算子比如elementwise、softmax、reduce这一类最容易卡在带宽上。如果op_summary里显示某个算子HBM带宽利用率长期靠近峰值那就说明它已经是访存瓶颈光优化计算指令没有意义得从数据搬运次数、数据排布格式、融合度上去想问题。第三个数据搬运耗时也就是H2D和D2H的耗时。这里的H指HostCPU内存D指DeviceNPU内存。如果profile数据里显示大量的时间花在Host和Device之间的数据拷贝上通常说明任务切分不合理、CPU侧预处理过度、或者中间结果频繁回读。遇到这种情况优先考虑算子融合、数据异步拷贝甚至把整张图留在设备侧执行减少内外存交换。第四个是算子耗时占比。把op_summary.csv按算子耗时从大到小排个序排名前几的算子如果占据了总耗时60%以上的时间那优化的方向就非常明确了。这时再结合AI Core利用率和HBM带宽利用率判断该算子的瓶颈类型然后决定是优化访存策略还是优化计算策略。3.4 案例一个elementwise算子如何定位到访存瓶颈这里说一个我实际调过的例子。当时一个逐元素相加的算子整体耗时从期望的50微秒跑到了300微秒性能差距巨大。拿到msprof数据后第一个发现就是H2D和D2H耗时占了算子总耗时的70%——系统在每次执行算子前都要把输入从CPU内存搬到NPU显存计算结果再搬回去。这个时候当然不用去管AI Core利用率了直接把算子从循环里抽出来把数据常驻在显存里只搬一次输入输出耗时立刻降到80微秒。接下来继续看发现AI Core利用率只有40%但HBM带宽利用率已经90%以上。这说明计算单元并没有在计算上浪费时间而是被数据读取的等待时间拖住了。确认访存瓶颈之后优化思路就变成了减少对HBM的访问次数。具体做法是把多个elementwise操作融合成一个kernel避免每个算子都从HBM读一遍数据再从HBM写一遍中间结果全部留在片上。融合之后算子耗时又进一步降到35微秒HBM带宽利用率反而降下来了因为存取次数变少了。这个案例想表达的核心是性能优化不是靠感觉“优化代码”而是先看profile数据得到瓶颈类型再根据瓶颈类型选择对应的技术手段。数据在哪个指标上吃不消就去动哪个方向的刀。3.5 算子优化的三板斧融合、访存、并行结合上面案例我把CANN算子性能优化总结成三板斧按优先级来用。第一板斧是算子融合。这是收益最高、风险最低的手段。把多个连续算子融合成一个kernel能减少kernel启动次数缩短任务下发间隙更重要的是让中间数据直接留在片上缓存里省去HBM读写。CANN的图引擎本身有融合优化能力但也有很多情况需要开发者手动把几个串行的elementwise或reduce操作合在一起写。判断是否该融合看两个数据kernel启动频次是否过高、中间张量读写时间是否占比过大。第二板斧是访存优化。在昇腾NPU上算子性能的上限往往由访存模式决定。具体手段包括把数据排布改成硬件友好的格式比如Conv场景用NC1HWC0替代NCHW尽量让数据在片上多复用避免同一份数据多次从HBM读对于可减少精度的场景用低精度类型减少单次数据搬运量。HBM带宽利用率这个指标就是用来验证访存优化有没有起效的。第三板斧是并行与流水。当一个算子本身计算和访存交错密集时可以尝试调整核数分配、调整tiling策略让AI Core之间的负载更均衡也可以在计算和搬运之间建立流水线让数据提前预取到位缩短等待时间。多卡场景下还要关注通信层的优化比如Allreduce的bucket大小调整、梯度压缩、通信与计算的重叠这已经超出单个算子的范畴但对端到端的性能提升非常明显。三板斧不是每次都要全用而是根据瓶颈类型选择性地用。核心判断依据都来自profile数据融合针对启动间隙和中间张量访存针对带宽利用率并行针对AI Core利用率和负载均衡。4. 一套可复用的CANN调试工作流4.1 从功能Bug到性能瓶颈的分步排查法把前面的内容串起来我在实际项目里反复使用的是一套五步排查法每次都按这个顺序走极少卡壳。第一步确认版本与设备。检查CANN、PyTorch、torch_npu版本配套用npu-smi info确认设备健康。这一步骤能排除至少三成问题。第二步跑小规模功能验证。用一个小的输入shape把日志级别设为0先确认算子功能正确、精度在可接受范围内。功能不对讨论性能没有意义。第三步看日志定位功能异常。如果报错按“模块名→错误码→上下文日志”的顺序排查不要跳跃式猜测。第四步功能过了再上性能剖析。在性能测试阶段把日志级别切到ERROR用msprof采集profile数据按“AI Core利用率、HBM带宽、拷贝耗时、算子耗时占比”四个指标分类判断瓶颈类型。第五步定向优化再验证。根据瓶颈类型选择融合、访存、并行等手段改完重新跑profile用同样的指标对比验证优化效果。这五步每一步都有明确的输入和输出不会让人觉得“我应该做点什么但不知道从何开始”。这也是我向团队里新人反复强调的先把流程跑熟再谈主观发挥。4.2 更大规模下把Ascend日志交给ELK统一管理当你的业务从单机调试发展到多机多卡训练或者你的团队需要处理多份历史日志时直接在服务器上翻日志文件就太原始了。日志量一大靠grep已经没法做全局检索和关联分析。我所在的项目组后来把整套Ascend日志采集之后接入了ELK日志分析系统效果非常明显。具体做法并不复杂每台训练服务器上用filebeat或fluentd采集~/ascend/log目录下的plog和slog日志按进程名和device id打成标签输出到Logstash做字段解析和清洗比如把日志级别、时间戳、模块名、错误码这些字段拆分出来最后写入Elasticsearch再用Kibana做可视化检索。这样排查一个问题时可以在Kibana里直接按时间线、按设备ID、按错误码、按进程ID做多维筛选甚至把多个进程的日志聚合到同一时间线上对比看是不是某个设备拖慢了整个集群。有一点要提醒Ascend日志格式在不同版本里会有细微差异Logstash的grok解析规则要专门写至少预留一天的调试解析格式的时间。并且日志采集要设置合理的保留策略Kibana上一般保留30天就够否则存储压力会很大。这套体系搭好之后再配合msprof在性能侧的profiling数据基本可以实现从“运行异常”到“性能劣化”的全方位线上可观测。4.3 调试效率提升的五个小习惯最后再分享几个长期积累的小习惯谈不上高深但确实能大幅减少无效工作时间。第一个习惯环境变量管理脚本化。不要在shell里随手export而是把所有CANN相关环境变量写到一个env.sh里按调试、性能、发布三种场景分别维护一套配置要用哪个直接source哪个。这样既不会忘记改回日志级别也方便同事之间同步环境。第二个习惯日志和profile结果按日期和场景归档。每次调试把plog的关键片段、错误的截图、msprof的summary文件存到同一个目录按“日期_模型名_场景”命名。时间久了这个目录就是你的个人排错知识库再碰到相似问题翻一下历史记录比重新排查快得多。第三个习惯性能优化每做一步立刻跑一次profile数据做前后对比。不要等到优化了好几版再一次性验证那样根本说不清是哪一步起作用、哪一步又引入了回退。小步验证、频繁对比是我认为最稳妥的优化节奏。第四个习惯充分使用dump能力做算子的前向对齐。精度异常时先把算子的输入输出dump下来和标杆结果做逐元素对比确定是哪个位置开始偏差再回到算子内部查访存、类型转换或者边界处理。在整个调试工具链里dump配合日志能解决大部分精度问题。第五个习惯善用社区和官方工具链。CANN生态里其实有很多调试器和辅助工具比如用于单算子开发和验证的工具、图级调试工具、以及统一的性能分析工具链ait功能比直接裸写调用更丰富。遇到某个问题觉得官方工具不支持时先花半小时翻一下工具文档往往能发现一个现成的解决方案。一些个人体会收尾调试CANN算子和优化性能这件事做久了就会发现它拼的不是某个瞬间的灵感而是对工具链的熟悉程度和对异常现象的分类能力。我个人的体会是每次拿到一个新问题先别急着怀疑是框架bug或者硬件故障按“版本配套→设备体检→日志分层→profile数据→单算子验证”这个顺序走基本都能定位到根因。很多看起来玄乎的问题最后落点其实都很朴素不是版本不对就是日志没看对地方再不然就是profile指标没看懂。最后再分享一个小技巧每次性能优化做完把msprof的op_summary导出存档按算子名和时间整理成一份简单的CSV基线库。后面再碰到性能退化拿当前数据和基线一对比很快就能看出是哪一次改动把性能带崩的——这一步长期来看能帮你省下比想象中多得多的时间。
返回列表