ANR: Broadcast of Intent android.intent.action.SCREEN_OFF


#1

I have a lot of ANR in my project with next error message:
(first part of the log, full log is huge, but I’m sure that your games has this bug too)

Broadcast of Intent { act=android.intent.action.SCREEN_OFF flg=0x50000010 (has extras) }

"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 obj=0x76d7ff48 self=0xb8459e68
  | sysTid=15376 nice=-4 cgrp=bg_non_interactive sched=0/0 handle=0xb6f62bec
  | state=S schedstat=( 6275909428 1884074543 19538 ) utm=396 stm=231 core=1 HZ=100
  | stack=0xbe28f000-0xbe291000 stackSize=8MB
  | held mutexes=
  #00  pc 000000000000f9a8  /system/lib/libc.so (syscall+28)
  #01  pc 00000000000131f9  /system/lib/libc.so (_Z33__pthread_cond_timedwait_relativeP14pthread_cond_tP15pthread_mutex_tPK8timespec+56)
  #02  pc 000000000015b22c  /data/app/com.potatojam.onet.minions.crush-2/lib/arm/libMonsters_Crush.so (???)
  #03  pc 0000000000063ef7  /system/lib/libandroid_runtime.so (???)
  #04  pc 0000000000240647  /system/framework/arm/boot.oat (Java_android_app_NativeActivity_onPauseNative__J+90)
  at android.app.NativeActivity.onPauseNative (Native method)
  at android.app.NativeActivity.onPause (NativeActivity.java:209)
  at com.dynamo.android.DefoldActivity.onPause (DefoldActivity.java:229)
  at android.app.Activity.performPause (Activity.java:6336)
  at android.app.Instrumentation.callActivityOnPause (Instrumentation.java:1322)
  at android.app.ActivityThread.performPauseActivity (ActivityThread.java:3691)
  at android.app.ActivityThread.performPauseActivity (ActivityThread.java:3664)
  at android.app.ActivityThread.handlePauseActivity (ActivityThread.java:3639)
  at android.app.ActivityThread.access$1100 (ActivityThread.java:177)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:1445)
  at android.os.Handler.dispatchMessage (Handler.java:102)
  at android.os.Looper.loop (Looper.java:135)
  at android.app.ActivityThread.main (ActivityThread.java:5930)
  at java.lang.reflect.Method.invoke! (Native method)
  at java.lang.reflect.Method.invoke (Method.java:372)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run (ZygoteInit.java:1405)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1200)

I tried to find the reason, and found only one relevant link:

Maybe it’s possible to change onReceive method in BroadcastReceiver to avoid this?

After latest update of Google Play a count of ANR became more important and may be a reason of lower place in a search and other organic traffic sources.

Docs: https://developer.android.com/topic/performance/vitals/anr


#2

vote for this
The same thing - a lot of ANR like this


#3

It looks similar to this SO post: https://stackoverflow.com/a/20164998/468516

It would be interesting to see what function it is calling at 0x15b22c: /data/app/com.potatojam.onet.minions.crush-2/lib/arm/libMonsters_Crush.so

@insality, does your report look the same, with the same callstack?


#4

@Mathias_Westerdahl looks very similar

"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x72a1f618 self=0xf19dd000
  | sysTid=30900 nice=0 cgrp=default sched=0/0 handle=0xf64f64bc
  | state=S schedstat=( 5748132693 465711711 25622 ) utm=354 stm=220 core=5 HZ=100
  | stack=0xff5af000-0xff5b1000 stackSize=8MB
  | held mutexes=
  #00  pc 0000000000018e9c  /system/lib/libc.so (syscall+28)
  #01  pc 0000000000048515  /system/lib/libc.so (_ZL24__pthread_cond_timedwaitP23pthread_cond_internal_tP15pthread_mutex_tbPK8timespec+102)
  #02  pc 0000000000161c74  /data/app/com.test.familyage-2RcLh8tEQnaq3Yw_SbeoUw==/lib/arm/libFamily_Age.so (???)
  #03  pc 00000000001a8443  /system/framework/arm/boot-framework.oat (Java_android_app_NativeActivity_onPauseNative__J+82)
  at android.app.NativeActivity.onPauseNative (Native method)
  at android.app.NativeActivity.onPause (NativeActivity.java:202)
  at com.dynamo.android.DefoldActivity.onPause (DefoldActivity.java:227)
  at android.app.Activity.performPause (Activity.java:7391)
  at android.app.Instrumentation.callActivityOnPause (Instrumentation.java:1414)
  at android.app.ActivityThread.performPauseActivityIfNeeded (ActivityThread.java:4113)
  at android.app.ActivityThread.performPauseActivity (ActivityThread.java:4090)
  at android.app.ActivityThread.performPauseActivity (ActivityThread.java:4064)
  at android.app.ActivityThread.handlePauseActivity (ActivityThread.java:4038)
  at android.app.ActivityThread.-wrap16 (ActivityThread.java)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:1708)
  at android.os.Handler.dispatchMessage (Handler.java:105)
  at android.os.Looper.loop (Looper.java:164)
  at android.app.ActivityThread.main (ActivityThread.java:6938)
  at java.lang.reflect.Method.invoke (Native method)
  at com.android.internal.os.Zygote$MethodAndArgsCaller.run (Zygote.java:327)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1374)

