Android ANR, no activity code in sight

2k views Asked by At

I've got an ANR happening, while trying to open 2 separate activities. Very sporadic, only certain users, haven't been able to replicate on any of our test hardware. Both reports have a series of nondescript threads, and two background threads of ours rightly waiting on their notifier locks. The main thread is doing this, in both cases:

"main" prio=5 tid=1 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x41790710 self=0x41775c90
| sysTid=347 nice=0 sched=0/0 cgrp=apps handle=1074003964
| state=S schedstat=( 0 0 0 ) utm=10817 stm=2453 core=0
#00 pc 0001b6e4 /system/lib/libc.so (__ioctl+8)
#01 pc 0002be67 /system/lib/libc.so (ioctl+14)
#02 pc 0001b929 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
#03 pc 0001c0c7 /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
#04 pc 00001451 /system/lib/libsystem_server.so (system_init+384)
#05 pc 00020b4c /system/lib/libdvm.so (dvmPlatformInvoke+112)
#06 pc 000516ab /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+398)
#07 pc 00029fe0 /system/lib/libdvm.so
#08 pc 0002e9a4 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
#09 pc 00063aeb /system/lib/libdvm.so (dvmInvokeMethod(Object*, Method const*, ArrayObject*, ArrayObject*, ClassObject*, bool)+350)
#10 pc 0006b80f /system/lib/libdvm.so
#11 pc 00029fe0 /system/lib/libdvm.so
#12 pc 0002e9a4 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
#13 pc 0006382d /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292)
#14 pc 0004d27f /system/lib/libdvm.so
#15 pc 0005477b /system/lib/libandroid_runtime.so
#16 pc 00055ca3 /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+378)
#17 pc 0000105b /system/bin/app_process
#18 pc 0000ddf7 /system/lib/libc.so (__libc_init+50)
#19 pc 00000d7c /system/bin/app_process
at com.android.server.SystemServer.init1(Native Method)
at com.android.server.SystemServer.main(SystemServer.java:2012)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:525)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1187)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1003)
at dalvik.system.NativeStart.main(Native Method)

Here is the app dump:

