Filesystem not available

Hello there,

After having flashed the firmware files from the tools-images-hikey960 repo and the latest version of AOSP from the linaro website, I can’t seem to get the file-system to mount and Android to boot.

Judging from the logs, I’m encountering an issue similar to [1]. What are my options to fix it?

Thanks.

[1] Failed mounting rootfs on HiKey960 board with Hynix UFS flash

The logs for reference:

[...]
[    7.948777] ALSA device list:
[    7.951780]   #0: hikey-sndcard
[    8.001158] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=6,+++
[    8.007185] [I/hisi_pd] pd_dpm_handle_pe_event  unkonw event 
[    8.013450] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=5,+++
[    8.019434] Pending event is same --> ignore this event 2
[    8.025048] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=3,+++
[    8.183105] usb usb2-port1: attempt power cycle
[    8.504598] xhci-hcd xhci-hcd.0.auto: USB bus 2 deregistered
[    8.510481] xhci-hcd xhci-hcd.0.auto: remove, state 4
[    8.516098] usb usb1: USB disconnect, device number 1
[    8.522815] xhci-hcd xhci-hcd.0.auto: USB bus 1 deregistered
[    8.528935] [dwc3_otg_stop_host]-
[    8.532382] [dwc3_suspend_device] +
[    8.536276] [dwc3_suspend_device] -
[    8.539931] [dwc3_otg_work]-
[    8.542975] [USB3][hisi_dwc3_wake_unlock]usb otg wake unlock
[    8.548789] [USB3][handle_event]hiusb_status: HOST -> OFF
[    8.554360] [USB3][handle_event][handle_event] type: 0
[    8.870468] [USB3][detect_charger_type]DCD done
[    8.902867] [USB3][detect_charger_type]Primary Detection done
[    8.908790] [USB3][detect_charger_type]Secondary Detection done
[    8.942469] [USB3][detect_charger_type]type: 0
[    8.947071] [I/hisi_pd] pd_dpm_report_bc12 : event (0)
[    8.952370] [E/hisi_pd] pd_dpm_vbus_notifier_call: pd_dpm_vbus_notifier_call!!!,++++
[    8.960348] [dwc3_otg_work]+
 evt = 3[    8.964051] [dwc3_resume_device] +
