ANR keyDispatchingTimedOut

Question

I'm experiencing some issues with application freezes. It looks like it has something to do with the hardwarerenderer and perhaps the amount of threads I'm using. I'd love for someone to have a look at the logs and tell me if there's anything obvious pointing out. Thanks.

    DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0 hwl=0 hwll=0)
"main" prio=5 tid=1 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x401f6600 self=0x125f8
  | sysTid=15811 nice=0 sched=0/0 cgrp=default handle=-1345129368
  | schedstat=( 0 0 0 ) utm=2495 stm=1172 core=0
  at com.google.android.gles_jni.EGLImpl.eglSwapBuffers(Native Method)
  at android.view.HardwareRenderer$GlRenderer.draw(HardwareRenderer.java:648)
  at android.view.ViewRoot.draw(ViewRoot.java:1594)
  at android.view.ViewRoot.performTraversals(ViewRoot.java:1410)
  at android.view.ViewRoot.handleMessage(ViewRoot.java:2040)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:132)
  at android.app.ActivityThread.main(ActivityThread.java:4123)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:491)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:841)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:599)
  at dalvik.system.NativeStart.main(Native Method)

"Thread-811" prio=5 tid=31 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x412479c0 self=0x45e478
  | sysTid=17073 nice=0 sched=0/0 cgrp=default handle=2020736
  | schedstat=( 0 0 0 ) utm=4 stm=0 core=1

"Thread-810" prio=5 tid=29 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x41296560 self=0x4d2f38
  | sysTid=17072 nice=0 sched=0/0 cgrp=default handle=10050328
  | schedstat=( 0 0 0 ) utm=3 stm=1 core=1

"Thread-809" prio=5 tid=28 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x4129b490 self=0x45e710
  | sysTid=17071 nice=0 sched=0/0 cgrp=default handle=5146952
  | schedstat=( 0 0 0 ) utm=3 stm=0 core=0

"Thread-808" prio=5 tid=27 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x412d6008 self=0x44aa48
  | sysTid=17070 nice=0 sched=0/0 cgrp=default handle=3737640
  | schedstat=( 0 0 0 ) utm=2 stm=0 core=0

"Thread-807" prio=5 tid=26 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x41352300 self=0x3abee0
  | sysTid=17069 nice=0 sched=0/0 cgrp=default handle=5418280
  | schedstat=( 0 0 0 ) utm=3 stm=0 core=1

"Thread-806" prio=5 tid=25 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x41352a00 self=0x4d0a00
  | sysTid=17068 nice=0 sched=0/0 cgrp=default handle=5327520
  | schedstat=( 0 0 0 ) utm=3 stm=0 core=1

"Thread-805" prio=5 tid=24 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x41352ef0 self=0x49bec8
  | sysTid=17067 nice=0 sched=0/0 cgrp=default handle=6587488
  | schedstat=( 0 0 0 ) utm=3 stm=0 core=1

"Thread-804" prio=5 tid=23 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x4138be18 self=0x4e2c18
  | sysTid=17066 nice=0 sched=0/0 cgrp=default handle=9299592
  | schedstat=( 0 0 0 ) utm=3 stm=0 core=1

"Thread-803" prio=5 tid=22 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x4138e5e0 self=0x483e58
  | sysTid=17065 nice=0 sched=0/0 cgrp=default handle=8949624
  | schedstat=( 0 0 0 ) utm=4 stm=0 core=0

"Thread-802" prio=5 tid=21 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x4151b210 self=0x4b23d0
  | sysTid=17064 nice=0 sched=0/0 cgrp=default handle=4798984
  | schedstat=( 0 0 0 ) utm=3 stm=0 core=0

"Thread-801" prio=5 tid=20 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x4151d118 self=0x492bd0
  | sysTid=17063 nice=0 sched=0/0 cgrp=default handle=10231792
  | schedstat=( 0 0 0 ) utm=3 stm=0 core=0

"Thread-800" prio=5 tid=19 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x416cf1f8 self=0x482808
  | sysTid=17062 nice=0 sched=0/0 cgrp=default handle=1742184
  | schedstat=( 0 0 0 ) utm=4 stm=0 core=1

"Thread-799" prio=5 tid=18 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x416daed8 self=0x488218
  | sysTid=17061 nice=0 sched=0/0 cgrp=default handle=4954264
  | schedstat=( 0 0 0 ) utm=3 stm=1 core=0

"Thread-798" prio=5 tid=17 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x40850ce8 self=0x4a9a28
  | sysTid=17060 nice=0 sched=0/0 cgrp=default handle=5096688
  | schedstat=( 0 0 0 ) utm=5 stm=0 core=0

"Thread-797" prio=5 tid=16 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x40870490 self=0x39e6e8
  | sysTid=17059 nice=0 sched=0/0 cgrp=default handle=6489784
  | schedstat=( 0 0 0 ) utm=6 stm=0 core=0