"AsyncTask #4" prio=5 tid=17 WAIT
| group="main" sCount=1 dsCount=0 obj=0x424f4178 self=0x5bad64c8
| sysTid=2943 nice=0 sched=0/0 cgrp=apps handle=1537449072
| schedstat=( 0 0 0 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x424f4298> (a java.lang.VMThread) held by tid=17 (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: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:1009)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
at java.lang.Thread.run(Thread.java:856)

"Thread-8753" prio=5 tid=1 VMWAIT
| group="main" sCount=1 dsCount=0 obj=0x42647520 self=0x413fa188
| sysTid=2903 nice=0 sched=0/0 cgrp=apps handle=1074526288
| schedstat=( 0 0 0 ) utm=27 stm=8 core=0
#00 pc 0000dce0 /system/lib/libc.so (__futex_syscall3+8)
#01 pc 00012ef4 /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
#02 pc 00012f50 /system/lib/libc.so (__pthread_cond_timedwait+60)
#03 pc 0004b12f /system/lib/libdvm.so
#04 pc 0004e191 /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+416)
#05 pc 00000dcf /system/bin/app_process
#06 pc 000171d3 /system/lib/libc.so (__libc_init+38)
#07 pc 00000b34 /system/bin/app_process
at dalvik.system.NativeStart.run(Native Method)

"AsyncTask #3" prio=5 tid=15 WAIT
| group="main" sCount=1 dsCount=0 obj=0x424dc8a0 self=0x5c0252c0
| sysTid=2941 nice=0 sched=0/0 cgrp=apps handle=1516141776
| schedstat=( 0 0 0 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x424dc9c0> (a java.lang.VMThread) held by tid=15 (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: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:1009)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
at java.lang.Thread.run(Thread.java:856)

"Thread-8740" prio=5 tid=10 WAIT
| group="main" sCount=1 dsCount=0 obj=0x424860c8 self=0x5a5e1d88
| sysTid=2929 nice=0 sched=0/0 cgrp=apps handle=1543661352
| schedstat=( 0 0 0 ) utm=0 stm=0 core=1
at java.lang.Object.wait(Native Method)
- waiting on <0x42486340> (a java.lang.VMThread) held by tid=10 (Thread-8740)
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:157)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
at com.my_foo2.Bluetooth.ModelAccessorNew$SingleStuffProcessingThread.run(ModelAccessorNew.java:139)

"pool-1-thread-2" prio=5 tid=13 WAIT
| group="main" sCount=1 dsCount=0 obj=0x421cb830 self=0x5a5e1730
| sysTid=2927 nice=0 sched=0/0 cgrp=apps handle=1094606048
| schedstat=( 0 0 0 ) utm=11 stm=4 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x421cbd98> (a java.lang.VMThread) held by tid=13 (pool-1-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: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:1009)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
at java.lang.Thread.run(Thread.java:856)

"Thread-8735" prio=5 tid=12 WAIT
| group="main" sCount=1 dsCount=0 obj=0x4216e7f0 self=0x413e4f20
| sysTid=2926 nice=0 sched=0/0 cgrp=apps handle=1094604160
| schedstat=( 0 0 0 ) utm=0 stm=0 core=1
at java.lang.Object.wait(Native Method)
- waiting on <0x4216e918> (a java.lang.Object)
at java.lang.Object.wait(Object.java:364)
at com.my_foo2.Persistence.Factories.StuffFactory$CalculationThread.run(StuffFactory.java:97)

"pool-1-thread-1" prio=5 tid=11 WAIT
| group="main" sCount=1 dsCount=0 obj=0x42144498 self=0x413e46d0
| sysTid=2924 nice=0 sched=0/0 cgrp=apps handle=1094601544
| schedstat=( 0 0 0 ) utm=18 stm=5 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x421447e8> (a java.lang.VMThread) held by tid=11 (pool-1-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: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:1009)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
at java.lang.Thread.run(Thread.java:856)

"Binder_2" prio=5 tid=9 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x42097bd8 self=0x5183e668
| sysTid=2915 nice=0 sched=0/0 cgrp=apps handle=1538927224
| schedstat=( 0 0 0 ) utm=0 stm=0 core=1
#00 pc 0000cbd0 /system/lib/libc.so (__ioctl+8)
#01 pc 00028035 /system/lib/libc.so (ioctl+16)
#02 pc 00016b6d /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+124)
#03 pc 0001731f /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
#04 pc 0001af55 /system/lib/libbinder.so
#05 pc 00011087 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
#06 pc 0004c985 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+44)
#07 pc 00010bed /system/lib/libutils.so
#08 pc 00012eb0 /system/lib/libc.so (__thread_entry+48)
#09 pc 00012608 /system/lib/libc.so (pthread_create+172)
at dalvik.system.NativeStart.run(Native Method)

"Binder_1" prio=5 tid=8 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x420978a8 self=0x5183e010
| sysTid=2914 nice=0 sched=0/0 cgrp=apps handle=1538927416
| schedstat=( 0 0 0 ) utm=0 stm=0 core=0
#00 pc 0000cbd0 /system/lib/libc.so (__ioctl+8)
#01 pc 00028035 /system/lib/libc.so (ioctl+16)
#02 pc 00016b6d /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+124)
#03 pc 0001731f /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
#04 pc 0001af55 /system/lib/libbinder.so
#05 pc 00011087 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
#06 pc 0004c985 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+44)
#07 pc 00010bed /system/lib/libutils.so
#08 pc 00012eb0 /system/lib/libc.so (__thread_entry+48)
#09 pc 00012608 /system/lib/libc.so (pthread_create+172)
at dalvik.system.NativeStart.run(Native Method)

"FinalizerWatchdogDaemon" daemon prio=5 tid=7 WAIT
| group="system" sCount=1 dsCount=0 obj=0x420940e8 self=0x412487a8
| sysTid=2913 nice=0 sched=0/0 cgrp=apps handle=1538927528
| schedstat=( 0 0 0 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x41414ec8> (a java.lang.Daemons$FinalizerWatchdogDaemon)
at java.lang.Object.wait(Object.java:364)
at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:214)
at java.lang.Thread.run(Thread.java:856)

"FinalizerDaemon" daemon prio=5 tid=6 WAIT
| group="system" sCount=1 dsCount=0 obj=0x42093f90 self=0x41248358
| sysTid=2912 nice=0 sched=0/0 cgrp=apps handle=1538927616
| schedstat=( 0 0 0 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x41403690> (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:169)
at java.lang.Thread.run(Thread.java:856)

"ReferenceQueueDaemon" daemon prio=5 tid=5 WAIT
| group="system" sCount=1 dsCount=0 obj=0x42093e28 self=0x5bb9f218
| sysTid=2911 nice=0 sched=0/0 cgrp=apps handle=1538927752
| schedstat=( 0 0 0 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x414035b8> 
at java.lang.Object.wait(Object.java:364)
at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:129)
at java.lang.Thread.run(Thread.java:856)

"Compiler" daemon prio=5 tid=4 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x42093d38 self=0x400173b8
| sysTid=2910 nice=0 sched=0/0 cgrp=apps handle=1087627008
| schedstat=( 0 0 0 ) utm=9 stm=4 core=1
#00 pc 0000dce0 /system/lib/libc.so (__futex_syscall3+8)
#01 pc 00012ef4 /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
#02 pc 00012f50 /system/lib/libc.so (__pthread_cond_timedwait+60)
#03 pc 0006e7d7 /system/lib/libdvm.so
#04 pc 0005425b /system/lib/libdvm.so
#05 pc 00012eb0 /system/lib/libc.so (__thread_entry+48)
#06 pc 00012608 /system/lib/libc.so (pthread_create+172)
at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
| group="system" sCount=0 dsCount=0 obj=0x42093c40 self=0x40cfa8a8
| sysTid=2909 nice=0 sched=0/0 cgrp=apps handle=1087816224
| schedstat=( 0 0 0 ) utm=1 stm=0 core=0
at dalvik.system.NativeStart.run(Native Method)

"GC" daemon prio=5 tid=2 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x42093b60 self=0x40d6bdd0
| sysTid=2907 nice=0 sched=0/0 cgrp=apps handle=1538927840
| schedstat=( 0 0 0 ) utm=0 stm=0 core=0
#00 pc 0000dce0 /system/lib/libc.so (__futex_syscall3+8)
#01 pc 00012ef4 /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
#02 pc 00012f50 /system/lib/libc.so (__pthread_cond_timedwait+60)
#03 pc 0006d5db /system/lib/libdvm.so
#04 pc 0005425b /system/lib/libdvm.so
#05 pc 00012eb0 /system/lib/libc.so (__thread_entry+48)
#06 pc 00012608 /system/lib/libc.so (pthread_create+172)
at dalvik.system.NativeStart.run(Native Method)

----- end 2903 -----

The other thing that's weird is that this is the only user code I'm seeing. I've tracked where these two threads get started and its during onCreate events of various activities, but the activities themselves aren't running, or at least not visible in the trace. Any ideas would be appreciated.

0

There are 0 answers