How to analyze an Android /data/anr/traces.txt file?

StackOverflow https://stackoverflow.com/questions/17646964

  •  03-06-2022
  •  | 
  •  

Question

I've got an ANR error on my android app.

It's trace is below

"main" and "Thread-20153" are main problem of ANR?

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
"main" prio=5 tid=1 SUSPENDED
  | group="main" sCount=2 dsCount=1 obj=0x40aee490 self=0x1fbad70
  | sysTid=3805 nice=0 sched=0/0 cgrp=default handle=1074664744
  | schedstat=( 378517060062 270739989762 791048 ) utm=33581 stm=4270 core=0
  at android.app.ActivityThread.performResumeActivity(ActivityThread.java:~2812)
  at android.app.ActivityThread.handleResumeActivity(ActivityThread.java:2851)
  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1287)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:154)
  at android.app.ActivityThread.main(ActivityThread.java:4945)
  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)

"Thread-20153" prio=5 tid=22 TIMED_WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41463760 self=0x3018ea0
  | sysTid=7466 nice=0 sched=0/0 cgrp=default handle=43164240
  | schedstat=( 32867433 91186523 62 ) utm=2 stm=1 core=0
  at java.lang.VMThread.sleep(Native Method)
  at java.lang.Thread.sleep(Thread.java:1047)
  at java.lang.Thread.sleep(Thread.java:1029)
  at com.mocoplex.adlib.AdlibManager$b.run(AdlibManager.java:1068)

"Timer-3" prio=5 tid=18 TIMED_WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4114a748 self=0x2984f48
  | sysTid=5953 nice=0 sched=0/0 cgrp=default handle=46807576
  | schedstat=( 48645025 59570314 230 ) utm=4 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4114a748> (a java.util.Timer$TimerImpl)
  at java.lang.Object.wait(Object.java:401)
  at java.util.Timer$TimerImpl.run(Timer.java:238)

"Timer-2" prio=5 tid=20 TIMED_WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41103688 self=0x2a53738
  | sysTid=5861 nice=0 sched=0/0 cgrp=default handle=43212688
  | schedstat=( 48461919 64544676 234 ) utm=4 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41103688> (a java.util.Timer$TimerImpl)
  at java.lang.Object.wait(Object.java:401)
  at java.util.Timer$TimerImpl.run(Timer.java:238)

"Binder Thread #4" prio=5 tid=16 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x410d7a90 self=0x2877ef8
  | sysTid=4496 nice=0 sched=0/0 cgrp=default handle=43222816
  | schedstat=( 556243916 622314442 2261 ) utm=30 stm=25 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #3" prio=5 tid=21 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40e9bd30 self=0x296a800
  | sysTid=3971 nice=0 sched=0/0 cgrp=default handle=43484856
  | schedstat=( 755767858 956115700 2837 ) utm=47 stm=28 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Timer-1" prio=5 tid=12 TIMED_WAIT
  | group="main" sCount=1 dsCount=0 obj=0x40da4778 self=0x2817d28
  | sysTid=3955 nice=0 sched=0/0 cgrp=default handle=42812624
  | schedstat=( 78033460 63385008 360 ) utm=3 stm=4 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40da4778> (a java.util.Timer$TimerImpl)
  at java.lang.Object.wait(Object.java:401)
  at java.util.Timer$TimerImpl.run(Timer.java:238)

"Thread-19213" prio=5 tid=14 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40f47bc0 self=0x28397d8
  | sysTid=3894 nice=0 sched=0/0 cgrp=default handle=41749600
  | schedstat=( 6582580563 4471832242 16030 ) utm=317 stm=341 core=0
  at dalvik.system.NativeStart.run(Native Method)

"AsyncTask #1" prio=5 tid=19 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x40ec6b60 self=0x2799b10
  | sysTid=3886 nice=10 sched=0/0 cgrp=default handle=41517920
  | schedstat=( 85784919 298645016 925 ) utm=5 stm=3 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40ec70f8> (a java.lang.VMThread) held by tid=19 (AsyncTask #1)
  at java.lang.Thread.parkFor(Thread.java:1250)
  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:864)

"GAThread" prio=5 tid=17 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x40e14cd8 self=0x265ea78
  | sysTid=3849 nice=0 sched=0/0 cgrp=default handle=40098064
  | schedstat=( 98105010984 112702484189 420613 ) utm=8608 stm=1202 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40e14f48> (a java.lang.VMThread) held by tid=17 (GAThread)
  at java.lang.Thread.parkFor(Thread.java:1250)
  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.google.analytics.tracking.android.GAThread.run(GAThread.java:518)