#5

Would either of you mind giving me one of the executables to me? (so I can try to lookup what function it is calling in the engine)


#6

apk 100.apk.zip (9.7 MB)

yesterday’s log received from user with this apk:

Broadcast of Intent { act=android.intent.action.SCREEN_OFF flg=0x50200010 }, InvisibleToUser

"main" tid=1 Native 
"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x7293e620 self=0xb2ab5000
  | sysTid=31912 nice=0 cgrp=default sched=0/0 handle=0xb6bac4a8
  | state=S schedstat=( 10061309413 7131975187 45296 ) utm=651 stm=353 core=3 HZ=100
  | stack=0xbe4de000-0xbe4e0000 stackSize=8MB
  | held mutexes=
  #00  pc 0000000000018e58  /system/lib/libc.so (syscall+28)
  #01  pc 00000000000477c7  /system/lib/libc.so (_ZL24__pthread_cond_timedwaitP23pthread_cond_internal_tP15pthread_mutex_tbPK8timespec+102)
  #02  pc 000000000015b438  /data/app/com.potatojam.onet.minions.crush-DjziDaTmZzi_3zX1atlubg==/lib/arm/libMonsters_Crush.so (???)
  #03  pc 000000000007d283  /system/lib/libandroid_runtime.so (???)
  #04  pc 000000000007cd55  /system/lib/libandroid_runtime.so (???)
  #05  pc 00000000001a560b  /system/framework/arm/boot-framework.oat (Java_android_app_NativeActivity_unloadNativeCode__J+82)
  at android.app.NativeActivity.unloadNativeCode (Native method)
  at android.app.NativeActivity.onDestroy (NativeActivity.java:195)
  at android.app.Activity.performDestroy (Activity.java:7191)
  at android.app.Instrumentation.callActivityOnDestroy (Instrumentation.java:1270)
  at android.app.ActivityThread.performDestroyActivity (ActivityThread.java:4534)
  at android.app.ActivityThread.handleDestroyActivity (ActivityThread.java:4565)
  at android.app.ActivityThread.handleRelaunchActivity (ActivityThread.java:4839)
  at android.app.ActivityThread.-wrap18 (ActivityThread.java)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:1672)
  at android.os.Handler.dispatchMessage (Handler.java:105)
  at android.os.Looper.loop (Looper.java:164)
  at android.app.ActivityThread.main (ActivityThread.java:6695)
  at java.lang.reflect.Method.invoke (Native method)
  at com.android.internal.os.Zygote$MethodAndArgsCaller.run (Zygote.java:240)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:772)

#7

Thx @AGulev (and @Insality) , some questions:

  • Do you use WebP compression?
  • Do you use Native Extensions?

I think it’s interesting that it hangs when it’s already trying to shutdown?

Currently, we have no real leads as to why this is happening.


#8

Yes.

Yes:
DefVideoAds
DefAppsFlyer
Other app with the same ANR only DefVideoAds (webP too)


#9

Do you use WebP compression? – idk
Do you use Native Extensions? – yes : defAppsFlyer, defUnityAds + (facebook)

More info:

  1. Broadcast of Intent { act=android.intent.action.SCREEN_OFF flg=0x50000010 launchParam=MultiScreenLaunchParams { mDisplayId=0 mBaseDisplayId=0 mFlags=0 } (has extras) }
    with :
    #03 pc 0000000000133ddf /system/framework/arm/boot-framework.oat (Java_android_app_NativeActivity_onStopNative__J+82)
    at android.app.NativeActivity.onStopNative (Native method)
    at android.app.NativeActivity.onStop (NativeActivity.java:237)
    at android.app.Instrumentation.callActivityOnStop (Instrumentation.java:1297)
    at android.app.Activity.performStop (Activity.java:7195)

  2. Broadcast of Intent { act=android.intent.action.SCREEN_OFF flg=0x50000010 launchParam=MultiScreenLaunchParams { mDisplayId=0 mFlags=0 } (has extras) }
    with :
    #05 pc 0000000000130d17 /system/framework/arm/boot-framework.oat (Java_android_app_NativeActivity_unloadNativeCode__J+82)
    at android.app.NativeActivity.unloadNativeCode (Native method)
    at android.app.NativeActivity.onDestroy (NativeActivity.java:203)


