Analyze the deadlock ANR instance process using the Android trace file

For Android Developers, ANR (Application Not Responding) is a common problem. Generally, if an ANR occurs, the system generates a trace file in the/data/anr/directory. By analyzing the trace file, you can locate the cause of the ANR. There are many reasons for the generation of ANR, such as CPU usage is too high, events are not responded to in a timely manner, deadlocks, etc. Next we will solve the ANR problem caused by deadlocks, to describe how to analyze ANR through the trace file.

The corresponding trace file content is as follows:
"PowerManagerService" prio = 5 tid = 24 MONITOR
| Group = "main" sCount = 1 dsCount = 0 obj = 0x41dd0eb0 self = 0x5241b218
| Shard id = 567 nice = 0 sched = 0/0 MRM = apps handle = 1380038664
| State = S schedstat = (6682116007 11324451214 33313) utm = 450 stm = 219 core = 1
At com. android. server. am. ActivityManagerService. broadcastIntent (ActivityManagerService. java :~ 13045)
-Waiting to lock <0x41a874a0> (a com. android. server. am. ActivityManagerService) held by tid = 12 (android. server. ServerThread)
At android. app. ContextImpl. sendBroadcast (ContextImpl. java: 1144)
At com. android. server. power. PowerManagerService $ DisplayBlankerImpl. unblankAllDisplays (PowerManagerService. java: 3442)
At com. android. server. power. DisplayPowerState $ PhotonicModulator $ 1.run( DisplayPowerState. java: 456)
At android. OS. Handler. handleCallback (Handler. java: 800)
At android. OS. Handler. dispatchMessage (Handler. java: 100)
At android. OS. lorule. loop (lorule. java: 194)
At android. OS. HandlerThread. run (HandlerThread. java: 60)
"Binder_ B" prio = 5 tid = 85 MONITOR
| Group = "main" sCount = 1 dsCount = 0 obj = 0x42744770 self = 0x58329e88
| Shard id = 3700 nice =-20 sched = 0/0 MRM = apps handle = 1471424616
| State = S schedstat = (1663727513 2044643318 6806) utm = 132 stm = 34 core = 1
At com. android. server. power. PowerManagerService $ DisplayBlankerImpl. toString (PowerManagerService. java :~ 3449)
-Waiting to lock <0x41a7e420> (a com. android. server. power. PowerManagerService $ DisplayBlankerImpl) held by tid = 24 (PowerManagerService)
At java. lang. StringBuilder. append (StringBuilder. java: 202)
At com. android. server. power. PowerManagerService. dump (PowerManagerService. java: 3052)
At android. OS. Binder. dump (Binary. java: 264)
At android. OS. Binder. onTransact (Binary. java: 236)
At android. OS. IPowerManager $ Stub. onTransact (IPowerManager. java: 373)
At android. OS .Binder.exe cTransact (Binder. java: 351)
At dalvik. system. NativeStart. run (Native Method)
"Android. server. ServerThread" prio = 5 tid = 12 MONITOR
| Group = "main" sCount = 1 dsCount = 0 obj = 0x41a76178 self = 0x507837a8
| Shard id = 545 nice =-2 sched = 0/0 MRM = apps handle = 1349936616
| State = S schedstat = (15368096286 21707846934 69485) utm = 1226 stm = 310 core = 0
At com. android. server. power. PowerManagerService. isScreenOnInternal (PowerManagerService. java :~ 2529)
-Waiting to lock <0x41a7e2e8> (a java. lang. Object) held by tid = 85 (Binder_ B)
At com. android. server. power. PowerManagerService. isScreenOn (PowerManagerService. java: 2522)
At com. android. server. wm. WindowManagerService. sendScreenStatusToClientsLocked (WindowManagerService. java: 7749)
At com. android. server. wm. WindowManagerService. setEventDispatching (WindowManagerService. java: 7628)
At com. android. server. am. ActivityManagerService. updateEventDispatchingLocked (ActivityManagerService. java: 8083)
At com. android. server. am. ActivityManagerService. wakingUp (ActivityManagerService. java: 8077)
At com. android. server. power. Notifier. sendWakeUpBroadcast (Notifier. java: 474)
At com. android. server. power. Notifier. sendNextBroadcast (Notifier. java: 455)
At com. android. server. power. Notifier. access $700 (Notifier. java: 62)
At com. android. server. power. Notifier $ NotifierHandler. handleMessage (Notifier. java: 600)
At android. OS. Handler. dispatchMessage (Handler. java: 107)
At android. OS. lorule. loop (lorule. java: 194)
At com. android. server. ServerThread. run (SystemServer. java: 1328)
From the trace file, the reason is that the thread whose TID is 24 waits for a lock held by the thread whose TID is 12, and the thread whose TID is 12 waits for the lock held by the thread whose TID is 85, the thread whose TID is 85 does wait for the lock held by the thread whose TID is 24, leading to loop wait. The statement of the corresponding trace file is as follows:
TID 24:-waiting to lock <0x41a874a0> (a com. android. server. am. ActivityManagerService) held by tid = 12 (android. server. ServerThread)
TID 12:-waiting to lock <0x41a7e2e8> (a java. lang. Object) held by tid = 85 (Binder_ B)
TID 85:-waiting to lock <0x41a7e420> (a com. android. server. power. PowerManagerService $ DisplayBlankerImpl) held by tid = 24 (PowerManagerService)
Since it is a deadlock, first look at the locks in each thread.
First look at the top of the stack of the thread TID = 24. The broadcastIntent Function Code of ActivityManagerService is as follows:Copy codeThe Code is as follows: public final int broadcastIntent (IApplicationThread caller,
Intent intent, String resolvedType, IIntentReceiver resuler,
Int resultCode, String resultData, Bundle map,
String requiredPermission, boolean serialized, boolean sticky, int userId ){
EnforceNotIsolatedCaller ("broadcastIntent ");
Synchronized (this ){
Intent = verifyBroadcastLocked (intent );
Final ProcessRecord callerApp = getRecordForAppLocked (caller );
Final int callingPid = Binder. getCallingPid ();
Final int callingUid = Binder. getCallingUid ();
Final long origId = Binder. clearCallingIdentity ();
Int res = broadcastIntentLocked (callerApp,
CallerApp! = Null? CallerApp.info. packageName: null,
Intent, resolvedType, resul.pdf,
ResultCode, resultData, map, requiredPermission, serialized, sticky,
CallingPid, callingUid, userId );
Binder. restoreCallingIdentity (origId );
Return res;
}

We can see that the ActivityManagerService lock is required for TID = 24. Look at the top of the stack where TID = 12 threads exist. The isScreenOnInternal Function Code of PowerManagerService is as follows:Copy codeThe Code is as follows: private boolean isScreenOnInternal (){
Synchronized (mLock ){
Return! MSystemReady
| MDisplayPowerRequest. screenState! = DisplayPowerRequest. SCREEN_STATE_OFF;
}
}

You can see the mlock that requires PowerManagerService. Finally, let's take a look at the top of the stack where TID = 85 threads. Similarly, in PowerManagerService, the internal toString function of DisplayBlankerImpl is as follows:Copy codeThe Code is as follows: public String toString (){
Synchronized (this ){
Return "blanked =" + mBlanked;
}
}