"Thread-796" prio=5 tid=15 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x40941f78 self=0x399aa8
  | sysTid=17058 nice=0 sched=0/0 cgrp=default handle=8600264
  | schedstat=( 0 0 0 ) utm=6 stm=0 core=0

"Thread-795" prio=5 tid=14 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x4102be68 self=0x1700b8
  | sysTid=17057 nice=0 sched=0/0 cgrp=default handle=9814600
  | schedstat=( 0 0 0 ) utm=5 stm=0 core=1

"Thread-794" prio=5 tid=13 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x41082f70 self=0x1f78d0
  | sysTid=17056 nice=0 sched=0/0 cgrp=default handle=7060200
  | schedstat=( 0 0 0 ) utm=4 stm=0 core=1

"Thread-793" prio=5 tid=12 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x410dcbf0 self=0x2ef6a0
  | sysTid=17055 nice=0 sched=0/0 cgrp=default handle=7993768
  | schedstat=( 0 0 0 ) utm=4 stm=0 core=0

"Thread-792" prio=5 tid=11 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x4113a620 self=0x5edf28
  | sysTid=17054 nice=0 sched=0/0 cgrp=default handle=7291408
  | schedstat=( 0 0 0 ) utm=6 stm=0 core=0

"Thread-791" prio=5 tid=10 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x4084c0a0 self=0x5c6b28
  | sysTid=17053 nice=0 sched=0/0 cgrp=default handle=6171632
  | schedstat=( 0 0 0 ) utm=6 stm=0 core=0

"AsyncTask #5" prio=5 tid=767 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x410cbcb0 self=0x85fca0
  | sysTid=16758 nice=10 sched=0/0 cgrp=bg_non_interactive handle=10617808
  | schedstat=( 0 0 0 ) utm=12 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x410cbe80> (a java.lang.VMThread) tid=767
  at java.lang.Thread.parkFor(Thread.java:1425)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:329)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1014)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1074)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:574)
  at java.lang.Thread.run(Thread.java:1020)

"AsyncTask #4" prio=5 tid=766 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4101c710 self=0x9e6ca8
  | sysTid=16757 nice=10 sched=0/0 cgrp=bg_non_interactive handle=10383448
  | schedstat=( 0 0 0 ) utm=36 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41079430> (a java.lang.VMThread) tid=766
  at java.lang.Thread.parkFor(Thread.java:1425)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:329)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1014)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1074)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:574)
  at java.lang.Thread.run(Thread.java:1020)

"AsyncTask #5" prio=5 tid=765 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x410a9788 self=0x7c0cd0
  | sysTid=16738 nice=10 sched=0/0 cgrp=bg_non_interactive handle=2062320
  | schedstat=( 0 0 0 ) utm=5 stm=0 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41352368> (a java.lang.VMThread) tid=765
  at java.lang.Thread.parkFor(Thread.java:1425)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:329)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1014)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1074)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:574)
  at java.lang.Thread.run(Thread.java:1020)

"AsyncTask #4" prio=5 tid=411 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x415f0098 self=0x779eb8
  | sysTid=16372 nice=10 sched=0/0 cgrp=bg_non_interactive handle=7993152
  | schedstat=( 0 0 0 ) utm=47 stm=2 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4113ed48> (a java.lang.VMThread) tid=411
  at java.lang.Thread.parkFor(Thread.java:1425)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:329)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1014)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1074)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:574)
  at java.lang.Thread.run(Thread.java:1020)

"AsyncTask #3" prio=5 tid=410 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x411276c8 self=0x66bb20
  | sysTid=16371 nice=10 sched=0/0 cgrp=bg_non_interactive handle=7590640
  | schedstat=( 0 0 0 ) utm=125 stm=1 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41127860> (a java.lang.VMThread) tid=410
  at java.lang.Thread.parkFor(Thread.java:1425)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:329)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObj...

Answer 1

ANR is well known issue. Make sure you do all the expensive operations in AsyncTask and do not overburden onCreate, onStart or onResume activities.

Look at Responsiveness for more info.

In particular, Activities should do as little as possible to set up in key life-cycle methods such as onCreate() and onResume(). Potentially long running operations such as network or database operations, or computationally expensive calculations such as resizing bitmaps should be done in a child thread (or in the case of databases operations, via an asynchronous request). However, this does not mean that your main thread should block while waiting for the child thread to complete — nor should you call Thread.wait() or Thread.sleep(). Instead of blocking while waiting for a child thread to complete, your main thread should provide a Handler for child threads to post back to upon completion. Designing your application in this way will allow your main thread to remain responsive to input and thus avoid ANR dialogs caused by the 5 second input event timeout. These same practices should be followed for any other threads that display UI, as they are also subject to the same timeouts.

Answer 2

I found a very specific cause for one of these ANR errors.

In one of my app's layout definitions I had set android:layout_alignRight="fieldX"

But then in the definition of fieldX I had android:visibility="gone".

So the display was trying to align fields to a field that was not visible.

By taking out the android:visibility line for the fieldX definition the app started to work correctly without hanging.