#10

Those call stacks look truncated? I’d like to see the #00-#02 in the first one, and #00-#04 in the second one.


#11

Regarding WebP: Do you use texture profiles with WebP Compression?


#12

DefAppsflyer has no finalize method, but DefVideoAds has: https://github.com/AGulev/DefVideoAds/blob/643faae4bb673b3eefdfdfa29a3622c3d7ceda75/defunityads/src/DefUnityCallback.cpp#L26


#13
Broadcast of Intent { act=android.intent.action.SCREEN_OFF flg=0x50000010 launchParam=MultiScreenLaunchParams { mDisplayId=0 mFlags=0 } (has extras) }
(no location available)
"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 obj=0x75e7c730 self=0xeff05900
  | sysTid=13986 nice=-4 cgrp=default sched=0/0 handle=0xf344f534
  | state=S schedstat=( 4868703975 927298695 21048 ) utm=336 stm=150 core=5 HZ=100
  | stack=0xff167000-0xff169000 stackSize=8MB
  | held mutexes=
  #00  pc 0000000000017728  /system/lib/libc.so (syscall+28)
  #01  pc 0000000000046d1d  /system/lib/libc.so (_ZL24__pthread_cond_timedwaitP23pthread_cond_internal_tP15pthread_mutex_tbPK8timespec+102)
  #02  pc 0000000000161e80  /data/app/com.test.familyage-2/lib/arm/libFamily_Age.so (???)
  #03  pc 000000000006ca75  /system/lib/libandroid_runtime.so (???)
  #04  pc 000000000006cb35  /system/lib/libandroid_runtime.so (???)
  #05  pc 0000000000130d17  /system/framework/arm/boot-framework.oat (Java_android_app_NativeActivity_unloadNativeCode__J+82)
  at android.app.NativeActivity.unloadNativeCode (Native method)
  at android.app.NativeActivity.onDestroy (NativeActivity.java:203)
  at android.app.Activity.performDestroy (Activity.java:7186)

and


Broadcast of Intent { act=android.intent.action.SCREEN_OFF flg=0x50000010 launchParam=MultiScreenLaunchParams { mDisplayId=0 mBaseDisplayId=0 mFlags=0 } (has extras) }
(no location available)
"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 obj=0x758e3728 self=0xeb805400
  | sysTid=16066 nice=-4 cgrp=default sched=0/0 handle=0xeea31534
  | state=S schedstat=( 7474764823 1032494442 28966 ) utm=515 stm=232 core=0 HZ=100
  | stack=0xff54f000-0xff551000 stackSize=8MB
  | held mutexes=
  #00  pc 0000000000017530  /system/lib/libc.so (syscall+28)
  #01  pc 0000000000047b1b  /system/lib/libc.so (_ZL24__pthread_cond_timedwaitP23pthread_cond_internal_tP15pthread_mutex_tbPK8timespec+102)
  #02  pc 0000000000161c74  /data/app/com.test.familyage-1/lib/arm/libFamily_Age.so (???)
  #03  pc 0000000000133ddf  /system/framework/arm/boot-framework.oat (Java_android_app_NativeActivity_onStopNative__J+82)
  at android.app.NativeActivity.onStopNative (Native method)
  at android.app.NativeActivity.onStop (NativeActivity.java:237)
  at android.app.Instrumentation.callActivityOnStop (Instrumentation.java:1297)
  at android.app.Activity.performStop (Activity.java:7195)

#14