[    8.967780] [dwc3_resume_device] -
[    8.971304] [dwc3_otg_start_peripheral]+
[    8.975356] [dwc3_otg_start_peripheral]-
[    8.979426] [dwc3_otg_work]-
[    8.982481] [USB3][hisi_dwc3_wake_lock]usb otg wake lock
[    8.987990] [USB3][handle_event]hisi usb status: OFF -> DEVICE
[    8.993964] [USB3][event_work]-
[    8.997195] [USB3][event_work]+
[    9.000427] [USB3][event_work]-
[   12.734179] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=6,+++
[   12.740227] [I/hisi_pd] pd_dpm_handle_pe_event  unkonw event 
[   12.746547] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=5,+++
[   12.752558] Pending event is same --> ignore this event 2
[   12.758286] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=3,+++
[   17.469092] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=6,+++
[   17.475147] [I/hisi_pd] pd_dpm_handle_pe_event  unkonw event 
[   17.481485] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=5,+++
[   17.487505] Pending event is same --> ignore this event 2
[   17.493211] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=3,+++
[   22.200276] [I/hisi_pd] PE:TYPE-C Only Charger!
[   22.205113] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=3,+++
[   22.211127] [I/hisi_pd] pd_dpm_report_pd_sink_vbus : Sink 5000 mV, 500 mA
[   22.218148] [E/hisi_pd] pd_dpm_vbus_notifier_call: pd_dpm_vbus_notifier_call!!!,++++
[   22.226109] [E/hisi_pd] pd_dpm_handle_pe_event:!!!,event=8,+++
[   25.226491] ufshcd-hi3660 ff3b0000.ufs: ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out
[   25.235526] ufshcd-hi3660 ff3b0000.ufs: ufshcd_abort: failed with err -110
[   25.346480] ufshcd-hi3660 ff3b0000.ufs: ufshcd_issue_tm_cmd: task management cmd 0x08 timed-out
[   25.355448] ufshcd-hi3660 ff3b0000.ufs: ufshcd_eh_device_reset_handler: failed with err -110
[   25.551582] ufshcd-hi3660 ff3b0000.ufs: ufshcd_read_desc_param: Failed reading descriptor. desc_id 0 param_offset 0 buff_len 31 re0
[   25.563976] ufshcd-hi3660 ff3b0000.ufs: ufs_get_device_info: Failed reading Device Desc. err = -22
[   25.573329] ufshcd-hi3660 ff3b0000.ufs: ufs_advertise_fixup_device: Failed getting device info. err = -22
[   25.585183] ufs final power mode: gear = 3, lane = 2, pwr = 1, rate = 2
[   25.591966] ufshcd-hi3660 ff3b0000.ufs: set TX_EQUALIZER 3.5db
[   25.600722] ufshcd-hi3660 ff3b0000.ufs: check TX_EQUALIZER DB value lane0 = 0x1
[   25.608230] ufshcd-hi3660 ff3b0000.ufs: check TX_EQUALIZER DB value lane1 = 0x1
[   35.866480] ufshcd-hi3660 ff3b0000.ufs: ufshcd_task_req_compl: failed, ocs = 0xf
[   35.874155] ufshcd-hi3660 ff3b0000.ufs: ufshcd_abort: failed with err 15
[   35.982471] ufshcd-hi3660 ff3b0000.ufs: ufshcd_issue_tm_cmd: task management cmd 0x08 timed-out
[   35.991437] ufshcd-hi3660 ff3b0000.ufs: ufshcd_eh_device_reset_handler: failed with err -110
[   36.111254] ufshcd-hi3660 ff3b0000.ufs: dme-link-startup: error code 1
[   36.304844] ufshcd-hi3660 ff3b0000.ufs: ufshcd_read_desc_param: Failed reading descriptor. desc_id 0 param_offset 0 buff_len 31 re0
[   36.317241] ufshcd-hi3660 ff3b0000.ufs: ufs_get_device_info: Failed reading Device Desc. err = -22
[   36.326621] ufshcd-hi3660 ff3b0000.ufs: ufs_advertise_fixup_device: Failed getting device info. err = -22
[   36.338699] ufs final power mode: gear = 3, lane = 2, pwr = 1, rate = 2
[   36.345490] ufshcd-hi3660 ff3b0000.ufs: set TX_EQUALIZER 3.5db
[   36.354241] ufshcd-hi3660 ff3b0000.ufs: check TX_EQUALIZER DB value lane0 = 0x1
[   36.361757] ufshcd-hi3660 ff3b0000.ufs: check TX_EQUALIZER DB value lane1 = 0x1
[   46.618485] ufshcd-hi3660 ff3b0000.ufs: ufshcd_task_req_compl: failed, ocs = 0xf
[   46.626167] ufshcd-hi3660 ff3b0000.ufs: ufshcd_abort: failed with err 15
[   46.734521] ufshcd-hi3660 ff3b0000.ufs: ufshcd_issue_tm_cmd: task management cmd 0x08 timed-out
[   46.743565] ufshcd-hi3660 ff3b0000.ufs: ufshcd_eh_device_reset_handler: failed with err -110
[   46.864082] ufshcd-hi3660 ff3b0000.ufs: dme-link-startup: error code 1
[   47.060723] ufshcd-hi3660 ff3b0000.ufs: ufshcd_read_desc_param: Failed reading descriptor. desc_id 0 param_offset 0 buff_len 31 re0
[   47.073048] ufshcd-hi3660 ff3b0000.ufs: ufs_get_device_info: Failed reading Device Desc. err = -22
[   47.082480] ufshcd-hi3660 ff3b0000.ufs: ufs_advertise_fixup_device: Failed getting device info. err = -22
[   47.094275] ufs final power mode: gear = 3, lane = 2, pwr = 1, rate = 2
[   47.101060] ufshcd-hi3660 ff3b0000.ufs: set TX_EQUALIZER 3.5db
[   47.109795] ufshcd-hi3660 ff3b0000.ufs: check TX_EQUALIZER DB value lane0 = 0x1
[   47.117302] ufshcd-hi3660 ff3b0000.ufs: check TX_EQUALIZER DB value lane1 = 0x1
[   49.770480] random: crng init done
[   57.366514] scsi 0:0:0:49488: Device offlined - not ready after error recovery
[   57.377620] Freeing unused kernel memory: 1152K
[   57.388241] init: init first stage started!
[   57.392729] init: Using Android DT directory /proc/device-tree/firmware/android/
[   57.400602] init: [libfs_mgr]fs_mgr_read_fstab_dt(): failed to read fstab from dt
[   57.408396] init: Failed to read fstab from device tree
[   57.414061] init: [libfs_mgr]fs_mgr_read_fstab_dt(): failed to read fstab from dt
[   57.421709] init: First stage mount skipped (missing/incompatible/empty fstab in device tree)
[   57.430455] init: Skipped setting INIT_AVB_VERSION (not in recovery mode)
[   57.437406] init: Loading SELinux policy
[   57.445290] SELinux: 8192 avtab hash slots, 17982 rules.
[   57.454352] SELinux: 8192 avtab hash slots, 17982 rules.
[   57.459743] SELinux:  1 users, 4 roles, 1256 types, 0 bools, 1 sens, 1024 cats
[   57.467070] SELinux:  93 classes, 17982 rules
[   57.472856] SELinux:  Completing initialization.
[   57.477529] SELinux:  Setting up existing superblocks.
[   57.540188] audit: type=1403 audit(64.095:2): policy loaded auid=4294967295 ses=4294967295
[   57.548751] selinux: SELinux: Loaded policy from /sepolicy
[   57.548751] 
[   57.556120] audit: type=1404 audit(64.111:3): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295
[   57.576046] selinux: SELinux: Loaded file_contexts
[   57.576046] 
[   57.585537] init: init second stage started!
[   57.595453] init: Using Android DT directory /proc/device-tree/firmware/android/
[   57.603568] init: Init cannot set 'ro.boot.hardware' to 'HiKey960': Read-only property was already set
[   57.613904] selinux: SELinux: Loaded file_contexts
[   57.613904] 
[   57.620260] init: Running restorecon...
[   57.625530] selinux: SELinux:  Could not stat /dev/block: No such file or directory.
[   57.625530] 
[   57.634879] selinux: SELinux:  setxattr failed: /dev/block:  No such file or directory
[   57.634879] 
[   57.644472] init: Couldn't load property file '/system/etc/prop.default': open() failed: No such file or directory: No such file oy
[   57.657342] init: Couldn't load property file '/prop.default': open() failed: No such file or directory: No such file or directory
[   57.669542] init: Couldn't load property file '/product/build.prop': open() failed: No such file or directory: No such file or diry
[   57.719415] ueventd: ueventd started!
[   57.729019] selinux: SELinux: Loaded file_contexts
[   57.729019] 
[   57.735677] ueventd: Parsing file /ueventd.rc...
[   57.740934] ueventd: /ueventd.rc: 43: Invalid section keyword found
[   57.747403] ueventd: /ueventd.rc: 44: Invalid section keyword found
[   57.753823] ueventd: /ueventd.rc: 45: Invalid section keyword found
[   57.760260] ueventd: /ueventd.rc: 46: Invalid section keyword found
[   57.766665] ueventd: /ueventd.rc: 47: Invalid section keyword found
[   57.773043] ueventd: /ueventd.rc: 48: Invalid section keyword found
[   57.779461] ueventd: /ueventd.rc: 49: Invalid section keyword found
[   57.913561] Registered swp emulation handler
[   57.919119] audit: type=1400 audit(64.475:4): avc:  denied  { write } for  pid=1 comm="init" name="enabled" dev="sysfs" ino=6362 s0
[   57.943802] watchdogd: watchdogd started (interval 10, margin 20)!
[   68.630981] Bluetooth: hci0: request_firmware failed(errno -11) for ti-connectivity/TIInit_11.8.32.bts
[   68.632518] wlcore: ERROR could not get configuration binary ti-connectivity/wl18xx-conf.bin: -11
[   68.632523] wlcore: WARNING falling back to default config
[   68.655457] Bluetooth: hci0: download firmware failed, retrying...
[   68.786885] hci-ti serial0-0: Direct firmware load for ti-connectivity/TIInit_11.8.32.bts failed with error -2
[   68.797248] hci-ti serial0-0: Falling back to user helper
[   68.806641] ueventd: firmware: loading 'ti-connectivity/TIInit_11.8.32.bts' for '/devices/platform/soc/fdf01000.serial/serial0/ser'
[   68.876266] wlcore: wl18xx HW: 183x or 180x, PG 2.2 (ROM 0x11)
[   68.893596] wlcore: loaded
[   77.962043] init: [libfs_mgr]Skipping '/dev/block/sdd10' during mount_all
[   97.984476] init: [libfs_mgr]Skipping '/dev/block/sdd11' during mount_all
[  118.003784] init: [libfs_mgr]Skipping '/dev/block/sdd5' during mount_all
[  130.070929] Bluetooth: hci0: request_firmware failed(errno -11) for ti-connectivity/TIInit_11.8.32.bts
[  130.080766] Bluetooth: hci0: download firmware failed, retrying...
[  130.214993] hci-ti serial0-0: Direct firmware load for ti-connectivity/TIInit_11.8.32.bts failed with error -2
[  130.225330] hci-ti serial0-0: Falling back to user helper
[  130.240031] ueventd: firmware: loading 'ti-connectivity/TIInit_11.8.32.bts' for '/devices/platform/soc/fdf01000.serial/serial0/ser'
[  138.044530] init: [libfs_mgr]Skipping '/dev/block/sdd13' during mount_all
[  158.055880] init: [libfs_mgr]Skipping '/dev/block/sdd13' during mount_all
[  158.065405] init: Parsing file /system/etc/init...
[  158.070714] init: Unable to read config file '/system/etc/init': open() failed: No such file or directory
[  158.080740] init: Parsing file /product/etc/init...
[  158.085846] init: Unable to read config file '/product/etc/init': open() failed: No such file or directory
[  158.095917] init: Parsing file /odm/etc/init...
[  158.100635] init: Unable to read config file '/odm/etc/init': open() failed: No such file or directory
[  158.110170] init: Parsing file /vendor/etc/init...
[  158.115102] init: Unable to read config file '/vendor/etc/init': open() failed: No such file or directory
[  158.125520] init: Command 'mount_all /fstab.${ro.+-----------------------------+ey960.rc:30) took 100184ms and succeeded
[  158.141585] audit: type=1400 audit(164.695:5): av|                             |d=1 comm="init" name="slabinfo" dev="proc" ino=4020
[  158.160944] audit: type=1400 audit(164.715:6): av|  Cannot open /dev/ttyUSB5!  |d=1 comm="init" name="slabinfo" dev="proc" ino=4020
[  158.180569] audit: type=1400 audit(164.735:7): av|                             |1 comm="init" name="trigger" dev="sysfs" ino=162310
[  158.199345] audit: type=1400 audit(164.755:8): av+-----------------------------+1 comm="init" name="sched_features" dev="debugfs" 0
[  158.218939] audit: type=1400 audit(164.775:9): avc:  denied  { write } for  pid=1 comm="init" name="sched_cstate_aware" dev="proc"0
[  158.238295] audit: type=1400 audit(164.791:10): avc:  denied  { write } for  pid=1 comm="init" name="sched_sync_hint_enable" dev="0
[  158.268272] file system registered
[  158.300313] ueventd: firmware: could not find firmware for ti-connectivity/TIInit_11.8.32.bts
[  158.309319] ueventd: firmware: could not find firmware for ti-connectivity/TIInit_11.8.32.bts
[  158.309523] ueventd: loading /devices/platform/soc/fdf01000.serial/serial0/serial0-0/firmware/ti-connectivity!TIInit_11.8.32.bts ts
[  158.311008] ueventd: firmware: could not find firmware for ti-connectivity/wl18xx-conf.bin
[  158.311163] ueventd: loading /devices/platform/soc/ff3ff000.dwmmc2/mmc_host/mmc1/mmc1:0001/mmc1:0001:2/wl18xx.2.auto/firmware/ti-cs
[  158.312496] ueventd: firmware: could not find firmware for ti-connectivity/TIInit_11.8.32.bts
[  158.312642] ueventd: loading /devices/platform/soc/fdf01000.serial/serial0/serial0-0/firmware/ti-connectivity!TIInit_11.8.32.bts ts
[  158.381545] ueventd: loading /devices/platform/soc/fdf01000.serial/serial0/serial0-0/firmware/ti-connectivity!TIInit_11.8.32.bts ts
[  158.381806] Bluetooth: hci0: request_firmware failed(errno -11) for ti-connectivity/TIInit_11.8.32.bts
[  158.381809] Bluetooth: hci0: download firmware failed, retrying...
[  158.506065] hci-ti serial0-0: Direct firmware load for ti-connectivity/TIInit_11.8.32.bts failed with error -2
[  158.516254] hci-ti serial0-0: Falling back to user helper
[  158.525465] ueventd: firmware: loading 'ti-connectivity/TIInit_11.8.32.bts' for '/devices/platform/soc/fdf01000.serial/serial0/ser'
[  158.542160] ueventd: firmware: could not find firmware for ti-connectivity/TIInit_11.8.32.bts
[  158.551181] Bluetooth: hci0: request_firmware failed(errno -11) for ti-connectivity/TIInit_11.8.32.bts
[  158.560698] Bluetooth: hci0: download firmware failed, retrying...

