Jak debugować Androida ANR?

Question

Moja aplikacja na Androida otrzymuje ostatnio wiele raportów ANR w konsoli Google Play. Ponieważ to się zaczęło, gdy dodałem Google Analytics do aplikacji, podejrzewam, że Analytics spowodował to.

Problem polega na tym, że wiem, jak debugować awarię za pomocą śledzenia stosu. Ale nie jestem pewien, jak debugować ANR. Przypuszczam, że ANR oznacza, że ​​główny wątek jest gdzieś zablokowany. Ale jak się dowiedzieć, gdzie jest zablokowany? Zobacz poniżej jedną z typowych ANR, którą mam ostatnio. Jak zinterpretować to i zacząć zastanawiać się, gdzie aplikacja się zawiesza?

PS: Niektóre klasy/metody w stosach wyglądają dziwnie ze względu na użycie obfuscatora kodu DexGuard.

ANR zgłosić:

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

Ale jak wiesz gdzie to jest zablokowany?

Zacznij od enabling StrictMode i uruchom swoją aplikację. Jeśli (lub Analytics) robią dysku lub sieci I/O na głównym wątku aplikacji, będzie dowiedzieć się o tym, w oparciu o swój styl karnego wybranego (np zalogować LogCat):

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

    super.onCreate(); 

    // rest of onCreate() logic here 
}