App crashes, adb log available, what's next?

Using /e/OS Applications
,
1

Hi,

I upgraded Clash of Clans (upgrade forced by Supercell). I’m now running the latest: 15.83.13.
Every time I start it, the app crashes. I tried rebooting the device, I also tried uninstall + reinstall, but still the same crash.

Time for some fun, then… :wink: Installed adb on my laptop, connected to my device, then fetched the logs when it crashes. See below.

Aside from the java stack which looks obfuscated and likely difficult to investigate without access to the source code of this non-free app, the only thing I see:

12-14 16:09:38.910 25373 25373 I droid.deskclock: type=1400 audit(0.0:1100): avc: denied { read } for name="enforce" dev="selinuxfs" ino=4 scontext=u:r:untrusted_app:s0:c236,c256,c512,c768 tcontext=u:object_r:selinuxfs:s0 tclass=file permissive=1 app=com.supercell.clashofclans

Could it be an interesting lead to look at ?
What’s next ? Any advice welcome.

Thanks,
Flavien.

12-14 16:09:38.416  3758  4180 I ActivityTaskManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10000000 pkg=com.supercell.clashofclans cmp=com.supercell.clashofclans/com.supercell.titan.GameApp} from uid 10040
12-14 16:09:38.423  4782  5011 I WeatherUpdater: elapsedTime=1083391 vs refreshPeriod=3600000
12-14 16:09:38.462  3758  3782 E system_server: Invalid ID 0x00000000.
12-14 16:09:38.471  3536  3536 D Zygote  : Forked child process 25373
12-14 16:09:38.483  3758  3791 I ActivityManager: Start proc 25373:com.supercell.clashofclans/u0a236 for pre-top-activity {com.supercell.clashofclans/com.supercell.titan.GameApp}
12-14 16:09:38.490 25373 25373 E ll.clashofclan: Not starting debugger since process cannot load the jdwp agent.
12-14 16:09:38.569  3939  3939 D ImageWallpaper: wallpaper visibility changes to: true
12-14 16:09:38.613  3939  4009 D ImageWallpaper: onSurfaceRedrawNeeded: mNeedRedraw=false
12-14 16:09:38.626  3939  4009 D ImageWallpaper: onSurfaceRedrawNeeded: mNeedRedraw=false
12-14 16:09:38.723  3939  3951 I ndroid.systemu: NativeAlloc concurrent copying GC freed 96939(3910KB) AllocSpace objects, 1(32KB) LOS objects, 72% free, 9531KB/33MB, paused 100us total 106.308ms
12-14 16:09:38.910 25373 25373 I droid.deskclock: type=1400 audit(0.0:1098): avc: denied { read } for name="tcp" dev="proc" ino=4026534957 scontext=u:r:untrusted_app:s0:c236,c256,c512,c768 tcontext=u:object_r:proc_net_tcp_udp:s0 tclass=file permissive=1 app=com.supercell.clashofclans
12-14 16:09:38.930 25373 25373 E Report  : Exiting: 
12-14 16:09:38.930 25373 25373 E Report  : ythekfj.h: 00
12-14 16:09:38.930 25373 25373 E Report  :      at ythekfj.ab.b(Unknown Source:159)
12-14 16:09:38.930 25373 25373 E Report  :      at ythekfj.ab.a(Unknown Source:0)
12-14 16:09:38.930 25373 25373 E Report  :      at java.lang.Runtime.nativeLoad(Native Method)
12-14 16:09:38.930 25373 25373 E Report  :      at java.lang.Runtime.nativeLoad(Runtime.java:1115)
12-14 16:09:38.930 25373 25373 E Report  :      at java.lang.Runtime.loadLibrary0(Runtime.java:1069)
12-14 16:09:38.930 25373 25373 E Report  :      at java.lang.Runtime.loadLibrary0(Runtime.java:1007)
12-14 16:09:38.930 25373 25373 E Report  :      at java.lang.System.loadLibrary(System.java:1667)
12-14 16:09:38.930 25373 25373 E Report  :      at ythekfj.y.a(Unknown Source:8)
12-14 16:09:38.930 25373 25373 E Report  :      at ythekfj.Q.a(Unknown Source:13)
12-14 16:09:38.930 25373 25373 E Report  :      at ythekfj.Q.b(Unknown Source:24)
12-14 16:09:38.930 25373 25373 E Report  :      at ythekfj.Q.b(Unknown Source:6)
12-14 16:09:38.930 25373 25373 E Report  :      at ythekfj.Q.<clinit>(Unknown Source:0)
12-14 16:09:38.930 25373 25373 E Report  :      at ythekfj.Q.b(Unknown Source:0)
12-14 16:09:38.930 25373 25373 E Report  :      at androidx.core.app.CoreComponentFactory.<clinit>(Unknown Source:0)
12-14 16:09:38.930 25373 25373 E Report  :      at java.lang.Class.newInstance(Native Method)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.LoadedApk.createAppFactory(LoadedApk.java:256)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.LoadedApk.createOrUpdateClassLoaderLocked(LoadedApk.java:860)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.LoadedApk.getClassLoader(LoadedApk.java:955)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.LoadedApk.getResources(LoadedApk.java:1193)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.ContextImpl.createAppContext(ContextImpl.java:2462)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.ContextImpl.createAppContext(ContextImpl.java:2454)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.ActivityThread.handleBindApplication(ActivityThread.java:6343)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.ActivityThread.access$1300(ActivityThread.java:219)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1859)
12-14 16:09:38.930 25373 25373 E Report  :      at android.os.Handler.dispatchMessage(Handler.java:107)
12-14 16:09:38.930 25373 25373 E Report  :      at android.os.Looper.loop(Looper.java:214)
12-14 16:09:38.930 25373 25373 E Report  :      at android.app.ActivityThread.main(ActivityThread.java:7356)
12-14 16:09:38.930 25373 25373 E Report  :      at java.lang.reflect.Method.invoke(Native Method)
12-14 16:09:38.930 25373 25373 E Report  :      at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:491)
12-14 16:09:38.930 25373 25373 E Report  :      at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:940)
12-14 16:09:38.930 25373 25373 E AndroidRuntime: FATAL EXCEPTION: main
12-14 16:09:38.930 25373 25373 E AndroidRuntime: Process: com.supercell.clashofclans, PID: 25373
12-14 16:09:38.930 25373 25373 E AndroidRuntime: ythekfj.h: 00
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at ythekfj.ab.b(Unknown Source:159)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at ythekfj.ab.a(Unknown Source:0)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at java.lang.Runtime.nativeLoad(Native Method)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at java.lang.Runtime.nativeLoad(Runtime.java:1115)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at java.lang.Runtime.loadLibrary0(Runtime.java:1069)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at java.lang.Runtime.loadLibrary0(Runtime.java:1007)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at java.lang.System.loadLibrary(System.java:1667)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at ythekfj.y.a(Unknown Source:8)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at ythekfj.Q.a(Unknown Source:13)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at ythekfj.Q.b(Unknown Source:24)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at ythekfj.Q.b(Unknown Source:6)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at ythekfj.Q.<clinit>(Unknown Source:0)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at ythekfj.Q.b(Unknown Source:0)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at androidx.core.app.CoreComponentFactory.<clinit>(Unknown Source:0)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at java.lang.Class.newInstance(Native Method)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.LoadedApk.createAppFactory(LoadedApk.java:256)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.LoadedApk.createOrUpdateClassLoaderLocked(LoadedApk.java:860)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.LoadedApk.getClassLoader(LoadedApk.java:955)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.LoadedApk.getResources(LoadedApk.java:1193)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.ContextImpl.createAppContext(ContextImpl.java:2462)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.ContextImpl.createAppContext(ContextImpl.java:2454)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.ActivityThread.handleBindApplication(ActivityThread.java:6343)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.ActivityThread.access$1300(ActivityThread.java:219)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1859)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.os.Handler.dispatchMessage(Handler.java:107)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.os.Looper.loop(Looper.java:214)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at android.app.ActivityThread.main(ActivityThread.java:7356)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at java.lang.reflect.Method.invoke(Native Method)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:491)
12-14 16:09:38.930 25373 25373 E AndroidRuntime:        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:940)
12-14 16:09:38.910 25373 25373 I droid.deskclock: type=1400 audit(0.0:1100): avc: denied { read } for name="enforce" dev="selinuxfs" ino=4 scontext=u:r:untrusted_app:s0:c236,c256,c512,c768 tcontext=u:object_r:selinuxfs:s0 tclass=file permissive=1 app=com.supercell.clashofclans
12-14 16:09:38.935  3758  6955 W ActivityTaskManager:   Force finishing activity com.supercell.clashofclans/com.supercell.titan.GameApp
12-14 16:09:38.936  3758 25396 I DropBoxManagerService: add tag=data_app_crash isTagEnabled=true flags=0x2
12-14 16:09:38.910 25373 25373 I droid.deskclock: type=1400 audit(0.0:1101): avc: denied { open } for path="/sys/fs/selinux/enforce" dev="selinuxfs" ino=4 scontext=u:r:untrusted_app:s0:c236,c256,c512,c768 tcontext=u:object_r:selinuxfs:s0 tclass=file permissive=1 app=com.supercell.clashofclans
12-14 16:09:38.949 25373 25373 I Process : Sending signal. PID: 25373 SIG: 9
12-14 16:09:38.979  3536  3536 I Zygote  : Process 25373 exited due to signal 9 (Killed)
12-14 16:09:38.979  3758  4180 I ActivityManager: Process com.supercell.clashofclans (pid 25373) has died: fore TOP 
12-14 16:09:38.981  3758  3792 I libprocessgroup: Successfully killed process cgroup uid 10236 pid 25373 in 0ms
2

