rustyshelf
rustyshelf

Reputation: 45101

How Do you Interpret Android ANR Reports

I've googled till my fingers were sore, but I couldn't figure out how to interpret the ANR reports that are sent to developers by Google.

So at the top of the report, this intent is listed as the cause:

ANR Executing service blah.blah.removed.UpdateEpisodesFileDetails

With the following threads listed. (note that we have quite a few of these ANRs, and in every case File.deleteImpl is listed as what's running on the main thread, which seems to be a clue, but the intent listed doesn't do deleting):

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=0x40022268 self=0xcea0
  | sysTid=313 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=-1345006432
  | schedstat=( 6115674000 2882269000 4010 )
  at java.io.File.deleteImpl(Native Method)
  at java.io.File.delete(File.java:375)
  at au.com.shiftyjelly.pocketcasts.a.i.a(SourceFile:256)
  at au.com.shiftyjelly.pocketcasts.a.i.a(SourceFile:177)
  at au.com.shiftyjelly.pocketcasts.a.i.c(SourceFile:374)
  at au.com.shiftyjelly.pocketcasts.a.i.a(SourceFile:290)
  at au.com.shiftyjelly.pocketcasts.a.e.a(SourceFile:1)
  at au.com.shiftyjelly.pocketcasts.server.t.a(SourceFile:393)
  at au.com.shiftyjelly.pocketcasts.server.x.onPostExecute(SourceFile:1)
  at android.os.AsyncTask.finish(AsyncTask.java:417)
  at android.os.AsyncTask.access$300(AsyncTask.java:127)
  at android.os.AsyncTask$InternalHandler.handleMessage(AsyncTask.java:429)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:130)
  at android.app.ActivityThread.main(ActivityThread.java:3806)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:507)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:839)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:597)
  at dalvik.system.NativeStart.main(Native Method)

"AsyncTask #1" prio=5 tid=13 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4078adc0 self=0x415c80
  | sysTid=2601 nice=10 sched=0/0 cgrp=[fopen-error:2] handle=4283832
  | schedstat=( 270113000 194565000 1121 )
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4078b000> (a java.lang.VMThread)
  at java.lang.Thread.parkFor(Thread.java:1424)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:337)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:411)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1021)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1081)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:581)
  at java.lang.Thread.run(Thread.java:1019)

"Binder Thread #3" prio=5 tid=10 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x405be0c0 self=0x3ba1e8
  | sysTid=700 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=3991064
  | schedstat=( 8717000 2885597000 235 )
  at dalvik.system.NativeStart.run(Native Method)

"Thread-16" prio=5 tid=11 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40623f98 self=0x3a3600
  | sysTid=332 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=3815224
  | schedstat=( 24507000 2874905000 281 )
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:119)
  at android.os.Looper.loop(Looper.java:117)
  at au.com.shiftyjelly.pocketcasts.service.k.run(SourceFile:1078)
  at java.lang.Thread.run(Thread.java:1019)

"background thread" prio=5 tid=9 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40617c90 self=0x34eb00
  | sysTid=330 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=3468344
  | schedstat=( 8289000 2632928000 198 )
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:119)
  at android.os.Looper.loop(Looper.java:117)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"pool-1-thread-1" prio=5 tid=8 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x405446b8 self=0x34ace0
  | sysTid=329 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=3451952
  | schedstat=( 39981000 2194522000 271 )
  at java.lang.Object.wait(Native Method)
  - waiting on <0x405447d8> (a java.lang.VMThread)
  at java.lang.Thread.parkFor(Thread.java:1424)
  at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
  at sun.misc.Unsafe.park(Unsafe.java:337)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:411)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1021)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1081)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:581)
  at java.lang.Thread.run(Thread.java:1019)

"Binder Thread #2" prio=5 tid=7 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40514c80 self=0x1373b8
  | sysTid=319 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=2641200
  | schedstat=( 13291000 2392775000 260 )
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #1" prio=5 tid=6 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40514b70 self=0x2849c0
  | sysTid=318 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=603856
  | schedstat=( 12253000 2190249000 264 )
  at dalvik.system.NativeStart.run(Native Method)

"Compiler" daemon prio=5 tid=5 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x40510d28 self=0x29f0a0
  | sysTid=317 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=602784
  | schedstat=( 433121000 2151691000 3736 )
  at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=4 RUNNABLE
  | group="system" sCount=0 dsCount=0 obj=0x40510c68 self=0x29ef68
  | sysTid=316 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=602720
  | schedstat=( 8292000 1519782000 208 )
  at dalvik.system.NativeStart.run(Native Method)

"GC" daemon prio=5 tid=3 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x40510bc0 self=0x930a0
  | sysTid=315 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=602208
  | schedstat=( 37690000 1428592000 208 )
  at dalvik.system.NativeStart.run(Native Method)

"HeapWorker" daemon prio=5 tid=2 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x40510b08 self=0x93510
  | sysTid=314 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=602008
  | schedstat=( 74593000 1863624000 297 )
  at dalvik.system.NativeStart.run(Native Method)

Upvotes: 5

Views: 5239

Answers (2)

rustyshelf
rustyshelf

Reputation: 45101

Well don't I feel like a git this is the cause:

 at au.com.shiftyjelly.pocketcasts.server.x.onPostExecute(SourceFile:1)
  at android.os.AsyncTask.finish(AsyncTask.java:417)

So everything is asynchronous but an async onPostExecute is being called, which runs on the main thread, that code then went off and called a whole bunch of other code, also on the main thread. This wasn't obvious, because all the code was coded with async callbacks etc, so it all looked asynchronous.

Upvotes: 1

user123321
user123321

Reputation: 12783

ANR (Application Not Responding) means you are locking the UI thread for too long. Typically this means you're making a network call on the UI thread or something like that.

Upvotes: 2

Related Questions