Come eseguire il debug di Android ANR?

Question

La mia app per Android riceve molti rapporti ANR nella console di Google Play. Poiché questo ha iniziato a verificarsi quando ho incluso Google Analytics nell'app, sospetto fortemente che Analytics lo causi.

Il problema è che so come eseguire il debug di un arresto anomalo utilizzando la traccia dello stack. Ma non sono sicuro di come eseguire il debug di un ANR. Immagino che un ANR significhi che il thread principale è bloccato da qualche parte. Ma come sapere dove è bloccato? Vedi sotto uno dei tipici ANR che ho ultimamente. Come interpretarlo e iniziare a capire dove si blocca l'app?

PS: Alcune delle classi/metodi negli stack sembrano strani a causa dell'uso del codice DexGuard.

ANR segnalare:

DALVIK THREADS: 
(mutexes: tll=0 tsl=0 tscl=0 ghl=0 hwl=0 hwll=0) 
"main" prio=5 tid=1 VMWAIT 
| group="main" sCount=1 dsCount=0 obj=0x40022198 self=0xcec8 
| sysTid=5001 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=-1345006496 
| schedstat=(1265991222 1037628169 649) 
at dalvik.system.DexFile.openDexFile(Native Method) 
at dalvik.system.DexFile.<init>(DexFile.java:103) 
at dalvik.system.DexFile.loadDex(DexFile.java:142) 
at java.lang.reflect.Method.invokeNative(Native Method) 
at java.lang.reflect.Method.invoke(Method.java:507) 
at o.Ə$鷭$囃.<clinit>((null):-1) 
at o.Ə$櫯.onServiceConnected(:-1) 
at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1064) 
at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1081) 
at android.os.Handler.handleCallback(Handler.java:587) 
at android.os.Handler.dispatchMessage(Handler.java:92) 
at android.os.Looper.loop(Looper.java:130) 
at android.app.ActivityThread.main(ActivityThread.java:3687) 
at java.lang.reflect.Method.invokeNative(Native Method) 
at java.lang.reflect.Method.invoke(Method.java:507) 
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:867) 
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:625) 
at dalvik.system.NativeStart.main(Native Method) 

"Binder Thread #3" prio=5 tid=14 NATIVE 
| group="main" sCount=1 dsCount=0 obj=0x40624cc0 self=0x27eeb0 
| sysTid=5046 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=2499688 
| schedstat=(946046 5981445 3) 
at dalvik.system.NativeStart.run(Native Method) 

"Thread-15" prio=5 tid=13 TIMED_WAIT 
| group="main" sCount=1 dsCount=0 obj=0x405e2a10 self=0x1c99e0 
| sysTid=5020 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1845856 
| schedstat=(41442864 92254646 93) 
at java.lang.Object.wait(Native Method) 
- waiting on <0x4050ddb0> (a o.㱽) 
at java.lang.Object.wait(Object.java:395) 
at o.㱽.run(:723) 
at java.lang.Thread.run(Thread.java:1019) 

"CookieSyncManager" prio=5 tid=12 NATIVE 
| group="main" sCount=1 dsCount=0 obj=0x40575550 self=0x1ca5a0 
| sysTid=5019 nice=10 sched=0/0 cgrp=[fopen-error:2] handle=1844760 
| schedstat=(793456 13153076 3) 
at android.os.MessageQueue.nativePollOnce(Native Method) 
at android.os.MessageQueue.next(MessageQueue.java:119) 
at android.os.Looper.loop(Looper.java:117) 
at android.webkit.WebSyncManager.run(WebSyncManager.java:90) 
at android.webkit.CookieSyncManager.run(CookieSyncManager.java:61) 
at java.lang.Thread.run(Thread.java:1019) 

"WebViewWorkerThread" prio=5 tid=11 NATIVE 
| group="main" sCount=1 dsCount=0 obj=0x40572d28 self=0x1cec60 
| sysTid=5017 nice=1 sched=0/0 cgrp=[fopen-error:2] handle=1904424 
| schedstat=(21575930 39001463 32) 
at android.os.MessageQueue.nativePollOnce(Native Method) 
at android.os.MessageQueue.next(MessageQueue.java:119) 
at android.os.Looper.loop(Looper.java:117) 
at android.os.HandlerThread.run(HandlerThread.java:60) 

