android - 如何调试Android ANR？

Question

我的 Android 应用最近在 Google Play 控制台中收到大量 ANR 报告。 当我在应用程序中加入 Google Analytics 时就开始出现这种情况，我强烈怀疑是 Google Analytics 引起的。

问题是我知道如何使用堆栈跟踪来调试崩溃。但我不确定如何调试 ANR。我猜 ANR 意味着主线程在某处被阻塞。但是怎么知道它被阻塞在哪里呢？请参阅下面我最近收到的典型 ANR 之一。如何解释它并开始弄清楚应用挂起的位置？

PS:由于使用了 DexGuard 代码混淆器，堆栈中的一些类/方法看起来很奇怪。

ANR 报告:

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

But how to know where it is blocked?

开始 enabling StrictMode并运行您的应用程序。如果您(或 Analytics)在主应用程序线程上执行磁盘或网络 I/O，您将​​根据您选择的惩罚方式(例如，登录 LogCat)找到它:

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

     super.onCreate();

     // rest of onCreate() logic here
 }