could it be an interesting lead … ?

the App wants to check if selinux is enforced (reads out /sys/fs/selinux/enforce) … because selinux isn’t enforced (permissive=1) the app is allowed to read from sysfs, but the access logged. With selinux enforced, the read would fail and the App think “uh yes, it’s enforced” and be happy I guess. I don’t know why the log facility is “droid.deskclock” though, is this an exec escalation joke? not my territory

Search for selinux in the settings if its permissive or enforced. Device, /e/-version and Android? you downloaded from AppLounge / Google Play?

3

Hi,

The /e/-version is 1.6-20221129238948, Android 10.
I downloaded the app from AppLounge.

Note that I upgraded the OS and the app the same day, so I cannot tell for sure which of the app or the OS introduced the change. :confused:

I did not notice the “permissive=1”. Always good to have a second pair of eyes. :slight_smile:
So this is only be a warning and the app does not get the permdenied it would get if selinux was enforced (does it expect it and fail because of this ? Or is it harmless ? No idea…)

However, selinux looks enforced:

Linux localhost 3.18.91-g35f12d2389e #1 SMP PREEMPT Tue Nov 29 23:47:15 UTC 2022 aarch64
heroltexx:/ $ getenforce
Enforcing
heroltexx:/ $

No idea either about the “droid.deskclock” thing either. :thinking:

