topjohnwu / Magisk

The Magic Mask for Android
GNU General Public License v3.0
47.59k stars 12.08k forks source link

Magisk v17.4-ab5fedda(17316) failed to install modules #791

Closed RuAnShi closed 5 years ago

RuAnShi commented 5 years ago

Cause: mount /sbin/.magisk/block/loop09->/dev/tmp/magisk_img failed with 13: Permission denied

Device: Huawei MediaPad M3 Lite 8.0 LTE (CPN-L09C170B271) Install method: boot.img patching and flashing.

magisk.log

04-21 11:46:30.820   481   481 I Magisk  : * Creating /sbin overlay
04-21 11:46:30.875   483   483 I Magisk  : Magisk v17.4-ab5fedda(17316) daemon started
04-21 11:46:30.875   483   484 I Magisk  : ** post-fs-data mode running
04-21 11:46:30.875   483   484 I Magisk  : * Initializing Magisk environment
04-21 11:46:30.878   483   484 I Magisk  : * Mounting mirrors
04-21 11:46:30.881   483   484 I Magisk  : mount: /sbin/.magisk/mirror/system <- /dev/block/bootdevice/by-name/system
04-21 11:46:30.881   483   484 I Magisk  : mount: /sbin/.magisk/mirror/vendor <- /dev/block/bootdevice/by-name/vendor
04-21 11:46:30.881   483   484 I Magisk  : bind_mount: /sbin/.magisk/mirror/bin <- /data/adb/magisk
04-21 11:46:30.882   483   484 I Magisk  : * Setting up internal busybox
04-21 11:46:30.972   489   489 I Magisk  : Magisk v17.4-ab5fedda(17316) logger started
04-21 11:46:31.114   483   484 E Magisk  : mount /sbin/.magisk/block/loop08->/dev/.img_src failed with 13: Permission denied
04-21 11:46:31.143   483   484 E Magisk  : mount /sbin/.magisk/block/loop09->/dev/.img_tgt failed with 13: Permission denied
04-21 11:46:31.143   483   484 I Magisk  : Create /data/adb/tmp.img with size 64M
04-21 11:46:31.295   483   484 E Magisk  : mount /sbin/.magisk/block/loop10->/dev/.img_mrg failed with 13: Permission denied
04-21 11:46:31.295   483   484 I Magisk  : * Merging /data/adb/magisk_merge.img + /data/adb/magisk.img -> /data/adb/tmp.img
04-21 11:46:31.296   483   484 E Magisk  : umount /dev/.img_src failed with 22: Invalid argument
04-21 11:46:31.296   483   484 E Magisk  : umount /dev/.img_tgt failed with 22: Invalid argument
04-21 11:46:31.298   483   484 E Magisk  : umount /dev/.img_mrg failed with 22: Invalid argument
04-21 11:46:31.305   483   484 I Magisk  : * Move /data/adb/tmp.img -> /data/adb/magisk.img
04-21 11:46:31.307   483   484 I Magisk  : * Mounting /data/adb/magisk.img
04-21 11:46:31.329   483   484 E Magisk  : mount /sbin/.magisk/block/loop08->/sbin/.magisk/img failed with 13: Permission denied
04-21 11:46:31.343   483   484 I Magisk  : * Running post-fs-data.d scripts
04-21 11:46:31.344   483   484 I Magisk  : * Running module post-fs-data scripts
04-21 11:46:31.344   483   484 I Magisk  : * Loading modules
04-21 11:46:31.365   483   509 I Magisk  : * Starting MagiskHide
04-21 11:46:31.365   483   509 I Magisk  : hide_utils: Hiding sensitive props
04-21 11:46:31.374   483   509 I Magisk  : hide_list: [com.google.android.gms.unstable]
04-21 11:46:32.652   483   754 I Magisk  : ** late_start service mode running
04-21 11:46:32.657   483   754 I Magisk  : * Running service.d scripts
04-21 11:46:32.668   483   754 I Magisk  : * Running module service scripts
11-21 16:34:44.009   483   509 I Magisk  : proc_monitor: com.google.android.gms.unstable (PID=[6146] ns=4026533843)(PPID=[641] ns=4026533708)
11-21 16:34:56.293  7330  7330 F Adjust  : PRODUCTION: Adjust is running in Production mode. Use this setting only for the build that you want to publish. Set the environment to `sandbox` if you want to test your app!
11-21 16:35:17.018   483   509 I Magisk  : proc_monitor: com.google.android.gms.unstable (PID=[10710] ns=4026533883)(PPID=[641] ns=4026533708)
11-21 16:35:17.695 10639 10639 F Adjust  : PRODUCTION: Adjust is running in Production mode. Use this setting only for the build that you want to publish. Set the environment to `sandbox` if you want to test your app!

