[ANR] Input dispatching timed out. Discuss thread (SOLVED)

britzl · February 17, 2019, 9:08pm

Ok, so 0.04% for Classic Solitaire is proof that it is not the Defold engine itself that is at fault, at least not when used like in Classic Solitaire.

Bring Me Cakes shows a higher percentage (0.29%), is that with DefUnityAds or any other larger native extensions?

So, the question is what the difference is between Family Age and Solitaire (and to some extent Bring Me Cakes)?

Are you using any native extensions? If so, which ones?
Are you using local push notifications?
Are you stripping parts of the engine using an app manifest? If so, what are you removing?
That memory investigation I mentioned before would be interesting to know more about.

andreas.strangequest · February 18, 2019, 6:38am

As soon as we get a little more data we will as well join the discussion as we always have suffered from a bunch of ANR’s. Most of them immediately at the loading screen. We are releasing a new version today and will gather info.

AGulev · February 18, 2019, 7:17am

As I remember, most of ANR on Blastlands load was caused by this issue.

AGulev · February 18, 2019, 8:09am

Both projects without NE,
BMC:

excludeLibs: [“record”,“vpx”,“profilerext”,“engine”]
excludeSymbols: [“ProfilerExt”]
libs: [“engine_release”,“record_null”]

Solitaire:

excludeLibs:[“physics”,“LinearMath”,“BulletDynamics”,“BulletCollision”,“Box2D”,“record”,“vpx”,“profilerext”,“facebookext”]
excludeJars: ["(.)/facebooksdk.jar","(.)/facebook_android.jar"]
excludeSymbols: [“ProfilerExt”,“FacebookExt”]
libs: [“physics_null”,“record_null”]

britzl · February 18, 2019, 8:43am

Any ideas why BMC would show higher numbers? More on_input code? Heavy code in update(), garbage collection, HTTP requests?

AGulev · February 18, 2019, 8:48am

No Idea right now, but I’ll continue my investigation. I wanna release the new version of solitaire with some fixes and with new Defold (waiting for new version now).

Dragosha · March 21, 2019, 8:42am

1.08% is current ANR rate after added “exit from app” button:

britzl · March 21, 2019, 10:20am

Huh, so ANRs have gone up and not down? This is opposite of what we have seen for other projects.

You should be using sys.exit() (or the old “exit” message) and never use os.exit(). Can you please confirm this?

Potential known causes of ANRs:

Engine
- HTTP requests on crappy connections. This is caused by getaddrinfo being synchronous. We are working on this issue in our current sprint.
- Local notifications. I see this issue in some games, but it is not very frequent. Do you have any ANRs with com.defold.push.LocalNotificationReceiver
User code
- Doing too much work in a single frame. Examples:
  - Calculations in Lua code that take too long to execute.
  - Doing a lot of I/O operations (I/O operations are typically quite slow on mobile devices).
  - Using factory.create() or collectionfactory.create() on a factory component where Load Dynamically is checked and you haven’t called (collection)factory.load() prior to instantiating the first instance.
Using os.exit() instead of sys.exit()

If anyone has more ANR causes, please share them here!

Dragosha · March 21, 2019, 10:09am

I’m using

msg.post("@system:", "exit", {code = 0})

Full list of registered ANR:

Insality · March 27, 2019, 9:05am

So, I removed exit button on android too and have next results:

With exit button:

Without exit button:

Just for statistics. Exit was with msg too

timer.delay(0.01, false, function()
    msg.post("@system:", "exit", {code = 0})
end)

AGulev · March 27, 2019, 9:16am

Thanks for sharing your statistics!
We think the reason for ANR is this known issue:

Exit from the application one of the most simple way to reproduce this ANR but not the only one.

@jhonny.goransson is working on this issue.

britzl · March 27, 2019, 9:33am

Ys, it’s actively being worked on. It will unfortunately not get finished in time for the release on Monday. It will be included in 1.2.151 instead.

AGulev · May 13, 2019, 2:23pm

It should work fine in 1.2.153 (DEF-3815)

AGulev · May 21, 2019, 6:16am

It seems like in my game count of ANR impacted session reduced 3 times.

Dragosha · June 7, 2019, 7:47am

My current ANR stats (67 build with 1.2.154):

also:

xndr · June 7, 2019, 8:13am

1.2.154

Nokia Nokia 5 (ND1), Android 9

Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 7094.6ms.)

