android - 需要对这个反复出现的问题有所了解，ANR keyDispatchingTimedOut

Question

我有一个应用程序在一个特定组件中不断获得 ANR，我无法弄清楚是什么占用了 cpu 时间。最近我得到了两种 ANR，一种是原生的，一种是等待的。

 DALVIK THREADS:
"main" prio=5 tid=1 NATIVE
  | group="main" sCount=1 dsCount=0 s=N obj=0x4001d8c0 self=0xccc8
  | sysTid=10569 nice=0 sched=0/0 cgrp=default handle=-1345017816
  | schedstat=( 9041503981 6690216078 17225 )
  at android.view.Surface.lockCanvasNative(Native Method)
  at android.view.Surface.lockCanvas(Surface.java:314)
  at android.view.SurfaceView$3.internalLockCanvas(SurfaceView.java:773)
  at android.view.SurfaceView$3.lockCanvas(SurfaceView.java:756)
  at com.dane.hud.Surfaceview$DrawThread.run(Surfaceview.java:776)
  at com.dane.hud.Surfaceview.onTouchEvent(Surfaceview.java:322)
  at android.view.View.dispatchTouchEvent(View.java:3766)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at com.android.internal.policy.impl.PhoneWindow$DecorView.superDispatchTouchEvent(PhoneWindow.java:1671)
  at com.android.internal.policy.impl.PhoneWindow.superDispatchTouchEvent(PhoneWindow.java:1107)
  at android.app.Activity.dispatchTouchEvent(Activity.java:2086)
  at com.android.internal.policy.impl.PhoneWindow$DecorView.dispatchTouchEvent(PhoneWindow.java:1655)
  at android.view.ViewRoot.handleMessage(ViewRoot.java:1785)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:123)
  at android.app.ActivityThread.main(ActivityThread.java:4627)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:521)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
  at dalvik.system.NativeStart.main(Native Method)

"Binder Thread #3" prio=5 tid=9 NATIVE
  | group="main" sCount=1 dsCount=0 s=N obj=0x44821de0 self=0x2b9b78
  | sysTid=10585 nice=0 sched=0/0 cgrp=default handle=2857768
  | schedstat=( 726806597 708740243 2395 )
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #2" prio=5 tid=6 NATIVE
  | group="main" sCount=1 dsCount=0 s=N obj=0x4476c5e8 self=0x13cbf8
  | sysTid=10574 nice=0 sched=0/0 cgrp=default handle=1213280
  | schedstat=( 767669649 687500005 2512 )
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #1" prio=5 tid=5 NATIVE
  | group="main" sCount=1 dsCount=0 s=N obj=0x4476b310 self=0x126f90
  | sysTid=10573 nice=0 sched=0/0 cgrp=default handle=1208144
  | schedstat=( 749938913 622802748 2497 )
  at dalvik.system.NativeStart.run(Native Method)

"Compiler" daemon prio=5 tid=4 VMWAIT
  | group="system" sCount=1 dsCount=0 s=N obj=0x447652a0 self=0x125b80
  | sysTid=10572 nice=0 sched=0/0 cgrp=default handle=1251720
  | schedstat=( 999145549 669586193 5169 )
  at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
  | group="system" sCount=0 dsCount=0 s=N obj=0x447651e8 self=0x121988
  | sysTid=10571 nice=0 sched=0/0 cgrp=default handle=1251656
  | schedstat=( 16204836 16693113 8 )
  at dalvik.system.NativeStart.run(Native Method)

"HeapWorker" daemon prio=5 tid=2 VMWAIT
  | group="system" sCount=1 dsCount=0 s=N obj=0x431a9650 self=0x1317c0
  | sysTid=10570 nice=0 sched=0/0 cgrp=default handle=1172520
  | schedstat=( 28203003083 34572570617 10984 )
  at dalvik.system.NativeStart.run(Native Method)

和

DALVIK THREADS:
"main" prio=5 tid=1 WAIT
  | group="main" sCount=1 dsCount=0 s=N obj=0x4001d8c0 self=0xccc8
  | sysTid=2428 nice=0 sched=0/0 cgrp=default handle=-1345017816
  | schedstat=( 5054412632 4232574644 11781 )
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4001d950> (a java.lang.VMThread)
  at java.lang.Thread.parkFor(Thread.java:1535)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:317)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:131)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153)
  at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:185)
  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
  at android.view.SurfaceView$3.internalLockCanvas(SurfaceView.java:764)
  at android.view.SurfaceView$3.lockCanvas(SurfaceView.java:756)
  at com.dane.hud.Surfaceview$DrawThread.run(Surfaceview.java:776)
  at com.dane.hud.Surfaceview.onTouchEvent(Surfaceview.java:319)
  at android.view.View.dispatchTouchEvent(View.java:3766)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:936)
  at com.android.internal.policy.impl.PhoneWindow$DecorView.superDispatchTouchEvent(PhoneWindow.java:1671)
  at com.android.internal.policy.impl.PhoneWindow.superDispatchTouchEvent(PhoneWindow.java:1107)
  at android.app.Activity.dispatchTouchEvent(Activity.java:2086)
  at com.android.internal.policy.impl.PhoneWindow$DecorView.dispatchTouchEvent(PhoneWindow.java:1655)
  at android.view.ViewRoot.handleMessage(ViewRoot.java:1785)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:123)
  at android.app.ActivityThread.main(ActivityThread.java:4627)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:521)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
  at dalvik.system.NativeStart.main(Native Method)

