Magisk
Magisk copied to clipboard
Opening `/data/adb/magisk.db` causes vold to kill `magiskd` when it's umounting tmpfs data partition on FDE devices
Device: Samsung Galaxy S8 (Exynos) (SM-G950F) Android version: 12L (Ivan Meler's LineageOS 19.1 ROM) Magisk version name: 25.2 Magisk version code: 25200
Additional info:
- My ROM installation is a Samsung phone ROM with encryption enabled. I can not run on unencrypted data on this particular phone for non-technical reasons.
- This issue can not be reproduced with debug build (presumably because APK signature verification is skipped for debug purposes?), so I will have to refer to the release build for this one. If there is a way to reproduce this with debug and it makes sense to do it, please let me know.
The Magisk app uninstalls itself on launch right after installation. Logcat output hints at an APK signature mismatch causing a trigger of deletePackageX, leading to the app getting killed and the APK getting completely uninstalled.
The only relevant lines from logcat here seem to be as follows, though I did attach some more logs at the end of this description:
07-29 22:16:13.073 5306 5308 E Magisk : pkg: APK signature mismatch: /data/app/~~krn7_P6YhCO6wsaM6DuHNw==/com.topjohnwu.magisk-6V6BbOlZYiJu3yThSKBn7w==/base.apk
07-29 22:16:13.098 13037 13037 I Magisk : pm_uninstall: com.topjohnwu.magisk
07-29 22:16:13.131 5388 5416 I ActivityManager: Force stopping com.topjohnwu.magisk appid=10251 user=-1: deletePackageX
And maybe the fact that this is encryption on a Samsung device specifically may play into Magisk having difficulty to deal with /data? Just guessing on my part though.
This appears on the release files distributed through GitHub Releases (https://github.com/topjohnwu/Magisk/releases/download/v25.2/Magisk-v25.2.apk) and it also happens when upgrading through Magisk 24.3's update installation option (24.3 runs pretty much fine except for Zygisk always detected as unloaded which is unrelated to this issue).
Reproduction steps:
- Start with a normal installation of the mentioned ROM. Keep a copy of boot.img from the ZIP. Encrypt the phone data.
- Install Magisk v25.2 APK straight from GitHub.
- Open the app. It will open just fine, patch the boot.img there with options left as-is.
- Flash boot.img (I specifically did it by using
adb root,dd if=/storage/emulated/0/Download/magisk_patched-25200_U4Bsz.img of=/dev/block/platform/11120000.ufs/by-name/BOOTandsync). - Reboot phone. Note that after this the "Magisk" app is no longer installed despite us not uninstalling it.
- Reinstall the exact APK used in step 2.
- Launch the app. It will close immediately and uninstall itself.
I attached more complete logs here:
/cache/magisk.log
magisk.loglogcat excerpt where I started the app
07-29 22:16:12.836 5388 10954 I ActivityTaskManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.topjohnwu.magisk/.ui.MainActivity bnds=[584,1538][856,1970]} from uid 10092
07-29 22:16:12.885 5388 5417 I ActivityManager: Start proc 13004:com.topjohnwu.magisk/u0a251 for pre-top-activity {com.topjohnwu.magisk/com.topjohnwu.magisk.ui.MainActivity}
07-29 22:16:12.985 13004 13004 V GraphicsEnvironment: ANGLE Developer option for 'com.topjohnwu.magisk' set to: 'default'
07-29 22:16:12.986 13004 13004 V GraphicsEnvironment: ANGLE GameManagerService for com.topjohnwu.magisk: false
07-29 22:16:13.073 5306 5308 E Magisk : pkg: APK signature mismatch: /data/app/~~krn7_P6YhCO6wsaM6DuHNw==/com.topjohnwu.magisk-6V6BbOlZYiJu3yThSKBn7w==/base.apk
07-29 22:16:13.098 13037 13037 I Magisk : pm_uninstall: com.topjohnwu.magisk
07-29 22:16:13.131 5388 5416 I ActivityManager: Force stopping com.topjohnwu.magisk appid=10251 user=-1: deletePackageX
07-29 22:16:13.132 5388 5416 I ActivityManager: Killing 13004:com.topjohnwu.magisk/u0a251 (adj 0): stop com.topjohnwu.magisk due to deletePackageX
07-29 22:16:13.133 5388 5416 W ActivityTaskManager: Force removing ActivityRecord{7d81d96 u0 com.topjohnwu.magisk/.ui.MainActivity t540 f}}: app died, no saved state
07-29 22:16:13.139 4148 4370 E installd: Couldn't opendir /data/user/10/com.topjohnwu.magisk: No such file or directory
07-29 22:16:13.139 4148 4370 E installd: Failed to delete /data/user/10/com.topjohnwu.magisk: No such file or directory
07-29 22:16:13.140 4148 4370 E installd: Couldn't opendir /data/user_de/10/com.topjohnwu.magisk: No such file or directory
07-29 22:16:13.140 4148 4370 E installd: Failed to delete /data/user_de/10/com.topjohnwu.magisk: No such file or directory
07-29 22:16:13.156 5388 5435 W PackageManager: com.android.server.pm.Installer$InstallerException: android.os.ServiceSpecificException: Failed to delete /data/user_de/10/com.topjohnwu.magisk (code 2)
07-29 22:16:13.260 0 0 I [5: PackageManager: 5435] sdcardfs: removing com.topjohnwu.magisk
07-29 22:16:13.339 5388 5416 W WindowManager: Failed to deliver inset state change to w=Window{7f8d1da u0 com.topjohnwu.magisk/com.topjohnwu.magisk.ui.MainActivity}
07-29 22:16:13.339 5388 5416 W WindowManager: android.os.DeadObjectException
07-29 22:16:13.339 5388 5416 W WindowManager: at android.os.BinderProxy.transactNative(Native Method)
07-29 22:16:13.339 5388 5416 W WindowManager: at android.os.BinderProxy.transact(BinderProxy.java:571)
07-29 22:16:13.339 5388 5416 W WindowManager: at android.view.IWindow$Stub$Proxy.insetsControlChanged(IWindow.java:687)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.WindowState.notifyInsetsControlChanged(WindowState.java:4037)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.InsetsStateController.lambda$notifyPendingInsetsControlChanged$6$InsetsStateController(InsetsStateController.java:552)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.InsetsStateController$$ExternalSyntheticLambda1.run(Unknown Source:2)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.WindowAnimator.executeAfterPrepareSurfacesRunnables(WindowAnimator.java:345)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.RootWindowContainer.performSurfacePlacementNoTrace(RootWindowContainer.java:887)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.RootWindowContainer.performSurfacePlacement(RootWindowContainer.java:824)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.WindowSurfacePlacer.performSurfacePlacementLoop(WindowSurfacePlacer.java:177)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.WindowSurfacePlacer.performSurfacePlacement(WindowSurfacePlacer.java:126)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.WindowSurfacePlacer.performSurfacePlacement(WindowSurfacePlacer.java:115)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.WindowSurfacePlacer.continueLayout(WindowSurfacePlacer.java:97)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.ActivityTaskManagerService.continueWindowLayout(ActivityTaskManagerService.java:4355)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.wm.ActivityTaskManagerService$LocalService.handleAppDied(ActivityTaskManagerService.java:5941)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.am.ActivityManagerService.handleAppDiedLocked(ActivityManagerService.java:3053)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.am.ProcessList.removeProcessLocked(ProcessList.java:2958)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.am.ProcessList.killPackageProcessesLSP(ProcessList.java:2903)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.am.ActivityManagerService.forceStopPackageLocked(ActivityManagerService.java:4188)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.am.ActivityManagerService$MainHandler.handleMessage(ActivityManagerService.java:1706)
07-29 22:16:13.339 5388 5416 W WindowManager: at android.os.Handler.dispatchMessage(Handler.java:106)
07-29 22:16:13.339 5388 5416 W WindowManager: at android.os.Looper.loopOnce(Looper.java:201)
07-29 22:16:13.339 5388 5416 W WindowManager: at android.os.Looper.loop(Looper.java:288)
07-29 22:16:13.339 5388 5416 W WindowManager: at android.os.HandlerThread.run(HandlerThread.java:67)
07-29 22:16:13.339 5388 5416 W WindowManager: at com.android.server.ServiceThread.run(ServiceThread.java:44)
07-29 22:16:13.342 5388 7931 I WindowManager: WIN DEATH: Window{7f8d1da u0 com.topjohnwu.magisk/com.topjohnwu.magisk.ui.MainActivity}
07-29 22:16:13.343 5388 7931 W InputManager-JNI: Input channel object '7f8d1da com.topjohnwu.magisk/com.topjohnwu.magisk.ui.MainActivity (client)' was disposed without first being removed with the input manager!
07-29 22:16:13.399 5388 5664 V ActivityManager: Got obituary of 13004:com.topjohnwu.magisk
07-29 22:16:13.483 5388 5409 W InputManager-JNI: Input channel object '449dd70 Splash Screen com.topjohnwu.magisk (client)' was disposed without first being removed with the input manager!
07-29 22:16:13.500 5538 5609 E BufferQueueProducer: [ViewRootImpl[magisk]#12(BLAST Consumer)12](id:15a20000000c,api:0,p:-1,c:5538) disconnect: not connected (req=1)
07-29 22:16:13.766 5388 5435 I ActivityManager: Force stopping com.topjohnwu.magisk appid=10251 user=0: pkg removed
07-29 22:16:13.798 5306 5308 W Magisk : pkg: cannot find com.topjohnwu.magisk for user=[0]
07-29 22:16:13.995 6941 6941 I Finsky : [2] plc.n(8): Invalidating cached PackageState for com.topjohnwu.magisk
Invalid bug report, automatically closed. Please report issues using the latest debug Magisk build (version code: 25201).
@topjohnwu Not sure how special case issues like this are handled in your repository, but I did explain the situation for why this can not be reproduced on the debug build. Can you let me know whether this is still to be seen as invalid?
07-29 20:14:02.760 5306 5306 I : Magisk 25.2(25200) daemon started
07-29 20:14:02.761 5306 5306 I : * Device API level: 32
07-29 20:14:02.770 5306 5308 I : ** post-fs-data mode running
07-29 20:14:02.774 5306 5308 I : * Mounting mirrors
07-29 20:14:02.774 5306 5308 I : link: /dev/lqIgKb/.magisk/mirror/cache
07-29 20:14:02.774 5306 5308 I : mount: /dev/lqIgKb/.magisk/mirror/data
07-29 20:14:02.774 5306 5308 I : link: /dev/lqIgKb/.magisk/mirror/system
07-29 20:14:02.775 5306 5308 I : mount: /dev/lqIgKb/.magisk/mirror/system_root
07-29 20:14:02.775 5306 5308 I : link: /dev/lqIgKb/.magisk/mirror/vendor
07-29 20:14:02.775 5306 5308 I : link: /dev/lqIgKb/.magisk/mirror/product
07-29 20:14:02.775 5306 5308 I : link: /dev/lqIgKb/.magisk/mirror/system_ext
07-29 20:14:02.841 5306 5308 I : * Initializing Magisk environment
07-29 20:14:03.330 5306 5308 I : * Running post-fs-data.d scripts
07-29 20:14:03.332 5306 5308 I : * Running module post-fs-data scripts
07-29 20:14:03.332 5306 5308 I : * Loading modules
07-29 20:14:03.721 5306 5308 I : ** post-fs-data mode running
07-29 20:14:03.724 5306 5308 I : * Mounting mirrors
07-29 20:14:03.724 5306 5308 E : symlink /cache->/dev/lqIgKb/.magisk/mirror/cache failed with 17: File exists
07-29 20:14:03.724 5306 5308 I : link: /dev/lqIgKb/.magisk/mirror/cache
07-29 20:14:03.725 5306 5308 E : mount /dev/lqIgKb/.magisk/block/data->/dev/lqIgKb/.magisk/mirror/data failed with 16: Device or resource busy
07-29 20:14:03.725 5306 5308 I : mount: /dev/lqIgKb/.magisk/mirror/data
07-29 20:14:03.729 5306 5308 I : * Initializing Magisk environment
07-29 20:14:03.729 5306 5308 E : open: /dev/lqIgKb/stub.apk failed with 2: No such file or directory
post-fs-data ran twice. I think your ROM is messed up. Try to do a data wipe or change to another ROM (like #877)
We already have stage_lock and DAEMON_STATE which should prevent this.
Wiping /data does not help: Magisk killing itself occurs the moment that the phone uses encryption after any wipe. I've now tested this on two separate ROMs (PixelExperience for S8 and the one mentioned in the issue description), both times fully wiping everything beforehand, then doing the usual device setup up to enabling encryption, then installing Magisk, patching the boot image, etc.
I also noticed if I use 24.3 instead of 25.x (where the APK signature mismatch check does not exist), if I try to enable Zygisk and reboot, Zygisk never gets detected as enabled. I originally considered this to be an unrelated issue but this may be yet another consequence of this issue.
My thoughts on the post-fs-data dupe trigger: Maybe post-fs-data is triggered once due to loading the decryption prompt and then once again for the full boot?
Does your device use full-disk encryption(FDE)? If you don't know what's it, execute getprop ro.crypto.type. A full bootlog (logcat when it boots) is also required
do you think maybe it is unofficial? careful could brick it.
On Tue, Aug 2, 2022, 3:45 AM ncc1701-enterprise @.***> wrote:
I'm facing the same behaviour on SM-G920F (S6) with stock Android 7. Update 24.3 -> 25.x results in Magisk Manager not detecting root or phone not booting, depending on wether the update was flashed via recovery or done with Magisk Manager. Also, even though I enable Zygisk the Manager reports it as being disabled after reboot.
— Reply to this email directly, view it on GitHub https://github.com/topjohnwu/Magisk/issues/6148#issuecomment-1202134875, or unsubscribe https://github.com/notifications/unsubscribe-auth/AWIIQL5VM4ZWEYV2YCG7OG3VXDGZVANCNFSM55B4DMKA . You are receiving this because you are subscribed to this thread.Message ID: @.***>
@canyie
Does your device use full-disk encryption(FDE)? If you don't know what's it, execute
getprop ro.crypto.type.
Output is block.
A full bootlog (logcat when it boots) is also required
Getting back to you with a full bootlog later.
A full logcat (as far as I could fetch it at least) from boot containing the deletePackageX message.
08-02 10:48:38.446 3911 4021 I Cryptfs : Password matches
08-02 10:48:38.446 3911 4021 D Cryptfs : test_mount_encrypted_fs(): Master key saved
08-02 10:48:39.449 3911 5759 I Cryptfs : cryptfs_restart
08-02 10:48:39.450 3911 5759 D Cryptfs : Just asked init to shut down class main
08-02 10:48:39.456 0 0 I [5: init: 1] init: processing action (vold.decrypt=trigger_shutdown_framework) from (/system/etc/init/hw/init.rc:1191)
08-02 10:48:41.454 3911 5759 W Cryptfs : found sub-directory mount /data - /data/user/0
08-02 10:48:41.469 3911 5759 W Cryptfs : umount sub-directory mount /data/user/0
08-02 10:48:41.671 3911 5759 W Cryptfs : sending SIGTERM to processes with open files
08-02 10:48:41.783 3911 5759 W vold : Found symlink /proc/4032/fd/11 referencing /data/adb/magisk.db
08-02 10:48:42.014 3911 5759 W vold : Sending Terminated to pid 4032 (magiskd, /dev/8MbuM/magisk64)
08-02 10:48:42.114 3911 5759 W Cryptfs : sending SIGKILL to processes with open files
08-02 10:48:42.183 3911 5759 W vold : Found symlink /proc/4032/fd/11 referencing /data/adb/magisk.db
08-02 10:48:42.293 3911 5759 W vold : Sending Killed to pid 4032 (magiskd, /dev/8MbuM/magisk64)
No it is not the actual reason. magiskd skipped the first post-fs-data correctly, and at that time it can be killed safely. The real reason is post-fs-data gets triggered twice after /data is decrypted.