"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x75d7f890 self=0x7cfa80dc00
  | sysTid=1615 nice=-2 cgrp=default sched=0/0 handle=0x7d807af548
  | state=S schedstat=( 1179115000727 1219747882521 3643016 ) utm=70734 stm=47177 core=4 HZ=100
  | stack=0x7fc6a75000-0x7fc6a77000 stackSize=8MB
  | held mutexes=
  #00  pc 00000000000802f0  /system/lib64/libc.so (__epoll_pwait+8)
  #01  pc 0000000000015148  /system/lib64/libutils.so (android::Looper::pollInner(int)+152)
  #02  pc 000000000001500c  /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+60)
  #03  pc 00000000001294dc  /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+44)
  at android.os.MessageQueue.nativePollOnce (Native method)
  at android.os.MessageQueue.next (MessageQueue.java:326)
  at android.os.Looper.loop (Looper.java:165)
  at com.android.server.SystemServer.run (SystemServer.java:479)
  at com.android.server.SystemServer.main (SystemServer.java:307)
  at java.lang.reflect.Method.invoke (Native method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:493)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:838)
"ReferenceQueueDaemon" tid=3 Waiting 
"ReferenceQueueDaemon" daemon prio=5 tid=3 Waiting
  | group="system" sCount=1 dsCount=0 flags=1 obj=0x151c01c0 self=0x7cfa93c000
  | sysTid=1621 nice=4 cgrp=default sched=0/0 handle=0x7cf3c744f0
  | state=S schedstat=( 61439609669 36810068915 301674 ) utm=2847 stm=3296 core=7 HZ=100
  | stack=0x7cf3b71000-0x7cf3b73000 stackSize=1041KB
  | held mutexes=
  at java.lang.Object.wait (Native method)
- waiting on <0x0cab2a9a> (a java.lang.Class<java.lang.ref.ReferenceQueue>)
  at java.lang.Daemons$ReferenceQueueDaemon.runInternal (Daemons.java:178)
- locked <0x0cab2a9a> (a java.lang.Class<java.lang.ref.ReferenceQueue>)
  at java.lang.Daemons$Daemon.run (Daemons.java:103)
  at java.lang.Thread.run (Thread.java:764)
"FinalizerDaemon" tid=4 Waiting 
"FinalizerDaemon" daemon prio=5 tid=4 Waiting
  | group="system" sCount=1 dsCount=0 flags=1 obj=0x151c0248 self=0x7cfa93cc00
  | sysTid=1622 nice=4 cgrp=default sched=0/0 handle=0x7ce3b054f0
  | state=S schedstat=( 29438957656 26811979103 149130 ) utm=1814 stm=1129 core=4 HZ=100
  | stack=0x7ce3a02000-0x7ce3a04000 stackSize=1041KB
  | held mutexes=
  at java.lang.Object.wait (Native method)
- waiting on <0x08f83fcb> (a java.lang.Object)
  at java.lang.Object.wait (Object.java:422)
  at java.lang.ref.ReferenceQueue.remove (ReferenceQueue.java:188)
- locked <0x08f83fcb> (a java.lang.Object)
  at java.lang.ref.ReferenceQueue.remove (ReferenceQueue.java:209)
  at java.lang.Daemons$FinalizerDaemon.runInternal (Daemons.java:232)
  at java.lang.Daemons$Daemon.run (Daemons.java:103)
  at java.lang.Thread.run (Thread.java:764)
"FinalizerWatchdogDaemon" tid=5 Waiting 
"FinalizerWatchdogDaemon" daemon prio=5 tid=5 Waiting
  | group="system" sCount=1 dsCount=0 flags=1 obj=0x151c02d0 self=0x7cfa93d800
  | sysTid=1623 nice=4 cgrp=default sched=0/0 handle=0x7ce39ff4f0
  | state=S schedstat=( 863740695 2573258706 8607 ) utm=37 stm=49 core=4 HZ=100
  | stack=0x7ce38fc000-0x7ce38fe000 stackSize=1041KB
  | held mutexes=
  at java.lang.Object.wait (Native method)
- waiting on <0x072533a8> (a java.lang.Daemons$FinalizerWatchdogDaemon)
  at java.lang.Daemons$FinalizerWatchdogDaemon.sleepUntilNeeded (Daemons.java:297)