"Thread-448" prio=5 tid=16 WAIT
  | group="main" sCount=1 dsCount=0 s=N obj=0x447e4b40 self=0x2e5960
  | sysTid=2892 nice=0 sched=0/0 cgrp=default handle=3037856
  | schedstat=( 495635974 519531260 463 )
  at java.lang.Object.wait(Native Method)
  - waiting on <0x447eeb10> (a java.lang.VMThread)
  at java.lang.Thread.parkFor(Thread.java:1535)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:317)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:131)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153)
  at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:185)
  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
  at android.view.SurfaceView$3.internalLockCanvas(SurfaceView.java:764)
  at android.view.SurfaceView$3.lockCanvas(SurfaceView.java:756)
  at com.dane.hud.Surfaceview$DrawThread.run(Surfaceview.java:776)
  at com.dane.hud.HUD.updateWithNewLocation(HUD.java:639)
  at com.dane.hud.HUD.access$3(HUD.java:618)
  at com.dane.hud.HUD$updateEverythingFromGPS.run(HUD.java:573)

"Thread-447" prio=5 tid=15 WAIT
  | group="main" sCount=1 dsCount=0 s=N obj=0x447fb5f0 self=0x2bd690
  | sysTid=2890 nice=0 sched=0/0 cgrp=default handle=2873296
  | schedstat=( 636688219 727813733 545 )
  at java.lang.Object.wait(Native Method)
  - waiting on <0x447fb780> (a java.lang.VMThread)
  at java.lang.Thread.parkFor(Thread.java:1535)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:317)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:131)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153)
  at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:185)
  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
  at android.view.SurfaceView$3.internalLockCanvas(SurfaceView.java:764)
  at android.view.SurfaceView$3.lockCanvas(SurfaceView.java:756)
  at com.dane.hud.Surfaceview$DrawThread.run(Surfaceview.java:776)
  at com.dane.hud.HUD.updateWithNewLocation(HUD.java:639)
  at com.dane.hud.HUD.access$3(HUD.java:618)
  at com.dane.hud.HUD$updateEverythingFromGPS.run(HUD.java:573)

"Thread-446" prio=5 tid=14 WAIT
  | group="main" sCount=1 dsCount=0 s=N obj=0x44823a68 self=0x2ccac0
  | sysTid=2889 nice=0 sched=0/0 cgrp=default handle=2874496
  | schedstat=( 774780280 777496325 693 )
  at java.lang.Object.wait(Native Method)
  - waiting on <0x44786fe8> (a java.lang.VMThread)
  at java.lang.Thread.parkFor(Thread.java:1535)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:317)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:131)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153)
  at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:185)
  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
  at android.view.SurfaceView$3.internalLockCanvas(SurfaceView.java:764)
  at android.view.SurfaceView$3.lockCanvas(SurfaceView.java:756)
  at com.dane.hud.Surfaceview$DrawThread.run(Surfaceview.java:776)
  at com.dane.hud.HUD.updateWithNewLocation(HUD.java:639)
  at com.dane.hud.HUD.access$3(HUD.java:618)
  at com.dane.hud.HUD$updateEverythingFromGPS.run(HUD.java:573)

"Thread-445" prio=5 tid=13 WAIT
  | group="main" sCount=1 dsCount=0 s=N obj=0x447f2288 self=0x2e2a80
  | sysTid=2888 nice=0 sched=0/0 cgrp=default handle=3026032
  | schedstat=( 831634516 815490735 696 )
  at java.lang.Object.wait(Native Method)
  - waiting on <0x447f2418> (a java.lang.VMThread)
  at java.lang.Thread.parkFor(Thread.java:1535)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:317)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:131)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153)
  at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:185)
  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
  at android.view.SurfaceView$3.internalLockCanvas(SurfaceView.java:764)
  at android.view.SurfaceView$3.lockCanvas(SurfaceView.java:756)
  at com.dane.hud.Surfaceview$DrawThread.run(Surfaceview.java:776)
  at com.dane.hud.HUD.updateWithNewLocation(HUD.java:639)
  at com.dane.hud.HUD.access$3(HUD.java:618)
  at com.dane.hud.HUD$updateEverythingFromGPS.run(HUD.java:573)