Lots of more fun/debugging to come ! :wink:

4

I have no clue how to read that permissive=1 argument then and online docs weren’t helpful yet (like, only an old man 4 page)

While you can’t run the logcat output through selinux tooling, dmesg output is formatted appropriately → Walidacja SELinux  |  Android Open Source Project

The audit logline prior to the App exiting wants to read out the tcp state at proc, seems normal… I have no idea what’s happening :slight_smile:

5

Hi,

I upgraded ClashOfClans to version 15.83.17 yesterday, and it works again. No more crashes.

For the record, I had a look at the logs of the new working version, and the line we were looking at is still there:

12-19 10:11:41.768 32714 32714 I auditd  : type=1400 audit(0.0:2287): avc: denied { read } for comm="pool-8-thread-1" name="version" dev="proc" ino=4026534936 context=u:r:untrusted_app:s0:c236,c256,c512,c768 tcontext=u:object_r:proc_version:s0 tclass=file permissive=1 app=com.supercell.clashofclans

It must have been something else, and unless we have access to the git log of the source code of the game, there’s little chance we’ll ever know what it was. :wink:

Thanks for the help @tcecyk !

Flavien.

6

:person_shrugging: - but to be pedantic - they’re not the same, as in: this is some java thread at /proc that access denied is logged this time

7

You’re right.
Here’s the matching line:

12-19 11:34:57.348 26402 26402 I auditd  : type=1400 audit(0.0:2505): avc: denied { read } for comm="" name="enforce" dev="selinuxfs" ino=4 scontext=u:r:untrusted_app:s0:c236,c256,c512,c768 tcontext=u:object_r:selinuxfs:s0 tclass=file permissive=1 app=com.supercell.clashofclans