ARTICLE DETAIL

资讯详情

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

高通thermal-engine调试实战:从debug日志到CPU降频根因分析

高通thermal-engine调试实战:从debug日志到CPU降频根因分析 先说说我为什么写这个题目。做高通平台BSP或者系统性能优化的朋友十有八九都跟thermal-engine打过照面。多数情况下它是乖乖干活的但一旦遇到CPU莫名其妙降频、跑分掉链子、游戏锁帧板子一热就“癫痫”你第一个想抓来问话的就是它。更麻烦的是thermal-engine默认日志级别很低出了问题你想查它做了啥日志里干干净净一脸无辜。这篇文章是我在Android 12平台高通SM8250/SM8350等平台都适用上做thermal-engine高通热管理服务调试的实战记录。我会从如何快速打开debug日志讲起再结合一个我实际处理的CPU降频问题把日志分析、根因定位到最终修改配置的完整链路拆开讲。内容偏工程实操适合系统软件工程师、性能调优工程师、以及正在被“手机发热降频”折磨的底层开发朋友参考。1. thermal-engine到底在干啥为什么默认日志这么“闷”1.1 高通thermal-engine的工作逻辑thermal-engine在高通平台的Android系统里是一个运行在用户态的常驻服务二进制通常在/vendor/bin/thermal-engine配置文件在/vendor/etc/thermal-engine.conf部分平台已经改成thermal-engine-normal.conf或者XML格式的配置但核心逻辑一致。它的工作流程用一句话概括周期性读取各个温度传感器的值对照配置文件里的策略表决定要不要通过冷却设备去限频、限流或者关机。具体拆开看就三步采样。通过内核提供的thermal_zone节点位于/sys/class/thermal/目录读取各传感器温度。高通平台的传感器不只是CPU表面温度还包括电池温度、PA温度、充电IC温度、外壳温度、用算法估算的皮肤温度等。决策。thermal-engine内部有一套算法比如高通自己的PID算法、monitor算法、virtual sensor算法把当前温度和配置的阈值做比较一旦触发就进入下一环节。执行。通过操作内核接口通常是/sys/class/thermal/cooling_device*/cur_state或者QTI特有的lmh接口、msm_thermal接口去请求降低CPU频率、限制GPU频率、关核、限制充电电流等。所以thermal-engine就是系统热策略的“大脑”CPU降频就是它手里的“大棒”之一。理解了这点你就能明白为什么CPU被莫名其妙降频时第一个要怀疑的就是它。1.2 为什么默认情况下它像个“哑巴”我排查过不少thermal问题最大的痛点不是thermal-engine逻辑难懂而是日志关着。默认的thermal-engine日志级别很低正常运行时只输出error级别信息甚至有些平台的release版本干脆把debug日志编译关掉了。这意味着什么CPU降频发生了温度到了多少、哪个传感器触发、请求降到多少频率你是看不到的。没有日志就只能靠猜。高通其实提供了日志开关但有一个“鸡生蛋”的问题你要让thermal-engine输出日志系统得能写属性、能重启服务而对于量产机可能连root都没有。另外不同Android版本的属性名还不一样网上很多资料写的是老平台的拿到Android 12上用可能完全无效。所以这篇文章的目的就很明确了把“快速开启debug日志”这件事讲透并且结合日志去解决实际的CPU降频问题。接下来我从两个方向讲一是运行时动态开日志适合已经焊上adb的userdebug机器二是编译期改默认日志级别适合需要刷到量产机上复现问题的情况。2. 快速开启debug日志两种方案都给你2.1 运行时动态开启推荐优先用这个方案拿到一台userdebug或者eng版本的Android 12设备第一件事就是用adb连上去。确认系统里有thermal-engine服务在跑adb shell ps -A | grep thermal正常情况下你会看到类似thermal-engine或者vendor.thermal-engine的进程。接下来核心操作就是通过setprop命令设置高通热管理服务的debug开关。注意Android 12高通平台主流的属性是这两条adb root adb shell setprop persist.vendor.thermal.debug.enable 1 adb shell setprop persist.vendor.thermal.debug.log_level 8 adb shell stop vendor.thermal-engine adb shell start vendor.thermal-engine第一条属性负责总开关第二条属性是日志级别8对应的是VERBOSE级别基本能把thermal-engine所有内部决策过程都打出来。如果你们项目里没有persist.vendor.thermal.debug.enable可以试试高通的通用属性adb shell setprop vendor.thermal.debug.log_level 8 adb shell setprop persist.thermal.debug.mask 0xFFFFFFFF设置完之后重启thermal-engine服务让属性生效。有些版本设置完属性后服务会自动重启加载但稳妥起见还是手动stop/start一拨。执行完后再看日志adb shell logcat -c adb shell logcat -s thermal:V thermal-engine:V或者直接抓全部日志再按关键字号过滤adb shell logcat -b all thermal_debug.log我在SM8350平台上实测过打开后日志量明显变大会持续输出类似下面的内容thermal-engine: sensor [cpu-0-usr] temp 75.5 (threshold 70.0) state [1] thermal-engine: Request cooling state 3 for cpu0看到这些就说明debug日志生效了。2.2 编译期默认开启debug日志如果你手上只有量产机器没有root也没有adb root权限那只能在编译的时候就把debug日志打开。以Android 12高通代码为例需要改的地方有几个。第一步修改thermal-engine的日志级别宏定义。高通thermal-engine代码通常在vendor/qcom/proprietary/thermal-engine/目录下部分平台可能在vendor/qcom/opensource/thermal-engine/。关键头文件是thermal.h或者thermal_utils.h里面一般有类似这样的定义#ifndef THERMAL_DEBUG_ENABLE #define THERMAL_DEBUG_ENABLE 0 #endif把它改成1或者把代码里控制日志输出的宏强制打开。还要检查一下thermal_config.h里有没有默认的日志级别配置如果有把默认日志级别设置成8或对应debug级别。第二步检查Android.bp或Android.mk里的编译选项。有些平台会通过-DTHERMAL_DEBUG_ENABLE这种编译宏来控制日志代码是否编进去。在vendor/qcom/proprietary/thermal-engine/Android.bp里找到cflags加上cppflags: [ -DTHERMAL_DEBUG_ENABLE, ],第三步处理权限。Android 12上selinux策略很严格。如果你在setprop的时候就发现权限被拒绝那多半是thermal-engine的te规则没放行属性。需要检查device/qcom/sepolicy/vendor/thermal-engine.te里是否有对应的属性权限比如set_prop(thermal-engine, thermal_debug_prop)或者是allow thermal-engine vendor_thermal_prop:file write;。编译期如果直接把debug打开也别忘了把日志写入/data/vendor/thermal/目录的权限加上否则调试信息无处落盘。编译完整个vendor分区刷进去开机后logcat里就会一直有thermal-engine的详细日志不再需要手动setprop。2.3 关于日志开关选型我的一点心得我不建议一上来就改编译选项。因为debug日志全开会带来两个副作用一是logcat刷屏非常快影响其他模块日志的排查二是thermal-engine的日志大部分走logcat如果刚好触发问题的是storage或者CPU频率相关的场景日志量太大反而会加大系统负载让问题更难定位。正确的顺序是先用运行时开关快速定位确认真实问题后需要复现场景再考虑编译期默认开启。另外如果设备支持优先用高通提供的diag接口去抓thermal日志那个对系统负载影响更小。不过diag需要配合QPST工具操作门槛高一些这里就不展开了。3. 日志抓到了怎么从一堆输出里定位CPU降频真因3.1 先看懂日志里的“关键信号”把debug日志打开后你会看到大量输出但如果看不懂那跟没开没区别。我总结了一下thermal-engine日志里最核心的就是下面几类信号。传感器温度采样日志。这类日志会告诉你当前读取到的温度值。比如thermal-engine: [thermal_sensor] cpu-0-usr: temp85.0, tsens_tz_sensor[0]看到这个就看到温度来源了。高通平台传感器命名规则比较固定cpu-0-usr代表CPU0用户态温度传感器cpu-0-mx代表CPU0核芯温度pa_therm代表PA温度quiet_therm代表机身温度battery就是电池温度。你要关心的是哪个传感器导致降频名字里基本已经剧透了。阈值判断与状态机切换日志。这类日志是定位降频最关键的依据。thermal-engine配置文件里每个传感器都会配置多级阈值常见格式是这个意思temperature: 70 80 90 action: none low medium highdebug日志会打印当前温度命中了哪一档thermal-engine: [sensor cpu-0-usr] temperature86.0 threshold80.0 level2 actionmedium看到这个基本就锁定了是哪个传感器、哪一级阈值触发了。冷却设备请求日志。这是“降频动作”的直接证据thermal-engine: [cooling_device] cdevcpu0 cur_state4 requested6或者thermal-engine: [lmh] Setting CPU0 max freq to 1497600 KHz这说明thermal-engine正在通过冷却设备把CPU最大频率往下压。日志里会有requested和cur_state两个值requested是thermal-engine希望设置的档位cur_state是当前实际档位。如果两者长时间不一致说明冷却设备的请求没有被内核完全接受又是另一种问题了。3.2 实战案例一个被“安静温度”背刺的CPU降频问题下面这个案例是我在Android 12 SM8250平台调试中真实遇到过的场景很典型。问题现象。设备跑性能测试时刚开始CPU频率还能冲到2.8GHz左右一分钟左右掉到1.7GHz而且再也没回来。表面看像是CPU过热降频但整机外壳温度其实一点都不烫用户体感最多40多度。排查过程。我首先打开debug日志跑了一遍性能测试抓取logcat。日志里很快就出现了重复刷屏的信息thermal-engine: [virtual_sensor quiet_therm] temp45.2 threshold43 threshold_index2 thermal-engine: [cooling_device] cdevcpu0 requested6 cur_state6问题原因浮出水面不是真正的CPU太热而是quiet_therm这个虚拟传感器上报的温度超过了43℃的阈值触发了CPU降频。那为什么quiet_therm会到45℃这个传感器在配置里通常会被设计成“皮肤温度估算传感器”它会根据CPU温度、充电电流、机身热敏电阻等多个输入源算出一个估算值。问题恰恰出在估算模型的配置上。我继续翻日志看到这几个输入源的温度变化thermal-engine: [virtual_sensor] input cpu-0-usr temp65.2 thermal-engine: [virtual_sensor] input pa_therm temp42.1 thermal-engine: [virtual_sensor] input charger_therm temp50.3充电电流那一路温度奇高把虚拟传感器的估算结果抬上去了。也就是说表面看是机身温度触发限频实际上是因为测试设备当时插着USB充电充电IC发热偏高里应外合让quiet_therm冲破了阈值。解决方案。定位到根因后就不慌了。我在thermal-engine.conf对应平台配置文件里把quiet_therm的第三级阈值从43℃调整到了47℃同时把CPU降温的action从直接降两档改成了降一档并增加了恢复的迟滞时间。重新编译烧录后验证同样场景下跑性能测试CPU最高频率维持时间从一分钟左右延长到了七八分钟用户体感温度没有明显变化。这个案例想说明一个道理CPU降频的锅不一定是CPU背。很多时候是某个外围传感器或者虚拟传感器触发的日志的价值就是帮你把“真凶”揪出来。3.3 日志之外别忘了配合sysfs节点交叉验证只看thermal-engine日志还不够我习惯同时抓内核sysfs节点的数据来做交叉验证。因为thermal-engine是“决策者”但真正执行频率限制的是内核的cpufreq框架和冷却设备接口。经常会出现“thermal-engine觉得它已经限频了但内核实际没执行”或者反过来“内核限频了但thermal-engine日志里没有任何记录”的情况。诊断CPU降频问题时下面几个节点我必看# 查看当前在线CPU的频率 adb shell cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq adb shell cat /sys/devices/system/cpu/cpu4/cpufreq/scaling_cur_freq # 查看系统当前允许的最大最小频率 adb shell cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq adb shell cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_min_freq # 查看内核thermal模块是否在限频 adb shell cat /sys/class/thermal/thermal_message/cpu_limit # 查看各冷却设备当前状态 adb shell cat /sys/class/thermal/cooling_device*/cur_state如果thermal-engine日志里出现了明确的限频请求但scaling_cur_freq和scaling_max_freq没变化那可能是cpufreq驱动的问题如果cpu_limit有值但thermal-engine日志里干净得很那可能是内核侧其他模块比如lmh或者schedutil governor的降频逻辑在起作用跟thermal-engine无关。3.4 结合AOSP新增功能去理解平台差异Android 12 AOSP在热管理上有一个比较重要的变化Framework层引入了更完善的Thermal HALIThermal和对应的thermal服务上层应用可以通过PowerManager的addThermalStatusListener感知到系统热状态。高通平台的实现里thermal-engine会把一些关键温度点上报给HAL再由HAL回报给Framework。这就带来一个调试上的新问题有时候你看到的现象是“应用收到了热状态通知然后自己把帧率降了”但底层thermal-engine的温度阈值并没有到真正限频的程度。这种情况下你只盯thermal-engine日志是不够的还得看Framework层的ThermalService日志adb shell logcat -s ThermalService:I ThermalHAL:I我当时也踩过这个坑。某个App在设备温度到45℃时主动锁了60帧我以为是thermal-engine限频了结果打开thermal-engine日志发现CPU频率根本没动最后一看是Framework热状态回调在作怪。所以做Android 12平台热问题排查一定要有“两级视角”底层thermal-engine的决策日志和上层Framework的ThermalService状态机。4. 常见问题与排查技巧实录4.1 debug日志开不起来的几种情况实操中“开了日志但没输出”的情况非常常见。我整理了几种高频原因供大家对照排查。**原因一属性没设置对。**不同平台、不同Android版本、不同QSSI版本thermal-engine的debug属性名可能不一样。有些是persist.vendor.thermal.debug.enable有些是vendor.thermal.debug.log_level还有老的代码里是persist.thermal.debug.mask。我的建议是设置前先adb shell getprop | grep thermal看看系统里到底有哪些thermal相关属性别照搬网上的老命令。**原因二属性被selinux挡住了。**这种情况下设置属性时不会报错但服务读不到因为服务进程没有权限访问该属性。可以用adb shell dmesg | grep avc查看有没有avc denial日志。有的话需要调整sepolicy策略。**原因三服务进程没有重启。**很多属性是服务启动时读取一次的不是动态变化的。如果不重启服务设置了也没效果。注意有些高版本的thermal-engine会带-s参数用stop vendor.thermal-engine停掉后服务名可能带后缀想精确一点可以用adb shell kill -9 $(pidof thermal-engine)系统会自动拉起服务因为有init配置相比stop/start有时更干净。**原因四你用的是user版本。**user版本跑thermal-engine的进程可能没有root权限而且很多debug日志代码在编译时就被裁剪掉了。这种case就别折腾运行时了老老实实改编译宏重新打包vendor。4.2 降频问题排查的几个实用技巧这里分享几个我自己的“土办法”虽然不优雅但在现场排查时真的很救命。技巧一用“挖坑法”确认是不是thermal-engine干的活。如果你怀疑CPU降频是thermal-engine干的但又不确定可以临时把thermal-engine停掉试一下adb shell stop vendor.thermal-engine然后跑测试场景看CPU频率是否恢复正常。如果恢复说明确实是thermal-engine的策略在起作用如果还是降频那就是内核侧或者其他模块的问题别在thermal-engine上浪费时间了。当然这仅限于userdebug机器量产机器别这么干停掉后温度过高可能直接关机或者硬件损伤。技巧二把日志落盘不要只靠logcat。处理复杂问题往往需要长时间抓日志。logcat有缓冲区上限抓久了早期的日志就丢了。我的做法是设置logcat到文件同时打开内核日志adb shell logcat -v threadtime -b all /data/vendor/thermal/thermal_dbg.log adb shell cat /proc/kmsg /data/vendor/thermal/kmsg_dbg.log 日志文件放在/data/vendor/thermal/目录下然后开始复现问题。这样抓回来的日志时间线完整还能保留内核侧的证据。技巧三关注“恢复”日志不只是“触发”日志。很多人只看触发降频的日志忽略了恢复的日志。但恢复过程的日志里藏着很多信息比如触发阈值是75℃但要降到70℃才恢复——这个“迟滞带”如果设置得太小就会出现频繁“降频-恢复-降频”的抖动现象对用户体验影响极大。我在log里看到过threshold75 recovery73这种日志两者只差2℃实际跑起来CPU频率会来回跳动观感就是“卡顿-流畅-卡顿”。所以如果你发现设备有反复降频的迹象重点看恢复阈值和触发阈值的差距。4.3 关于配置修改的几点避坑建议如果你的最终方案是修改thermal-engine.conf里的阈值或者action那有几个坑一定要避开。第一先备份原文件。这个文件虽然不大但它跟系统稳定性直接挂钩改错了轻则热保护失效重则系统反复重启。我一般在改前先adb pull /vendor/etc/thermal-engine.conf ./thermal-engine.conf.bak。第二不要只改数值还要看上下文。比如你把CPU降频的阈值从80℃提到了90℃但GPU、充电、屏幕的阈值没同步调可能出现“CPU没事机身已经很烫”的情况。热设计是整个系统的事CPU只是其中一个发热源修改策略要整体评估。第三验证时要覆盖多种场景。我见过同事改了阈值后常温场景跑分确实很高结果夏天在户外阳光下用机器直接热关机了。改完配置后除了跑基准测试一定要做持续负载测试、充电负载测试、静置恢复测试。等这些场景都过一遍才能下结论。5. 最后再分享一点个人体会文章写到这里核心的操作流程和思路都讲完了。回想我自己从“面对降频问题两眼一抹黑”到“能从容定位根因”其实就是把“看日志”这三个字做深了。thermal-engine的调试并不神秘它就是一个用户态服务按照配置文件里的规则做温度决策而你只要能看见它的决策过程所有问题都会变得清晰起来。如果你现在正被某个CPU降频问题困扰我的建议是先花半小时把debug日志打开跑一遍复现场景然后找到“哪个传感器突破了哪个阈值”这个答案就是你解决问题的钥匙。不要急着去调配置更不要一上来就问别人“阈值设多少合适”先让数据说话。工具和命令都摆在这了接下来就是你动手实践的时间。调试过程中如果遇到其他奇葩现象欢迎在评论区把日志贴出来一起讨论毕竟这类问题光靠冥想是解决不了的。
返回列表