Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How do I interpret ANR traces.txt when my code doesn't appear on stack?

I am trying to debug a persistent ANR ("application not responding") in my Android application.

I have read these threads:

  • Android - how do I investigate an ANR?
  • How to debug Android ANR?
  • Interpreting an ANR stack trace

The overriding message is to use StrictMode, which I will do.

However, I would still like to interpret the cause of the ANR stack I am repeatedly seeing. First, I don't see any main thread -- instead I see many threads in the main "group", including one thread named "waitForActivityStart".

On none of the threads do I see my code, so I am confused as to how this ANR can be happening due to my own code. The only code I see from a library that I installed was Google Analytics (GA) which you can see titled "GAThread". Could that be the culprit? If so, could someone explain how I could deduce that from this report?

Here is the output from traces.txt that I pulled using ADB on a Nexus 7 running 4.2.2

----- pid 15370 at 2013-05-11 11:12:04 -----
Cmd line: com.appspot.myapp

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)

"waitForActivityStart" prio=5 tid=12 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41d63a98 self=0x658cafd0
  | sysTid=16096 nice=0 sched=0/0 cgrp=apps handle=1736692928
  | state=S schedstat=( 27554000 13871100000 1319 ) utm=2 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41d63a98> (a java.util.Timer$TimerImpl)
  at java.lang.Object.wait(Object.java:364)
  at java.util.Timer$TimerImpl.run(Timer.java:214)

"Binder_5" prio=5 tid=32 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41dd6570 self=0x678fa458
  | sysTid=29473 nice=0 sched=0/0 cgrp=apps handle=1732666432
  | state=S schedstat=( 578000 10600000 3 ) utm=0 stm=0 core=0
  #00  pc 00016fe4  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002a97d  /system/lib/libc.so (ioctl+16)
  #02  pc 00016ba1  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)
  #03  pc 00017363  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 0001b15d  /system/lib/libbinder.so
  #05  pc 00011267  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
  #06  pc 0004679f  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
  #07  pc 00010dcd  /system/lib/libutils.so
  #08  pc 0000e3d8  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000dac4  /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

"Binder_4" prio=5 tid=31 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41dd7568 self=0x67beb3d0
  | sysTid=29471 nice=0 sched=0/0 cgrp=apps handle=1740371672
  | state=S schedstat=( 889000 17652000 4 ) utm=0 stm=0 core=0
  #00  pc 00016fe4  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002a97d  /system/lib/libc.so (ioctl+16)
  #02  pc 00016ba1  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)
  #03  pc 00017363  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 0001b15d  /system/lib/libbinder.so
  #05  pc 00011267  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
  #06  pc 0004679f  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
  #07  pc 00010dcd  /system/lib/libutils.so
  #08  pc 0000e3d8  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000dac4  /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

"Thread-591" prio=5 tid=1 VMWAIT
  | group="main" sCount=1 dsCount=0 obj=0x420e8b20 self=0x4008dbf8
  | sysTid=15370 nice=0 sched=0/0 cgrp=apps handle=1075213276
  | state=S schedstat=( 41399201000 18980658000 498884 ) utm=3147 stm=992 core=0
  #00  pc 00018104  /system/lib/libc.so (__futex_syscall3+8)
  #01  pc 0000e41c  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
  #02  pc 0000e478  /system/lib/libc.so (__pthread_cond_timedwait+60)
  #03  pc 0004a471  /system/lib/libdvm.so
  #04  pc 0003a19d  /system/lib/libdvm.so
  #05  pc 00047571  /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+452)
  #06  pc 00000db7  /system/bin/app_process
  #07  pc 0001271f  /system/lib/libc.so (__libc_init+38)
  #08  pc 00000ae8  /system/bin/app_process
  at dalvik.system.NativeStart.run(Native Method)