magisk_install_log

- Copying zip to temp directory
- Installing MagiskHide_Props_Config-v2.6.5-v37.zip
- Mounting /system, /vendor
Archive:  /data/user/0/com.topjohnwu.magisk/cache/install.zip
  inflating: common/busybox-arm.md5
  inflating: common/busybox-arm64.md5
  inflating: common/busybox-mips.md5
  inflating: common/busybox-mips64.md5
  inflating: common/busybox-x86.md5
  inflating: common/busybox-x86_64.md5
  inflating: common/post-fs-data.sh
  inflating: common/prints.sh
  inflating: common/propsconf_conf
  inflating: common/propsconf_late
  inflating: common/propsconf_post
  inflating: common/util_functions.sh
  inflating: config.sh
  inflating: module.prop
*******************************
 MagiskHide Props Config v2.6.5
*******************************
******************************
Powered by Magisk (@topjohnwu)
******************************
- Creating /data/adb/magisk_merge.img with size 64M
Creating filesystem with parameters:
    Size: 67108864
    Block size: 4096
    Blocks per group: 32768
    Inodes per group: 4096
    Inode size: 256
    Journal blocks: 1024
    Label:
    Blocks: 16384
    Block groups: 1
    Reserved block group size: 7
Created filesystem with 11/4096 inodes and 1294/16384 blocks
Create /data/adb/magisk_merge.img with size 64M
e2fsck 1.42.9 (28-Dec-2013)
mount /sbin/.magisk/block/loop09->/dev/tmp/magisk_img failed with 13: Permission denied
! /data/adb/magisk_merge.img mount failed...
! Installation failed
topjohnwu commented 5 years ago

Do you have the logcat while installing?

RuAnShi commented 5 years ago

Yes, please see below. But there nothing special inside...

PS: I have performed some tests on my Huawei with mounting of loopback devices under magisk root (su shell) and found that if I losetup file located not on /sdcard then writeability of this loopback device is restricted, there is no special in logcat log or dmesg log. Only dmesg says that mount failed to write to this loopback device. But if loopback file located on /sdcard than it can be mounted anywhere with writeabillity successfully.

If you need to perform some tests, I am able to support your on my Device.

logcat.log