Solitaire with WebP compression and has no NEs - count of ANR like this is zero (here is only "
Input dispatching timed out"), looks like the reason is DefVideoAds then.
If you told that it happens when app is closing - something with this method in finalize.


#15

I’m trying to see a pattern from the java part of the callstack, and you see above, there’s onPause(), onStop(), onDestroy().

The WebP compression question stems from the fact that the addr2line gives me WebPCopyPixels (a function I don’t think we even use!). SO no real clue there I think.


#16

We do not use WebP compression


#17

@Mathias_Westerdahl I see the same thing on our internal Google Play Console as well for some of our games. Let’s see if we can together with the data collected in this post and from our own games figure out what this is.


#18

Unlike the topicstarter with SCREEN_OFF my favorite ANR is "
Broadcast of Intent { act=android.intent.action.SCREEN_ON …}"

Broadcast of Intent { act=android.intent.action.SCREEN_ON flg=0x58200010 }
Android 9, 6 users impacted 

"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x74aeb550 self=0xec1cd000
  | sysTid=11578 nice=0 cgrp=default sched=0/0 handle=0xf032a494
  | state=S schedstat=( 3655555365 2721586037 13274 ) utm=270 stm=95 core=0 HZ=100
  | stack=0xff6f6000-0xff6f8000 stackSize=8MB
  | held mutexes=
  #00  pc 0000000000019d3c  /system/lib/libc.so (syscall+28)
  #01  pc 000000000001d1e7  /system/lib/libc.so (__futex_wait_ex(void volatile*, bool, int, bool, timespec const*)+86)
  #02  pc 0000000000062d57  /system/lib/libc.so (pthread_cond_wait+32)
  #03  pc 0000000000140754  /data/app/com.dragosha.hamster-lchKpf1g9n9PjY8vLgnVNw==/lib/arm/libLookYourLoot.so (???)
  #04  pc 000000000007a32b  /system/lib/libandroid_runtime.so (android::NativeCode::~NativeCode()+26)
  #05  pc 0000000000079d81  /system/lib/libandroid_runtime.so (android::unloadNativeCode_native(_JNIEnv*, _jobject*, long long)+16)
  at android.app.NativeActivity.unloadNativeCode (Native method)
  at android.app.NativeActivity.onDestroy (NativeActivity.java:195)
  at android.app.Activity.performDestroy (Activity.java:7417)
  at android.app.Instrumentation.callActivityOnDestroy (Instrumentation.java:1323)
  at android.app.ActivityThread.performDestroyActivity (ActivityThread.java:4579)
  at android.app.ActivityThread.handleDestroyActivity (ActivityThread.java:4612)
  at android.app.servertransaction.DestroyActivityItem.execute (DestroyActivityItem.java:39)
  at android.app.servertransaction.TransactionExecutor.executeLifecycleState (TransactionExecutor.java:145)
  at android.app.servertransaction.TransactionExecutor.execute (TransactionExecutor.java:70)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:1906)
  at android.os.Handler.dispatchMessage (Handler.java:106)
  at android.os.Looper.loop (Looper.java:193)
  at android.app.ActivityThread.main (ActivityThread.java:6863)
  at java.lang.reflect.Method.invoke (Native method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:537)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:858)
Broadcast of Intent { act=android.intent.action.SCREEN_ON flg=0x50200010 }
|Android 8.0|4|66.7%|
|Android 7.0|2|33.3%|
	

"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x74258488 self=0xe80f3000
  | sysTid=18446 nice=-10 cgrp=default sched=0/0 handle=0xebfe94a8
  | state=S schedstat=( 0 0 0 ) utm=198 stm=88 core=0 HZ=100
  | stack=0xff637000-0xff639000 stackSize=8MB
  | held mutexes=
  #00  pc 0000000000018e18  /system/lib/libc.so (syscall+28)
  #01  pc 00000000000492a5  /system/lib/libc.so (_ZL24__pthread_cond_timedwaitP23pthread_cond_internal_tP15pthread_mutex_tbPK8timespec+102)
  #02  pc 0000000000140548  /data/app/com.dragosha.hamster-Qc-whdz9yrtqYLasyzhv7A==/lib/arm/libLookYourLoot.so (???)
  #03  pc 00000000001b5683  /system/framework/arm/boot-framework.oat (Java_android_app_NativeActivity_onPauseNative__J+82)
  at android.app.NativeActivity.onPauseNative (Native method)
  at android.app.NativeActivity.onPause (NativeActivity.java:202)
  at com.dynamo.android.DefoldActivity.onPause (DefoldActivity.java:243)
  at android.app.Activity.performPause (Activity.java:7120)
  at android.app.Instrumentation.callActivityOnPause (Instrumentation.java:1408)
  at android.app.ActivityThread.performPauseActivityIfNeeded (ActivityThread.java:4064)
  at android.app.ActivityThread.performPauseActivity (ActivityThread.java:4041)
  at android.app.ActivityThread.performPauseActivity (ActivityThread.java:4015)
  at android.app.ActivityThread.handlePauseActivity (ActivityThread.java:3989)
  at android.app.ActivityThread.-wrap15 (ActivityThread.java)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:1628)
  at android.os.Handler.dispatchMessage (Handler.java:105)
  at android.os.Looper.loop (Looper.java:164)
  at android.app.ActivityThread.main (ActivityThread.java:6759)
  at java.lang.reflect.Method.invoke (Native method)
  at com.android.internal.os.Zygote$MethodAndArgsCaller.run (Zygote.java:240)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:770)

Look Your Loot aka Hamster