It looks like, do you have a SKHynix UFS as well ?
@leo-yan, @guodong , is it a known issue ? Is it supposed to happen despite the xloader patch ?

Sorry for the late reply. I have indeed a SKHynix UFS on my board.

I am puzzled because it came in with a pre-installed version of AOSP that worked like a charm.

What are my options? Thanks!

When you changed the Android images you are running, did you just flash the system/boot/dts images? Or did you also flash the bootloader images?

Newer builds of AOSP from sometime near APRIL onward depend on changes to the bootloader;

https://android.googlesource.com/device/linaro/hikey/+/master/installer/hikey960/

Yes, I basically flashed everything. My end goal was trying to have a build combining AOSP + OP-TEE (which I know isn’t supported officially for the Hikey 960). I followed the unofficial instructions in [1] and ended up trying to flash every combination possible of ptable, xloader, fastboot, nvme, fw_lpm3, trustfirmware, boot, dts, system, vendor, cache, userdata from multiple sources. Given that it wasn’t working at all, I tried bringing back the board to a nominal state. I used the recovery-flash.sh script from the tools-images-hikey960, then the flash-all.sh script from the latest AOSP build for Hikey960 from Linaro’s website, but to no avail.

[1] OpTEE + Android in Hikey960 - #120 by rabindranath-derebac

@aadamski Please refer to https://github.com/ARM-software/arm-trusted-firmware/blob/master/docs/plat/hikey960.rst doc for board recovery and latest boot-loader version. Then try to flash latest AOSP using flash-all.sh script.

I have followed the instructions from your link, but I am still getting the same issue. The only thing that I did differently was to reboot into fastboot mode using the switches on the board. If I pressed ‘f’ on the boot screen, flashing the fastboot partition with l-loader.bin would fail. So I powered down the board, toggled the switches 2 and 3, and powered it back on. Only then could I flash the partition successfully. Is that why I can’t seem to fix it? Thanks.

In Recovery mode follow step #1 ,reboot the board manually then follow step #2
In Flash mode follow step #3 and step #4
In Normal mode follow step #6

Skip step #5 if you don’t want to build the latest kernel.