11-22 15:27:43.058  1689  1689 I TrafficMonitor: update:rxPkts:1,txPkts:0,rxBytes:78,txBytes:0
11-22 15:27:43.058  1689  1689 I TrafficMonitor: start expired. level:-1
11-22 15:27:43.058  1689  1689 I TrafficMonitor: gettimer:interval=2000
11-22 15:27:43.553  2189  2189 E wpa_supp: RSSI=-48;LINKSPEED=72;NOISE=9999;FREQUENCY=2437;
11-22 15:27:43.554  1689  2010 E WifiConfigManager: updateConfiguration freq=2437 BSSID=a8:b1:**:**:6c:b0 RSSI=-47 "PERSONAL-DEV"WPA_PSK
11-22 15:27:43.572  1689  2072 I HuaweiWifiWatchdogStateMachine: spd good count:0, add sc:0.0, rate:1.0
11-22 15:27:43.572  1689  2072 I HuaweiWifiWatchdogStateMachine: current mHighDataFlowRate = 1.0
11-22 15:27:43.572  1689  2072 I HuaweiWifiWatchdogStateMachine: POta txb txg rxg:0, 2, 0. Lr =0% Totpkt=2
11-22 15:27:43.572  1689  1689 I QosMonitor: queryRtt: rtt_type = 3
11-22 15:27:43.572  1689  1689 I WifiProJNI: ######### GET RTT:3 ########
11-22 15:27:43.572  1689  1689 I WifiProJNI: ######### CMD_QUERY_PKTS ########
11-22 15:27:43.572  1689  2070 I QosMonitor: postEventFromNative: msg=100,arg1=4,arg2=9
11-22 15:27:43.573  1689  2070 W WifiProJNI: poll before: g_monitor_fd =337
11-22 15:27:43.573  1689  2070 I QosMonitor: postEventFromNative: msg=100,arg1=0,arg2=9
11-22 15:27:43.573  1689  2070 W WifiProJNI: poll before: g_monitor_fd =337
11-22 15:27:43.573  1689  1689 I MQoS    : rtt=800,tcp_tx_pkts=2511,tcp_rx_pkts=2187
11-22 15:27:43.573  1689  5178 I MQoS    : QOS_level:0(0),DataDisable;use level-0
11-22 15:27:43.574  1689  2072 I HuaweiWifiWatchdogStateMachine: PTcp RTT:0, rtt pkt=0, tcp_rx=0, tcp_tx=0, tcp_reTran=0, rtRate=0
11-22 15:27:44.818  1689  2062 E HwCHRWebMonitor: WebMonitor [mNetWorkIsSuck=0 mUIDIsSuck=]  WebSpeed [WEBSENDSEGS=0  WEBRESENDSEGS=0  WEBRECVSEGS=0  WEBERRSEGS=0  WEBOUTRSTS=0  WEBESTABLISRST=0  WEBRTTDURATION=0  WEBRTTSEGS=0  WEBSRTT=800  WEBSNDDUPACKS=0  SENDSEGS=0  RESENDSEGS=0  RECVSEGS=0  ERRSEGS=0  OUTRSTS=0  ESTABLISRST=0  RTTDURATION=0  RTTSEGS=0  SNDDUPACKS=0  suckTimes=0 recovage_times=0]
11-22 15:27:44.818  1689  2062 E HwCHRWifiRSSIGroupSummery: updateTcpSummery mRSSI:-48  HwCHRWifiRSSIGroup [rssi_index=4, rtt_tcp_packets=892, rtt_tcp_duration=6781, rtt_lan_duration=898, rtt_lan_failures=0, rtt_lan_succ=14, rtt_lan_max=727, rtt_lan_min=3,same_area_frequency=0,adjacent_area_frequency=0]
11-22 15:27:44.836  1689  2062 E HwCHRWebMonitor: HwCHRWifiPacketCnt [mTXGood=0, mTXbad=0, mRXGood=0] rssi=-48
11-22 15:27:44.837  1689  2062 E HwCHRWebMonitor: running processName=com.huawei.hidisk
11-22 15:27:45.061  1689  1689 I TrafficMonitor: update:rxPkts:5,txPkts:0,rxBytes:885,txBytes:0
11-22 15:27:45.061  1689  1689 I TrafficMonitor: start expired. level:-1
11-22 15:27:45.061  1689  1689 I TrafficMonitor: gettimer:interval=2000
11-22 15:27:45.227  2189  2189 E wpa_supp: RSSI=-48;LINKSPEED=72;NOISE=9999;FREQUENCY=2437;
11-22 15:27:45.228  1689  2010 E WifiConfigManager: updateConfiguration freq=2437 BSSID=a8:b1:**:**:6c:b0 RSSI=-47 "PERSONAL-DEV"WPA_PSK
11-22 15:27:46.304   712   712 E         : [E/capacity_limit_control] not demo version, not set power control prop!
11-22 15:27:46.333   712   712 E         : [E/capacity_limit_control] not demo version, not set power control prop!
11-22 15:27:46.953  1689  1811 W HwPolicyFactoryImpl: mAware is disable
11-22 15:27:47.059  1689  1855 I SendBroadcastPermission: action:huawei.intent.action.APP_KILLED_FOR_KARAOKE_ACTION, mPermissionType:0
11-22 15:27:47.061  1689  1689 I TrafficMonitor: update:rxPkts:0,txPkts:0,rxBytes:0,txBytes:0
11-22 15:27:47.061  1689  1689 I TrafficMonitor: start expired. level:-1
11-22 15:27:47.061  1689  1689 I TrafficMonitor: gettimer:interval=2000
11-22 15:27:47.061  2510  2596 I ScenarioService: old above launcher pkgs: [com.topjohnwu.magisk, com.android.documentsui, com.huawei.hidisk] new front:com.android.documentsui
11-22 15:27:47.081  1689  1855 I SendBroadcastPermission: action:huawei.intent.action.APP_KILLED_FOR_KARAOKE_ACTION, mPermissionType:0
11-22 15:27:47.092  2510  2775 I BacklightControl: can't adjust backlight when app launch from other scene.
11-22 15:27:47.107  2510  2790 I PGServer: report state:10000 event type:2 pid:0 uid:0 pkg:com.huawei.hidisk to pid: 2510
11-22 15:27:47.107  2510  2790 I SceneReceiver: state type: 10000 eventType:2 pid:0 uid:0 pkg:com.huawei.hidisk
11-22 15:27:47.107  2510  2790 I PGServer: report state:10000 event type:1 pid:0 uid:0 pkg:com.android.documentsui to pid: 2510
11-22 15:27:47.107  2510  2790 I SceneReceiver: state type: 10000 eventType:1 pid:0 uid:0 pkg:com.android.documentsui
11-22 15:27:47.107  2510  2945 I HwThermalStateManager: current foreapp pkg : com.android.documentsui
11-22 15:27:47.107  2510  2945 I LowBatteryManager: Only handle msg event!
11-22 15:27:47.114   698  1000 W JankService: virtual bool android::JankManualDumpLogAnalyser::processEntry(android::LogEntry *, int, bool), not beta version or commercial log off
11-22 15:27:47.116  1689  2554 I SendBroadcastPermission: action:huawei.intent.action.APP_KILLED_FOR_KARAOKE_ACTION, mPermissionType:0
11-22 15:27:47.118  2510  2596 I ScenarioService: old above launcher pkgs: [com.topjohnwu.magisk, com.android.documentsui] new front:com.topjohnwu.magisk
11-22 15:27:47.130  1689  2554 I SendBroadcastPermission: action:huawei.intent.action.APP_KILLED_FOR_KARAOKE_ACTION, mPermissionType:0
11-22 15:27:47.131  2510  2775 I BacklightControl: can't adjust backlight when app launch from other scene.
11-22 15:27:47.139  1689  2498 I HwResourcesImpl: can't get the package name, so lock resource
11-22 15:27:47.143  2510  2790 I PGServer: report state:10000 event type:2 pid:0 uid:0 pkg:com.android.documentsui to pid: 2510
11-22 15:27:47.143  2510  2790 I SceneReceiver: state type: 10000 eventType:2 pid:0 uid:0 pkg:com.android.documentsui
11-22 15:27:47.143  2510  2790 I PGServer: report state:10000 event type:1 pid:0 uid:0 pkg:com.topjohnwu.magisk to pid: 2510
11-22 15:27:47.143  2510  2790 I SceneReceiver: state type: 10000 eventType:1 pid:0 uid:0 pkg:com.topjohnwu.magisk
11-22 15:27:47.143  2510  2945 I HwThermalStateManager: current foreapp pkg : com.topjohnwu.magisk
11-22 15:27:47.144  2510  2945 I LowBatteryManager: Only handle msg event!
11-22 15:27:47.160  1689  2545 I SendBroadcastPermission: action:huawei.intent.action.APP_KILLED_FOR_KARAOKE_ACTION, mPermissionType:0
11-22 15:27:47.168  1689  2545 I SendBroadcastPermission: action:huawei.intent.action.APP_KILLED_FOR_KARAOKE_ACTION, mPermissionType:0
11-22 15:27:47.230  5794  5794 I HwPointEventFilter: do not support AFT because of no config
11-22 15:27:47.234  3879  3896 I ctaifs<Magisk Manager>[Magisk Manager][com.topjohnwu.magisk]: [openFile] 打开文件
11-22 15:27:47.241  2112  2112 I PhoneStatusBarPolicy: updateBluetooth:::setBluetoothBatteryEnable false.
11-22 15:27:47.241  2112  2112 I PhoneStatusBarPolicy: updateBluetooth::bluetoothEnabled:false, bluetoothConnected=false, bluetoothTransfering=false
11-22 15:27:47.277  1689  2499 E HsmCoreServiceImpl: onTransact in code is: 103
11-22 15:27:47.277  1689  2499 I MediaProcessHandler: playingUids: 
11-22 15:27:47.288  1689  1846 I HwResourcesImpl: can't get the package name, so lock resource
11-22 15:27:47.310  1689  1846 I ActivityManager: Displayed com.topjohnwu.magisk/a.b: 0 (total +149ms)
11-22 15:27:47.310  1689  1846 I ActivityManager: Displayed com.topjohnwu.magisk/a.f: +149ms
11-22 15:27:48.059  1689  1689 I TrafficMonitor: expired arrive. level:-1
11-22 15:27:48.059  1689  1689 I TrafficMonitor: during_ms:2001,period_ms:2000
11-22 15:27:48.059  1689  1689 I TrafficMonitor: count:201,rx_sum:0,tx_sum:0,rxBytes:0,during_ms:2001,rx_speed:0.0,tx_speed:0.0,rto:0.0
11-22 15:27:48.250  2189  2189 E wpa_supp: RSSI=-51;LINKSPEED=72;NOISE=9999;FREQUENCY=2437;
11-22 15:27:48.252  1689  2010 E WifiConfigManager: updateConfiguration freq=2437 BSSID=a8:b1:**:**:6c:b0 RSSI=-49 "PERSONAL-DEV"WPA_PSK
11-22 15:27:49.063  1689  1689 I TrafficMonitor: update:rxPkts:3,txPkts:3,rxBytes:300,txBytes:327
11-22 15:27:49.063  1689  1689 I TrafficMonitor: start expired. level:-1
11-22 15:27:49.063  1689  1689 I TrafficMonitor: gettimer:interval=2000
RuAnShi commented 5 years ago

