2020-12-16_r12_afe_irq_mcu_b

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。常用定位分析方法有如下几种：

active_since name
24           WLAN 
79           mt6360_pmu_chg.2.auto
24271        PowerManagerService.WakeLocks （PMS持锁）
35558        musb-hdrc （USB持锁，因插usb，属于正常现象）

 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)

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唤醒；