AlarmManager使用不当导致的充电低概率dead lock-6580-O1平台

记录碰到的一个比较简单的Android dead lock分析过程。

现象：

偶现一次开机充电过程中断开充电器后，充电指示灯长亮，手机屏幕全黑，按power键无法点亮屏幕（有log）

DEBUG:

Exception Log Time:[Wed Mar 21 09:16:58 CST 2018] [424.407980]

Exception Class: SWT

Exception Type: system_server_watchdog

Current Executing Process:

system_server

Trigger time:[2018-03-21 09:16:58.397693] pid:649

Backtrace:

Process: system_server

Subject: Blocked in handler on foreground thread (android.fg), Blocked in handler on main thread (main), Blocked in handler on ActivityManager (ActivityManager), Blocked in handler on PowerManagerService ( PowerManagerService)

"PowerManagerService" prio=5 tid=22 Blocked

| group="main" sCount=1 dsCount=0 flags=1 obj=0x12d41408 self=0x92d45000

| sysTid=708 nice=-4 cgrp=default sched=0/0 handle=0x91e01970

| state=S schedstat=( 391648918 501538997 3617 ) utm=13 stm=26 core=0 HZ=100

| stack=0x91cff000-0x91d01000 stackSize=1038KB

| held mutexes=

at com.android.server.BatteryService$LocalService.isPowered( BatteryService.java:1550)

- waiting to lock < 0x0c24c737> (a java.lang.Object) held by thread 98

at com.android.server.power.PowerManagerService.updateIsPoweredLocked(PowerManagerService.java:2291)

at com.android.server.power.PowerManagerService.updatePowerStateLocked(PowerManagerService.java:1757)

at com.android.server.power.PowerManagerService.handleBatteryStateChangedLocked(PowerManagerService.java:3316)

at com.android.server.power.PowerManagerService.-wrap13(PowerManagerService.java:-1)

at com.android.server.power.PowerManagerService$BatteryReceiver.onReceive(PowerManagerService.java:4370)

- locked < 0x0b68805b> (a java.lang.Object)

at android.app.LoadedApk$ReceiverDispatcher$Args.lambda$-android_app_LoadedApk$ReceiverDispatcher$Args_53034(LoadedApk.java:1323)

sysTid=708线程持有锁： 0x0b68805b，等待锁： 0x0c24c737

搜索 0x0c24c737看谁拿住：

"Binder:649_B" prio=5 tid=98 Blocked

| group="main" sCount=1 dsCount=0 flags=1 obj=0x14000630 self=0x92d5ce00

| sysTid=1388 nice=0 cgrp=default sched=0/0 handle=0x85dd2970

| state=S schedstat=( 1576343098 2184001289 3933 ) utm=103 stm=54 core=0 HZ=100

| stack=0x85cd8000-0x85cda000 stackSize=1006KB

| held mutexes=

at com.android.server.am.ActivityManagerService.isAppStartModeDisabled( ActivityManagerService.java:8943)

- waiting to lock < 0x0648d36a> (a com.android.server.am. ActivityManagerService) held by thread 112

at com.android.server.AlarmManagerService.setImplLocked( AlarmManagerService.java:1367)

at com.android.server.AlarmManagerService.setImpl( AlarmManagerService.java:1347)

- locked < 0x06c3e5e0> (a java.lang.Object)

at com.android.server.AlarmManagerService$2.set( AlarmManagerService.java:1591)

at android.app.AlarmManager.setImpl( AlarmManager.java:687)

at android.app.AlarmManager.setExact( AlarmManager.java:548)

at com. xxxx .android.server.lights.LightsController.updateLightsStatus( LightsController.java:231)

at com.android.server.lights.LightsService$LightImpl.setLightLocked(LightsService.java:163)

at com.android.server.lights.LightsService$LightImpl.setFlashing(LightsService.java:82)

- locked < 0x0a06364b> (a com.android.server.lights.LightsService$LightImpl)

at com.android.server.BatteryService$Led.updateLightsLocked(BatteryService.java:1483)

at com.android.server.BatteryService.processValuesLocked(BatteryService.java:1070)

at com.android.server.BatteryService.update( BatteryService.java:360)

- locked < 0x0c24c737> (a java.lang.Object)

at com.android.server.BatteryService.-wrap11(BatteryService.java:-1)

at com.android.server.BatteryService$BatteryListener.batteryPropertiesChanged(BatteryService.java:1522)

at android.os.IBatteryPropertiesListener$Stub.onTransact(IBatteryPropertiesListener.java:58)

sysTid=1388线程持有锁： 0x0c24c737，0x0a06364b，0x06c3e5e0，等待锁： 0x0648d36a

继续搜索： 0x0648d36a ：

"Binder:649_F" prio=5 tid=112 Blocked

| group="main" sCount=1 dsCount=0 flags=1 obj=0x13740960 self=0x92d69400

| sysTid=2839 nice=-2 cgrp=default sched=0/0 handle=0x8a47e970

| state=S schedstat=( 2105535904 2553635464 4928 ) utm=160 stm=50 core=0 HZ=100

| stack=0x8a384000-0x8a386000 stackSize=1006KB

| held mutexes=

at com.android.server.power.PowerManagerService.startUidChangesInternal(PowerManagerService.java:3446)

- waiting to lock < 0x0b68805b> (a java.lang.Object) held by thread 22

at com.android.server.power.PowerManagerService$LocalService.startUidChanges(PowerManagerService.java:5351)

at com.android.server.am.ActivityManagerService.updateOomAdjLocked(ActivityManagerService.java:23393)

at com.android.server.am.ActivityManagerService.trimApplications(ActivityManagerService.java:23842)

- locked < 0x0648d36a> (a com.android.server.am.ActivityManagerService)

at com.android.server.am.ActivityManagerService.finishReceiver(ActivityManagerService.java:20414)

at android.app.IActivityManager$Stub.onTransact(IActivityManager.java:283)

at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:3099)

at android.os.Binder.execTransact(Binder.java:697)

sysTid=2839是一个binder线程，持有： 0x0648d36a，等待： 0x0b68805b

从这里开始出现循环等待了：

PowerManagerService <sysTid= 708> 线程持有锁： 0x0b68805b，等待锁： 0x0c24c737

Binder:649_B <sysTid= 1388> 线程持有锁： 0x0c24c737，0x0a06364b，0x06c3e5e0 ，等待锁： 0x0648d36a

Binder:649_F <sysTid= 2839> 这是一个binder线程，持有锁： 0x0648d36a，等待锁 ： 0x0b68805b

=》dead lock！

仔细分析互锁关系调用栈，发现 sysTid=1388线程调用栈：

at android.app.AlarmManager.setExact(AlarmManager.java:548)

at com.xxxx .android.server.lights.LightsController.updateLightsStatus( LightsController.java:231)

at com.android.server.lights.LightsService$LightImpl.setLightLocked(LightsService.java:163)

从包名可以看出，极大可能是这里导致了问题，需要拉该块代码的owner协助分析解决此问题。

展开代码：at com.xxxx .android.server.lights.LightsController.updateLightsStatus( LightsController.java:231)

那么这里是在做什么呢？查看mBlinkIntent：

从这里可以分析出，当前的行为是通过AlarmManager的函数来实现定时发生广播的功能，而当前死锁的环节之一就在这个AlarmManager，所以可以推断是这个对象的使用引入了死锁因素，一种解决的方法就是换用另外的替代实现这个功能，比如Timer + Handler 来实现延迟发广播，规避死锁因素。