Also forget to mention that setenforce also does not help on this subject.

RuAnShi commented 5 years ago

I was able to install module in manual mode by first moving /data/adb/magisk_merge.img to /cache and make symbolic link to it in /data/adb, then perform regular module installation using manager after that I have removed symlink from /data/adb/magisk_merge.img and remove file /data/adb/magisk.img. Than I renamed /cache/magisk_merge.img to /cache/some_name and made symbolic link at /data/adb/magisk.img to point to /cache/some_file. Then on boot magisk able to mount magisk.img and module get up and running.

RuAnShi commented 5 years ago

I have tryed to play with sepolicy, using seinfo i have found that there is ~89 entryes with allowaudit and ~367 with dontaudit, so i have tryed to use magiskpolicy with args "allowaudit " but this is took 20 minutes more and I stoped this process, is there any way to enable audit logging for denial for all entries on sepolicy by simple magiskpolicy command? Then we be able to see what is exact cause of mount failure on such device, i think...

RuAnShi commented 5 years ago

Sorry for close/reopen, not adopted to write on ths tablet...

nekomekoraiyuu commented 5 years ago

Dear, @RuAnShi Seems like im Facing this issue too

I Cannot Sure That This Issue Similar To Magisk Module Crush Similar to #779 and #788

RuAnShi commented 5 years ago

