Custota app randomly crashes on background on Android 14 Beta 5.2
archandanime opened this issue · 7 comments
archandanime commented
My device is Pixel 7a lynx with Android 14 Beta 5.2 and lynx_beta-upb5.230623.006-factory-de16f61a.zip from Google with KernelSU's android13-5.10.177_2023-06-boot.img.
I randomly received toast messages that Custota crashed on background. Logcat:
08-28 18:40:50.072 13428 13428 D nativeloader: Configuring clns-shared-4 for other apk /system/priv-app/com.chiller3.custota/app-release.apk. target_sdk_version=33, uses_libraries=, library_path=/system/priv-app/com.chiller3.custota/lib/arm64:/system/priv-app/com.chiller3.custota/app-release.apk!/lib/arm64-v8a:/system/lib64:/system_ext/lib64, permitted_path=/data:/mnt/expand:/data/user/0/com.chiller3.custota:/system/priv-app/com.chiller3.custota:/system/lib64:/system_ext/lib64
08-28 18:40:50.076 1714 1714 D ActivityManager: sync unfroze 9875 org.mozilla.firefox:tab12 for 6
08-28 18:40:50.081 1714 5540 W JobScheduler: Job didn't exist in JobStore: a9920f #u0a147/9 com.google.android.carrier/.CheckinService
08-28 18:40:50.085 13428 13428 V GraphicsEnvironment: Currently set values for:
08-28 18:40:50.085 13428 13428 V GraphicsEnvironment: angle_gl_driver_selection_pkgs=[]
08-28 18:40:50.085 13428 13428 V GraphicsEnvironment: angle_gl_driver_selection_values=[]
08-28 18:40:50.085 13428 13428 V GraphicsEnvironment: ANGLE GameManagerService for com.chiller3.custota: false
08-28 18:40:50.085 13428 13428 V GraphicsEnvironment: com.chiller3.custota is not listed in per-application setting
08-28 18:40:50.086 13428 13428 V GraphicsEnvironment: Neither updatable production driver nor prerelease driver is supported.
08-28 18:40:50.092 1714 5540 D CompatibilityChangeReporter: Compat change id reported: 161145287; UID 10147; state: DISABLED
08-28 18:40:50.092 5574 13452 W fb4a.ContextScope: Warning: Memory Leak Likely! Caching values for context: com.facebook.papaya.fb.client.services.FBPapayaJobService@b70b246
08-28 18:40:50.092 5574 13452 W fb4a.ContextScope: You should make this context implement the PropertyBag interface to avoid this leak
08-28 18:40:50.098 13428 13428 D CompatibilityChangeReporter: Compat change id reported: 194532703; UID 10244; state: ENABLED
08-28 18:40:50.098 13428 13428 D CompatibilityChangeReporter: Compat change id reported: 253665015; UID 10244; state: DISABLED
08-28 18:40:50.099 13428 13428 I UpdaterJob: Job already exists and is unchanged: (job:2/com.chiller3.custota/.updater.UpdaterJob)
08-28 18:40:50.099 1714 5237 I ActivityManager: Flag disabled. Ignoring finishAttachApplication from uid: 10244. pid: 13428
08-28 18:40:50.114 1714 5540 I ActivityManager: Background started FGS: Allowed [callingPackage: com.chiller3.custota; callingUid: 10244; uidState: TRNB; uidBFSL: n/a; intent: Intent { act=com.chiller3.custota.updater.UpdaterService.start cmp=com.chiller3.custota/.updater.UpdaterService (has extras) }; code:SYSTEM_ALLOW_LISTED; tempAllowListReason:<,reasonCode:SYSTEM_ALLOW_LISTED,duration:9223372036854775807,callingUid:-1>; targetSdkVersion:33; callerTargetSdkVersion:33; startForegroundCount:0; bindFromPackage:null: isBindService:false]
08-28 18:40:50.122 1714 5540 D ActivityManager: sync unfroze 6249 com.google.android.apps.turbo for 6
08-28 18:40:50.125 13428 13428 D UpdaterService: Received intent: Intent { act=com.chiller3.custota.updater.UpdaterService.start cmp=com.chiller3.custota/.updater.UpdaterService (has extras) }
08-28 18:40:50.125 13428 13428 D UpdaterService: Updating foreground notification for state: null
08-28 18:40:50.125 13428 13428 D CompatibilityChangeReporter: Compat change id reported: 160794467; UID 10244; state: ENABLED
08-28 18:40:50.127 1714 5540 D CompatibilityChangeReporter: Compat change id reported: 170668199; UID 10244; state: ENABLED
08-28 18:40:50.127 1714 5540 W ActivityManager: Foreground service started from background can not have location/camera/microphone access: service com.chiller3.custota/.updater.UpdaterService
08-28 18:40:50.127 1714 5540 D CompatibilityChangeReporter: Compat change id reported: 255038118; UID 10244; state: DISABLED
08-28 18:40:50.127 1714 5540 D CompatibilityChangeReporter: Compat change id reported: 255042465; UID 10244; state: DISABLED
08-28 18:40:50.128 13428 13428 D UpdaterService: Creating new updater thread
08-28 18:40:50.129 13428 13428 D UpdaterService: Updating foreground notification for state: null
08-28 18:40:50.131 1714 5540 W ActivityManager: Foreground service started from background can not have location/camera/microphone access: service com.chiller3.custota/.updater.UpdaterService
08-28 18:40:50.134 13428 13428 W UpdaterService: Failed to handle intent: Intent { act=com.chiller3.custota.updater.UpdaterService.start cmp=com.chiller3.custota/.updater.UpdaterService (has extras) }
08-28 18:40:50.134 13428 13428 W UpdaterService: java.lang.reflect.InvocationTargetException
08-28 18:40:50.134 13428 13428 W UpdaterService: at java.lang.reflect.Method.invoke(Native Method)
08-28 18:40:50.134 13428 13428 W UpdaterService: at com.chiller3.custota.updater.UpdaterThread.<init>(Unknown Source:30)
08-28 18:40:50.134 13428 13428 W UpdaterService: at com.chiller3.custota.updater.UpdaterService.startUpdate(Unknown Source:70)
08-28 18:40:50.134 13428 13428 W UpdaterService: at com.chiller3.custota.updater.UpdaterService.onStartCommand(Unknown Source:51)
08-28 18:40:50.134 13428 13428 W UpdaterService: at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4821)
08-28 18:40:50.134 13428 13428 W UpdaterService: at android.app.ActivityThread.-$$Nest$mhandleServiceArgs(Unknown Source:0)
08-28 18:40:50.134 13428 13428 W UpdaterService: at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2289)
08-28 18:40:50.134 13428 13428 W UpdaterService: at android.os.Handler.dispatchMessage(Handler.java:106)
08-28 18:40:50.134 13428 13428 W UpdaterService: at android.os.Looper.loopOnce(Looper.java:205)
08-28 18:40:50.134 13428 13428 W UpdaterService: at android.os.Looper.loop(Looper.java:294)
08-28 18:40:50.134 13428 13428 W UpdaterService: at android.app.ActivityThread.main(ActivityThread.java:8177)
08-28 18:40:50.134 13428 13428 W UpdaterService: at java.lang.reflect.Method.invoke(Native Method)
08-28 18:40:50.134 13428 13428 W UpdaterService: at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:552)
08-28 18:40:50.134 13428 13428 W UpdaterService: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:971)
08-28 18:40:50.134 13428 13428 W UpdaterService: Caused by: android.os.ServiceManager$ServiceNotFoundException: No service published for: android.os.UpdateEngineService
08-28 18:40:50.134 13428 13428 W UpdaterService: at android.os.ServiceManager.getServiceOrThrow(ServiceManager.java:166)
08-28 18:40:50.134 13428 13428 W UpdaterService: ... 14 more
08-28 18:40:50.134 13428 13428 D AndroidRuntime: Shutting down VM
08-28 18:40:50.135 13428 13428 E AndroidRuntime: FATAL EXCEPTION: main
08-28 18:40:50.135 13428 13428 E AndroidRuntime: Process: com.chiller3.custota, PID: 13428
08-28 18:40:50.135 13428 13428 E AndroidRuntime: java.lang.RuntimeException: Unable to start service com.chiller3.custota.updater.UpdaterService@28405e5 with Intent { act=com.chiller3.custota.updater.UpdaterService.start cmp=com.chiller3.custota/.updater.UpdaterService (has extras) }: java.lang.NullPointerException
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4839)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at android.app.ActivityThread.-$$Nest$mhandleServiceArgs(Unknown Source:0)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2289)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at android.os.Handler.dispatchMessage(Handler.java:106)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at android.os.Looper.loopOnce(Looper.java:205)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at android.os.Looper.loop(Looper.java:294)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at android.app.ActivityThread.main(ActivityThread.java:8177)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at java.lang.reflect.Method.invoke(Native Method)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:552)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:971)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: Caused by: java.lang.NullPointerException
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at com.chiller3.custota.updater.UpdaterService.notifyAlert(Unknown Source:187)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at com.chiller3.custota.updater.UpdaterService.onStartCommand(Unknown Source:208)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4821)
08-28 18:40:50.135 13428 13428 E AndroidRuntime: ... 9 more
08-28 18:40:50.136 13428 13428 E MainApplication: Saving logcat to /storage/emulated/0/Android/data/com.chiller3.custota/files/crash.log due to uncaught exception in Thread[main,5,main]
08-28 18:40:50.136 13428 13428 E MainApplication: java.lang.RuntimeException: Unable to start service com.chiller3.custota.updater.UpdaterService@28405e5 with Intent { act=com.chiller3.custota.updater.UpdaterService.start cmp=com.chiller3.custota/.updater.UpdaterService (has extras) }: java.lang.NullPointerException
08-28 18:40:50.136 13428 13428 E MainApplication: at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4839)
08-28 18:40:50.136 13428 13428 E MainApplication: at android.app.ActivityThread.-$$Nest$mhandleServiceArgs(Unknown Source:0)
08-28 18:40:50.136 13428 13428 E MainApplication: at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2289)
08-28 18:40:50.136 13428 13428 E MainApplication: at android.os.Handler.dispatchMessage(Handler.java:106)
08-28 18:40:50.136 13428 13428 E MainApplication: at android.os.Looper.loopOnce(Looper.java:205)
08-28 18:40:50.136 13428 13428 E MainApplication: at android.os.Looper.loop(Looper.java:294)
08-28 18:40:50.136 13428 13428 E MainApplication: at android.app.ActivityThread.main(ActivityThread.java:8177)
08-28 18:40:50.136 13428 13428 E MainApplication: at java.lang.reflect.Method.invoke(Native Method)
08-28 18:40:50.136 13428 13428 E MainApplication: at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:552)
08-28 18:40:50.136 13428 13428 E MainApplication: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:971)
08-28 18:40:50.136 13428 13428 E MainApplication: Caused by: java.lang.NullPointerException
08-28 18:40:50.136 13428 13428 E MainApplication: at com.chiller3.custota.updater.UpdaterService.notifyAlert(Unknown Source:187)
08-28 18:40:50.136 13428 13428 E MainApplication: at com.chiller3.custota.updater.UpdaterService.onStartCommand(Unknown Source:208)
08-28 18:40:50.136 13428 13428 E MainApplication: at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4821)
08-28 18:40:50.136 13428 13428 E MainApplication: ... 9 more
I don't know the issue will remain on official Android 14 but still would like to hear from you.
chenxiaolong commented
Thanks for the logs. It looks like there are two issues:
-
Custota can't connect to
update_engine.08-28 18:40:50.134 13428 13428 W UpdaterService: Caused by: android.os.ServiceManager$ServiceNotFoundException: No service published for: android.os.UpdateEngineService 08-28 18:40:50.134 13428 13428 W UpdaterService: at android.os.ServiceManager.getServiceOrThrow(ServiceManager.java:166)This is the main issue and depending on the root cause, I might not be able to fix it until the Android 14 source code is released in AOSP. In the meantime, can you upload all of Custota's logs from
/data/local/tmp/? -
Custota is failing to show an error notification when the issue above occurs:
08-28 18:40:50.136 13428 13428 E MainApplication: Caused by: java.lang.NullPointerException 08-28 18:40:50.136 13428 13428 E MainApplication: at com.chiller3.custota.updater.UpdaterService.notifyAlert(Unknown Source:187) 08-28 18:40:50.136 13428 13428 E MainApplication: at com.chiller3.custota.updater.UpdaterService.onStartCommand(Unknown Source:208) 08-28 18:40:50.136 13428 13428 E MainApplication: at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4821) 08-28 18:40:50.136 13428 13428 E MainApplication: ... 9 more
This is likely a dumb bug in Custota. I'll look into this soon.
chenxiaolong commented
Oh also, in the meantime, the crashes should stop if you disable the update checks.
archandanime commented
Thank you for the info! Here is Custota log:
:/data/local/tmp # cat custota_selinux.log
----- Environment -----
Timestamp: Mon Aug 28 19:02:07 +07 2023
Script: /data/adb/modules/com.chiller3.custota/post-fs-data.sh
App ID: com.chiller3.custota
App version: v2.1
UID/GID/Context: uid=0(root) gid=0(root) context=u:r:su:s0
----- Creating custota_app domain -----
Policy version: 30
----- Updating seapp_contexts -----
/data/adb/modules/com.chiller3.custota/post-fs-data.sh: line 21: can't create /dev/selinux/apex_seapp_contexts: nonexistent directory
SELinux: Loaded file context from:
/system/etc/selinux/plat_file_contexts
/system_ext/etc/selinux/system_ext_file_contexts
/product/etc/selinux/product_file_contexts
/vendor/etc/selinux/vendor_file_contexts
SELinux: Could not stat /dev/selinux: No such file or directory.
chenxiaolong commented
Huh, interesting. I took a quick look at the Android 14 beta's libselinux.so and it looks like it still reads that file. That's good because there's probably nothing that needs to be changed in Custota's SELinux code.
❯ strings system/lib64/libselinux.so | grep apex
/dev/selinux/apex_service_contexts
/dev/selinux/apex_file_contexts
/dev/selinux/apex_seapp_contexts
I'm guessing the issue is that /system/bin/init doesn't create the /dev/selinux directory anymore.
If you're feeling a bit adventurous, you can try editing /data/adb/modules/com.chiller3.custota/post-fs-data.sh to add:
mkdir -p /dev/selinux
# Before the following line:
# cat >> /dev/selinux/apex_seapp_contexts << EOFarchandanime commented
I added mkdir -p /dev/selinux before cat >> /dev/selinux/apex_seapp_contexts << EOF and rebooted:
:/data/ssh/root # ls /dev/selinux/
apex_seapp_contexts
:/data/ssh/root # cat /dev/selinux/apex_seapp_contexts
user=_app isPrivApp=true name=com.chiller3.custota domain=custota_app type=app_data_file levelFrom=all
:/data/ssh/root # strings /system/bin/init |grep selinux
selinux_android_restorecon
selinux_check_access
selinux_set_callback
selinux_android_file_context_handle
selinux_android_set_sehandle
set_selinuxmnt
libselinux.so
selinux
/sys/fs/selinux/null
/system_ext/etc/selinux/system_ext_sepolicy_and_mapping.sha256
/system/etc/selinux/apex/
/dev/selinux/
/system/etc/selinux/plat_sepolicy_and_mapping.sha256
security.selinux
selinux_setup
/odm/etc/selinux/odm_sepolicy.cil
/dev/selinux/apex_sepolicy.sha256
system/core/init/selinux.cpp
Unable to write to /sys/fs/selinux/checkreqprot:
/vendor/etc/selinux/plat_sepolicy_vers.txt
/dev/selinux/apex_property_contexts
Failed to read /vendor/etc/selinux/plat_sepolicy_vers.txt
/vendor/etc/selinux/plat_pub_versioned.cil
ro.boottime.init.selinux
/odm/etc/selinux/odm_property_contexts
/product/etc/selinux/product_property_contexts
/sys/fs/selinux/checkreqprot
mount("selinuxfs", "/sys/fs/selinux", "selinuxfs", 0, NULL) failed
/system_ext/etc/selinux/mapping/
/product/etc/selinux/product_sepolicy.cil
selinuxfs
selinux_android_restorecon(
/system_ext/etc/selinux/system_ext_sepolicy.cil
/product/etc/selinux/mapping/
/vendor/etc/selinux/vendor_sepolicy.cil
/product/etc/selinux/product_sepolicy_and_mapping.sha256
restorecon failed of /dev/selinux failed
Could not perform selinux transition
selinux_android_restorecon() failed
to another SELinux domain defined. Have you configured your service correctly? https://source.android.com/security/selinux/device-policy#label_new_services_and_address_denials. Note: this error shows up even in permissive mode in order to make auditing denials possible.
/system/etc/selinux/plat_property_contexts
/system/etc/selinux/mapping/
/dev/selinux/apex_sepolicy.cil
/system_ext/etc/selinux/system_ext_property_contexts
/sys/fs/selinux
/system/etc/selinux/com.android.sepolicy.cert-release.der
/vendor/etc/selinux/vendor_property_contexts
selinux.restorecon_recursive
selinux.restorecon_recursive
/system/etc/selinux/plat_sepolicy.cil
/vendor/etc/selinux/precompiled_sepolicy
/odm/etc/selinux/precompiled_sepolicy
chenxiaolong commented
Great! Looks like that worked then.
I think I found the commit that caused this. Google luckily isn't withholding init's code until the Android 14 release date. https://android.googlesource.com/platform/system/core/+/d01921034cc63c9f0942b5fb451cbc971e7407b1%5E%21/
I think the extra mkdir is a proper fix, so I've added it in #14.
archandanime commented
Thank you for the info and the fix!