Recovery failure on Hikey960

Hello,

I’m experiencing issues with recovering my Hikey960, from what it looks like fastboot won’t start. I’ve tried both master and 3.3.0 of https://github.com/OP-TEE/build.git with no success. Logs follow:

mpp@os-lin-mpp:~/devel/hikey_960/build$ make recovery
Enter recovery mode to flash a new bootloader

Make sure udev permissions are set appropriately:
  # /etc/udev/rules.d/hikey960.rules
  SUBSYSTEM=="usb", ATTRS{idVendor}=="18d1", ATTRS{idProduct}=="d00d", MODE="0666"
  SUBSYSTEM=="usb", ATTRS{idVendor}=="12d1", MODE="0666", ENV{ID_MM_DEVICE_IGNORE}="1"

Set jumpers or switches as follows:
Jumper 1-2: Closed	or	Switch	1: On
       3-4: Closed	or		2: On
       5-6: Open	or		3: Off
Press enter to continue

Connect HiKey960 to power up (press enter)
Connect USB OTG cable, the micro USB cable (press enter)

Check the device node (/dev/ttyUSBx) of the micro USB connection
Note the value x of the device node. Default is 1
Enter the device node. Press enter for /dev/ttyUSB1: 
[sudo] password for mpp: 
Config name: /home/mpp/devel/hikey_960/build/../out/config
Port name: /dev/ttyUSB1
0: Image: ./hisi-sec_usb_xloader.img Downalod Address: 0x20000
1: Image: ./hisi-sec_uce_boot.img Downalod Address: 0x6a908000
2: Image: ./recovery.bin Downalod Address: 0x1ac00000
Serial port open successfully!
Start downloading ./hisi-sec_usb_xloader.img@0x20000...
file total size 99584
downlaod address 0x20000
Finish downloading
Start downloading ./hisi-sec_uce_boot.img@0x6a908000...
file total size 23680
downlaod address 0x6a908000
Finish downloading
Start downloading ./recovery.bin@0x1ac00000...
file total size 1179648
downlaod address 0x1ac00000
Finish downloading

If you see dots starting to appear on the console,
press f ON THE CONSOLE (NOT HERE!) to run fastboot.
You have 10 seconds! Go!
If not, fastboot should load automatically.
Press enter (HERE) to continue flashing
Wait until you see the (UART) message
    "Android Fastboot mode - version x.x."
     Press RETURN or SPACE key to quit."
It can take a while for the fastboot device to come up,
so please wait ~10 seconds.
Then press enter to continue flashing

fastboot flash ptable /home/mpp/devel/hikey_960/build/../l-loader/prm_ptable.img
< waiting for any device >

Log from ttyUSB0:

Welcome to minicom 2.7.1

OPTIONS: I18n 
Compiled on Aug 13 2017, 15:25:34.
Port /dev/ttyUSB0, 08:35:44

Press CTRL-A Z for help on special keys

hikey960 boarid:5301 xloader use UART6
scsysstat_value[0].
clear reset source
last_keypoint0,reboot_type0
secdbg not DCU.
SecDbgVer exit

 xloader chipid is: 0x36600110, start at 25949ms.
