ARTICLE DETAIL

资讯详情

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

无需改代码:用TRACE32 RunTime和DWT周期计数器精确测量代码耗时

无需改代码:用TRACE32 RunTime和DWT周期计数器精确测量代码耗时 我当年第一次被问到这段代码到底跑了多久时第一反应是找示波器、找空闲的GPIO引脚然后在代码里上翻下翻插两行电平翻转重新编译、下载、抓波形。这一套流程下来少说一刻钟多则半小时而且测的还是被我改过之后的代码。后来换了Lauterbach TRACE32调试器我才发现以前那些手动打点计时的方法基本属于自虐用TRACE32的RunTime功能不改一行C代码、不重新编译5分钟就能拿到一段代码从入口到出口的精确执行时间精确到CPU周期级别。这篇文章就把这套方法完整写出来——它背后的测量原理是什么、具体怎么操作、有哪些坑以及如何从测一次进化成日常性能回归。无论你是在调电机控制里的某个ISR还是在优化一个加解密算法这套思路都能直接落地。1. 手动打点计时的困局改一行代码就要等一次编译下载1.1 三个最常见的土办法及其代价先说说我以前用过的三种土办法每一种都有它让人抓狂的地方。第一种是GPIO翻转接示波器。在待测代码段开头把引脚拉高结尾拉低示波器量高电平宽度。听起来很朴素做起来全是坑先要找一个没被占用的引脚光这点就能卡住半块板然后要加初始化代码重新编译下载示波器探头本身有寄生电容对上升沿有影响测几十纳秒级别的信号基本不可信更关键的是很多现场环境根本没有示波器下探针的位置。第二种是硬件定时器打点比如用TIM2-CNT或者SysTick-VAL在代码前后各读一次做差值。精度比GPIO法好得多但代价也很实在要初始化定时器、处理溢出、考虑中断抢占而且这些计时调用本身插在目标代码里改变了你本来想测的时序。更隐蔽的问题是如果系统里已经有RTOS或者其他驱动在共享定时器你的计时基准随时可能被改掉。第三种是用调试器设断点断下来之后看PC值或者周期计数。这个基本不可行——程序一停下来时间就停了你只能看到程序停在这根本得不到一个连续的、不被打断的执行时间。除非有片上trace否则单纯靠断点暂停拿不到严格的耗时数据。1.2 手动打点为什么让我越干越烦躁把上面这三种方法放在一起我总结出了手动打点计时的四大原罪基本解释了为什么它让人越干越烦躁。第一是侵入性。所有土办法都要求改动源代码。哪怕只是加两行读计数器也是改代码这一改就可能引入新bug或者影响编译优化结果。第二是编译下载循环太慢。在稍微大一点的工程里改一行代码后完整编译加固件再烧录5分钟起步很正常。如果被测的不是一个函数而是五六个候选函数这一套流程要反复执行五六遍一天时间基本就耗在编译和下载上了。第三是精度被插桩代码污染。你插进去的GPIO操作、定时器读取指令本身就要花几十个周期。更阴险的是编译器优化——读一个没被volatile修饰的寄存器可能被挪到函数开头统一读一次甚至直接删除测出来的结果根本不是真实的执行时间。第四是不可复现、难以自动对比。手动打点得到的结果记在一张草稿纸上下次改了代码再测一次没法和以前的数据做系统对比。性能是变好了还是变坏了全靠感觉。1.3 一个关键认知调试器可以不打断程序来测时间这里我想先说一个很多工程师没转过弯来的认知调试器介入程序不等于程序一定会被拖慢或者打断。大多数人对调试器的印象停留在设断点、停下来看变量、单步走所以理所当然地认为调试器只会把程序卡住。但TRACE32这类专业调试器里的断点功能并不只有暂停程序这一种玩法。断点命中时可以执行一段调试器脚本然后自动把程序恢复运行。整个过程目标CPU只是极短暂地停了一下几微秒级别其余时间都是全速运行。加上目标芯片内部的周期计数器作为一个完全没有侵入性的秒表就能实现程序正常跑、代码段进出点自动打点、最终自动打印耗时。这就是TRACE32 RunTime测量这类功能的核心逻辑也是这篇文章真正要讲的方案。2. RunTime测量原理周期计数器加断点动作程序全速跑也能计时2.1 时间基准CPU周期计数器DWT-CYCCNT要理解TRACE32是怎么测时间的得先认识一个硬件资源ARM Cortex-M内核里的DWTData Watchpoint and Trace单元。在这个单元中有一个32位的CYCCNT计数器它的作用非常纯粹——每来一个CPU时钟周期它就自动加一。不依赖定时器外设、不依赖操作系统、不需要初始化中断它就像是CPU内部自带的一个节拍器。三个关键寄存器的地址建议直接背下来寄存器地址作用DEMCR0xE000EDFC调试异常控制寄存器需要解锁才能操作DWTDWT-CTRL0xE0001000bit0置1时使能CYCCNT计数DWT-CYCCNT0xE000100432位周期计数器CPU每跑一个周期加1为什么不用SysTick或者TIM因为SysTick经常被RTOS接管用作系统节拍重载值和时钟源都可能被系统改掉TIM还要独占外设、配置预分频等等。而DWT-CYCCNT就是给调试和分析用的不占用业务资源不需要配置中断时机一到就可以读出来用最适合这种轻量级打点。2.2 断点动作不只是停下来还能记一笔再继续TRACE32的断点支持挂动作Action。在断点触发时不一定要让程序停在那里等你而是可以执行一段PRACTICE脚本然后自动恢复运行。最常用的两个选项/Write指定断点触发时要执行的命令。/RESUME执行完动作后自动让程序继续运行。板子上跑一个真实场景比如内核里某个任务周期调用待测函数你只需要在函数的入口和出口各设一个这种带动作的断点。入口断点一命中就把当前的DWT-CYCCNT值存到变量v.t0出口断点一命中再读一次存到v.t1打印差值。整个测量过程中程序除了断点命中瞬间的极短暂停之外其他时间全部全速运行。这个思路的本质就是把我以前在C代码里插定时器读数的操作搬到了调试器侧。搬完之后的效果是目标代码一个字都不用改编译产物完全不变测的就是线上真实运行的代码。2.3 为什么这个结果可靠没有中间商赚差价用这套方法测得的周期数是从起点断点的最后一条指令到终点断点的最后一条指令之间CPU实际执行的时钟周期总数。它不经过编译器重排、不经过操作系统调度、不经过任何软件层的包装直接从芯片内部计数器中读出来。这意味着两个优势第一所得结果和理论分析对得上。拿到周期数后自己数指令、查手册估算指令周期两者可以互相验证。我之前测过一个哈希函数理论上估算约2.3万个周期实测2.28万个周期差距在1%以内。第二不受系统调度影响。如果被测代码段在执行过程中没有被任务切换打断那么测量值就是这段代码在干净环境下的真实耗时。即便中间来了一个高优先级中断你也能从异常偏大的测量值里看出问题——这是后面避坑部分要展开讲的。2.4 RunTime打点和片上Trace的区别什么时候用哪个可能有读者会问TRACE32不是还有Trace模块吗把整个执行流抓下来慢慢分析每条指令的时间戳岂不是更准确实片上TraceETM/ITM配合TRACE32的时间戳功能可以做到指令级的执行时间分析精度最高。但它有两个门槛一是目标芯片得有Trace引脚并且被正确接线二是调试器得带Trace接口整体成本高出一截。RunTime打点法不需要额外的硬件Trace支持只要一个基础版的调试器就能做对绝大多数我想知道这个函数跑多久的需求已经足够。我总结的使用策略是这样的日常性能体检、定位某个代码段的耗时用RunTime打点就够如果要做全量执行流覆盖、分析每条分支的时间分布才需要上Trace。两者是互补关系不是替代关系。3. 5分钟实操从使能DWT周期计数器到拿打印结果3.1 准备环境一个能连上目标板的TRACE32会话这一步没有什么神秘的地方把你平时调试用的环境准备出来就好。具体包括目标板和调试器连接正常能在TRACE32里成功连上CPU。已加载可执行文件ELF符号表可用。这一点很重要——符号表能让你直接用函数名去设断点不用去翻反汇编地址。打开命令行/Practice窗口后面所有操作都可以在这里之一气呵成。如果你平时习惯用界面菜单操作也没关系。我下面要写的所有命令都能在菜单里找到对应位置但命令行的好处是可复制、可沉淀成脚本以后一键执行。3.2 第一步让DWT周期计数器跑起来在命令行里依次执行下面三条命令; 解锁DWT控制 Data.Long 0xE000EDFC 0xC5ACCE55 ; 使能CYCCNT计数 Data.Long 0xE0001000 0x00000001 ; 清零周期计数器给一个已知起点 Data.Long 0xE0001004 0x00000000第一条命令把DEMCR寄存器解锁。0xC5ACCE55是ARM调试架构规定的解锁密钥不写这一条后面的使能和清零操作可能根本没生效。第二条命令置起DWT-CTRL的bit0让CYCCNT开始随CPU时钟累加。第三条命令把计数器清零这样后面读到的值就是从零开始的相对周期数。有些芯片出厂可能默认就已经使能了DWT但我的习惯是每次测量前都执行一遍保证脚本在任何状态下都能给出可复现的结果。3.3 第二步给待测代码段设一对带动作的断点假设你现在要测的是函数crc32_process的耗时命令可以这样写; 在函数入口记录起始周期 Break.Set crc32_process /Program /Write v.t0 Data.Long(0xE0001004) /RESUME ; 在函数出口记录结束周期并打印差值 Break.Set crc32_process /Program /Write v.t1 Data.Long(0xE0001004); PRINT \crc32_process cycles\ v.t1-v.t0 /RESUME这里我故意把两个断点都设在crc32_process上是因为TRACE32遇到函数符号时默认指向函数入口。要测函数完整执行时间入口设一个、出口设一个就可以。如果只想测函数中间某一段比如一个循环体那就在反汇编窗口里找到那段代码的起始指令地址把第二个断点设在那条指令上。如果你的TRACE32版本对/Write的语法支持略有差异或者你更习惯图形界面可以打开Breakpoints窗口在某个断点上右键找到Action相关配置把v.t0 Data.Long(0xE0001004)这类命令填进去效果一样。这里有个细节v.t0和v.t1是TRACE32里的工程变量不用提前声明直接赋值就能用。它们在脚本执行期间一直存在方便后续计算和打印。3.4 第三步全速运行等待目标函数被触发断点设置好后直接在命令行执行GO程序开始全速运行。此时如果目标函数是由外部事件触发的那就按正常的业务逻辑触发它——比如串口来一条命令、按一个按键、或者等待周期性任务自然调用。断点命中后TRACE32会自动完成记录时间、打印、继续运行整套动作不需要你手动干预。举例说明如果函数被调用了三次你就可能在Practice窗口看到三行crc32_process cycles 1684235 crc32_process cycles 1684290 crc32_process cycles 1684178三次的周期数非常接近说明测量稳定可信度高。如果数值差别很大那就说明有中断或者别的因素在干扰。3.5 第四步把周期数换算成时间拿到周期数后要根据CPU主频换算成时间。这里有个非常实用的小技巧直接用周期数除以主频的MHz数值得到的就是微秒数。比如目标主频是168MHz那么PRINT crc32_process elapsed_us (v.t1-v.t0)/168算出来的就是微秒。如果主频是72MHz就除以72如果是400MHz就除以400。不需要在脚本里做浮点运算T32的整数除法这时候就够用了。想要毫秒就把结果再除以1000。3.6 顺手把步骤存成可复用脚本每次打开命令行敲这三五条命令还是太麻烦。更推荐的做法是把整个过程存成一个.cmm脚本以后双击执行。我自己现在用的最小模板长这样; perf_crc32.cmm SYStem.RESET SYStem.CPU STM32F407 SYStem.Up LOAD.auto D:\proj\build\app.elf ; enable DWT cycle counter Data.Long 0xE000EDFC 0xC5ACCE55 Data.Long 0xE0001000 0x00000001 Data.Long 0xE0001004 0x00000000 ; setup breakpoints with actions Break.Set crc32_process /Program /Write v.t0 Data.Long(0xE0001004) /RESUME Break.Set crc32_process /Program /Write v.t1 Data.Long(0xE0001004); PRINT \crc32_process cycles\ v.t1-v.t0 /RESUME ; run and wait GO WAIT !RUN ENDDO把CPU型号、ELF路径、函数名换成你自己的以后每次要测性能连接好目标板执行这个脚本就行。5分钟确实是保守说法熟练了可能连3分钟都用不到。4. 再进一步批量测函数、找热点、把性能检查变成日常4.1 一次测多个函数循环设断点加汇总打印实际项目中需要测的往往不是一个函数而是一条调用链上的三五个函数。比如一次完整的网络帧处理可能包含eth_input、ip_parse、tcp_process、app_handle这些环节每个环节都要记录耗时。这时候手动一个一个设断点就显得蠢了。写个循环脚本能大幅提高效率。伪代码思路长这样GLOBAL i FOR i1 TO 4 funcfuncs[i] Break.Set func /Program /Write v.t0 Data.Long(0xE0001004) /RESUME Break.Set func /Program /Write v.t1 Data.Long(0xE0001004); PRINT \func cycles\ v.t1-v.t0 /RESUME ENDFOR具体PRACTICE脚本里对字符串列表的处理方式可能因版本而异但思路是确定的把待测函数名维护成一个列表循环设断点。测完一轮之后把所有打印结果收集起来就是一个初步的性能台账。4.2 多次测量取中位数别让抖动骗了你单片机上的代码执行时间并不是永远恒定不变的。指令Cache命中率、总线仲裁、DMA访问、中断响应都会让同一段代码在不同时刻的耗时产生小幅波动。要拿到可靠的数据惯例是连续测10次甚至20次然后取中位数或平均值。在脚本层面可以这样实现用Break.Set的计数功能配合循环变量每次断点命中就把周期差值累加到一个累加器里测完N次后除以N。需要注意的是被测代码必须能被重复调用而且调用之间不能有依赖上一次结果的副作用否则测量本身会改变行为。4.3 用Performance Analyzer做全局热点扫描RunTime打点解决的是点对点测量问题。但如果不知道热点在哪只是盲目地测一个个函数效率还是低。这时候就该用TRACE32的性能分析器菜单路径一般是Analyze-Performance Analyzer。启动性能分析后让程序全速跑一段时间它会基于代码采样统计出每个函数或地址区间的执行时间占比和调用次数。我通常这么配合着用先用性能分析器全盘扫一遍找到占比最高的几个热点函数。再用RunTime打点法对热点函数做精确的周期级测量。优化完一个再扫一遍观察热点是否转移。这个组合拳比单纯埋头测某一个函数要高效得多因为嵌入式性能优化的瓶颈往往不在你最先想到的那个地方。4.4 把性能检查变成日常回归守住性能红线写了这么多手动测量最终极的目标是让性能检查自动化。我个人的做法是维护一个perf_check.cmm脚本内容比上面那个模板复杂一些加载当前版本的ELF对一组关键函数逐一打点把结果输出到一个log文件再和一个基线文件做对比。对比的逻辑很简单如果当前版本某个函数的耗时比基线版本超出一定比例比如5%脚本就高亮报警。我把这个脚本挂到发布流程里每次要发版之前跑一遍。这样能拦住很多看着没改动性能却悄悄劣化的问题——这类问题最难查因为往往不是某一次提交导致的而是在多次小改动中慢慢累积出来的。5. 坑与补救DWT失效、短代码段、溢出、优化干扰这些我都遇到过5.1 DWT计数器读出恒为0先检查这三件事最让我哭笑不得的一次排查是脚本写好之后怎么测都是0一度以为是寄存器地址写错了。后来逐个排除才发现是芯片进入低功耗模式后把DWT的时钟给关了。所以如果你发现CYCCNT读出来一直是0或者变化异常慢建议按这个顺序排查DEMCR是否解锁成功读一下0xE000EDFC的值确认最高位已经被置起。DWT-CTRL的bit0是否真的为10xE0001000读出来应该是0x00000001。芯片的时钟树配置是否让DWT所在时钟域处于关断或降频状态。低功耗芯片尤其要多瞄一眼电源管理寄存器。排查这些小问题不难但如果你不知道有这些坑光为什么读出来全零这一句就能在论坛里泡半天。5.2 几十个周期的代码别直接测用循环累加如果被测代码段只有几十到几百个CPU周期断点命中后CPU停住、执行脚本、再恢复运行这个过程本身会产生微秒级的额外时间。虽然这段开销理论上发生在测量区间之外但当被测区间本身极短时整个测量结果的信噪比会很差反复测几次数值可能都不同。解决办法很简单把被测代码放进一个空循环里跑N次测总耗时再除以N。比如循环100次测出来的周期总数除以100就能把噪声摊薄。这也是为什么我特别建议在优化一些短小的临界区代码时不要试图单次测量而是用批量放大的方法。5.3 周期计数溢出别用土办法处理32位计数器在168MHz下约25.5秒回绕一次在400MHz下约10.7秒回绕一次。如果你测的是秒级以上的长时间段就必须考虑溢出问题。处理溢出的正确姿势是利用无符号整数减法自动回绕的特性直接计算v.t1 - v.t0只要测量区间长度小于回绕周期差值本身就是正确的周期数。不要自己写if (t1 t0) t1 0xFFFFFFFF再去减这种土办法很容易在边界条件下出错而且凭空增加脚本复杂度。多实测几次你就知道无符号减法值比你想的可靠得多。5.4 编译器优化可能偷走你的断点高优化级别下函数可能被内联到调用点循环可能被展开某些你以为是独立的函数在反汇编里根本不存在。如果你用函数名设断点结果函数没有命中不要先怀疑调试器先去反汇编窗口看一眼你那个函数到底还在不在原地。这种情况的处理方法是反汇编窗口里找到对应源码行的实际指令地址用地址设断点。或者用源码行号断点让TRACE32自己去做映射。需要注意代码段优化后地址和指令都可能变化所以每次重新编译后最好重新确认一次断点位置别让旧地址在脑子里形成习惯。5.5 测ISR耗时别把执行时间当成中断延迟RunTime打点法测到的ISR执行时间是ISR入口到ISR出口之间的周期数。但很多人真正关心的是中断触发到ISR第一条指令执行的延迟——也就是中断延迟。这个延迟发生在ISR入口断点命中之前所以入口断点根本没被触发自然测不到。要测真正的入口延迟需要更底层的硬件支持比如让trace时间戳配合中断控制器的触发信号。所以在和别人讨论我这个IRQ是不是太慢了的时候先确认说的是哪个指标ISR内部执行时间还是从中断到ISR开始的总延迟。这两个指标的意义完全不同测量方法也完全不同。5.6 断点动作和测量结果的关系放宽心也要留意经常有人问断点动作本身会不会污染测量结果严格来说断点命中时CPU停止会让被测代码段的执行上下文出现一个缝隙。如果这个缝隙正好赶上外部事件到来可能会让代码段前后的状态发生变化导致某次测量值出现明显偏差。但对绝大多数毫秒级、微秒级的代码段来说这种影响非常小。实际使用中如果发现某次测量值特别离谱比平均值高出好几倍第一反应应该是有中断进来插了一脚把这次数据剔掉或者重测即可。如果代码段处在真正的硬实时环节里连断点的极小扰动都不希望有那就不该用打点法而该上Trace去记录完整执行流了。5.7 别忘了硬件断点的数量限制ARM Cortex-M0和M0内核的硬件断点通常只有4个M3/M4一般是6到10个。如果你设了一堆带动作的断点要注意数量是否超过了芯片的硬件断点上限。超出时TRACE32会尝试用软件断点替代但如果目标代码在Flash里软件断点的改写操作会受限。批量测多个函数的时候尤其容易踩这个坑我的建议是每次只测一小批比如4个以内测完一批再测下一批既避免断点不足也让输出结果按批次分块阅读起来更清晰。最后再分享一个既有习惯不知道你有没有过这种经历代码逻辑明明没动换个编译器版本或者改一个优化选项整个系统的表现就变得不一样了。我现在的习惯是不管项目多急都会在一个版本稳定后跑一次性能快照把所有关键函数的耗时存成一个基线文件。之后任何可能影响性能的改动都拿新数据跟基线对比。这套工作流已经帮我拦下过不止一次看着没变、实际慢了一倍的隐蔽回归。TRACE32的RunTime打点法说白了就是给嵌入式项目配了一个随时随地都能用的体检工具。希望你看完这篇文章也能扔掉在代码里插计时的老办法把时间花在真正需要思考的优化上。
返回列表