"Thread-444" prio=5 tid=12 WAIT
  | group="main" sCount=1 dsCount=0 s=N obj=0x447c97c0 self=0x2c4910
  | sysTid=2887 nice=0 sched=0/0 cgrp=default handle=2780792
  | schedstat=( 1249114988 1195007328 1038 )
  at java.lang.Object.wait(Native Method)
  - waiting on <0x447cd918> (a java.lang.VMThread)
  at java.lang.Thread.parkFor(Thread.java:1535)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:317)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:131)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153)
  at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:185)
  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
  at android.view.SurfaceView$3.internalLockCanvas(SurfaceView.java:764)
  at android.view.SurfaceView$3.lockCanvas(SurfaceView.java:756)
  at com.dane.hud.Surfaceview$DrawThread.run(Surfaceview.java:776)
  at com.dane.hud.HUD.updateWithNewLocation(HUD.java:639)
  at com.dane.hud.HUD.access$3(HUD.java:618)
  at com.dane.hud.HUD$updateEverythingFromGPS.run(HUD.java:573)

"Thread-443" prio=5 tid=11 VMWAIT JIT
  | group="main" sCount=1 dsCount=0 s=Y obj=0x4480cd28 self=0x2d27b0
  | sysTid=2886 nice=0 sched=0/0 cgrp=default handle=2959600
  | schedstat=( 1636657703 1482391360 1374 )
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.addWaiter(AbstractQueuedSynchronizer.java:~562)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153)
  at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:185)
  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
  at android.view.Surfa...

有任何想法吗？我已将操作移至新线程，也许我没有调用 join(); 在他们。

谢谢你的帮助。

Answer 1

在这里：

http://developer.android.com/guide/practices/design/responsiveness.html

ANR 是当主线程阻塞某事时，所以总是建议在子线程中进行长时间操作：

去引用：

因此，在主线程中运行的任何方法都应该尽可能少地工作。特别是，Activity 应该尽可能少地设置关键生命周期方法，例如 onCreate() 和 onResume()。可能长时间运行的操作（例如网络或数据库操作）或计算量大的计算（例如调整位图大小）应该在子线程中完成（或者在数据库操作的情况下，通过异步请求）。但是，这并不意味着您的主线程应该在等待子线程完成时阻塞——您也不应该调用 Thread.wait() 或 Thread.sleep()。而不是在等待子线程完成时阻塞，您的主线程应该为子线程提供一个处理程序，以便在完成后回发。以这种方式设计您的应用程序将使您的主线程保持对输入的响应，从而避免由 5 秒输入事件超时引起的 ANR 对话框。任何其他显示 UI 的线程都应遵循这些相同的做法，因为它们也受到相同的超时限制。

我知道这并不容易，但上面的建议是 UI 不应该在主线程中完成。

另一方面，您的主线程处于“等待”状态，这意味着使用了非异步操作。也许你想尝试异步选项 - 这应该会导致 TIMED_WAIT 状态，如下所示：

Android - 我如何调查 ANR？

（其主线程没问题）。

但就像这里讨论的那样：

http://groups.google.com/group/android-ndk/browse_thread/thread/84d6a9be21f4e579/b83537161b96da82?q=%22Bitmap+creation+and+composition+in+native+code%22#b83537161b96da82

我怀疑您的问题是因为位图绘制在 lockCanvas() 和 unlockCanvas() 之间花费的时间太长 - 也许您可能想将位图更新分成更小的部分？在同一个讨论中还提到了使用 JNI/NDK 来进行位图计算——这不应该在基于 Java 的位图更新方法中完成——如果计算时间太长的话。

推荐阅读：

http://obviam.net/index.php/the-android-game-loop/

谢谢。

Answer 2

根据日志，我能想到的可能触发 ANR 的唯一原因是：

据我所知，通常在 Java 中每个线程都与 2 个组件相关联。一个是程序计数器，另一个是垃圾收集器。所以每个线程都会有一个 gc 监视器在整个过程中发生。

在 java.lang.Object.wait(Native Method) - 等待 <0x4001d950> (a java.lang.VMThread)

VMThreads 理想地用于处理监控 gc 的这一方面，几乎是并行的。因此，对于您的情况，我能想到的是 SurfaceView 试图获取锁但无法获取锁，因为 VMThread 持有锁，尚未释放（可能是由于某些主要的 GC 操作），因此等待 vmthread 释放锁.

您可能想检查记录了 gc 活动的主日志转储，这可能会让您更好地了解 gc 为何如此占用此线程 CPU 时间，然后应用程序分析可能会有所帮助。检查一下。