- locked <0x072533a8> (a java.lang.Daemons$FinalizerWatchdogDaemon)
  at java.lang.Daemons$FinalizerWatchdogDaemon.runInternal (Daemons.java:277)
  at java.lang.Daemons$Daemon.run (Daemons.java:103)
  at java.lang.Thread.run (Thread.java:764)
"Binder:1615_1" tid=7 Native 
"Binder:1615_1" prio=5 tid=7 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x151c03e0 self=0x7cf214a400
  | sysTid=1634 nice=0 cgrp=default sched=0/0 handle=0x7ce0aa34f0
  | state=S schedstat=( 801255765939 370561739940 1567212 ) utm=50170 stm=29955 core=4 HZ=100
  | stack=0x7ce09a8000-0x7ce09aa000 stackSize=1009KB
  | held mutexes=
  #00  pc 00000000000803dc  /system/lib64/libc.so (__ioctl+4)
  #01  pc 000000000002ccec  /system/lib64/libc.so (ioctl+132)
  #02  pc 000000000005d6a0  /system/lib64/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+248)
  #03  pc 000000000005d880  /system/lib64/libbinder.so (android::IPCThreadState::getAndExecuteCommand()+24)
  #04  pc 000000000005dfd8  /system/lib64/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+64)
  #05  pc 0000000000080bc0  /system/lib64/libbinder.so (android::PoolThread::threadLoop()+24)
  #06  pc 000000000001039c  /system/lib64/libutils.so (android::Thread::_threadLoop(void*)+284)
  #07  pc 00000000000b5974  /system/lib64/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+140)
  #08  pc 00000000000963b4  /system/lib64/libc.so (__pthread_start(void*)+36)
  #09  pc 0000000000023afc  /system/lib64/libc.so (__start_thread+68)
"Binder:1615_2" tid=8 Native 
"Binder:1615_2" prio=5 tid=8 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x151c0468 self=0x7cf2153000
  | sysTid=1635 nice=0 cgrp=default sched=0/0 handle=0x7ce09a54f0
  | state=S schedstat=( 754854505917 387901430512 1554842 ) utm=48039 stm=27446 core=4 HZ=100
  | stack=0x7ce08aa000-0x7ce08ac000 stackSize=1009KB
  | held mutexes=
  #00  pc 00000000000803dc  /system/lib64/libc.so (__ioctl+4)
  #01  pc 000000000002ccec  /system/lib64/libc.so (ioctl+132)
  #02  pc 000000000005d6a0  /system/lib64/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+248)
  #03  pc 000000000005d880  /system/lib64/libbinder.so (android::IPCThreadState::getAndExecuteCommand()+24)
  #04  pc 000000000005e004  /system/lib64/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+108)
  #05  pc 0000000000080bc0  /system/lib64/libbinder.so (android::PoolThread::threadLoop()+24)
  #06  pc 000000000001039c  /system/lib64/libutils.so (android::Thread::_threadLoop(void*)+284)
  #07  pc 00000000000b5974  /system/lib64/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+140)
  #08  pc 00000000000963b4  /system/lib64/libc.so (__pthread_start(void*)+36)
  #09  pc 0000000000023afc  /system/lib64/libc.so (__start_thread+68)
"HwBinder:1615_1" tid=9 Native 
"HwBinder:1615_1" prio=5 tid=9 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x151c0b90 self=0x7cf2153c00
  | sysTid=1638 nice=0 cgrp=default sched=0/0 handle=0x7ce07a94f0
  | state=S schedstat=( 4151173391 2969449057 13355 ) utm=269 stm=146 core=5 HZ=100
  | stack=0x7ce06ae000-0x7ce06b0000 stackSize=1009KB
  | held mutexes=
  #00  pc 00000000000803dc  /system/lib64/libc.so (__ioctl+4)
  #01  pc 000000000002ccec  /system/lib64/libc.so (ioctl+132)
  #02  pc 000000000001ed58  /system/lib64/libhwbinder.so (android::hardware::IPCThreadState::talkWithDriver(bool)+208)
  #03  pc 000000000001ee5c  /system/lib64/libhwbinder.so (android::hardware::IPCThreadState::getAndExecuteCommand()+20)
  #04  pc 00000000000137a0  /system/lib64/libhwbinder.so (android::hardware::IPCThreadState::joinThreadPool(bool)+96)
  #05  pc 000000000001aa10  /system/lib64/libhwbinder.so (???)
  #06  pc 000000000001039c  /system/lib64/libutils.so (android::Thread::_threadLoop(void*)+284)
  #07  pc 00000000000b5974  /system/lib64/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+140)
  #08  pc 00000000000963b4  /system/lib64/libc.so (__pthread_start(void*)+36)
  #09  pc 0000000000023afc  /system/lib64/libc.so (__start_thread+68)