"pool-5-thread-1" prio=5 tid=35 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x42313ee0 self=0x67a998c0
  | sysTid=15727 nice=0 sched=0/0 cgrp=apps handle=1739169040
  | state=S schedstat=( 37218000 13354072000 1531 ) utm=0 stm=3 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x42314090> (a java.lang.VMThread) held by tid=35 (pool-5-thread-1)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"Binder_3" prio=5 tid=34 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41d60f08 self=0x67b39348
  | sysTid=15539 nice=0 sched=0/0 cgrp=apps handle=1737253696
  | state=S schedstat=( 147555000 13725277000 1713 ) utm=5 stm=9 core=0
  #00  pc 00016fe4  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002a97d  /system/lib/libc.so (ioctl+16)
  #02  pc 00016ba1  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)
  #03  pc 00017363  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 0001b15d  /system/lib/libbinder.so
  #05  pc 00011267  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
  #06  pc 0004679f  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
  #07  pc 00010dcd  /system/lib/libutils.so
  #08  pc 0000e3d8  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000dac4  /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

"Thread-558" prio=5 tid=25 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41a47528 self=0x67653008
  | sysTid=15453 nice=0 sched=0/0 cgrp=apps handle=1696217960
  | state=S schedstat=( 360133000 13802662000 2116 ) utm=18 stm=18 core=0
  #00  pc 00017ee4  /system/lib/libc.so (epoll_wait+12)
  #01  pc 0012b949  /system/lib/libchromium_net.so
  #02  pc 0012b755  /system/lib/libchromium_net.so
  #03  pc 00058415  /system/lib/libchromium_net.so
  #04  pc 00056b13  /system/lib/libchromium_net.so (MessageLoop::RunInternal()+114)
  #05  pc 00056b71  /system/lib/libchromium_net.so (MessageLoop::Run()+16)
  #06  pc 000771d9  /system/lib/libchromium_net.so (base::Thread::ThreadMain()+188)
  #07  pc 00076c93  /system/lib/libchromium_net.so
  #08  pc 0000e3d8  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000dac4  /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

"IntentService[1020055585435]" prio=5 tid=30 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41bab2c8 self=0x658e8d78
  | sysTid=15445 nice=0 sched=0/0 cgrp=apps handle=1732697176
  | state=S schedstat=( 65802000 13690073000 1380 ) utm=3 stm=3 core=0
  #00  pc 00017ee4  /system/lib/libc.so (epoll_wait+12)
  #01  pc 00014b09  /system/lib/libutils.so (android::Looper::pollInner(int)+96)
  #02  pc 00014d71  /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+104)
  #03  pc 0005ed53  /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22)
  #04  pc 0001e290  /system/lib/libdvm.so (dvmPlatformInvoke+112)
  #05  pc 0004d411  /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+396)
  #06  pc 00000214  /dev/ashmem/dalvik-jit-code-cache (deleted)
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:125)
  at android.os.Looper.loop(Looper.java:124)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"pool-2-thread-3" prio=5 tid=29 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41dbf1c0 self=0x652f9308
  | sysTid=15436 nice=0 sched=0/0 cgrp=apps handle=1697608048
  | state=S schedstat=( 1491948000 14906498000 27824 ) utm=100 stm=49 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41dbf2e0> (a java.lang.VMThread) held by tid=29 (pool-2-thread-3)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-2" prio=5 tid=28 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41dd7218 self=0x652f8cb0
  | sysTid=15435 nice=0 sched=0/0 cgrp=apps handle=1697608112
  | state=S schedstat=( 1408475000 14385713000 28965 ) utm=82 stm=58 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41dd74f0> (a java.lang.VMThread) held by tid=28 (pool-2-thread-2)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-1" prio=5 tid=27 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41dd2f50 self=0x652f8658
  | sysTid=15434 nice=0 sched=0/0 cgrp=apps handle=1697610152
  | state=S schedstat=( 1290069000 14078945000 26535 ) utm=80 stm=49 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41dd3348> (a java.lang.VMThread) held by tid=27 (pool-2-thread-1)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"CookieSyncManager" prio=5 tid=26 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41d57ea0 self=0x65118458
  | sysTid=15427 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1695647912
  | state=S schedstat=( 72284000 33324218000 1453 ) utm=5 stm=2 core=0
  #00  pc 00017ee4  /system/lib/libc.so (epoll_wait+12)
  #01  pc 00014b09  /system/lib/libutils.so (android::Looper::pollInner(int)+96)
  #02  pc 00014d71  /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+104)
  #03  pc 0005ed53  /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22)
  #04  pc 0001e290  /system/lib/libdvm.so (dvmPlatformInvoke+112)
  #05  pc 0004d411  /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+396)
  #06  pc 000276e4  /system/lib/libdvm.so
  #07  pc 000fedd0  <unknown>
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:125)
  at android.os.Looper.loop(Looper.java:124)
  at android.webkit.WebSyncManager.run(WebSyncManager.java:90)
  at android.webkit.CookieSyncManager.run(CookieSyncManager.java:58)
  at java.lang.Thread.run(Thread.java:856)