Build Date: Dec  6 2017, 15:31:59
[clock_init] ++
hikey960 [hikey960_clk_init]
hi3660 [clk_setup]
[clock_init] --
storage type is UFS
ufs retry: 6 count v_tx:0 v_rx:0
ufs set v_tx:0 v_rx:0
UfsLuInit ret:0
UsbMode, nvData invalid
rtc_nve_read failed !
Hikey960[5301] no need avs_init.
ddr ft:0xf20332a3,mode:1 target:4
[USBI]driver init:0003e800 0003f840 00000000
[USBI]download start! total_frame:24
+1      0|+2    0|+3    0|+4    0|+5    0|+6    0|+7    0|+8    0|+9    0|+10   0|+11   0|+12   0|+13   0|+14   0|+15   0|+16   0|+17   0|+18   0|+19   0|+20   0|+21 0|+22 0|+23 0|+24 0|
[USBI]expected:23680, received:23680 (bytes)
[USBI]download suc
UceLdOk
ch 0 gt_errfail, STATUS:0x00000060
ch 0 gdst_errfail, STATUS:0x00000040
ch 1 gt_errfail, STATUS:0x00000060
ch 1 gdst_errfail, STATUS:0x00000040
ch 2 gt_errfail, STATUS:0x00000060
ch 2 gdst_errfail, STATUS:0x00000040                                                                                                       
ch 3 gt_errfail, STATUS:0x00000060                                                                                                         
ch 3 gdst_errfail, STATUS:0x00000040                                                                                                       
timeout                                                                                                                                    
timeout                                                                                                                                    
timeout                                                                                                                                    
timeout                                                                                                                                    
density: 0x0c0c0c0c,0x00000000,0x0c0c0c0c,0x00000000,0x0c0c0c0c,0x00000000,0x0c0c0c0c,0x00000000                                           
ddr info 0x00000306                                                                                                                        
400M                                                                                                                                       
685M                                                                                                                                       
1067M                                                                                                                                      
C1R,V0x0000002d e:66                                                                                                                       
C2R,V0x0000002c e:66                                                                                                                       
C3R,V0x0000002d e:66                                                                                                                       
C0R,V0x0000002d e:66                                                                                                                       
C1R,V0x0000002e e:66                                                                                                                       
C2R,V0x0000002d e:66                                                                                                                       
C3R,V0x0000002e e:66                                                                                                                       
C0R,V0x0000002e e:66
C1R,V0x0000002f e:66
C2R,V0x0000002e e:66
C3R,V0x0000002f e:66
C0R,V0x0000002f e:65
C1R,V0x00000030 e:65
C2R,V0x0000002f e:66
C3R,V0x00000030 e:65
1244M
1866M
C0R,V0x00000015 e:193
C0R,V0x00000016 e:66
C2R,V0x00000016 e:66
C0R,V0x00000017 e:66
C1R,V0x00000017 e:66
C2R,V0x00000017 e:66
C3R,V0x00000017 e:66
UsbMode, nvData invalid
UsbMode, nvData invalid
UsbMode, nvData invalid
[USBI]driver init:0003e800 0003f840 00000000
[USBI]download start! total_frame:1152
+1      0|+2    0|+3    0|+4    0|+5    0|+6    0|+7    0|+8    0|+9    0|+10   0|+11   0|+12   0|+13   0|+14   0|+15   0|+16   0|+17   0|+18   0|+19   0|+20   0|+21 0|+22 0|+23 0|+24 0|+25 0|+26 0|+27 0|+28 0||
[USBI]expected:1179648, received:1179648 (bytes)
[USBI]download suc
iomcu_subsys_init
boot_c0 PROFILE 4
slave0 irq0:0x00000014
slave1 irq0:0x00000004
NOTICE:  Booting Trusted Firmware
NOTICE:  BL1: v2.0(release):v2.0-507-g34efb683
NOTICE:  BL1: Built : 15:05:47, Mar  7 2019
NOTICE:  BL1-FWU: *******FWU Process Started*******

And my dmsg showing USB-C recognized as ttyUSB1:

[558402.248609] usb 1-4: new full-speed USB device number 51 using xhci_hcd
[558402.400333] usb 1-4: New USB device found, idVendor=12d1, idProduct=3609
[558402.400337] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[558402.400339] usb 1-4: Product: USB SER
[558402.400341] usb 1-4: Manufacturer: HISILICON
[558402.402028] option 1-4:1.0: GSM modem (1-port) converter detected
[558402.402326] usb 1-4: GSM modem (1-port) converter now attached to ttyUSB1

From the log, the recovery.bin image is unexpected; could you check if the recovery binary is correct or not? You could compare the prebuilt recovery.bin in [1].

[1] http://snapshots.linaro.org/96boards/reference-platform/components/uefi-staging/latest/hikey960/debug/recovery.bin

UEFI binaries for Hikey and Hikey960 have been moved here since build #86: http://snapshots.linaro.org/reference-platform/components/uefi-staging/latest/

Hi leo-yan, thanks for that, prebuilt recovery works for me.

From the log, the recovery.bin image is unexpected;

What do you mean by that?

When download binaries, it outputs logs with the packet index numbers. From you shared log, it only dump very short logs for recovery.bin but recovery.bin is not a small binary (should > 1MB). So if download a ‘correct’ recovery.bin, you should see very long log with many packet index numbers.

That’s just minicom not wrapping long lines. I can enable line wrapping and provide you another log if needed, but notice this:

expected:1179648, received:1179648 (bytes)

This is the same size as the prebuilt (and working) recovery.

So after recovering successfully using the prebuilt binaries, flashing fails (while using the prebuilt binaries).