"Timer-0" prio=5 tid=15 TIMED_WAIT
  | group="main" sCount=1 dsCount=0 obj=0x40e0b258 self=0x2644908
  | sysTid=3847 nice=0 sched=0/0 cgrp=default handle=39852224
  | schedstat=( 8728025 27526859 49 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40e0b258> (a java.util.Timer$TimerImpl)
  at java.lang.Object.wait(Object.java:401)
  at java.util.Timer$TimerImpl.run(Timer.java:238)

"CookieSyncManager" prio=5 tid=13 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40dd51d8 self=0x2205750
  | sysTid=3839 nice=10 sched=0/0 cgrp=default handle=35690744
  | schedstat=( 3601070 48522953 21 ) 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:124)
  at android.webkit.WebSyncManager.run(WebSyncManager.java:90)
  at android.webkit.CookieSyncManager.run(CookieSyncManager.java:61)
  at java.lang.Thread.run(Thread.java:864)

"WebViewCoreThread" prio=5 tid=11 SUSPENDED
  | group="main" sCount=1 dsCount=0 obj=0x40dd1000 self=0x21d3268
  | sysTid=3837 nice=0 sched=0/0 cgrp=default handle=35024464
  | schedstat=( 108778259167 88950927721 209209 ) utm=9772 stm=1105 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:124)
  at android.webkit.WebViewCore$WebCoreThread.run(WebViewCore.java:751)
  at java.lang.Thread.run(Thread.java:864)

"Binder Thread #2" prio=5 tid=10 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40dab048 self=0x21b4f78
  | sysTid=3817 nice=0 sched=0/0 cgrp=default handle=35045376
  | schedstat=( 753906254 1313110342 2682 ) utm=62 stm=13 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #1" prio=5 tid=9 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40daa018 self=0x220b6c0
  | sysTid=3816 nice=0 sched=0/0 cgrp=default handle=35448760
  | schedstat=( 763366698 866455078 2684 ) utm=56 stm=20 core=0
  at dalvik.system.NativeStart.run(Native Method)

"FinalizerWatchdogDaemon" daemon prio=5 tid=8 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x40da5910 self=0x21f8778
  | sysTid=3815 nice=0 sched=0/0 cgrp=default handle=35648680
  | schedstat=( 19226068 112762454 289 ) utm=1 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40af5ee8> (a java.lang.Daemons$FinalizerWatchdogDaemon)
  at java.lang.Object.wait(Object.java:364)
  at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:218)
  at java.lang.Thread.run(Thread.java:864)

"FinalizerDaemon" daemon prio=5 tid=7 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x40da57b8 self=0x21a4a20
  | sysTid=3814 nice=0 sched=0/0 cgrp=default handle=35665600
  | schedstat=( 5843750080 8033416627 35050 ) utm=463 stm=121 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40ae45e8> (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:173)
  at java.lang.Thread.run(Thread.java:864)

"ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x40da5650 self=0x21ce2e0
  | sysTid=3813 nice=0 sched=0/0 cgrp=default handle=35653416
  | schedstat=( 1158782901 1858612107 6973 ) utm=98 stm=17 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40ae4510> 
  at java.lang.Object.wait(Object.java:364)
  at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:133)
  at java.lang.Thread.run(Thread.java:864)

"Compiler" daemon prio=5 tid=5 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x40da5560 self=0x21ee180
  | sysTid=3812 nice=0 sched=0/0 cgrp=default handle=34074560
  | schedstat=( 1770019 3204346 7 ) utm=0 stm=0 core=0
  at dalvik.system.NativeStart.run(Native Method)

"JDWP" daemon prio=5 tid=4 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x40da5478 self=0x21f1988
  | sysTid=3811 nice=0 sched=0/0 cgrp=default handle=34075744
  | schedstat=( 681671184 898101870 8811 ) utm=24 stm=44 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
  | group="system" sCount=0 dsCount=0 obj=0x40da5380 self=0x220ebd0
  | sysTid=3809 nice=0 sched=0/0 cgrp=default handle=34074272
  | schedstat=( 6927491 39001465 8 ) utm=0 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=0x40da52a0 self=0x20801f0
  | sysTid=3807 nice=0 sched=0/0 cgrp=default handle=35471536
  | schedstat=( 2660827614 3416412375 2552 ) utm=254 stm=12 core=0
  at dalvik.system.NativeStart.run(Native Method)

----- end 3805 -----

But I'don't know where is a problem code.

How to interpret this?

It's too long trace, and question is too naive. You don't have to explain whole error, just please advise how to interpret the subjects.

Était-ce utile?

La solution

So far, it doesn't look like it has a problem. As we can observe here, The main thread is suspended and so is one more thread called WebViewCoreThread, apart from these 2 all others seem to be pretty alright either doing a classic wait or a timed wait or just running.

The 2 possible reasons why the ANR could have occurred here might be because either of the 2 threads is suspended indefinitely and the android (system) would have thought they have died , after waiting for some time out, say few seconds, thus throwing an ANR.

You might want to check if there are any break points in either of those threads or either of those threads are doing some heavy op involving instantiation of objects leading to gc which also might cause the thread to enter suspended mode.

Also check the logs for any sign on watchdog killing any of the system process.. might help fig this out!

Autres conseils

you should check the TIMED_WAIT thread, why every time it trying to lock a different subject? what caused this happen? - waiting on <0x40e0b258> (a java.util.Timer$TimerImpl)

Licencié sous: CC-BY-SA avec attribution
Non affilié à StackOverflow
scroll top