"WebViewCoreThread" prio=5 tid=10 NATIVE 
| group="main" sCount=1 dsCount=0 obj=0x405ded38 self=0x1c9300 
| sysTid=5016 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1872952 
| schedstat=(205108647 198852533 140) 
at android.os.MessageQueue.nativePollOnce(Native Method) 
at android.os.MessageQueue.next(MessageQueue.java:119) 
at android.os.Looper.loop(Looper.java:117) 
at android.webkit.WebViewCore$WebCoreThread.run(WebViewCore.java:685) 
at java.lang.Thread.run(Thread.java:1019) 

"pool-1-thread-1" prio=5 tid=9 WAIT 
| group="main" sCount=1 dsCount=0 obj=0x4050daa0 self=0x1c05b8 
| sysTid=5015 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1869904 
| schedstat=(5187987 16571046 6) 
at java.lang.Object.wait(Native Method) 
- waiting on <0x4050dc68> (a java.lang.VMThread) 
at java.lang.Thread.parkFor(Thread.java:1424) 
at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) 
at sun.misc.Unsafe.park(Unsafe.java:337) 
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157) 
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016) 
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:411) 
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1021) 
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1081) 
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:581) 
at java.lang.Thread.run(Thread.java:1019) 

"GAThread" prio=5 tid=8 WAIT 
| group="main" sCount=1 dsCount=0 obj=0x405a4518 self=0x1b8e58 
| sysTid=5014 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1806224 
| schedstat=(288482667 146301269 277) 
at java.lang.Object.wait(Native Method) 
- waiting on <0x405a4798> (a java.lang.VMThread) 
at java.lang.Thread.parkFor(Thread.java:1424) 
at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) 
at sun.misc.Unsafe.park(Unsafe.java:337) 
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157) 
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016) 
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:411) 
at o.뛖.run(:518) 

"Binder Thread #2" prio=5 tid=7 NATIVE 
| group="main" sCount=1 dsCount=0 obj=0x40516ed0 self=0xe4478 
| sysTid=5007 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1390912 
| schedstat=(5340576 31036382 32) 
at dalvik.system.NativeStart.run(Native Method) 

"Binder Thread #1" prio=5 tid=6 NATIVE 
| group="main" sCount=1 dsCount=0 obj=0x40515cb0 self=0x1534c8 
| sysTid=5006 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=577280 
| schedstat=(10803221 33203131 35) 
at dalvik.system.NativeStart.run(Native Method) 

"Compiler" daemon prio=5 tid=5 VMWAIT 
| group="system" sCount=1 dsCount=0 obj=0x40511d80 self=0x8cce0 
| sysTid=5005 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1146040 
| schedstat=(79406736 76446531 396) 
at dalvik.system.NativeStart.run(Native Method) 

"Signal Catcher" daemon prio=5 tid=4 RUNNABLE 
| group="system" sCount=0 dsCount=0 obj=0x40511cc0 self=0x117af8 
| sysTid=5004 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1145528 
| schedstat=(23651123 21545411 7) 
at dalvik.system.NativeStart.run(Native Method) 

"GC" daemon prio=5 tid=3 VMWAIT 
| group="system" sCount=1 dsCount=0 obj=0x40511c18 self=0x153240 
| sysTid=5003 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1389056 
| schedstat=(367523192 416046141 132) 
at dalvik.system.NativeStart.run(Native Method) 

"HeapWorker" daemon prio=5 tid=2 VMWAIT 
| group="system" sCount=1 dsCount=0 obj=0x40511b60 self=0xe6980 
| sysTid=5002 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=944960 
| schedstat=(52612306 103576660 48) 
at dalvik.system.NativeStart.run(Native Method) 

Answer 1

Ma come sapere dove si è bloccato?

Avviare da enabling StrictMode ed eseguire l'app. Se voi (o Analytics) sta facendo disco o rete di I/O sul thread dell'applicazione principale, si trova su di esso, in base al vostro stile di sanzione scelta (ad esempio, eseguire il login LogCat):

public void onCreate() { 
    if (BuildConfig.DEBUG) { 
     StrictMode.setThreadPolicy(new StrictMode.ThreadPolicy.Builder() 
       .detectAll() 
       .penaltyLog() 
       .build()); 
    } 

    super.onCreate(); 

    // rest of onCreate() logic here 
}