"android.bg" tid=11 Native 
"android.bg" prio=5 tid=11 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x15219700 self=0x7cf218b400
  | sysTid=1658 nice=10 cgrp=default sched=0/0 handle=0x7cdf8904f0
  | state=S schedstat=( 6382389620346 1321242304212 3615601 ) utm=167017 stm=471221 core=7 HZ=100
  | stack=0x7cdf78d000-0x7cdf78f000 stackSize=1041KB
  | held mutexes=
  #00  pc 00000000000802f0  /system/lib64/libc.so (__epoll_pwait+8)
  #01  pc 0000000000015148  /system/lib64/libutils.so (android::Looper::pollInner(int)+152)
  #02  pc 000000000001500c  /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+60)
  #03  pc 00000000001294dc  /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+44)
  at android.os.MessageQueue.nativePollOnce (Native method)
  at android.os.MessageQueue.next (MessageQueue.java:326)
  at android.os.Looper.loop (Looper.java:165)
  at android.os.HandlerThread.run (HandlerThread.java:65)
"ActivityManager" tid=12 Native 
"ActivityManager" prio=5 tid=12 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x152197f8 self=0x7cf21ce400
  | sysTid=1660 nice=-2 cgrp=default sched=0/0 handle=0x7cdf78a4f0
  | state=S schedstat=( 1633677591039 416968658945 1458447 ) utm=50291 stm=113077 core=6 HZ=100
  | stack=0x7cdf687000-0x7cdf689000 stackSize=1041KB
  | held mutexes=
  #00  pc 0000000000080e78  /system/lib64/libc.so (recvfrom+8)
  #01  pc 0000000000001df4  /system/lib64/libdebuggerd_client.so (debuggerd_trigger_dump(int, DebuggerdDumpType, unsigned int, android::base::unique_fd_impl<android::base::DefaultCloser>)+1480)
  #02  pc 0000000000002840  /system/lib64/libdebuggerd_client.so (dump_backtrace_to_file_timeout(int, DebuggerdDumpType, int, int)+104)
  #03  pc 000000000011b1ec  /system/lib64/libandroid_runtime.so (android::dumpTraces(_JNIEnv*, int, _jstring*, int, DebuggerdDumpType)+124)
  #04  pc 000000000011abec  /system/lib64/libandroid_runtime.so (android::android_os_Debug_dumpJavaBacktraceToFileTimeout(_JNIEnv*, _jobject*, int, _jstring*, int)+28)
  at android.os.Debug.dumpJavaBacktraceToFileTimeout (Native method)
  at com.android.server.am.ActivityManagerService.dumpJavaTracesTombstoned (ActivityManagerService.java:6841)
  at com.android.server.am.ActivityManagerService.dumpStackTraces (ActivityManagerService.java:6880)
  at com.android.server.am.ActivityManagerService.dumpStackTraces (ActivityManagerService.java:6718)
  at com.android.server.am.AppErrors.appNotResponding (AppErrors.java:1020)
  at com.android.server.am.ActivityManagerService$18.run (ActivityManagerService.java:14621)
  at android.os.Handler.handleCallback (Handler.java:874)
  at android.os.Handler.dispatchMessage (Handler.java:100)
  at android.os.Looper.loop (Looper.java:198)
  at android.os.HandlerThread.run (HandlerThread.java:65)
  at com.android.server.ServiceThread.run (ServiceThread.java:44)