"WebViewCoreThread" prio=5 tid=24 SUSPENDED
  | group="main" sCount=1 dsCount=0 obj=0x41d68058 self=0x65163bc0
  | sysTid=15425 nice=0 sched=0/0 cgrp=apps handle=1750731264
  | state=S schedstat=( 4316727011000 240001236000 3061982 ) utm=352956 stm=78716 core=1
  at android.os.Message.clearForRecycle(Message.java:~416)
  at android.os.Message.recycle(Message.java:249)
  at android.os.Looper.loop(Looper.java:154)
  at android.webkit.WebViewCore$WebCoreThread.run(WebViewCore.java:812)
  at java.lang.Thread.run(Thread.java:856)

"Timer-2" daemon prio=5 tid=20 TIMED_WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41a40d40 self=0x61e0fa60
  | sysTid=15416 nice=0 sched=0/0 cgrp=apps handle=1761429616
  | state=S schedstat=( 683553000 13044592000 2664 ) utm=35 stm=33 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41a40d40> (a java.util.Timer$TimerImpl)
  at java.lang.Object.wait(Object.java:401)
  at java.util.Timer$TimerImpl.run(Timer.java:238)

"Timer-1" prio=5 tid=17 TIMED_WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41a4da68 self=0x61e0efc0
  | sysTid=15415 nice=0 sched=0/0 cgrp=apps handle=1752179848
  | state=S schedstat=( 1730907000 12820407000 4622 ) utm=93 stm=80 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41a4da68> (a java.util.Timer$TimerImpl)
  at java.lang.Object.wait(Object.java:401)
  at java.util.Timer$TimerImpl.run(Timer.java:238)

