2020-12-16
作者：互联网
Suspend
Mediatek 完全使用Android Suspend框架
1、Suspend Flow
从灭屏到CPU进入suspend的大体流程框架如下:
Codepath:
- /frameworks/base/services/core/java/com/android/server/power/PowerManagerService.java
- /frameworks/base/services/core/jni/com_android_server_power_PowerManagerService.cpp
- /system/core/libsuspend/
- /kernel-x.x/kernel/power/
Note：
（1）如果系统完全休眠，则CPU相关power下电（包括Vproc/Vsram）、DRAM进入self-refresh状态（DRAMC所在power domain Vcore进入lowpower mode）、26M off，SPM（work clk 32K）接手监控系统；
（2）如果26M clk没有关闭，则表明sub-system仍有work，需从log尝试分析定位；
2、Check AP suspend
AP suspend后console均被disable，只能从kernel log中确认AP是否进入suspend；
以MT6853为例，有如下log则表明AP有进入suspend：
[ 169.752446] -(0)[12375:Binder:542_2][name:spm&][mt6853_suspend_prompt:116] - prepare suspend enter
[ 169.752454] -(0)[12375:Binder:542_2][name:spm&][mt6853_suspend_prompt:127] - suspend enter
[ 169.752469] -(0)[12375:Binder:542_2]update base: ts=169752469557, tick=0x87f803e7, fz=1, ver=2
[ 169.752469] -(0)[12375:Binder:542_2][Power/clkbuf] suspend warning: XO_WCN is on!!
[ 169.752469] -(0)[12375:Binder:542_2][Power/clkbuf] suspend warning: XO_CEL is on!!
[ 169.752469] -(0)[12375:Binder:542_2][Power/clkbuf] suspend warning: XO_EXT is on!!
[ 169.752469] -(0)[12375:Binder:542_2]suspend warning[0m: PG_MD1
[ 169.752469] -(0)[12375:Binder:542_2]suspend warning[0m: PG_CONN
[ 169.752526] -(0)[12375:Binder:542_2]update base: ts=169752483403, tick=0x87f8a3f3, fz=0, ver=3
//以上为syscore_suspend打印log
[ 169.752566] -(0)[12375:Binder:542_2][name:spm&][mt6853_suspend_reflect:160] - prepare suspend resume
[ 169.752575] -(0)[12375:Binder:542_2][name:spm&][mt6853_suspend_reflect:179] - resume
//以上为syscore_resume打印log，是系统唤醒后最先打印的log
[ 169.752646] -(0)[12375:Binder:542_2][name:spm&][SPM] suspend wake up by R12_CONN2AP_SPM_WAKEUP_B, timer_out = 1, r13 = 0xc400fab4, debug_flag = 0xfc140300 0x40000002, r12 = 0x20, r12_ext = 0x0, raw_sta = 0x0 0x0 0x0, idle_sta = 0x992141b3, req_sta = 0x1c3d077 0x180000 0x50000017 0x1f0000 0x0, cg_check_sta =0x0, isr = 0x0, rt_req_sta0 = 0x0 rt_req_sta1 = 0x0 rt_req_sta2 = 0xffffffff rt_req_sta3 = 0xffffffff dram_sw_con_3 = 0x0, raw_ext_sta = 0x180255, wake_misc = 0x390000, pcm_flag = 0x2588400 0x0 0x2588000 0x2588000, req = 0x0, clk_settle = 0x60fe, wlk_cntcv_l = 0x87f8ab9f, wlk_cntcv_h = 0x0, 26M_off_pct = 0
[ 169.752843] -(0)[12375:Binder:542_2]Resume caused by IRQ 218, wlan0
//以上log体现唤醒原因、AP suspend时长、子系统状态等
PS：旧有平台进入suspend打印log存在差异
以MT6779为例，进入suspend打印的最后一句log为：md_settle=99, settle = 48
[10693.518170] -(0)[5549:Binder:463_2][name:spm&][SPM] sec = 5401, wakesrc = 0x1ec7dded (1)(1)
[10693.518170] -(0)[5549:Binder:463_2][name:spm&][SPM] wlk_cntcv_l = 0x1a9bc0b, wlk_cntcv_h = 0x3c
[10693.518170] -(0)[5549:Binder:463_2][name:spm&][SPM] md_settle = 99, settle = 48
[10693.518170] -(0)[5549:Binder:463_2][name:spm&][SPM] suspend wake up by R12_EINT_EVENT_B, timer_out = 4499546, r13 = 0x4000000, debug_flag = 0xd0fff3ff 0x1f86e, r12 = 0x40, r12_ext = 0x0, raw_sta = 0x0, 0x240c8fb, 0x0 0x0, req_sta = 0x40000000 0x0 0x17 0x0 0xff00003f, isr = 0x0, raw_ext_sta = 0x54aa, wake_misc = 0xf80000, sw_flag = 0x400 0xc00380 0x80000 0xc00380, req = 0x0, clk_settle = 0x30, wlk_cntcv_l = 0x6c105280, wlk_cntcv_h = 0x3c, 26M_off_pct = 99
[10693.518170] -(0)[5549:Binder:463_2][name:spm&][SPM] sleep_count = 59
3、Wakeup Reasons
SPM R12寄存器记录MCU的唤醒源，MCU被唤醒时log中会将具体唤醒源打印：
#define R12_PCM_TIMER_EVENT (1U << 0) ----> SPM 定时器唤醒，基本不会有，只有当系统没有其他唤醒源时，超过1h，才会有此timer唤醒，可以理解为SPM 里面的看门狗
#define R12_SPM_TWAM_IRQ_B (1U << 1) ----> SPM 用来debug的中断，不会有
#define R12_KP_IRQ_B (1U << 2) ----> 按键中断
#define R12_APWDT_EVENT_B (1U << 3) ----> AP侧的WDT(看门狗)中断
#define R12_APXGPT1_EVENT_B (1U << 4) ----> APXGPT，这个是system timer，对应到软件的hrtimer，只有在idle时才有
#define R12_CONN2AP_SPM_WAKEUP_B (1U << 5) ----> CONN，WCN的中断，wifi/BT/GPS/FM的唤醒
#define R12_EINT_EVENT_B (1U << 6) ----> 外部中断唤醒，譬如PMIC EINT，这类唤醒比较常见
#define R12_CONN_WDT_IRQ_B (1U << 7) ----> CONN的WDT(看门狗)中断
#define R12_CCIF0_EVENT_B (1U << 8) ----> Modem的CCIF0唤醒，譬如，网络唤醒，网络URC唤醒，这类唤醒比较常见
#define R12_LOWBATTERY_IRQ_B (1U << 9) ----> 低电池唤醒，基本没有
#define R12_SC_SSPM2SPM_WAKEUP (1U << 10) ----> SSPM唤醒，基本没有
#define R12_SC_SCP2SPM_WAKEUP (1U << 11) ----> sensor hub唤醒
#define R12_SC_ADSP2SPM_WAKEUP (1U << 12) ----> ADSP 也就是audio之类的唤醒，基本没有
#define R12_PCM_WDT_EVENT_B (1U << 13) ---->跟1是类似
#define R12_USBX_CDSC_B (1U << 14) ---->USB 唤醒
#define R12_USBX_POWERDWN_B (1U << 15) ---->USB 唤醒
#define R12_SYS_TIMER_EVENT_B (1U << 16) ---->跟4类似
#define R12_EINT_EVENT_SECURE_B (1U << 17) ---->跟 SECURE EINT唤醒
#define R12_CCIF1_EVENT_B (1U << 18) ---->跟8类似
#define R12_UART0_IRQ_B (1U << 19) ---->uart 0唤醒
#define R12_AFE_IRQ_MCU_B (1U << 20) ---->AFE，audio相关的唤醒
#define R12_THERMAL_CTRL_EVENT_B (1U << 21) ---->Thermal的唤醒
#define R12_SYS_CIRQ_IRQ_B (1U << 22) ----> CIRQ的唤醒，系统休眠时会将GIC backup到CIRQ
#define R12_MD2AP_PEER_WAKEUP_EVENT (1U << 23) ----> 数据业务唤醒
#define R12_CSYSPWREQ_B (1U << 24) ----> debug用
#define R12_MD1_WDT_B (1U << 25) ----> Modem的WDT(看门狗)唤醒
#define R12_AP2AP_PEER_WAKEUP_EVENT (1U << 26) ----> 数据业务唤醒
#define R12_SEJ_EVENT_B (1U << 27) ----> SEJ模块唤醒
#define R12_SPM_CPU_WAKEUP_EVENT (1U << 28) ----> CPU唤醒
#define R12_CPU_IRQOUT (1U << 29) ----> CPU唤醒
#define R12_CPU_WFI (1U << 30) ----> CPU唤醒
#define R12_MCUSYS_IDLE_TO_EMI_ALL (1U << 31) ----> CPU唤醒
4、常见问题debug手法
suspend导致的耗电问题常见有如下几种：
4.1 持锁导致系统无法进入suspend
blocking wakelock一般分为两种，一是上层应用透过PowerManagerService（后简称PMS）拿锁，另一种是kernel wakelock。常用定位分析方法有如下几种：
4.1.1 使用adb cmd 定位 如果问题必现、或从电流图看到系统无法suspend，插入USB通过如下cmd、 dump出当前阻止休眠的wakelocks： #adb shell #cat /sys/kernel/debug/wakeup_sources |sed -e 's/"^ "/"unnamed"/g' | awk '{print $6 "\t" $1}' | grep -v "^0" |sort -n 例如:active_since name
24 WLAN
79 mt6360_pmu_chg.2.auto
24271 PowerManagerService.WakeLocks （PMS持锁）
35558 musb-hdrc （USB持锁，因插usb，属于正常现象）
如果确定是PMS持锁，则再执行如下cmd、 dump出持锁的应用： #dumpsys power | grep "PARTIAL_WAKE_LOCK" 例如：如下GMS应用持锁
PARTIAL_WAKE_LOCK 'wake:com.google.android.gms/.auth.account.be.accountstate.LoginAccountsChangedIntentService' ACQ=-15s910ms (uid=10177 (displayid =0 pid=4937 pkg=com.google.android.gms uid=10177)4.1.2 log定位 分析此类问题，需同步录制mobilelog和bugreport(录制前reset) 1）Kernel log解读 如果系统可以进入autosuspend flow，则在kernel log中搜索“active wakeup source”，可以定位到阻止系统休眠的wakelock：
active wakeup source: WLAN timeout
active wakeup source: PowerManagerService.WakeLocks
active wakeup source: ccci_poll
2）bugreport分析
用“battery historian”打开bugreport文件，通过图形化界面查看对应时间段的wakelock持锁情况，或直接raw data搜索关键：
底层的锁：
All kernel wake locks:
Kernel Wake lock ttyC0 : 1h 33m 15s 668ms (3856 times) realtime
Kernel Wake lock radio-interface: 1h 20m 56s 210ms (3995 times) realtime
Kernel Wake lock ccci3_at : 1h 9m 43s 491ms (2932 times) realtime
Kernel Wake lock ccci_fs : 1h 0m 52s 818ms (3432 times) realtime
Kernel Wake lock ccci3_at2 : 41m 16s 938ms (2465 times) realtime
上层的锁：
All partial wake locks:
Wake lock 1001 RILJ: 5m 29s 768ms (13118 times) realtime
Wake lock 1000 *alarm*: 4m 7s 823ms (2330 times) realtime
Wake lock 1000 ConnectivityService: 59s 513ms (1 times) realtime
Wake lock u0a111 *alarm*: 50s 334ms (751 times) realtime
Wake lock u0a111 WakerLock:999603354: 28s 655ms (125 times) realtime
Wake lock 1000 NetworkStats: 11s 434ms (569 times) realtime
3）Android log 应用
目前PMS的log 默认不会打开，可以通过如下修改打印记录PMS log：
/frameworks/base/services/core/java/com/android/server/power/PowerManagerService.java
private static final boolean DEBUG = true; private static final boolean DEBUG_SPEW = DEBUG && false;
修改为:
private static final boolean DEBUG = true;
private static final boolean DEBUG_SPEW = true;
打开上层的log
通过syslog：搜索关键字：total_time=来确定持锁的时间.
PowerManagerService: releaseWakeLockInternal: lock=31602562 [*job*/DownloadManager:com.android.providers.downloads], flags=0x0, total_time=600051ms
或者通过正则表达式：total_time=[\d]{4,}ms 过滤出持锁时间比较长的锁.
PowerManagerService: releaseWakeLockInternal: lock=31602562 [*job*/DownloadManager:com.android.providers.downloads], flags=0x0, total_time=600051ms
PowerManagerService: releaseWakeLockInternal: lock=56317918 [*job*/DownloadManager:com.android.providers.downloads], flags=0x0, total_time=283062ms
PowerManagerService: releaseWakeLockInternal: lock=216012597 [AudioMix], flags=0x0, total_time=120003ms
PowerManagerService: releaseWakeLockInternal: lock=41036921 [AudioMix], flags=0x0, total_time=167984ms
PowerManagerService: releaseWakeLockInternal: lock=70859243 [GsmInboundSmsHandler], flags=0x0, total_time=3206ms
PowerManagerService: releaseWakeLockInternal: lock=242046348 [AudioMix], flags=0x0, total_time=122205ms
4.1.3 wakeup source 信息详解
adb shell cat /sys/kernel/debug/wakeup_sources > wakeup_sources.log
通过读取上述节点可以dump出系统wakeup sources详情，读取的节点内容文件最好用excel打开、方便对齐查看：
- active_count:对应wakeup source被激活的次数.
- event_count:被信号唤醒的次数
- wakeup_count:中止suspend的次数.
- expire_count:对应wakeup source超时的次数.
- active_since:本地激活时长，时间单位跟kernel log前缀时间是一样(kernel单调递增时间). 0表示未激活；
- total_time:对应wakeup source活跃的总时长.
- max_time:对应的wakeup source持续活跃最长的一次时间.
- last_change:上一次wakeup source变化的时间(从持锁到释放or释放到持锁)，时间单位跟kernel log前缀时间是一样(kernel单调递增时间).
- prevent_suspend_time:对应wakeup source阻止进入autosleep的总累加时间.
4.2 频繁唤醒，或AP进入suspend但子系统仍在work
此类问题需从Kernel log分析wakeup reason或子系统休眠情况
AP suspend 常见唤醒源：
- R12_EINT_EVENT_B： 外部中断唤醒，cat /proc/interrupts
- R12_CONN2AP_SPM_WAKEUP_B: connsys唤醒，如应用需要使用wifi联网，需从netlog定位联网应用；
- R12_SCP2SPM_WAKEUP_B: scp sensor相关唤醒，如VOW唤醒系统；
- R12_CCIF0_EVENT_B: modem ccci唤醒，需从log中继续查找ccci channel，详细分析参考FAQ21806
- R12_AP2AP_PEER_EVENT_B： modem数据业务唤醒，旧平台可能叫R12_CLDMA_EVENT_B，需从netlog定位联网应用；
搜索“suspend wake up by”关键字，可以找到AP的唤醒原因、上次suspend时长、AP睡下去后subsystem休眠行为等信息：
注意“mcusys wake up by”关键字为系统退出idle状态时打印的log，非AP suspend唤醒；
<6>[244518.391597] -(0)[5430:Binder:535_2][name:spm&][SPM] suspend warning:(OneShot) System LPM is blocked by conn
<6>[244518.391605] -(0)[5430:Binder:535_2][name:spm&][SPM] Suspended for 140.122 seconds
<6>[244518.391615] -(0)[5430:Binder:535_2][name:spm&][SPM] md_slp_duration = 4430012
<6>[244518.391629] -(0)[5430:Binder:535_2][WMT-CONSYS-HW][I]mtk_wmt_resume: mtk_wmt_resume !!
<6>[244518.391719] -(0)[5430:Binder:535_2]alarmtimer_fired.: type=1, count=19, wakeup count=12, func=devalarm_alarmhandler
<6>[244518.392756] -(0)[833:mtk_wmtd][WMT-CONSYS-HW][I] mtk_wcn_consys_sleep_info_read_all_ctrl:TOP:0,0;MCU:305,4384893;BT:0,0;WIFI:507,4472662;GPS:0,4591656
<6>[244518.393447] (0)[833:mtk_wmtd][WMT-CONSYS-HW][I]consys_dump_osc_state:0x180c1340: 0xe010b (BT)
<6>[244518.428292] (4)[108:irq/143-mt6358-]mt6358-pmic 10026000.pwrap: mt6359-pmic: Reg[0x534]=0x1,name=rtc,hwirq=64,type=4 <6>[244518.544532] (1)[5430:Binder:535_2][name:scp&][mt_scp_dump_sleep_count:988] - scp_sleep_cnt_0 = 26862754 1） 唤醒原因：R12_EINT_EVENT_B表示本次由外部中断唤醒，具体中断为PMIC mt6359 rtc，即本次因alarmtimer到期唤醒系统，需从android log或者bugreport中对应时间点log定位alarmtimer所属应用； 如，AlarmManager: Native set alarm :Alarm{42786ea8 type 0 com.sina.weibo} ps：旧平台搜索关键字或有差别，可能是“[SPM] wake up by”。 2） suspend时长：timer_out = 4591536 表示上次AP suspend的时长（32k计数，除以32768可转换为秒数）。Suspended for 140.122 seconds打印转换为单位秒的suspend时长； ps：旧平台或许只打印32k计数suspend时长 ，没有转换为单位秒的suspend时长； 3） 唤醒瞬间子系统工作状态：如若log中debug_flag = 0xfc1f9b fc最后两个字符不是 ff，则表示唤醒前一瞬间子系统有起来工作；System LPM is blocked by conn打印具体子系统名称（conn subsys为wifi/bt/gps/fm四合一子系统）； ps：旧平台或许没有打印block子系统名称，则需要通过R13（如 r13 = 0x84006a80）确认到底哪个子系统： R13每个bit代表的意义可以在 ${platform}_pcm_def.h中找到
4）
AP休眠期间子系统行为：26M clk为所有系统模块提供clock，26M_off_pc表示AP suspend期间26M clock buffer关闭的比例，比例越高理论耗电越小；如上log26M_off_pct = 0则表示AP休眠期间子系统clk一直有开启，可以通过如下log定位哪个子系统模块的问题：
- md_slp_duration = 4430012； AP休眠期间modem休眠时长，32k计数，除以AP suspend时长即为modem休眠比例；
- mtk_wcn_consys_sleep_info_read_all_ctrl:TOP:0,0;MCU:305,4384893;BT:0,0;WIFI:507,4472662;GPS:0,4591656； AP休眠期间connsys各个模块休眠时长，32k计数；log可见BT期间一直没有休眠，需要BT owner帮忙进一步分析；
- scp_sleep_cnt_0 = 26862754；scp（sensorhub）core0休眠总次数，可以对比休眠前scp休眠次数确认是否scp导致问题；
标签：suspend,R12,16,0x0,12,2020,1U,唤醒,define 来源： https://blog.csdn.net/ljj342018214/article/details/111247774