"android.ui" tid=13 Native 
"android.ui" prio=5 tid=13 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x152198f0 self=0x7cf2023000
  | sysTid=1661 nice=-2 cgrp=default sched=0/0 handle=0x7cdf6844f0
  | state=S schedstat=( 2923431091943 2991184012412 12012645 ) utm=194950 stm=97393 core=6 HZ=100
  | stack=0x7cdf581000-0x7cdf583000 stackSize=1041KB
  | held mutexes=
  #00  pc 00000000000802f0  /system/lib64/libc.so (__epoll_pwait+8)
  #01  pc 0000000000015148  /system/lib64/libutils.so (android::Looper::pollInner(int)+152)
  #02  pc 000000000001500c  /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+60)
  #03  pc 00000000001294dc  /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+44)
  at android.os.MessageQueue.nativePollOnce (Native method)
  at android.os.MessageQueue.next (MessageQueue.java:326)
  at android.os.Looper.loop (Looper.java:165)
  at android.os.HandlerThread.run (HandlerThread.java:65)
  at com.android.server.ServiceThread.run (ServiceThread.java:44)
  at com.android.server.UiThread.run (UiThread.java:43)
"ActivityManager:procStart" tid=14 Native 
"ActivityManager:procStart" prio=5 tid=14 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x152199e8 self=0x7cf2023c00
  | sysTid=1662 nice=-2 cgrp=default sched=0/0 handle=0x7cdf57e4f0
  | state=S schedstat=( 90291368630 41189288704 283752 ) utm=4764 stm=4265 core=5 HZ=100
  | stack=0x7cdf47b000-0x7cdf47d000 stackSize=1041KB
  | held mutexes=
  #00  pc 00000000000802f0  /system/lib64/libc.so (__epoll_pwait+8)
  #01  pc 0000000000015148  /system/lib64/libutils.so (android::Looper::pollInner(int)+152)
  #02  pc 000000000001500c  /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+60)
  #03  pc 00000000001294dc  /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+44)
  at android.os.MessageQueue.nativePollOnce (Native method)
  at android.os.MessageQueue.next (MessageQueue.java:326)
  at android.os.Looper.loop (Looper.java:165)
  at android.os.HandlerThread.run (HandlerThread.java:65)
  at com.android.server.ServiceThread.run (ServiceThread.java:44)
"ActivityManager:kill" tid=15 Native 
"ActivityManager:kill" prio=5 tid=15 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x15219ae0 self=0x7cf2024800
  | sysTid=1663 nice=10 cgrp=default sched=0/0 handle=0x7cdf4784f0
  | state=S schedstat=( 45169638300 107840115068 120856 ) utm=1309 stm=3207 core=4 HZ=100
  | stack=0x7cdf375000-0x7cdf377000 stackSize=1041KB
  | held mutexes=
  #00  pc 00000000000802f0  /system/lib64/libc.so (__epoll_pwait+8)
  #01  pc 0000000000015148  /system/lib64/libutils.so (android::Looper::pollInner(int)+152)
  #02  pc 000000000001500c  /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+60)
  #03  pc 00000000001294dc  /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+44)
  at android.os.MessageQueue.nativePollOnce (Native method)
  at android.os.MessageQueue.next (MessageQueue.java:326)
  at android.os.Looper.loop (Looper.java:165)
  at android.os.HandlerThread.run (HandlerThread.java:65)
  at com.android.server.ServiceThread.run (ServiceThread.java:44)
"batterystats-worker" tid=16 TimedWaiting 
"batterystats-worker" prio=5 tid=16 TimedWaiting
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x15219bd8 self=0x7cf2025400
  | sysTid=1666 nice=0 cgrp=default sched=0/0 handle=0x7cdf3724f0
  | state=S schedstat=( 1031010583926 155344479859 399509 ) utm=19262 stm=83839 core=5 HZ=100
  | stack=0x7cdf26f000-0x7cdf271000 stackSize=1041KB
  | held mutexes=
  at java.lang.Object.wait (Native method)
- waiting on <0x0c845ec1> (a java.lang.Object)
  at java.lang.Thread.parkFor$ (Thread.java:2137)
- locked <0x0c845ec1> (a java.lang.Object)
  at sun.misc.Unsafe.park (Unsafe.java:358)
  at java.util.concurrent.locks.LockSupport.parkNanos (LockSupport.java:230)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos (AbstractQueuedSynchronizer.java:2101)
  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take (ScheduledThreadPoolExecutor.java:1132)
  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take (ScheduledThreadPoolExecutor.java:849)
  at java.util.concurrent.ThreadPoolExecutor.getTask (ThreadPoolExecutor.java:1092)
  at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1152)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:641)
  at java.lang.Thread.run (Thread.java:764)
