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

esilver picture esilver · May 11, 2013 · Viewed 11.9k times · Source

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

I have read these threads:

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 -----

Answer

phnmnn picture phnmnn · May 15, 2017

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