Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Can someone shed some light on this ANR log?

Received this ANR report on the Developer Console, and I thought it was a bit weird. Seems like it's something with File, but I'm not too sure, so I was hoping someone could shed some light on it. Thanks a lot!

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=1)
"main" prio=5 tid=1 SUSPENDED
  | group="main" sCount=1 dsCount=0 obj=0x40a4b460 self=0xa0f828
  | sysTid=17417 nice=0 sched=0/0 cgrp=default handle=1074566280
  | schedstat=( 10844308000 1221939000 8746 ) utm=972 stm=112 core=1
  at java.io.File.fixSlashes(File.java:~197)
  at java.io.File.<init>(File.java:134)
  at java.io.File.getAbsoluteFile(File.java:387)
  at com.miz.mizuu.UpdateMovieService.onStart(UpdateMovieService.java:179)
  at android.app.Service.onStartCommand(Service.java:438)
  at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:2359)
  at android.app.ActivityThread.access$1900(ActivityThread.java:123)
  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1210)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:137)
  at android.app.ActivityThread.main(ActivityThread.java:4424)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:511)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:784)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:551)
  at dalvik.system.NativeStart.main(Native Method)

"DispatcherThread" prio=5 tid=11 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41966bf8 self=0xe63280
  | sysTid=17452 nice=0 sched=0/0 cgrp=default handle=14719552
  | schedstat=( 280000 313000 4 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"AsyncTask #5" prio=5 tid=17 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x417c7f48 self=0xd01db0
  | sysTid=17440 nice=10 sched=0/0 cgrp=bg_non_interactive handle=13640192
  | schedstat=( 22850000 93316000 69 ) utm=2 stm=0 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x417c80b8> (a java.lang.VMThread) held by tid=17 (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: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)

"AsyncTask #4" prio=5 tid=16 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x417a2740 self=0xcff9b0
  | sysTid=17439 nice=10 sched=0/0 cgrp=bg_non_interactive handle=13604208
  | schedstat=( 39193000 106588000 94 ) utm=3 stm=0 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x417a2878> (a java.lang.VMThread) held by tid=16 (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)

"AsyncTask #3" prio=5 tid=15 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41774f28 self=0xcf3c48
  | sysTid=17438 nice=10 sched=0/0 cgrp=bg_non_interactive handle=13521264
  | schedstat=( 33842000 118576000 89 ) utm=3 stm=0 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41775060> (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)

"AsyncTask #2" prio=5 tid=14 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41758038 self=0xc1aa70
  | sysTid=17437 nice=10 sched=0/0 cgrp=bg_non_interactive handle=12116520
  | schedstat=( 28508000 73514000 90 ) utm=1 stm=1 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41758170> (a java.lang.VMThread) held by tid=14 (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: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)

"AsyncTask #1" prio=5 tid=13 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4174c610 self=0xcdb768
  | sysTid=17436 nice=10 sched=0/0 cgrp=bg_non_interactive handle=12394856
  | schedstat=( 31306000 75384000 71 ) utm=3 stm=0 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4174c7c0> (a java.lang.VMThread) held by tid=13 (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: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)

"AsyncTask #2" prio=5 tid=12 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41651430 self=0xccafa0
  | sysTid=17434 nice=0 sched=0/0 cgrp=default handle=11708720
  | schedstat=( 891000 182000 7 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x410c15b0> (a java.lang.VMThread) held by tid=12 (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: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)

"AsyncTask #1" prio=5 tid=10 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x410b2f88 self=0xc2c800
  | sysTid=17430 nice=10 sched=0/0 cgrp=bg_non_interactive handle=12473264
  | schedstat=( 453884000 188589000 1537 ) utm=35 stm=10 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x410ad570> (a java.lang.VMThread) held by tid=10 (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: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 Thread #2" prio=5 tid=9 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x410bddf0 self=0xbe3d70
  | sysTid=17428 nice=0 sched=0/0 cgrp=default handle=12074328
  | schedstat=( 10983000 40959000 78 ) utm=1 stm=0 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #1" prio=5 tid=8 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x410bb088 self=0xb9f1a8
  | sysTid=17427 nice=0 sched=0/0 cgrp=default handle=12303632
  | schedstat=( 14487000 37152000 88 ) utm=1 stm=0 core=0
  at dalvik.system.NativeStart.run(Native Method)

"FinalizerWatchdogDaemon" daemon prio=5 tid=7 TIMED_WAIT
  | group="main" sCount=1 dsCount=0 obj=0x410b6dd8 self=0xbd3300
  | sysTid=17426 nice=0 sched=0/0 cgrp=default handle=12494048
  | schedstat=( 1417000 7766000 15 ) utm=0 stm=0 core=0
  at java.lang.VMThread.sleep(Native Method)
  at java.lang.Thread.sleep(Thread.java:1031)
  at java.lang.Thread.sleep(Thread.java:1013)
  at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:213)
  at java.lang.Thread.run(Thread.java:856)

"FinalizerDaemon" daemon prio=5 tid=6 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x410b6c80 self=0xc44500
  | sysTid=17425 nice=0 sched=0/0 cgrp=default handle=12500952
  | schedstat=( 19448000 5571000 36 ) utm=1 stm=0 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40a415d0> (a java.lang.ref.ReferenceQueue)
  at java.lang....
like image 938
Michell Bak Avatar asked Apr 01 '12 15:04

Michell Bak


1 Answers

It seems that the ANR was caused by the Service running for more than 5 seconds. Apparently a few users had a very large number of files that it had to go through. I've solved it by moving all the hard work to an AsyncTask.

like image 70
Michell Bak Avatar answered Oct 20 '22 22:10

Michell Bak