"FileObserver" tid=17 Native 
"FileObserver" prio=5 tid=17 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x15219d48 self=0x7cfa9c8c00
  | sysTid=1671 nice=0 cgrp=default sched=0/0 handle=0x7cdf26c4f0
  | state=S schedstat=( 4836395595 7725107284 63616 ) utm=225 stm=258 core=5 HZ=100
  | stack=0x7cdf169000-0x7cdf16b000 stackSize=1041KB
  | held mutexes=
  #00  pc 0000000000080e14  /system/lib64/libc.so (read+4)
  #01  pc 0000000000196234  /system/lib64/libandroid_runtime.so (android::android_os_fileobserver_observe(_JNIEnv*, _jobject*, int)+260)
  at android.os.FileObserver$ObserverThread.observe (Native method)
  at android.os.FileObserver$ObserverThread.run (FileObserver.java:86)
"android.fg" tid=18 Native 
"android.fg" prio=5 tid=18 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x15219dd8 self=0x7cfa9c9800
  | sysTid=1672 nice=0 cgrp=default sched=0/0 handle=0x7cdf1664f0
  | state=S schedstat=( 82686618261 131364408556 375756 ) utm=4726 stm=3542 core=4 HZ=100
  | stack=0x7cdf063000-0x7cdf065000 stackSize=1041KB
  | held mutexes=
  #00  pc 000000000001f26c  /system/lib64/libc.so (syscall+28)
  #01  pc 00000000000d7424  /system/lib64/libart.so (art::ConditionVariable::WaitHoldingLocks(art::Thread*)+148)
  #02  pc 000000000051b818  /system/lib64/libart.so (_ZN3artL12GoToRunnableEPNS_6ThreadE.llvm.2847759983+480)
  #03  pc 000000000051b5f4  /system/lib64/libart.so (art::JniMethodEnd(unsigned int, art::Thread*)+28)
  at android.os.MessageQueue.nativePollOnce (Native method)
  at android.os.MessageQueue.next (MessageQueue.java:326)
  at android.os.Looper.loop (Looper.java:165)
  at android.os.HandlerThread.run (HandlerThread.java:65)
  at com.android.server.ServiceThread.run (ServiceThread.java:44)
"android.io" tid=19 Native 
"android.io" prio=5 tid=19 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x15219ed0 self=0x7cfa9ca400
  | sysTid=1673 nice=0 cgrp=default sched=0/0 handle=0x7cdf0604f0
  | state=S schedstat=( 327849266548 172960638818 409580 ) utm=22653 stm=10131 core=6 HZ=100
  | stack=0x7cdef5d000-0x7cdef5f000 stackSize=1041KB
  | held mutexes=
  #00  pc 00000000000802f0  /system/lib64/libc.so (__epoll_pwait+8)
  #01  pc 0000000000015148  /system/lib64/libutils.so (android::Looper::pollInner(int)+152)
  #02  pc 000000000001500c  /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+60)
  #03  pc 00000000001294dc  /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+44)
  at android.os.MessageQueue.nativePollOnce (Native method)
  at android.os.MessageQueue.next (MessageQueue.java:326)
  at android.os.Looper.loop (Looper.java:165)
  at android.os.HandlerThread.run (HandlerThread.java:65)
  at com.android.server.ServiceThread.run (ServiceThread.java:44)
"android.display" tid=20 Native 
"android.display" prio=5 tid=20 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x15587620 self=0x7cfa9cc000
  | sysTid=1674 nice=-3 cgrp=default sched=0/0 handle=0x7cdef5a4f0
  | state=S schedstat=( 190386032127 232688357615 835625 ) utm=11772 stm=7266 core=5 HZ=100
  | stack=0x7cdee57000-0x7cdee59000 stackSize=1041KB
  | held mutexes=
  #00  pc 000000000001f26c  /system/lib64/libc.so (syscall+28)
  #01  pc 00000000000d7424  /system/lib64/libart.so (art::ConditionVariable::WaitHoldingLocks(art::Thread*)+148)
  #02  pc 000000000051b818  /system/lib64/libart.so (_ZN3artL12GoToRunnableEPNS_6ThreadE.llvm.2847759983+480)
  #03  pc 000000000051b5f4  /system/lib64/libart.so (art::JniMethodEnd(unsigned int, art::Thread*)+28)
  at android.os.MessageQueue.nativePollOnce (Native method)
  at android.os.MessageQueue.next (MessageQueue.java:326)
  at android.os.Looper.loop (Looper.java:165)
  at android.os.HandlerThread.run (HandlerThread.java:65)
  at com.android.server.ServiceThread.run (ServiceThread.java:44)