There is no crash in my case, this issue is related to device policy, i think...

RuAnShi commented 5 years ago

I have found that Huawei perform avc logging in dmesg, but again nothing special on new build (ec472309) when installing module or mount loopback from /data partition.

dmesg_and_policy.zip

BTW, today get Huawei OTA update notification with Google security patches. Will try to update and test.

Permission13 commented 5 years ago

Seems like the problem here. Besides SD-Card it also worked when you mounted an SDCARDFS "overlay". You can see my attempt of a workaround here If you have some fresh ideas...as soon as i got a new battery for my problematic device im in.

If you want to continue playing around: This might interest you.

nekomekoraiyuu commented 5 years ago

@RuAnShi

I have found that Huawei perform avc logging in dmesg, but again nothing special on new build (ec47230) when installing module or mount loopback from /data partition.

dmesg_and_policy.zip

BTW, today get Huawei OTA update notification with Google security patches. Will try to update and test.

Try To Downgrading The version

RuAnShi commented 5 years ago

Seems that Huawei users experiencing problem with broken f2fs module in kernel, so till there will be no updates from Huawei guys or we found a way to patch kernel to fix this f2fs mount problem we can use solution like fallback to /chache partition: https://forum.xda-developers.com/apps/magisk/guide-magisk-official-version-including-t3577875 https://www.didgeridoohan.com/magisk/MagiskIssues

So I think we can close this issue due not to Magisk related and put this to Known Issues list.

topjohnwu commented 5 years ago

I cannot fix your broken F2FS driver in your device's kernel. Either switch to EXT4, or flash an updated custom kernel.