"AsyncTask #5" prio=5 tid=21 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4159d000 self=0x61e0f410
  | sysTid=15399 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1752193288
  | state=S schedstat=( 993689000 34112882000 25528 ) utm=64 stm=35 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41258e38> (a java.lang.VMThread) held by tid=21 (AsyncTask #5)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"AsyncTask #4" prio=5 tid=19 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x415a1498 self=0x64fb3440
  | sysTid=15397 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1740995712
  | state=S schedstat=( 294266000 33025525000 4122 ) utm=14 stm=15 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x413ccdd0> (a java.lang.VMThread) held by tid=19 (AsyncTask #4)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"AsyncTask #3" prio=5 tid=18 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x415aa1e0 self=0x64fb2ff0
  | sysTid=15396 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1637810544
  | state=S schedstat=( 463352000 33418786000 16118 ) utm=24 stm=22 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41434770> (a java.lang.VMThread) held by tid=18 (AsyncTask #3)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"GAThread" prio=5 tid=16 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x413a02d0 self=0x67fca048
  | sysTid=15392 nice=0 sched=0/0 cgrp=apps handle=1741546872
  | state=S schedstat=( 271767000 12492783000 3617 ) utm=16 stm=11 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x413a07a0> (a java.lang.VMThread) held by tid=16 (GAThread)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at com.google.analytics.tracking.android.GAThread.run(GAThread.java:518)

"AsyncTask #2" prio=5 tid=15 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41336e00 self=0x68c253a8
  | sysTid=15391 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1739175192
  | state=S schedstat=( 161268000 33424207000 2235 ) utm=14 stm=2 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41337138> (a java.lang.VMThread) held by tid=15 (AsyncTask #2)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"com.google.common.base.internal.Finalizer" daemon prio=5 tid=14 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41597f60 self=0x687b1950
  | sysTid=15390 nice=0 sched=0/0 cgrp=apps handle=1738518000
  | state=S schedstat=( 33716000 11962753000 1419 ) utm=0 stm=3 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x415bd708> (a java.lang.ref.ReferenceQueue)
  at java.lang.Object.wait(Object.java:401)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
  at com.google.common.base.internal.Finalizer.run(Finalizer.java:127)

"AsyncTask #1" prio=5 tid=11 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x415b4808 self=0x68ef9008
  | sysTid=15384 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1759288072
  | state=S schedstat=( 1313537000 34846758000 40646 ) utm=66 stm=65 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x414d7b08> (a java.lang.VMThread) held by tid=11 (AsyncTask #1)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"Binder_2" prio=5 tid=10 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41259730 self=0x400c4890
  | sysTid=15382 nice=0 sched=0/0 cgrp=apps handle=1749727712
  | state=S schedstat=( 162809000 12976665000 1817 ) utm=4 stm=12 core=0
  #00  pc 00016fe4  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002a97d  /system/lib/libc.so (ioctl+16)
  #02  pc 00016ba1  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)
  #03  pc 00017363  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 0001b15d  /system/lib/libbinder.so
  #05  pc 00011267  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
  #06  pc 0004679f  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
  #07  pc 00010dcd  /system/lib/libutils.so
  #08  pc 0000e3d8  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000dac4  /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

"Binder_1" prio=5 tid=9 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41259528 self=0x686e9b50
  | sysTid=15381 nice=0 sched=0/0 cgrp=apps handle=1742555472
  | state=S schedstat=( 168070000 12929180000 1689 ) utm=5 stm=11 core=0
  #00  pc 00016fe4  /system/lib/libc.so (__ioctl+8)
  #01  pc 0002a97d  /system/lib/libc.so (ioctl+16)
  #02  pc 00016ba1  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)
  #03  pc 00017363  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04  pc 0001b15d  /system/lib/libbinder.so
  #05  pc 00011267  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
  #06  pc 0004679f  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
  #07  pc 00010dcd  /system/lib/libutils.so
  #08  pc 0000e3d8  /system/lib/libc.so (__thread_entry+72)
  #09  pc 0000dac4  /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

"FinalizerWatchdogDaemon" daemon prio=5 tid=8 WAIT
  | group="system" sCount=1 dsCount=0 obj=0x41256478 self=0x68e87008
  | sysTid=15380 nice=0 sched=0/0 cgrp=apps handle=1749728624
  | state=S schedstat=( 29418000 12402123000 1347 ) utm=0 stm=2 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40b2f4f0> (a java.lang.Daemons$FinalizerWatchdogDaemon)
  at java.lang.Object.wait(Object.java:364)
  at java.lang.Daemons$FinalizerWatchdogDaemon.waitForObject(Daemons.java:230)
  at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:207)
  at java.lang.Thread.run(Thread.java:856)

"FinalizerDaemon" daemon prio=5 tid=7 WAIT
  | group="system" sCount=1 dsCount=0 obj=0x412562c8 self=0x67fd5c98
  | sysTid=15379 nice=0 sched=0/0 cgrp=apps handle=1744330952
  | state=S schedstat=( 939854000 13219874000 23293 ) utm=44 stm=49 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40b1b610> (a java.lang.ref.ReferenceQueue)
  at java.lang.Object.wait(Object.java:401)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
  at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:170)
  at java.lang.Thread.run(Thread.java:856)

"ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
  | group="system" sCount=1 dsCount=0 obj=0x41256160 self=0x68c25b58
  | sysTid=15378 nice=0 sched=0/0 cgrp=apps handle=1752190528
  | state=S schedstat=( 202737000 12617578000 5722 ) utm=8 stm=12 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40b1b538> 
  at java.lang.Object.wait(Object.java:364)
  at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:130)
  at java.lang.Thread.run(Thread.java:856)

"Compiler" daemon prio=5 tid=5 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x41256070 self=0x68a0c008
  | sysTid=15377 nice=0 sched=0/0 cgrp=apps handle=1739196488
  | state=S schedstat=( 1621753000 12981418000 10901 ) utm=77 stm=85 core=0
  #00  pc 00018104  /system/lib/libc.so (__futex_syscall3+8)
  #01  pc 0000e41c  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
  #02  pc 0000e478  /system/lib/libc.so (__pthread_cond_timedwait+60)
  #03  pc 00072aed  /system/lib/libdvm.so
  #04  pc 00053ec3  /system/lib/libdvm.so
  #05  pc 0000e3d8  /system/lib/libc.so (__thread_entry+72)
  #06  pc 0000dac4  /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

"JDWP" daemon prio=5 tid=4 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x41255f88 self=0x686f5218
  | sysTid=15376 nice=0 sched=0/0 cgrp=apps handle=1751126616
  | state=S schedstat=( 454961000 13545739000 5922 ) utm=21 stm=24 core=0
  #00  pc 0001710c  /system/lib/libc.so (select+20)
  #01  pc 00060af3  /system/lib/libdvm.so
  #02  pc 00063685  /system/lib/libdvm.so
  #03  pc 00053ec3  /system/lib/libdvm.so
  #04  pc 0000e3d8  /system/lib/libc.so (__thread_entry+72)
  #05  pc 0000dac4  /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
  | group="system" sCount=0 dsCount=0 obj=0x41255e90 self=0x68707510
  | sysTid=15375 nice=0 sched=0/0 cgrp=apps handle=1750229976
  | state=R schedstat=( 108149000 12286071000 1367 ) utm=3 stm=7 core=2
  at dalvik.system.NativeStart.run(Native Method)

"GC" daemon prio=5 tid=2 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x41255db0 self=0x400c3120
  | sysTid=15374 nice=0 sched=0/0 cgrp=apps handle=1737473208
  | state=S schedstat=( 809115000 13436300000 1840 ) utm=78 stm=2 core=0
  #00  pc 00018104  /system/lib/libc.so (__futex_syscall3+8)
  #01  pc 0000e41c  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
  #02  pc 0000e478  /system/lib/libc.so (__pthread_cond_timedwait+60)
  #03  pc 0007189f  /system/lib/libdvm.so
  #04  pc 00053ec3  /system/lib/libdvm.so
  #05  pc 0000e3d8  /system/lib/libc.so (__thread_entry+72)
  #06  pc 0000dac4  /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

NATIVE THREADS:
"pspot.myapp" sysTid=15395 nice=0 sched=0/0 cgrp=apps
  | state=S schedstat=( 27404000 12509974000 1316 ) utm=0 stm=2 core=0

"WebViewCoreThre" sysTid=15428 nice=0 sched=0/0 cgrp=apps
  | state=S schedstat=( 64881000 14061064000 1376 ) utm=4 stm=2 core=0

"SignalSender" sysTid=15429 nice=0 sched=0/0 cgrp=apps
  | state=S schedstat=( 79512663000 70511451000 1497804 ) utm=1896 stm=6055 core=1

"WebViewCoreThre" sysTid=15455 nice=0 sched=0/0 cgrp=apps
  | state=S schedstat=( 46170000 14001776000 1413 ) utm=1 stm=3 core=0

"TexturesGenerat" sysTid=15459 nice=0 sched=0/0 cgrp=apps
  | state=S schedstat=( 110327000 13480426000 1402 ) utm=9 stm=2 core=0

----- end 15370 -----
like image 254
esilver Avatar asked May 11 '13 15:05

esilver


People also ask

How do you analyze ANR traces?

Using traces file:After ANR is recreated pull the traces file via adb pull /data/anr/traces. txt command. In the above example the main thread is held by SampleHandlerThread and SampleHandlerThread is held by the main thread causing a Deadlock.

How do you read ANR logs?

A good way to try to detect the problem is by fetching the file /data/anr/traces. txt which is generated after a ANR happens on a device (beware that it is overridden after another ANR happens). That offers you a overview of what each thread was doing at the time of the ANR.

How do you resolve ANR?

How to prevent an ANR? Stop doing heavy tasks on the main thread. Instead use worker threads such as IntentService, AsyncTask Handler, or another Thread simply.

Which of the following will trigger an ANR Application Not Responding dialog?

Android will display the ANR dialog for a particular application when it detects one of the following conditions: No response to an input event (such as key press or screen touch events) within 5 seconds. A BroadcastReceiver hasn't finished executing within 10 seconds.


1 Answers

Basic investigate steps

  1. Find "waiting to lock"

    • you can find monitor state "Binder Thread #15" prio=5 tid=75 MONITOR

    • you are lucky if find "waiting to lock"

    • example : waiting to lock <0xblahblah> (a com.foo.A) held by threadid=74

  2. You can notice that "tid=74" hold a task now. So go to tid=74

  3. tid=74 maybe SUSPENDED state! find main reason! trace does not always contain "waiting to lock". in this case it is hard to find main reason.

source: https://stackoverflow.com/a/24761645/2715054

like image 68
phnmnn Avatar answered Oct 20 '22 01:10

phnmnn