ttyUSB0 log:

hikey960 boarid:5301 xloader use UART6
scsysstat_value[0].
clear reset source
last_keypoint0,reboot_type0
secdbg not DCU.
SecDbgVer exit

 xloader chipid is: 0x36600110, start at 445ms.
Build Date: Dec  6 2017, 15:31:59
[clock_init] ++
hikey960 [hikey960_clk_init]
hi3660 [clk_setup]
[clock_init] --
storage type is UFS
ufs retry: 6 count v_tx:0 v_rx:0
ufs set v_tx:0 v_rx:0
Hikey960[5301] no need avs_init.
ddr ft:0xf20332a3,mode:1 target:4
UceLdOk
ch 0 gt_errfail, STATUS:0x00000060
ch 0 gdst_errfail, STATUS:0x00000040
ch 1 gt_errfail, STATUS:0x00000060
ch 1 gdst_errfail, STATUS:0x00000040
ch 2 gt_errfail, STATUS:0x00000060
ch 2 gdst_errfail, STATUS:0x00000040
ch 3 gt_errfail, STATUS:0x00000060
ch 3 gdst_errfail, STATUS:0x00000040
timeout
timeout
timeout
timeout
density: 0x0c0c0c0c,0x00000000,0x0c0c0c0c,0x00000000,0x0c0c0c0c,0x00000000,0x0c0c0c0c,0x00000000
ddr info 0x00000306
400M
685M
1067M
C1R,V0x0000002c e:66
C1R,V0x0000002d e:66
C2R,V0x0000002c e:66
C0R,V0x0000002d e:66
C1R,V0x0000002e e:66
C2R,V0x0000002d e:66
C3R,V0x0000002d e:66
C0R,V0x0000002e e:66
C1R,V0x0000002f e:66
C2R,V0x0000002e e:66
C3R,V0x0000002e e:66
C0R,V0x0000002f e:65
C1R,V0x00000030 e:65
C2R,V0x0000002f e:66
C3R,V0x0000002f e:66
1244M
1866M
C0R,V0x00000015 e:113
C0R,V0x00000016 e:66
C2R,V0x00000016 e:66
C3R,V0x00000016 e:193
C0R,V0x00000017 e:66
C1R,V0x00000017 e:66
C2R,V0x00000017 e:66
C3R,V0x00000017 e:66
iomcu_subsys_init
boot_c0 PROFILE 4
slave0 irq0:0x00000004
slave1 irq0:0x00000004
NOTICE:  BL2: v2.0(release):v2.0-507-g34efb683
NOTICE:  BL2: Built : 15:05:47, Mar  7 2019
NOTICE:  BL2: Booting BL31
NOTICE:  BL31: v2.0(release):v2.0-507-g34efb683
NOTICE:  BL31: Built : 15:05:47, Mar  7 2019
D/TC:0 0 add_phys_mem:536 TEE_SHMEM_START type NSEC_SHM 0x3ee00000 size 0x00200000
D/TC:0 0 add_phys_mem:536 TA_RAM_START type TA_RAM 0x3f200000 size 0x00e00000
D/TC:0 0 add_phys_mem:536 VCORE_UNPG_RW_PA type TEE_RAM_RW 0x3f04d000 size 0x001b3000
D/TC:0 0 add_phys_mem:536 VCORE_UNPG_RX_PA type TEE_RAM_RX 0x3f000000 size 0x0004d000
D/TC:0 0 add_phys_mem:536 CONSOLE_UART_BASE type IO_NSEC 0xffe00000 size 0x00200000
D/TC:0 0 verify_special_mem_areas:480 NSEC DDR memory [40000000 c0000000]
D/TC:0 0 verify_special_mem_areas:480 NSEC DDR memory [0 3e000000]
D/TC:0 0 add_va_space:575 type RES_VASPACE size 0x00a00000
D/TC:0 0 add_va_space:575 type SHM_VASPACE size 0x02000000
D/TC:0 0 dump_mmap_table:708 type IO_NSEC      va 0x3ae00000..0x3affffff pa 0xffe00000..0xffffffff size 0x00200000 (pgdir)
D/TC:0 0 dump_mmap_table:708 type TA_RAM       va 0x3b000000..0x3bdfffff pa 0x3f200000..0x3fffffff size 0x00e00000 (pgdir)
D/TC:0 0 dump_mmap_table:708 type SHM_VASPACE  va 0x3c000000..0x3dffffff pa 0x00000000..0x01ffffff size 0x02000000 (pgdir)
D/TC:0 0 dump_mmap_table:708 type RES_VASPACE  va 0x3e200000..0x3ebfffff pa 0x00000000..0x009fffff size 0x00a00000 (pgdir)
D/TC:0 0 dump_mmap_table:708 type NSEC_SHM     va 0x3ee00000..0x3effffff pa 0x3ee00000..0x3effffff size 0x00200000 (pgdir)
D/TC:0 0 dump_mmap_table:708 type TEE_RAM_RX   va 0x3f000000..0x3f04cfff pa 0x3f000000..0x3f04cfff size 0x0004d000 (smallpg)
D/TC:0 0 dump_mmap_table:708 type TEE_RAM_RW   va 0x3f04d000..0x3f1fffff pa 0x3f04d000..0x3f1fffff size 0x001b3000 (smallpg)
D/TC:0 0 core_mmu_entry_to_finer_grained:652 xlat tables used 1 / 5
D/TC:0 0 core_mmu_entry_to_finer_grained:652 xlat tables used 2 / 5
I/TC:
D/TC:0 0 init_canaries:166 #Stack canaries for stack_tmp[0] with top at 0x3f0a0e38
D/TC:0 0 init_canaries:166 watch *0x3f0a0e3c
D/TC:0 0 init_canaries:166 #Stack canaries for stack_tmp[1] with top at 0x3f0a1678
D/TC:0 0 init_canaries:166 watch *0x3f0a167c
D/TC:0 0 init_canaries:166 #Stack canaries for stack_tmp[2] with top at 0x3f0a1eb8
D/TC:0 0 init_canaries:166 watch *0x3f0a1ebc
D/TC:0 0 init_canaries:166 #Stack canaries for stack_tmp[3] with top at 0x3f0a26f8
D/TC:0 0 init_canaries:166 watch *0x3f0a26fc
D/TC:0 0 init_canaries:166 #Stack canaries for stack_tmp[4] with top at 0x3f0a2f38
D/TC:0 0 init_canaries:166 watch *0x3f0a2f3c
D/TC:0 0 init_canaries:166 #Stack canaries for stack_tmp[5] with top at 0x3f0a3778
D/TC:0 0 init_canaries:166 watch *0x3f0a377c
D/TC:0 0 init_canaries:166 #Stack canaries for stack_tmp[6] with top at 0x3f0a3fb8
D/TC:0 0 init_canaries:166 watch *0x3f0a3fbc
D/TC:0 0 init_canaries:166 #Stack canaries for stack_tmp[7] with top at 0x3f0a47f8
Press ESCAPE for boot options .Android Fastboot mode - version 0.7.
Press RETURN or SPACE key to quit.