This is implemented in the internal class DisplayBlankerImpl. Therefore, the DisplayBlankerImpl lock is required.
The corresponding table is as follows:

Table 1 waiting locks of various threads
From the table, there is no deadlock, which does not seem to be what we think. Isn't it a deadlock? I began to doubt myself a little. Is it caused by other reasons. It may not work if you only look at the top of the Call Stack. The top of the stack can only see the locks required by each thread, not just what you need! It's not good to ask for it! This is not what people do! Let's take a look at the entire stack call process and look at the locks we own.
Trace the stack of the TID = 24 thread and hold the lock in the unblankAllDisplays function of DisplayBlankerImpl in PowerManagerService:Copy codeThe Code is as follows: public void unblankAllDisplays (){
Synchronized (this ){
NativeSetAutoSuspend (false );
NativeSetInteractive (true );
MDisplayManagerService. unblkalldisplaysfrompowermanager ();
MBlanked = false;
/// M: add for tvout and hdmi
MTvOut. tvoutPowerEnable (true );
MHDMI. hdmiPowerEnable (true );
///@}
If (DEBUG ){
Slog. d (TAG_P, "unblankAllDisplays out ...");
}
If (mBootCompleted ){
Intent intent = new Intent (ACTION_LOCK_SCREEN_SHOW );
MContext. sendBroadcast (intent );
}
}
}

Finally, we added the code for sending broadcasts. According to the unblankAllDisplays function and broadcastIntent function, we can see that the thread with TID = 24 holds the DisplayBlankerImpl lock (unblankAllDisplays) and waits for the ActivityManagerService lock (broadcastIntent) to be released.
Similarly, the stack tracking TID = 12 threads is locked in the wake_up function of ActivityManagerService:Copy codeThe Code is as follows: public void wakingUp (){
If (checkCallingPermission (android. Manifest. permission. DEVICE_POWER)
! = PackageManager. PERMISSION_GRANTED ){
Throw new SecurityException ("Requires permission"
+ Android. Manifest. permission. DEVICE_POWER );
}
Synchronized (this ){
Slog. I (TAG, "wakingUp ");
MWentToSleep = false;
UpdateEventDispatchingLocked ();
ComeOutOfSleepIfNeededLocked ();
}
}

According to the wakingUp function and isScreenOnInternal function, we can see that the thread with TID = 12 holds the ActivityManagerService lock (wakingUp) and waits for the PowerManagerService. mLock lock (isScreenOnInternal ). At this point, we seem to have seen hope that the fog is about to be opened. A little bit of confidence is caused by a deadlock, but we still cannot reach a conclusion.
Keep track of the stack of the TID = 85 thread, and there is a lock operation in the dump of PowerManagerService:
Protected void dump (FileDescriptor fd, PrintWriter pw, String [] args ){
....
Synchronized (mLock ){
...
}
According to the toString function and the dump function, we can see that the TID = 85 thread holds the PowerManagerService. mLock lock (dump) at this time, and DisplayBlankerImpl (toString) is required ).
It seems that the answer has been revealed. If you haven't seen it yet (actually I haven't seen it), let's have a look at the table!

Table 2 thread locks
Are you clear? What a clear loop wait! The deadlock is so perfect, it is still a good chart effect, it seems that sometimes painting on paper is still useful!