"CpuTracker" tid=21 TimedWaiting 
"CpuTracker" prio=5 tid=21 TimedWaiting
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x15219fc8 self=0x7cfa9ccc00
  | sysTid=1677 nice=0 cgrp=default sched=0/0 handle=0x7cdee544f0
  | state=S schedstat=( 50483236935 3365369900 9370 ) utm=731 stm=4317 core=5 HZ=100
  | stack=0x7cded51000-0x7cded53000 stackSize=1041KB
  | held mutexes=
  at java.lang.Object.wait (Native method)
- waiting on <0x03815666> (a com.android.server.am.ActivityManagerService$5)
  at java.lang.Object.wait (Object.java:422)
  at com.android.server.am.ActivityManagerService$5.run (ActivityManagerService.java:3365)
- locked <0x03815666> (a com.android.server.am.ActivityManagerService$5)
"PowerManagerService" tid=22 Native 
"PowerManagerService" prio=5 tid=22 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x1521a060 self=0x7cfa9cd800
  | sysTid=1681 nice=-4 cgrp=default sched=0/0 handle=0x7cded4e4f0
  | state=S schedstat=( 603281948848 669364057024 3494663 ) utm=27542 stm=32786 core=6 HZ=100
  | stack=0x7cdec4b000-0x7cdec4d000 stackSize=1041KB
  | held mutexes=
  #00  pc 000000000001f26c  /system/lib64/libc.so (syscall+28)
  #01  pc 00000000000d7424  /system/lib64/libart.so (art::ConditionVariable::WaitHoldingLocks(art::Thread*)+148)
  #02  pc 000000000051b818  /system/lib64/libart.so (_ZN3artL12GoToRunnableEPNS_6ThreadE.llvm.2847759983+480)
  #03  pc 000000000051b5f4  /system/lib64/libart.so (art::JniMethodEnd(unsigned int, art::Thread*)+28)
  at android.os.MessageQueue.nativePollOnce (Native method)
  at android.os.MessageQueue.next (MessageQueue.java:326)
  at android.os.Looper.loop (Looper.java:165)
  at android.os.HandlerThread.run (HandlerThread.java:65)
  at com.android.server.ServiceThread.run (ServiceThread.java:44)
"BatteryStats_wakeupReason" tid=23 Native 
"BatteryStats_wakeupReason" prio=5 tid=23 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x1521a158 self=0x7cfa9ce400
  | sysTid=1682 nice=-2 cgrp=default sched=0/0 handle=0x7cdec484f0
  | state=S schedstat=( 8803034513 4324280948 19753 ) utm=360 stm=520 core=5 HZ=100
  | stack=0x7cdeb45000-0x7cdeb47000 stackSize=1041KB
  | held mutexes=
  #00  pc 000000000001f26c  /system/lib64/libc.so (syscall+28)
  #01  pc 00000000000226cc  /system/lib64/libc.so (__futex_wait_ex(void volatile*, bool, int, bool, timespec const*)+140)
  #02  pc 0000000000030a48  /system/lib64/libc.so (sem_wait+120)
  #03  pc 000000000004b900  /system/lib64/libandroid_servers.so (android::nativeWaitWakeup(_JNIEnv*, _jobject*, _jobject*)+120)
  at com.android.server.am.BatteryStatsService.nativeWaitWakeup (Native method)
  at com.android.server.am.BatteryStatsService.access$100 (BatteryStatsService.java:82)
  at com.android.server.am.BatteryStatsService$WakeupReasonThread.waitWakeup (BatteryStatsService.java:1193)
  at com.android.server.am.BatteryStatsService$WakeupReasonThread.run (BatteryStatsService.java:1178)
.....

Mathias_Westerdahl · June 7, 2019, 9:02am

@Dragosha and @xndr : Do you know at what stage in the game this ANR occurs? Is it at shutdown or in the middle of the game?

AGulev · June 7, 2019, 9:07am

That ANR looks similar to https://github.com/AGulev/DefVideoAds/issues/2
I don’t have any of that kind ANR in my app without ads.

Dragosha · June 7, 2019, 10:18am

Not sure when this ANR occurs. On my device I catch only one case, you know it

xndr · June 7, 2019, 12:21pm

I’m don’t know.