ttyUSB1 log:

Flash binaries using fastboot

Set jumpers or switches as follows:
Jumper 1-2: Closed	or	Switch	1: On
       3-4: Open	or		2: Off
       5-6: Closed	or		3: On
Press enter to continue

Connect HiKey960 to power up (press enter)
Connect USB OTG cable, the micro USB cable (press enter)
Wait until you see the (UART) message
    "Android Fastboot mode - version x.x."
     Press RETURN or SPACE key to quit."
It can take a while for the fastboot device to come up,
so please wait ~10 seconds.
Then press enter to continue flashing^C
[mpappas@localhost hikey960_prebuilts_release]$ ./flash.sh 
Flash binaries using fastboot

Set jumpers or switches as follows:
Jumper 1-2: Closed	or	Switch	1: On
       3-4: Open	or		2: Off
       5-6: Closed	or		3: On
Press enter to continue

Connect HiKey960 to power up (press enter)
Connect USB OTG cable, the micro USB cable (press enter)
Wait until you see the (UART) message
    "Android Fastboot mode - version x.x."
     Press RETURN or SPACE key to quit."
It can take a while for the fastboot device to come up,
so please wait ~10 seconds.
Then press enter to continue flashing

< waiting for any device >

dmsg:

[249910.495001] usb 1-2: New USB device found, idVendor=18d1, idProduct=d00d, bcdDevice= 1.00
[249910.495011] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[249910.495016] usb 1-2: Product: HiKey960
[249910.495022] usb 1-2: Manufacturer: 96Boards
[249910.495027] usb 1-2: SerialNumber: 2F14006A02516A36

Problem was due to udev rules, flashing works now, thanks.