OE4T / meta-tegra

BSP layer for NVIDIA Jetson platforms, based on L4T
MIT License
413 stars 228 forks source link

cboot 32.6.1 loads incorrect boot slots for kernel and kernel-dtb ? #879

Closed acostach closed 2 years ago

acostach commented 2 years ago

Hi @madisongh , I've previously tried this with L4T 32.5.1 and tegra boot tools and switching the boot with tegra-boot-control -a 1 worked fine, the second partitions (_b) were used for loading the kernel and dtb.

However, I'm now trying with tegra-boot-tools 2.5.2 and it seems that cboot still loads kernel and dtb from slots 0. I've also tried with tegra-boot-tools 2.5.1 and see the same thing.

My usecase is that I'm starting from L4T 32.5.1, update mtd0 with the new 32.6.1 boot blob (which I construct with dd from signed binaries and boots fine), write the kernel and dtb to the kernel_b and kernel-dtb_b and then do: tegra-boot-control -e # ensure redundancy is enabled after writing mtd0 tegra-boot-control -a 1 # switch from slot 0 to slot 1 tegra-boot-control -s # ensure slot 1 is set

I then reboot the device and see that slots kernel and kernel-dtb are loaded. I can confirm this by the kernel cmdline, which should've switched to resin-rootB. After a few minutes, the device starts to reboot and eventually (after 3 attempts that I configured in tegra-boot-tools, was originally 7), it switches to loading the new slots _b.

  [0001.017] I> Welcome to Cboot
��WARNING: no registered clock for FMON_NAFLL_CLUSTER1 (id 281)
fmon_post initialized
��[0001.017] I> Cboot Version: 32.06.01-poky-t194-59698135
[0001.020] I> CPU-BL Params @ 0xf2820000
[0001.024] I>  0) Base:0x00000000 Size:0x00000000
[0001.028] I>  1) Base:0xf1100000 Size:0x00100000
[0001.033] I>  2) Base:0xf2000000 Size:0x00200000
��clk_set_parent failed for clk i2c2, parent pll_aon (-22)
clk_set_parent failed for clk i2c8, parent pll_aon (-22)
clk_dt_late initialized
machine_check initialized
pm_post initialized
dbells initialized
avfs_clk_platform_post initialized
dmce initialized
cvc initialized
ccplex_avfs_hw_init: nafll_cluster0: not monitored
ccplex_avfs_hw_init: nafll_cluster2: not monitored
ccplex_avfs_hw_init: nafll_cluster3: not monitored
avfs_clk_mach_post initialized
regulator_post initialized
rm initialized
sc7_diag initialized
thermal_test initialized
serial_late initialized
clk_post initialized
clk_dt_post initialized
mc_reg initialized
pg_post initialized
dyn_modules initialized
sku_debugfs initialized
speedo_debugfs initialized
adc_debugfs initialized
Failed to register PTO counter for id 281
Failed to register PTO counter for id 281
Failed to register PTO counter for id 281
Failed to register PTO counter for id 281
clk_debugfs initialized
emc_debugfs initialized
dvs_debugfs initialized
fmon_debugfs_init_one: no clock debugfs node to attach FMON_NAFLL_CLUSTER1
fmon_debugfs initialized
vmon_debugfs initialized
pg_debugfs initialized
profile_fs initialized
debugfs_cons initialized
mail_fs initialized
profile initialized
cvc_debugfs initialized
dmce_debugfs initialized
ec_debugfs initialized
rm_rail_debugfs_init: /rm/vdd_cpu: failed
rm_rail_debugfs_init: /rm/vdd_cpu: failed
rm_debugfs initialized
soctherm_debug initialized
gr_reader initialized
mods initialized
dt_fs initialized
debugfs_mrq initialized
debug_mrq initialized
debug_safereg initialized
initializing target
calling apps_init()
starting app shell
entering main console loop
] ��[0001.037] I>  3) Base:0xf1200000 Size:0x00200000
[0001.191] I>  4) Base:0xf1000000 Size:0x00100000
[0001.196] I>  5) Base:0xf0f00000 Size:0x00100000
[0001.200] I>  6) Base:0xf3800000 Size:0x00400000
[0001.205] I>  7) Base:0xf1c00000 Size:0x00400000
[0001.209] I>  8) Base:0xf0e00000 Size:0x00100000
[0001.214] I>  9) Base:0xf0d00000 Size:0x00100000
[0001.218] I> 10) Base:0xf3000000 Size:0x00800000
[0001.223] I> 11) Base:0x40000000 Size:0x00040000
[0001.227] I> 12) Base:0xf0c00000 Size:0x00100000
[0001.231] I> 13) Base:0x40046000 Size:0x00002000
[0001.236] I> 14) Base:0x40048000 Size:0x00002000
[0001.240] I> 15) Base:0xac000000 Size:0x00004000
[0001.245] I> 16) Base:0x4004a000 Size:0x00002000
[0001.249] I> 17) Base:0xf0b00000 Size:0x00100000
[0001.254] I> 18) Base:0x4004c000 Size:0x00002000
[0001.258] I> 19) Base:0xf2200000 Size:0x00600000
[0001.263] I> 20) Base:0x4004e000 Size:0x00002000
[0001.267] I> 21) Base:0xf0ad0000 Size:0x0000c000
[0001.272] I> 22) Base:0x00000000 Size:0x00000000
[0001.276] I> 23) Base:0xf0ae0000 Size:0x00020000
[0001.281] I> 24) Base:0xf6000000 Size:0x02000000
[0001.285] I> 25) Base:0x40050000 Size:0x00002000
[0001.289] I> 26) Base:0x40040000 Size:0x00006000
[0001.294] I> 27) Base:0xf1800000 Size:0x00400000
[0001.298] I> 28) Base:0xf4c00000 Size:0x01400000
[0001.303] I> 29) Base:0xf1400000 Size:0x00400000
[0001.307] I> 30) Base:0x00000000 Size:0x00000000
[0001.312] I> 31) Base:0x00000000 Size:0x00000000
[0001.316] I> 32) Base:0xf8000000 Size:0x08000000
[0001.321] I> 33) Base:0x00000000 Size:0x00000000
[0001.325] I> 34) Base:0xf3c00000 Size:0x01000000
[0001.330] I> 35) Base:0xab000000 Size:0x01000000
[0001.334] I> 36) Base:0xa0000000 Size:0x0b000000
[0001.339] I> 37) Base:0xf2800000 Size:0x00800000
[0001.343] I> 38) Base:0x80000000 Size:0x20000000
[0001.347] I> 39) Base:0xb0000000 Size:0x08000000
[0001.352] I> 40) Base:0x00000000 Size:0x00000000
[0001.356] I> 41) Base:0x00000000 Size:0x00000000
[0001.361] I> 42) Base:0x00000000 Size:0x00000000
[0001.365] I> 43) Base:0x00000000 Size:0x00000000
[0001.370] I> 44) Base:0x00000000 Size:0x00000000
[0001.374] I> 45) Base:0x00000000 Size:0x00000000
[0001.379] GIC-SPI Target CPU: 0
[0001.382] Interrupts Init done
[0001.385] calling constructors
[0001.387] initializing heap
[0001.390] I> Heap: [0xa069cb70 ... 0xab000000]
[0001.394] initializing threads
[0001.397] initializing timers
[0001.400] creating bootstrap completion thread
[0001.404] top of bootstrap2()
[0001.407] CPU: MIDR: 0x4E0F0040, MPIDR: 0x80000000
[0001.412] initializing platform
[0001.415] E> DEVICE_PROD: Invalid value data = 0, size = 0.
[0001.420] W> device prod register failed
[0001.424] I> Bl_dtb @0xaaf00000
[0001.431] W> "plugin-manager" doesn't exist, creating
[0001.432] W> "ids" doesn't exist, creating
[0001.436] W> "connection" doesn't exist, creating
[0001.440] W> "configs" doesn't exist, creating
[0001.453] E> failed to read label property for node 158736: 13
[0001.455] E> failed to read reg property for node 158800: 13
[0001.457] E> failed to read reg property for node 158852: 13
[0001.463] E> failed to read reg property for node 158936: 13
[0001.469] I> Find /i2c@3160000's alias i2c0
[0001.471] I> Reading eeprom i2c=0 address=0x50
[0001.500] I> Device at /i2c@3160000:0x50
[0001.501] I> Reading eeprom i2c=0 address=0x57
[0001.525] I> Device at /i2c@3160000:0x57
[0001.528] I> Find /i2c@c240000's alias i2c1
[0001.528] I> Reading eeprom i2c=1 address=0x50
[0001.530] E> I2C: slave not found in slaves.
[0001.530] E> I2C: Could not write 0 bytes to slave: 0x00a0 with repeat start true.
[0001.531] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.532] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa0 at 0x00000000 via instance 1.
[0001.539] E> eeprom: Retry to read I2C slave device.
[0001.544] E> I2C: slave not found in slaves.
[0001.548] E> I2C: Could not write 0 bytes to slave: 0x00a0 with repeat start true.
[0001.556] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.562] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa0 at 0x00000000 via instance 1.
[0001.571] E> eeprom: Failed to read I2C slave device
[0001.576] I> Eeprom read failed 0x3526070d
[0001.580] I> create_pm_ids: id: 3668-0000-200-J, len: 15
[0001.585] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.596] I> create_pm_ids: id: 3509-0000-100-G, len: 15
[0001.601] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.612] I> Adding plugin-manager/ids/3668-0000-200=/i2c@3160000:module@0x50
[0001.620] W> "i2c@3160000" doesn't exist, creating
[0001.624] W> "module@0x50" doesn't exist, creating
[0001.629] I> Adding plugin-manager/ids/3509-0000-100=/i2c@3160000:module@0x57
[0001.636] W> "module@0x57" doesn't exist, creating
[0001.641] I> Adding plugin-manager/cvm
[0001.644] W> "chip-id" doesn't exist, creating
[0001.648] I> Adding plugin-manager/chip-id/A02P
[0001.653] I> Plugin-manager override starting
[0001.657] I> node /plugin-manager/fragment-pcie-c5-rp matches
[0001.667] I> node /plugin-manager/fragement-tegra-wdt-en matches
[0001.671] I> node /plugin-manager/fragement-tegra-sdhci-emmc-dis matches
[0001.678] I> Disable plugin-manager status in FDT
[0001.679] I> Plugin-manager override finished successfully
[0001.685] I> gpio framework initialized
[0001.689] I> tegrabl_gpio_driver_register: register 'nvidia,tegra194-gpio' driver
[0001.697] I> tegrabl_gpio_driver_register: register 'nvidia,tegra194-gpio-aon' driver
[0001.703] I> tegrabl_tca9539_init: i2c bus: 1, slave addr: 0x46
[0001.710] W> fetch_driver_phandle_from_dt: failed to get node with compatible ti,tca9539
[0001.718] W> fetch_driver_phandle_from_dt: failed to get node with compatible nxp,tca9539
[0001.725] W> tegrabl_tca9539_init: failed to fetch phandle from dt
[0001.731] I> tegrabl_tca9539_init: i2c bus: 1, slave addr: 0x44
[0001.738] W> fetch_driver_phandle_from_dt: failed to get node with compatible ti,tca9539
[0001.746] W> fetch_driver_phandle_from_dt: failed to get node with compatible nxp,tca9539
[0001.753] W> tegrabl_tca9539_init: failed to fetch phandle from dt
[0001.760] I> fixed regulator driver initialized
[0001.768] I> register 'maxim' power off handle
[0001.769] I> virtual i2c enabled
[0001.771] I> registered 'maxim,max20024' pmic
[0001.775] I> tegrabl_gpio_driver_register: register 'max20024-gpio' driver
[0001.782] I> Boot-device: QSPI
[0001.785] I> Boot_device: QSPI_FLASH instance: 0
[0001.790] I> QSPI source rate = 204000 Khz
[0001.793] I> Requested rate for QSPI clock = 34000 Khz
[0001.798] I> BPMP-set rate for QSPI clk = 34000 Khz
[0001.803] I> QSPI Flash Size = 32 MB
[0001.811] I> Qspi initialized successfully
[0001.811] I> qspi flash-0 params source = boot args
[0001.815] I> create_pm_ids: id: 3668-0000-200-J, len: 15
[0001.820] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.831] I> create_pm_ids: id: 3509-0000-100-G, len: 15
[0001.836] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.847] I> Found sdcard
[0001.852] I> enabling 'vdd-sdmmc1-sw' regulator
[0001.858] I> regulator 'vdd-sdmmc1-sw' already enabled
[0002.103] I> sdmmc SDR mode
[0002.117] I> -0 params source = 
[0002.119] I> Found 47 partitions in QSPI_FLASH (instance 0)
[0002.131] I> Found 13 partitions in SDCARD (instance 0)
[0002.138] I> regulator 'vdd-hdmi-5v0' already enabled
[0002.141] I> regulator 'vdd-hdmi-5v0' already enabled
[0002.142] E> tegrabl_display_init_regulator: hdmi cable is not connected
[0002.142] E> tegrabl_display_get_pdata, failed to parse dtb settings
[0002.145] E> invalid display type
[0002.146] E> cannot find any other nvdisp nodes
[0002.147] E> no valid display unit config found in dtb
[0002.149] W> display init failed
[0002.151] I> Load in CBoot Boot Options partition and parse it
[0002.157] I> Active slot suffix: _b <-- apparently suffix _b partitions should be loaded
[0002.160] E> Error -9 when finding node with path /boot-configuration
[0002.166] E> tegrabl_cbo_parse_info: "boot-configuration" not found in CBO file.
[0002.173] I> Using default boot order
[0002.177] I> boot-dev-order :-
[0002.180] I> 1.sd
[0002.182] I> 2.usb
[0002.183] I> 3.nvme
[0002.185] I> 4.emmc
[0002.187] I> 5.net
[0002.189] I> Hit any key to stop autoboot:     4       3       2       1
[0004.197] initializing target
[0004.197] calling apps_init()
[0004.198] starting app kernel_boot_app
[0004.208] I> found decompressor handler: lz4-legacy
[0004.209] I> decompressing BMP_b blob ... <----
[0004.220] I> Kernel type = Normal
[0004.220] I> ########## SD (0) boot ##########
[0004.220] I> Found sdcard
[0004.222] I> regulator 'vdd-sdmmc1-sw' already enabled
[0004.226] I> regulator 'vdd-sdmmc1-sw' already enabled
[0004.261] I> sdmmc SDR mode
[0004.275] I> -0 params source = 
[0004.276] I> Already published: 00060000
[0004.276] I> Look for boot partition
[0004.276] I> Fallback: assuming 0th partition is boot partition
[0004.277] I> Detect filesystem
[0004.281] I> fs_detect:173: Unsupported or no filesystem present
[0004.282] I> Loading kernel-bootctrl from partition
[0004.282] I> Loading partition kernel-bootctrl at 0xa42e0000 from device(0x6)
[0004.310] W> tegrabl_get_kernel_bootctrl: magic number(0x00000000) is invalid
[0004.311] W> tegrabl_get_kernel_bootctrl: use default dummy boot control data <-- is it because of this?
[0004.311] I> Loading kernel ...
[0009.751] I> Loading kernel-dtb ...
[0009.797] I> Validate kernel ...
[0009.797] I> T19x: Authenticate kernel (bin_type: 37), max size 0x5000000
[0010.407] I> Encryption fuse is not ON
[0010.422] I> Validate kernel-dtb ...
[0010.422] I> T19x: Authenticate kernel-dtb (bin_type: 38), max size 0x400000
[0010.428] I> Encryption fuse is not ON
[0010.428] I> Checking boot.img header magic ... [0010.429] I> [OK]
[0010.429] I> Kernel hdr @0xa42e0000
[0010.429] I> Kernel dtb @0x90000000
[0010.429] I> decompressor handler not found
[0010.430] I> Copying kernel image (40108040 bytes) from 0xa42e0800 to 0x80080000 ... [0010.441] I> Done
[0010.442] I> Move ramdisk (len: 0) from 0xa6921000 to 0x91000000
[0010.443] I> Updated bpmp info to DTB
[0010.447] I> Ramdisk: Base: 0x91000000; Size: 0x0
[0010.451] I> Updated initrd info to DTB
[0010.454] I> Active rootfs suffix: 
[0010.458] E> tegrabl_linuxboot_add_disp_param, du 0 failed to get display params
[0010.465] E> tegrabl_linuxboot_add_disp_param, du 0 failed to get display params
[0010.472] E> tegrabl_linuxboot_add_disp_param, du 0 failed to get display params
[0010.479] I> Active slot suffix: _b
[0010.483] I> add_boot_slot_suffix: slot_suffix = _b
[0010.488] I> Linux Cmdline: console=ttyTCU0,115200 root=LABEL=resin-rootA ro rootwait rootfstype=ext4 console=ttyTCU0,115200 console=tty0 fb  <-- should have been resin-rootB, which is contained by kernel-dtb-b
[0010.526] I> Updated bootarg info to DTB

I see this log here: '[0004.311] W> tegrabl_get_kernel_bootctrl: use default dummy boot control data' which I suspect might be causing this. How can I prevent it, maybe I can patch cboot to get around this? Thank you!

acostach commented 2 years ago

Forgot to mention, I'm checking on the Xavier NX Devkit SD-CARD.

madisongh commented 2 years ago

Hmm. Looks like I forgot to carry forward the patch to the SD/USB boot code to enable A/B slot selection.

acostach commented 2 years ago

Ok, so that would be only for SD I guess, I haven't tried the eMMC variant yet but it's probably best if l try with the patch applied.

madisongh commented 2 years ago

I've pushed updates to the master and honister branches to fix this. I'll follow with an update to the dunfell branch after running a couple more tests.

madisongh commented 2 years ago

OK, the missing patches are restored for the cboot-t19x recipe in all of the R32.6.1 branches now.

acostach commented 2 years ago

Thank you @madisongh and sorry for my late reply. I've tested the new patches on the honister branch 2ec80cc94bcd7428c80f505467be2f50ec3d64bd and it seems that I'm still running into this problem. The slot suffix can't be read by the code added in the new patches for some reason, but cboot is aware of the selected slot:

[0004.276] I> fs_detect:173: Unsupported or no filesystem present
[0004.276] I> Loading kernel-bootctrl from partition
[0004.276] I> Loading partition kernel-bootctrl at 0xa42e0000 from device(0x6)
[0004.305] W> tegrabl_get_kernel_bootctrl: magic number(0x00000000) is invalid
[0004.306] W> tegrabl_get_kernel_bootctrl: use default dummy boot control data
[0004.306] I> Active slot suffix: _b <---
[0004.306] W> Could not obtain bootslot suffix[0004.307] I> Loading kernel ... <--- Could not obtain bootslot suffix
[0009.750] I> Loading kernel-dtb ...

After setting the new active slot with tegra-boot-control I reboot the device and I don't touch the mtd0 partition in any way. Am I doing something wrong?

Full log:

parent failed for clk i2c2, parent pll_aon (-22)
clk_set_parent failed for clk i2c8, parent pll_aon (-22)
clk_dt_late initialized
machine_check initialized
pm_post initialized
dbells initialized
avfs_clk_platform_post initialized
dmce initialized
cvc initialized
ccplex_avfs_hw_init: nafll_cluster0: not monitored
ccplex_avfs_hw_init: nafll_cluster2: not monitored
ccplex_avfs_hw_init: nafll_cluster3: not monitored
avfs_clk_mach_post initialized
regulator_post initialized
rm initialized
sc7_diag initialized
thermal_test initialized
serial_late initialized
clk_post initialized
clk_dt_post initialized
mc_reg initialized
pg_post initialized
dyn_modules initialized
sku_debugfs initialized
speedo_debugfs initialized
adc_debugfs initialized
Failed to register PTO counter for id 281
Failed to register PTO counter for id 281
Failed to register PTO counter for id 281
Failed to register PTO counter for id 281
clk_debugfs initialized
emc_debugfs initialized
dvs_debugfs initialized
fmon_debugfs_init_one: no clock debugfs node to attach FMON_NAFLL_CLUSTER1
fmon_debugfs initialized
vmon_debugfs initialized
pg_debugfs initialized
profile_fs initialized
debugfs_cons initialized
mail_fs initialized
profile initialized
cvc_debugfs initialized
dmce_debugfs initialized
ec_debugfs initialized
rm_rail_debugfs_init: /rm/vdd_cpu: failed
rm_rail_debugfs_init: /rm/vdd_cpu: failed
rm_debugfs initialized
soctherm_debug initialized
gr_reader initialized
mods initialized
dt_fs initialized
debugfs_mrq initialized
debug_mrq initialized
debug_safereg initialized
initializing target
calling apps_init()
starting app shell
entering main console loop
] ��[0001.033] I>  2) Base:0xf2000000 Size:0x00200000
[0001.187] I>  3) Base:0xf1200000 Size:0x00200000
[0001.191] I>  4) Base:0xf1000000 Size:0x00100000
[0001.196] I>  5) Base:0xf0f00000 Size:0x00100000
[0001.200] I>  6) Base:0xf3800000 Size:0x00400000
[0001.205] I>  7) Base:0xf1c00000 Size:0x00400000
[0001.209] I>  8) Base:0xf0e00000 Size:0x00100000
[0001.214] I>  9) Base:0xf0d00000 Size:0x00100000
[0001.218] I> 10) Base:0xf3000000 Size:0x00800000
[0001.223] I> 11) Base:0x40000000 Size:0x00040000
[0001.227] I> 12) Base:0xf0c00000 Size:0x00100000
[0001.232] I> 13) Base:0x40046000 Size:0x00002000
[0001.236] I> 14) Base:0x40048000 Size:0x00002000
[0001.240] I> 15) Base:0xac000000 Size:0x00004000
[0001.245] I> 16) Base:0x4004a000 Size:0x00002000
[0001.249] I> 17) Base:0xf0b00000 Size:0x00100000
[0001.254] I> 18) Base:0x4004c000 Size:0x00002000
[0001.258] I> 19) Base:0xf2200000 Size:0x00600000
[0001.263] I> 20) Base:0x4004e000 Size:0x00002000
[0001.267] I> 21) Base:0xf0ad0000 Size:0x0000c000
[0001.272] I> 22) Base:0x00000000 Size:0x00000000
[0001.276] I> 23) Base:0xf0ae0000 Size:0x00020000
[0001.281] I> 24) Base:0xf6000000 Size:0x02000000
[0001.285] I> 25) Base:0x40050000 Size:0x00002000
[0001.290] I> 26) Base:0x40040000 Size:0x00006000
[0001.294] I> 27) Base:0xf1800000 Size:0x00400000
[0001.298] I> 28) Base:0xf4c00000 Size:0x01400000
[0001.303] I> 29) Base:0xf1400000 Size:0x00400000
[0001.307] I> 30) Base:0x00000000 Size:0x00000000
[0001.312] I> 31) Base:0x00000000 Size:0x00000000
[0001.316] I> 32) Base:0xf8000000 Size:0x08000000
[0001.321] I> 33) Base:0x00000000 Size:0x00000000
[0001.325] I> 34) Base:0xf3c00000 Size:0x01000000
[0001.330] I> 35) Base:0xab000000 Size:0x01000000
[0001.334] I> 36) Base:0xa0000000 Size:0x0b000000
[0001.339] I> 37) Base:0xf2800000 Size:0x00800000
[0001.343] I> 38) Base:0x80000000 Size:0x20000000
[0001.348] I> 39) Base:0xb0000000 Size:0x08000000
[0001.352] I> 40) Base:0x00000000 Size:0x00000000
[0001.356] I> 41) Base:0x00000000 Size:0x00000000
[0001.361] I> 42) Base:0x00000000 Size:0x00000000
[0001.365] I> 43) Base:0x00000000 Size:0x00000000
[0001.370] I> 44) Base:0x00000000 Size:0x00000000
[0001.374] I> 45) Base:0x00000000 Size:0x00000000
[0001.379] GIC-SPI Target CPU: 0
[0001.382] Interrupts Init done
[0001.385] calling constructors
[0001.388] initializing heap
[0001.390] I> Heap: [0xa069cb70 ... 0xab000000]
[0001.394] initializing threads
[0001.397] initializing timers
[0001.400] creating bootstrap completion thread
[0001.404] top of bootstrap2()
[0001.407] CPU: MIDR: 0x4E0F0040, MPIDR: 0x80000000
[0001.412] initializing platform
[0001.415] E> DEVICE_PROD: Invalid value data = 0, size = 0.
[0001.420] W> device prod register failed
[0001.424] I> Bl_dtb @0xaaf00000
[0001.431] W> "plugin-manager" doesn't exist, creating
[0001.432] W> "ids" doesn't exist, creating
[0001.436] W> "connection" doesn't exist, creating
[0001.440] W> "configs" doesn't exist, creating
[0001.451] E> failed to read label property for node 158736: 13
[0001.453] E> failed to read reg property for node 158800: 13
[0001.457] E> failed to read reg property for node 158852: 13
[0001.463] E> failed to read reg property for node 158936: 13
[0001.469] I> Find /i2c@3160000's alias i2c0
[0001.471] I> Reading eeprom i2c=0 address=0x50
[0001.500] I> Device at /i2c@3160000:0x50
[0001.501] I> Reading eeprom i2c=0 address=0x57
[0001.525] I> Device at /i2c@3160000:0x57
[0001.527] I> Find /i2c@c240000's alias i2c1
[0001.527] I> Reading eeprom i2c=1 address=0x50
[0001.529] E> I2C: slave not found in slaves.
[0001.530] E> I2C: Could not write 0 bytes to slave: 0x00a0 with repeat start true.
[0001.531] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.531] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa0 at 0x00000000 via instance 1.
[0001.539] E> eeprom: Retry to read I2C slave device.
[0001.544] E> I2C: slave not found in slaves.
[0001.548] E> I2C: Could not write 0 bytes to slave: 0x00a0 with repeat start true.
[0001.556] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.562] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa0 at 0x00000000 via instance 1.
[0001.571] E> eeprom: Failed to read I2C slave device
[0001.576] I> Eeprom read failed 0x3526070d
[0001.580] I> create_pm_ids: id: 3668-0000-200-J, len: 15
[0001.585] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.596] I> create_pm_ids: id: 3509-0000-100-G, len: 15
[0001.601] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.612] I> Adding plugin-manager/ids/3668-0000-200=/i2c@3160000:module@0x50
[0001.620] W> "i2c@3160000" doesn't exist, creating
[0001.624] W> "module@0x50" doesn't exist, creating
[0001.629] I> Adding plugin-manager/ids/3509-0000-100=/i2c@3160000:module@0x57
[0001.636] W> "module@0x57" doesn't exist, creating
[0001.641] I> Adding plugin-manager/cvm
[0001.644] W> "chip-id" doesn't exist, creating
[0001.648] I> Adding plugin-manager/chip-id/A02P
[0001.653] I> Plugin-manager override starting
[0001.657] I> node /plugin-manager/fragment-pcie-c5-rp matches
[0001.665] I> node /plugin-manager/fragement-tegra-wdt-en matches
[0001.671] I> node /plugin-manager/fragement-tegra-sdhci-emmc-dis matches
[0001.677] I> Disable plugin-manager status in FDT
[0001.679] I> Plugin-manager override finished successfully
[0001.685] I> gpio framework initialized
[0001.689] I> tegrabl_gpio_driver_register: register 'nvidia,tegra194-gpio' driver
[0001.696] I> tegrabl_gpio_driver_register: register 'nvidia,tegra194-gpio-aon' driver
[0001.703] I> tegrabl_tca9539_init: i2c bus: 1, slave addr: 0x46
[0001.710] W> fetch_driver_phandle_from_dt: failed to get node with compatible ti,tca9539
[0001.718] W> fetch_driver_phandle_from_dt: failed to get node with compatible nxp,tca9539
[0001.725] W> tegrabl_tca9539_init: failed to fetch phandle from dt
[0001.731] I> tegrabl_tca9539_init: i2c bus: 1, slave addr: 0x44
[0001.738] W> fetch_driver_phandle_from_dt: failed to get node with compatible ti,tca9539
[0001.746] W> fetch_driver_phandle_from_dt: failed to get node with compatible nxp,tca9539
[0001.753] W> tegrabl_tca9539_init: failed to fetch phandle from dt
[0001.760] I> fixed regulator driver initialized
[0001.767] I> register 'maxim' power off handle
[0001.768] I> virtual i2c enabled
[0001.771] I> registered 'maxim,max20024' pmic
[0001.775] I> tegrabl_gpio_driver_register: register 'max20024-gpio' driver
[0001.782] I> Boot-device: QSPI
[0001.785] I> Boot_device: QSPI_FLASH instance: 0
[0001.790] I> QSPI source rate = 204000 Khz
[0001.793] I> Requested rate for QSPI clock = 34000 Khz
[0001.798] I> BPMP-set rate for QSPI clk = 34000 Khz
[0001.803] I> QSPI Flash Size = 32 MB
[0001.811] I> Qspi initialized successfully
[0001.811] I> qspi flash-0 params source = boot args
[0001.815] I> create_pm_ids: id: 3668-0000-200-J, len: 15
[0001.820] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.831] I> create_pm_ids: id: 3509-0000-100-G, len: 15
[0001.836] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.847] I> Found sdcard
[0001.851] I> enabling 'vdd-sdmmc1-sw' regulator
[0001.857] I> regulator 'vdd-sdmmc1-sw' already enabled
[0002.099] I> sdmmc SDR mode
[0002.113] I> -0 params source = 
[0002.115] I> Found 47 partitions in QSPI_FLASH (instance 0)
[0002.127] I> Found 13 partitions in SDCARD (instance 0)
[0002.133] I> regulator 'vdd-hdmi-5v0' already enabled
[0002.136] I> regulator 'vdd-hdmi-5v0' already enabled
[0002.137] E> tegrabl_display_init_regulator: hdmi cable is not connected
[0002.137] E> tegrabl_display_get_pdata, failed to parse dtb settings
[0002.140] E> invalid display type
[0002.141] E> cannot find any other nvdisp nodes
[0002.141] E> no valid display unit config found in dtb
[0002.144] W> display init failed
[0002.146] I> Load in CBoot Boot Options partition and parse it
[0002.152] I> Active slot suffix: _b
[0002.156] E> Error -9 when finding node with path /boot-configuration
[0002.161] E> tegrabl_cbo_parse_info: "boot-configuration" not found in CBO file.
[0002.169] I> Using default boot order
[0002.172] I> boot-dev-order :-
[0002.175] I> 1.sd
[0002.177] I> 2.usb
[0002.179] I> 3.nvme
[0002.181] I> 4.emmc
[0002.183] I> 5.net
[0002.184] I> Hit any key to stop autoboot:     4       3       2       1
[0004.192] initializing target
[0004.192] calling apps_init()
[0004.193] starting app kernel_boot_app
[0004.203] I> found decompressor handler: lz4-legacy
[0004.204] I> decompressing BMP_b blob ...
[0004.215] I> Kernel type = Normal
[0004.215] I> ########## SD (0) boot ##########
[0004.216] I> Found sdcard
[0004.217] I> regulator 'vdd-sdmmc1-sw' already enabled
[0004.220] I> regulator 'vdd-sdmmc1-sw' already enabled
[0004.255] I> sdmmc SDR mode
[0004.270] I> -0 params source = 
[0004.270] I> Already published: 00060000
[0004.270] I> Look for boot partition
[0004.271] I> Fallback: assuming 0th partition is boot partition
[0004.271] I> Detect filesystem
[0004.276] I> fs_detect:173: Unsupported or no filesystem present
[0004.276] I> Loading kernel-bootctrl from partition
[0004.276] I> Loading partition kernel-bootctrl at 0xa42e0000 from device(0x6)
[0004.305] W> tegrabl_get_kernel_bootctrl: magic number(0x00000000) is invalid
[0004.306] W> tegrabl_get_kernel_bootctrl: use default dummy boot control data
[0004.306] I> Active slot suffix: _b
[0004.306] W> Could not obtain bootslot suffix[0004.307] I> Loading kernel ...
[0009.750] I> Loading kernel-dtb ...
[0009.795] I> Validate kernel ...
[0009.796] I> T19x: Authenticate kernel (bin_type: 37), max size 0x5000000
[0010.406] I> Encryption fuse is not ON
[0010.423] I> Validate kernel-dtb ...
[0010.423] I> T19x: Authenticate kernel-dtb (bin_type: 38), max size 0x400000
[0010.429] I> Encryption fuse is not ON
[0010.430] I> Checking boot.img header magic ... [0010.430] I> [OK]
[0010.430] I> Kernel hdr @0xa42e0000
[0010.430] I> Kernel dtb @0x90000000
[0010.431] I> decompressor handler not found
[0010.431] I> Copying kernel image (40108040 bytes) from 0xa42e0800 to 0x80080000 ... [0010.446] I> Done
[0010.446] I> Move ramdisk (len: 0) from 0xa6921000 to 0x91000000
[0010.447] I> Updated bpmp info to DTB
[0010.448] I> Ramdisk: Base: 0x91000000; Size: 0x0
[0010.452] I> Updated initrd info to DTB
[0010.455] I> Active rootfs suffix: 
[0010.459] E> tegrabl_linuxboot_add_disp_param, du 0 failed to get display params
[0010.466] E> tegrabl_linuxboot_add_disp_param, du 0 failed to get display params
[0010.473] E> tegrabl_linuxboot_add_disp_param, du 0 failed to get display params
[0010.481] I> Active slot suffix: _b
[0010.484] I> add_boot_slot_suffix: slot_suffix = _b
[0010.489] I> Linux Cmdline: console=ttyTCU0,115200 root=LABEL=resin-rootA ro rootwait rootfstype=ext4 console=ttyTCU0,115200 console=tty0 fb 
[0010.528] I> Updated bootarg info to DTB
[0010.531] W> MAC addr invalid!
[0010.534] E> Failed to get WIFI MAC address
[0010.538] W> MAC addr invalid!
[0010.541] E> Failed to get Bluetooth MAC address
[0010.546] I> eeprom_get_mac_addr: MAC (type: 2): 48:b0:2d:15:dc:6c
[0010.552] W> "plugin-manager" doesn't exist, creating
[0010.557] I> Adding /chosen/plugin-manager/cvm
[0010.561] W> "chip-id" doesn't exist, creating
[0010.565] I> Adding /chosen/plugin-manager/chip-id
[0010.570] W> "configs" doesn't exist, creating
[0010.574] I> Adding /chosen/plugin-manager/configs
[0010.579] W> "ids" doesn't exist, creating
[0010.583] I> Adding /chosen/plugin-manager/ids
[0010.587] W> "odm-data" doesn't exist, creating
[0010.591] I> Adding /chosen/plugin-manager/odm-data
[0010.599] W> "memory" doesn't exist, creating
[0010.601] I> [0] START: 0x80000000, END: 0xac000000
[0010.605] I> [1] START: 0xac004000, END: 0xf0ad0000
[0010.610] I> [2] START: 0xf0adc000, END: 0xf0ae0000
[0010.615] I> dram_block larger than 80000000
[0010.619] I> [3] START: 0x100000000, END: 0x280000000
[0010.624] I> added [base:0x80000000, size:0x2c000000] to /memory
[0010.629] I> added [base:0xac200000, size:0x44800000] to /memory
[0010.635] I> added [base:0x100000000, size:0x180000000] to /memory
[0010.642] I> Updated memory info to DTB
[0010.645] E> add_disp_param: failed to get display params for du=0
[0010.651] W> "reset" doesn't exist, creating
[0010.656] I> Adding ecid(00000001647147031400000019030240) to DT
[0010.661] I> NVG: Logical CPU: 0; MPIDR: 0x80000000
[0010.666] I> NVG: Logical CPU: 1; MPIDR: 0x80000001
[0010.670] I> NVG: Logical CPU: 2; MPIDR: 0x80000100
[0010.675] I> NVG: Logical CPU: 3; MPIDR: 0x80000101
[0010.680] I> NVG: Logical CPU: 4; MPIDR: 0x80000200
[0010.685] I> NVG: Logical CPU: 5; MPIDR: 0x80000201
[0010.689] I> Deleted cpu@6 node in DT
[0010.693] I> Deleted cpu@7 node in DT
[0010.696] I> Deleted cluster3 node in FDT
[0010.700] I> Update arm-pmu in FDT
[0010.703] I> - update property: interrupts
[0010.707] I> - update property: interrupt-affinity
[0010.713] W> "misc-data" doesn't exist, creating
[0010.717] I> Boot-device: QSPI
[0010.719] W> Unknown boot device
[0010.722] I> Add storage-qspi to plugin-manager/misc-data
[0010.728] W> Unknown storage device
[0010.731] I> Add serial number:1423220028426 as DT property
[0010.737] I> Plugin-manager override starting
[0010.741] I> node /plugin-manager/fragment-pcie-c5-rp matches
[0010.747] I> node /plugin-manager/fragement-tegra-wdt-en matches
[0010.754] I> node /plugin-manager/fragement-tegra-sdhci-emmc-dis matches
[0010.761] I> Disable plugin-manager status in FDT
[0010.763] I> Plugin-manager override finished successfully
[0010.769] I> tegrabl_load_kernel_and_dtb: Done
[0010.773] I> SMD partition is updated.
[0010.776] I> QSPI: erasing sectors from 177 - 177
[0010.781] I> QSPI: recoverying tail blocks from 22664 - 22784
[0011.480] I> QSPI: erasing sectors from 176 - 176
[0011.481] I> QSPI: recoverying tail blocks from 22536 - 22656
[0012.154] E> tegrabl_display_clear: display is not initialized
[0012.155] W> Boot logo display failed...
[0012.155] I> Kernel EP: 0x80080000, DTB: 0x90000000

Thank you

madisongh commented 2 years ago

Oops, it looks like I got the logic reversed when checking the return code from the function that gets the bootslot suffix. I'll update the patch to fix it.

madisongh commented 2 years ago

@acostach I've pushed the updated patch, which I've tested on my NX devkit and appears to be working better. Give it a try and let me know how it goes.

acostach commented 2 years ago

Thank you! I'll test now and let you know

acostach commented 2 years ago

Thanks again @madisongh , with the latest patches it worked and rolled back to slot _a.

acostach commented 2 years ago

Hi @madisongh , for the Xaviers NX SD and eMMC the process went fine, the system booted from the previous slot after X unsuccessful attempts. However, on the TX2 I'm seeing a different problem: booting forward from 32.5.1 to 32.6.1 there is no issue, second slot is used and all is loaded fine. However, if there are some unsuccessful attempts and slot 0 is picked for booting, I'm getting:

[0002.006] C> MTS error (4) : Unknown or unhandled failure
[0002.011] C> cpu way point1 failed
[0002.014] C> ERROR: Highest Layer Module = 0x32, Lowest Layer Module = 0x32,
Aux Info = 0x2, Reason = 0x6

I suspect this happens because the new contents of mmcblk0boot0 (which now contains 32.6.1 binaries) don't like the 32.5.1 binaries on the old slot 0 in the raw mmcblk0pX partitions, and this so far happens only on the TX2 .

If this is the case, do the tools you wrote in tegra-boot-tools accept creating a bup and updating /dev/mmcblk0boot0 slot contents only, from a custom flash.xml and signed binaries that were already generated at build-time? Or maybe from a any valid boot0.img that would be stored on mmcblk0boot0?

Thank you!

madisongh commented 2 years ago

I think it's because the USB firmware is signed in 32.6.1 where it wasn't in 32.5.1 (module 0x32 is related to USB PHY, from what I see in the cboot sources), although I could be wrong about the specifics.

An update to a new version of the BSP that has changes like these needs careful handling. You perhaps could use tegra-bootloader-update --slot_suffix _a (or _b - whichever slot is not the current one) after successfully booting with the update to write the update to the other slot using the bl_only.bup_payload to just write the boot firmware and not the kernel... I'm just not 100% sure the 32.5.1-based kernel will be compatible with the 32.6.1 boot firmware. You could test it to see if it's sufficiently compatible for your use case. Otherwise, it might be safer to just trigger a second full update (boot + kernel + rootfs) after you successfully complete the first one, so both slots will be fully compatible.

acostach commented 2 years ago

I see, thanks Matt. Unfortunately on the TX2 the 32.6.1 boot firmware won't load 32.5.1 bootloader (above error) and it doesn't work the other way around either, 32.5.1 boot firmware doesn't load the newer 32.6.1 bootloader due to the same error.

Best approach I see for now on the TX2 is to fallback to loading new boot firmware & new bootloader + old kernel & old rootfs in case of failure and then re-write the old boot firmware to restore to 32.5.1, like we did so far.

acostach commented 2 years ago

Sorry to bother again @madisongh , I was testing the fallback on Xavier AGX (boot from eMMC) and it works fine between 32.6.1 and 32.6.1, however from 32.6.1 to 32.5.1 it doesn't appear to work (i.e started from 32.5.1, updated to 32.6.1 but failed to boot in 32.6.1 enough times so fallback to loading 32.5.1 dtb and kernel). It looks like after the retries number is reached, the bootloaders enter recovery mode.

Although cboot 32.6.1 is loaded on the last attempt, it goes trough #### Fixed storage boot ####, and fixed_boot.c doesn't seem to have the A/B patches that removable_boot.c has.

This is the log from the last failed attempt:

��
  ��mrq initialized
��[0001.077] I> Welcome to Cboot
��fmon_post initialized
��[0001.078] I> Cboot Version: 32.06.01-poky-t194-dc175a98
[0001.078] I> CPU-BL Params @ 0xf2820000
[0001.079] I>  0) Base:0x00000000 Size:0x00000000
[0001.084] I>  1) Base:0xf1100000 Size:0x00100000
[0001.088] I>  2) Base:0xf2000000 Size:0x00200000
[0001.093] I>  3) Base:0xf1200000 Size:0x00200000
��clk_set_parent failed for clk i2c2, parent pll_aon (-22)
clk_set_parent failed for clk i2c8, parent pll_aon (-22)
clk_dt_late initialized
machine_check initialized
pm_post initialized
dbells initialized
avfs_clk_platform_post initialized
dmce initialized
cvc initialized
ccplex_avfs_hw_init: nafll_cluster0: not monitored
ccplex_avfs_hw_init: nafll_cluster1: not monitored
ccplex_avfs_hw_init: nafll_cluster2: not monitored
ccplex_avfs_hw_init: nafll_cluster3: not monitored
avfs_clk_mach_post initialized
regulator_post initialized
rm initialized
sc7_diag initialized
thermal_test initialized
serial_late initialized
clk_post initialized
clk_dt_post initialized
mc_reg initialized
pg_post initialized
dyn_modules initialized
sku_debugfs initialized
speedo_debugfs initialized
adc_debugfs initialized
clk_debugfs initialized
��[0001.097] I>  4) Base:0xf1000000 Size:0x00100000
[0001.176] I>  5) Base:0xf0f00000 Size:0x00100000
[0001.181] I>  6) Base:0xf3800000 Size:0x00400000
[0001.185] I>  7) Base:0xf1c00000 Size:0x00400000
[0001.190] I>  8) Base:0xf0e00000 Size:0x00100000
[0001.194] I>  9) Base:0xf0d00000 Size:0x00100000
[0001.199] I> 10) Base:0xf3000000 Size:0x00800000
[0001.203] I> 11) Base:0x40000000 Size:0x00040000
[0001.208] I> 12) Base:0xf0c00000 Size:0x00100000
[0001.212] I> 13) Base:0x40046000 Size:0x00002000
[0001.217] I> 14) Base:0x40048000 Size:0x00002000
��emc_debugfs initialized
dvs_debugfs initialized
fmon_debugfs initialized
vmon_debugfs initialized
pg_debugfs initialized
profile_fs initialized
debugfs_cons initialized
mail_fs initialized
profile initialized
cvc_debugfs initialized
dmce_debugfs initialized
ec_debugfs initialized
rm_debugfs initialized
soctherm_debug initialized
gr_reader initialized
mods initialized
dt_fs initialized
debugfs_mrq initialized
debug_mrq initialized
debug_safereg initialized
initializing target
calling apps_init()
starting app shell
entering main console loop
] ��[0001.221] I> 15) Base:0xac000000 Size:0x00004000
[0001.276] I> 16) Base:0x4004a000 Size:0x00002000
[0001.280] I> 17) Base:0xf0b00000 Size:0x00100000
[0001.285] I> 18) Base:0x4004c000 Size:0x00002000
[0001.289] I> 19) Base:0xf2200000 Size:0x00600000
[0001.294] I> 20) Base:0x4004e000 Size:0x00002000
[0001.298] I> 21) Base:0xf0ad0000 Size:0x0000c000
[0001.303] I> 22) Base:0x00000000 Size:0x00000000
[0001.307] I> 23) Base:0xf0ae0000 Size:0x00020000
[0001.312] I> 24) Base:0xf6000000 Size:0x02000000
[0001.316] I> 25) Base:0x40050000 Size:0x00002000
[0001.321] I> 26) Base:0x40040000 Size:0x00006000
[0001.325] I> 27) Base:0xf1800000 Size:0x00400000
[0001.330] I> 28) Base:0xf4c00000 Size:0x01400000
[0001.334] I> 29) Base:0xf1400000 Size:0x00400000
[0001.338] I> 30) Base:0x00000000 Size:0x00000000
[0001.343] I> 31) Base:0x00000000 Size:0x00000000
[0001.347] I> 32) Base:0xf8000000 Size:0x08000000
[0001.352] I> 33) Base:0x00000000 Size:0x00000000
[0001.356] I> 34) Base:0xf3c00000 Size:0x01000000
[0001.361] I> 35) Base:0xab000000 Size:0x01000000
[0001.365] I> 36) Base:0xa0000000 Size:0x0b000000
[0001.370] I> 37) Base:0xf2800000 Size:0x00800000
[0001.374] I> 38) Base:0x80000000 Size:0x20000000
[0001.379] I> 39) Base:0xb0000000 Size:0x08000000
[0001.383] I> 40) Base:0x00000000 Size:0x00000000
[0001.388] I> 41) Base:0x00000000 Size:0x00000000
[0001.392] I> 42) Base:0x00000000 Size:0x00000000
[0001.396] I> 43) Base:0x00000000 Size:0x00000000
[0001.401] I> 44) Base:0x00000000 Size:0x00000000
[0001.405] I> 45) Base:0x00000000 Size:0x00000000
[0001.410] GIC-SPI Target CPU: 0
[0001.413] Interrupts Init done
[0001.416] calling constructors
[0001.419] initializing heap
[0001.421] I> Heap: [0xa069cb70 ... 0xab000000]
[0001.425] initializing threads
[0001.428] initializing timers
[0001.431] creating bootstrap completion thread
[0001.435] top of bootstrap2()
[0001.438] CPU: MIDR: 0x4E0F0040, MPIDR: 0x80000000
[0001.443] initializing platform
[0001.446] E> DEVICE_PROD: Invalid value data = 0, size = 0.
[0001.451] W> device prod register failed
[0001.455] I> Bl_dtb @0xaaf00000
[0001.464] W> "plugin-manager" doesn't exist, creating
[0001.465] W> "ids" doesn't exist, creating
[0001.467] W> "connection" doesn't exist, creating
[0001.472] W> "configs" doesn't exist, creating
[0001.487] E> failed to read label property for node 227160: 13
[0001.490] E> failed to read reg property for node 227248: 13
[0001.493] E> failed to read label property for node 227300: 13
[0001.495] E> failed to read label property for node 227368: 13
[0001.500] E> failed to read label property for node 227404: 13
[0001.505] E> failed to read label property for node 227440: 13
[0001.511] E> failed to read reg property for node 227508: 13
[0001.516] E> failed to read label property for node 227560: 13
[0001.523] I> Find /i2c@3160000's alias i2c0
[0001.525] I> Reading eeprom i2c=0 address=0x50
[0001.554] I> Device at /i2c@3160000:0x50
[0001.555] I> Reading eeprom i2c=0 address=0x56
[0001.579] I> Device at /i2c@3160000:0x56
[0001.581] I> Find /i2c@3180000's alias i2c2
[0001.581] I> Reading eeprom i2c=2 address=0x54
[0001.583] E> I2C: slave not found in slaves.
[0001.583] E> I2C: Could not write 0 bytes to slave: 0x00a8 with repeat start true.
[0001.584] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.584] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa8 at 0x00000000 via instance 2.
[0001.593] E> eeprom: Failed to read I2C slave device
[0001.598] I> Eeprom read failed 0x3526070d
[0001.602] I> Reading eeprom i2c=2 address=0x57
[0001.606] E> I2C: slave not found in slaves.
[0001.610] E> I2C: Could not write 0 bytes to slave: 0x00ae with repeat start true.
[0001.618] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.624] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xae at 0x00000000 via instance 2.
[0001.633] E> eeprom: Failed to read I2C slave device
[0001.638] I> Eeprom read failed 0x3526070d
[0001.642] I> Reading eeprom i2c=2 address=0x52
[0001.646] E> I2C: slave not found in slaves.
[0001.650] E> I2C: Could not write 0 bytes to slave: 0x00a4 with repeat start true.
[0001.658] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.664] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa4 at 0x00000000 via instance 2.
[0001.673] E> eeprom: Failed to read I2C slave device
[0001.678] I> Eeprom read failed 0x3526070d
[0001.683] I> Find /i2c@c240000's alias i2c1
[0001.686] I> Reading eeprom i2c=1 address=0x52
[0001.692] E> I2C: slave not found in slaves.
[0001.695] E> I2C: Could not write 0 bytes to slave: 0x00a4 with repeat start true.
[0001.702] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.708] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa4 at 0x00000000 via instance 1.
[0001.717] E> eeprom: Retry to read I2C slave device.
[0001.722] E> I2C: slave not found in slaves.
[0001.726] E> I2C: Could not write 0 bytes to slave: 0x00a4 with repeat start true.
[0001.734] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.740] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa4 at 0x00000000 via instance 1.
[0001.749] E> eeprom: Failed to read I2C slave device
[0001.754] I> Eeprom read failed 0x3526070d
[0001.758] I> Reading eeprom i2c=1 address=0x50
[0001.762] E> I2C: slave not found in slaves.
[0001.766] E> I2C: Could not write 0 bytes to slave: 0x00a0 with repeat start true.
[0001.774] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.780] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa0 at 0x00000000 via instance 1.
[0001.789] E> eeprom: Retry to read I2C slave device.
[0001.794] E> I2C: slave not found in slaves.
[0001.798] E> I2C: Could not write 0 bytes to slave: 0x00a0 with repeat start true.
[0001.806] E> I2C_DEV: Failed to send register address 0x00000000.
[0001.812] E> I2C_DEV: Could not read 256 registers of size 1 from slave 0xa0 at 0x00000000 via instance 1.
[0001.821] E> eeprom: Failed to read I2C slave device
[0001.826] I> Eeprom read failed 0x3526070d
[0001.830] I> create_pm_ids: id: 2888-0001-400-J, len: 15
[0001.835] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.846] I> create_pm_ids: id: 2822-0000-600-D, len: 15
[0001.851] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0001.862] I> Adding plugin-manager/ids/2888-0001-400=/i2c@3160000:module@0x50
[0001.870] W> "i2c@3160000" doesn't exist, creating
[0001.874] W> "module@0x50" doesn't exist, creating
[0001.879] I> Adding plugin-manager/ids/2822-0000-600=/i2c@3160000:module@0x56
[0001.886] W> "module@0x56" doesn't exist, creating
[0001.892] I> Adding plugin-manager/cvm
[0001.894] W> "chip-id" doesn't exist, creating
[0001.898] I> Adding plugin-manager/chip-id/A02
[0001.903] I> Plugin-manager override starting
[0001.908] I> node /plugin-manager/fragement-tegra-wdt-en matches
[0001.916] I> node /plugin-manager/fragement-soft-wdt matches
[0001.925] I> node /plugin-manager/fragment-pcie-c5-rp matches
[0001.929] I> node /plugin-manager/fragment-tegra-ufs-lane10 matches
[0001.942] I> Disable plugin-manager status in FDT
[0001.942] I> Plugin-manager override finished successfully
[0001.942] I> gpio framework initialized
[0001.945] I> tegrabl_gpio_driver_register: register 'nvidia,tegra194-gpio' driver
[0001.952] I> tegrabl_gpio_driver_register: register 'nvidia,tegra194-gpio-aon' driver
[0001.958] I> tegrabl_tca9539_init: i2c bus: 1, slave addr: 0x46
[0001.967] W> fetch_driver_phandle_from_dt: failed to get node with compatible ti,tca9539
[0001.974] W> fetch_driver_phandle_from_dt: failed to get node with compatible nxp,tca9539
[0001.980] W> tegrabl_tca9539_init: failed to fetch phandle from dt
[0001.986] I> tegrabl_tca9539_init: i2c bus: 1, slave addr: 0x44
[0001.994] W> fetch_driver_phandle_from_dt: failed to get node with compatible ti,tca9539
[0002.002] W> fetch_driver_phandle_from_dt: failed to get node with compatible nxp,tca9539
[0002.008] W> tegrabl_tca9539_init: failed to fetch phandle from dt
[0002.016] I> fixed regulator driver initialized
[0002.030] I> register 'maxim' power off handle
[0002.031] I> virtual i2c enabled
[0002.032] I> registered 'maxim,max20024' pmic
[0002.032] I> tegrabl_gpio_driver_register: register 'max20024-gpio' driver
[0002.037] I> Boot-device: eMMC
[0002.040] I> Boot_device: SDMMC_BOOT instance: 3
[0002.048] I> sdmmc-3 params source = boot args
[0002.049] I> create_pm_ids: id: 2888-0001-400-J, len: 15
[0002.053] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0002.064] I> create_pm_ids: id: 2822-0000-600-D, len: 15
[0002.070] I> config: mem-type:00,power-config:00,misc-config:00,modem-config:00,touch-config:00,display-config:00,, len: 93
[0002.081] I> sdmmc bdev is already initialized
[0002.085] I> sdmmc-3 params source = boot args
[0002.116] I> Found 15 partitions in SDMMC_BOOT (instance 3)
[0002.128] I> Found 41 partitions in SDMMC_USER (instance 3)
[0002.140] I> enabling 'vdd-hdmi-5v0' regulator
[0002.147] I> regulator 'vdd-hdmi-5v0' already enabled
[0002.147] E> tegrabl_display_init_regulator: hdmi cable is not connected
[0002.148] E> tegrabl_display_get_pdata, failed to parse dtb settings
[0002.153] E> invalid display type
[0002.158] E> invalid display type
[0002.159] E> cannot find any other nvdisp nodes
[0002.159] E> no valid display unit config found in dtb
[0002.160] W> display init failed
[0002.161] I> Load in CBoot Boot Options partition and parse it
[0002.164] I> Active slot suffix: _b <-- This patch
[0002.167] E> Cannot find partition CPUBL-CFG_b
[0002.171] E> tegrabl_read_cbo: Failed to open CPUBL-CFG_b partition
[0002.177] W> platform_init: tegrabl_read_cbo failed with error 0xd0d000d
[0002.184] I> Using default boot order
[0002.188] I> boot-dev-order :-
[0002.190] I> 1.sd
[0002.192] I> 2.usb
[0002.194] I> 3.nvme
[0002.196] I> 4.emmc
[0002.198] I> 5.net
[0002.200] I> Hit any key to stop autoboot:     4       3       2       1
[0004.207] initializing target
[0004.207] calling apps_init()
[0004.208] starting app kernel_boot_app
[0004.215] E> tegrabl_blob_init: BMP_b partition does not have valid Blob
[0004.216] E> tegrabl_load_bmp_blob: BMP blob initialization failed
[0004.216] W> Loading bmp blob to memory failed
[0004.216] I> Kernel type = Normal
[0004.217] I> ########## SD (0) boot ##########
[0004.217] I> No sdcard
[0004.218] I> -0 params source = 
[0004.221] E> Blockdev open: exit error
[0004.224] E> SD boot failed, err: 724238353
[0004.228] I> ########## USB (0) boot ##########
[0004.244] I> Validate XUSB-FW ...
[0004.244] I> T19x: Authenticate XUSB-FW (bin_type: 11), max size 0x40000
[0004.244] E> Stage2Signature validation failed with SHA2!!
[0004.248] C> OEM authentication of XUSB-FW header failed!
[0004.253] E> Failed to validate XUSB-FW binary (err=1077936152)
[0004.259] E> failed to initialize xhci controller
[0004.263] E> Error in init of XUSB host driver, err: 40400018
[0004.269] W> Failed to initialize device 5-0
[0004.273] E> USB boot failed, err: 1077936152
[0004.277] I> ########## NVME (0) boot ##########
[0004.282] I> Initializing nvme device instance 0
[0004.286] I> Initializing nvme controller
[0004.290] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14180000
[0004.296] I> vpcie3v3-supply not found
[0004.300] I> vpcie12v-supply not found
[0004.303] W> Failed to get nvidia,plat-gpios
[0004.308] I> tegrabl_pcie_soc_preinit: (0):
[0004.312] I> Unpowergate
[0004.314] I> tegrabl_car_clk_disable(0) ...
[0004.318] I> tegrabl_car_rst_set(CORE, 0) ...
[0004.322] I> tegrabl_car_rst_set(APB, 0) ...
[0004.326] I> tegrabl_car_clk_enable(0) ...
[0004.330] I> tegrabl_car_rst_clear(APB, 0) ...
[0004.335] I> tegrabl_set_ctrl_state(0)
[0004.338] I> CLR PCIE_APB:6
[0004.341] I> tegrabl_pcie_soc_init: (0):
[0004.344] I> APPL initialization ...
[0004.348] I> poweron phys
[0004.351] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14180000
[0004.357] I> tegrabl_power_on_phy: power on phy @0x3e30000
[0004.362] I> tegrabl_power_on_phy: power on phy @0x3e40000
[0004.368] I> tegrabl_power_on_phy: power on phy @0x3e50000
[0004.373] I> tegrabl_power_on_phy: power on phy @0x3e60000
[0005.478] C> Failed to link up controller-0
[0005.479] W> Failed tegrabl_pcie_soc_init(), error=0x12
[0005.479] I> Failed to initialize SoC Host PCIe controller
[0005.480] E> tegrabl_nvme_init: Failed tegrabl_pcie_init(0); error=0x12
[0005.480] W> tegrabl_nvme_bdev_open: Failed NVME INIT; error=0x80800612
[0005.481] W> Failed to open NVME-0, err = 80800612
[0005.485] W> Failed to initialize device 10-0
[0005.489] E> NVME (0) boot failed, err: 0x80800612
[0005.494] I> ########## NVME (1) boot ##########
[0005.498] I> Initializing nvme device instance 1
[0005.503] I> Initializing nvme controller
[0005.507] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14100000
[0005.513] I> vpcie3v3-supply not found
[0005.517] I> vpcie12v-supply not found
[0005.520] W> Failed to get nvidia,plat-gpios
[0005.524] I> tegrabl_pcie_soc_preinit: (1):
[0005.528] I> Unpowergate
[0005.531] I> tegrabl_car_clk_disable(1) ...
[0005.535] I> tegrabl_car_rst_set(CORE, 1) ...
[0005.539] I> tegrabl_car_rst_set(APB, 1) ...
[0005.543] I> tegrabl_car_clk_enable(1) ...
[0005.547] I> tegrabl_car_rst_clear(APB, 1) ...
[0005.551] I> tegrabl_set_ctrl_state(1)
[0005.555] I> CLR PCIE_APB:6
[0005.558] I> tegrabl_pcie_soc_init: (1):
[0005.561] I> APPL initialization ...
[0005.565] I> poweron phys
[0005.568] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14100000
[0005.574] I> tegrabl_power_on_phy: power on phy @0x3e10000
[0005.681] I> PCIe controller-1 link is up
[0005.681] I> tegra_pcie_info[1].cfg0_base = 0x30000000
[0005.681] I> tegra_pcie_info[1].cfg1_base = 0x30020000
[0005.682] I> tegra_pcie_info[1].atu_dma_base = 0x30040000
[0005.682] I> tegra_pcie_bus[1].mem = 0x30200000
[0005.682] I> Scanning busnr: 0 devfn: 0
[0005.683] I> PCIe IDs: 0x1ad210de
[0005.686] I> PCIe RID_CC: 0x60400a1
[0005.689] I> Scanning busnr: 1 devfn: 0
[0005.693] I> PCIe IDs: 0x91711b4b
[0005.696] I> PCIe RID_CC: 0x1060113
[0005.699] I> PCI Config: I/O=0x30100000, Memory=0x30200000
[0005.705] I> IO bar_num=0 bar=0x30100000
[0005.708] I> IO bar_num=1 bar=0x30100008
[0005.712] I> IO bar_num=2 bar=0x30100010
[0005.716] I> IO bar_num=3 bar=0x30100018
[0005.720] I> IO bar_num=4 bar=0x30100020
[0005.724] I> MEM bar_num=5 bar=0x30200000
[0005.727] I> Number of PCIe devices detected: 2
[0005.732] E> tegrabl_nvme_init: Failed tegrabl_pcie_get_dev(1); error=0x0
[0005.739] W> tegrabl_nvme_bdev_open: Failed NVME INIT; error=0x80800612
[0005.745] W> Failed to open NVME-1, err = 80800612
[0005.749] W> Failed to initialize device 10-1
[0005.754] E> NVME (1) boot failed, err: 0x80800612
[0005.758] I> ########## NVME (2) boot ##########
[0005.763] I> Initializing nvme device instance 2
[0005.767] I> Initializing nvme controller
[0005.772] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14120000
[0005.778] I> vpcie3v3-supply not found
[0005.781] I> vpcie12v-supply not found
[0005.785] W> Failed to get nvidia,plat-gpios
[0005.789] I> tegrabl_pcie_soc_preinit: (2):
[0005.793] I> Unpowergate
[0005.795] I> tegrabl_car_clk_disable(2) ...
[0005.799] I> tegrabl_car_rst_set(CORE, 2) ...
[0005.803] I> tegrabl_car_rst_set(APB, 2) ...
[0005.808] I> tegrabl_car_clk_enable(2) ...
[0005.812] I> tegrabl_car_rst_clear(APB, 2) ...
[0005.816] I> tegrabl_set_ctrl_state(2)
[0005.819] I> CLR PCIE_APB:6
[0005.822] I> tegrabl_pcie_soc_init: (2):
[0005.826] I> APPL initialization ...
[0005.829] I> poweron phys
[0005.832] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14120000
[0005.838] I> tegrabl_power_on_phy: controller 2 not available
[0005.844] E> Failed to power on phy on controller-2
[0005.849] W> Failed tegrabl_pcie_soc_init(), error=0x1
[0005.853] I> Failed to initialize SoC Host PCIe controller
[0005.859] E> tegrabl_nvme_init: Failed tegrabl_pcie_init(2); error=0x1
[0005.865] W> tegrabl_nvme_bdev_open: Failed NVME INIT; error=0x80800601
[0005.871] W> Failed to open NVME-2, err = 80800601
[0005.876] W> Failed to initialize device 10-2
[0005.880] E> NVME (2) boot failed, err: 0x80800601
[0005.885] I> ########## NVME (3) boot ##########
[0005.889] I> Initializing nvme device instance 3
[0005.894] I> Initializing nvme controller
[0005.898] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14140000
[0005.904] I> vpcie3v3-supply not found
[0005.908] I> vpcie12v-supply not found
[0005.911] W> Failed to get nvidia,plat-gpios
[0005.915] I> tegrabl_pcie_soc_preinit: (3):
[0005.919] I> Unpowergate
[0005.922] I> tegrabl_car_clk_disable(3) ...
[0005.926] I> tegrabl_car_rst_set(CORE, 3) ...
[0005.930] I> tegrabl_car_rst_set(APB, 3) ...
[0005.934] I> tegrabl_car_clk_enable(3) ...
[0005.938] I> tegrabl_car_rst_clear(APB, 3) ...
[0005.942] I> tegrabl_set_ctrl_state(3)
[0005.946] I> CLR PCIE_APB:6
[0005.949] I> tegrabl_pcie_soc_init: (3):
[0005.952] I> APPL initialization ...
[0005.956] I> poweron phys
[0005.959] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14140000
[0005.965] I> tegrabl_power_on_phy: power on phy @0x3e80000
[0007.070] C> Failed to link up controller-3
[0007.071] W> Failed tegrabl_pcie_soc_init(), error=0x12
[0007.071] I> Failed to initialize SoC Host PCIe controller
[0007.071] E> tegrabl_nvme_init: Failed tegrabl_pcie_init(3); error=0x12
[0007.072] W> tegrabl_nvme_bdev_open: Failed NVME INIT; error=0x80800612
[0007.072] W> Failed to open NVME-3, err = 80800612
[0007.077] W> Failed to initialize device 10-3
[0007.081] E> NVME (3) boot failed, err: 0x80800612
[0007.086] I> ########## NVME (4) boot ##########
[0007.090] I> Initializing nvme device instance 4
[0007.095] I> Initializing nvme controller
[0007.099] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14160000
[0007.105] I> vpcie3v3-supply not found
[0007.109] I> vpcie12v-supply not found
[0007.112] W> Failed to get nvidia,plat-gpios
[0007.116] I> tegrabl_pcie_soc_preinit: (4):
[0007.120] I> Unpowergate
[0007.123] I> tegrabl_car_clk_disable(4) ...
[0007.127] I> tegrabl_car_rst_set(CORE, 4) ...
[0007.131] I> tegrabl_car_rst_set(APB, 4) ...
[0007.135] I> tegrabl_car_clk_enable(4) ...
[0007.139] I> tegrabl_car_rst_clear(APB, 4) ...
[0007.143] I> tegrabl_set_ctrl_state(4)
[0007.147] I> CLR PCIE_APB:6
[0007.150] I> tegrabl_pcie_soc_init: (4):
[0007.153] I> APPL initialization ...
[0007.157] I> poweron phys
[0007.160] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x14160000
[0007.165] I> tegrabl_power_on_phy: controller 4 not available
[0007.171] E> Failed to power on phy on controller-4
[0007.176] W> Failed tegrabl_pcie_soc_init(), error=0x1
[0007.181] I> Failed to initialize SoC Host PCIe controller
[0007.186] E> tegrabl_nvme_init: Failed tegrabl_pcie_init(4); error=0x1
[0007.193] W> tegrabl_nvme_bdev_open: Failed NVME INIT; error=0x80800601
[0007.199] W> Failed to open NVME-4, err = 80800601
[0007.204] W> Failed to initialize device 10-4
[0007.208] E> NVME (4) boot failed, err: 0x80800601
[0007.212] I> ########## NVME (5) boot ##########
[0007.217] I> Initializing nvme device instance 5
[0007.221] I> Initializing nvme controller
[0007.226] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x141a0000
[0007.232] I> i=0, reg_phandle=0x1b
[0007.237] I> reg_voltage=3300000
[0007.238] I> tegrabl_pcie_enable_regulators: regulator_set_voltage(0x1b, 3300000)
[0007.250] I> enabling 'vdd-3v3-pcie' regulator
[0007.251] I> i=1, reg_phandle=0x1c
[0007.255] I> reg_voltage=1200000
[0007.256] I> tegrabl_pcie_enable_regulators: regulator_set_voltage(0x1c, 1200000)
[0007.268] I> enabling 'vdd-12v-pcie' regulator
[0007.269] I> tegrabl_pcie_soc_preinit: (5):
[0007.272] I> Unpowergate
[0007.274] I> tegrabl_car_clk_disable(5) ...
[0007.278] I> tegrabl_car_rst_set(CORE, 5) ...
[0007.282] I> tegrabl_car_rst_set(APB, 5) ...
[0007.286] I> tegrabl_car_clk_enable(5) ...
[0007.290] I> tegrabl_car_rst_clear(APB, 5) ...
[0007.295] I> tegrabl_set_ctrl_state(5)
[0007.298] I> CLR PCIE_APB:6
[0007.301] I> tegrabl_pcie_soc_init: (5):
[0007.304] I> APPL initialization ...
[0007.308] I> poweron phys
[0007.311] I> tegrabl_locate_pcie_ctrl_in_dt: found match at 0x141a0000
[0007.317] I> tegrabl_power_on_phy: power on phy @0x3eb0000
[0007.322] I> tegrabl_power_on_phy: power on phy @0x3ec0000
[0007.328] I> tegrabl_power_on_phy: power on phy @0x3ed0000
[0007.333] I> tegrabl_power_on_phy: power on phy @0x3ee0000
[0007.338] I> tegrabl_power_on_phy: power on phy @0x3ef0000
[0007.344] I> tegrabl_power_on_phy: power on phy @0x3f00000
[0007.349] I> tegrabl_power_on_phy: power on phy @0x3f10000
[0007.354] I> tegrabl_power_on_phy: power on phy @0x3f20000
[0008.459] C> Failed to link up controller-5
[0008.460] W> Failed tegrabl_pcie_soc_init(), error=0x12
[0008.461] I> Failed to initialize SoC Host PCIe controller
[0008.461] E> tegrabl_nvme_init: Failed tegrabl_pcie_init(5); error=0x12
[0008.461] W> tegrabl_nvme_bdev_open: Failed NVME INIT; error=0x80800612
[0008.462] W> Failed to open NVME-5, err = 80800612
[0008.466] W> Failed to initialize device 10-5
[0008.471] E> NVME (5) boot failed, err: 0x80800612
[0008.475] I> ########## Fixed storage boot ##########
[0008.480] I> Loading kernel-bootctrl from partition
[0008.485] E> Cannot find partition kernel-bootctrl
[0008.490] E> Cannot open partition kernel-bootctrl
[0008.494] W> tegrabl_get_kernel_bootctrl: failed to read primary bootctrl data
[0008.501] I> Loading kernel-bootctrl_b from partition
[0008.506] E> Cannot find partition kernel-bootctrl_b
[0008.511] E> Cannot open partition kernel-bootctrl_b
[0008.516] W> tegrabl_get_kernel_bootctrl: failed to read recovery bootctrl data
[0008.523] W> tegrabl_get_kernel_bootctrl: use default dummy boot control data
[0008.536] I> Already published: 00010003
[0008.536] I> Look for boot partition
[0008.537] I> Fallback: assuming 0th partition is boot partition
[0008.543] I> Detect filesystem
[0008.552] I> fs_detect:173: Unsupported or no filesystem present
[0008.552] W> Invalid fm_handle (0xa069cd38) or mount path passed
[0008.558] W> Continue to load from partition
[0008.562] I> Loading kernel ...
[0008.565] I> No kernel binary path
[0008.568] I> Continue to load from partition ...
[0008.572] I> A/B: bin_type (37) slot 1 <-- Should have loaded from slot 0 (https://github.com/OE4T/meta-tegra/blob/master/recipes-bsp/cboot/cboot-t19x/0017-Support-A-B-slot-for-kernel-on-SDcards-and-USB-devic.patch#L39)
[0008.576] I> Loading kernel_b from partition
[0008.580] I> Loading partition kernel_b at 0xa06f0000 from device(0x1)
[0008.982] I> Validate kernel ...
[0008.982] I> T19x: Authenticate kernel (bin_type: 37), max size 0x5000000
[0009.316] I> Encryption fuse is not ON
[0009.347] I> Checking boot.img header magic ... [0009.347] I> [OK]
[0009.348] I> Loading kernel-dtb ...
[0009.348] I> No kernel-dtb binary path
[0009.348] I> Continue to load from partition ...
[0009.349] I> A/B: bin_type (38) slot 1
[0009.349] I> Loading kernel-dtb_b from partition
[0009.349] I> Loading partition kernel-dtb_b at 0x91000000 from device(0x1)
[0009.363] I> Validate kernel-dtb ...
[0009.363] I> T19x: Authenticate kernel-dtb (bin_type: 38), max size 0x400000
[0009.367] I> Encryption fuse is not ON
[0009.369] I> Kernel hdr @0xa06f0000
[0009.372] I> Kernel dtb @0x90000000
[0009.375] I> decompressor handler not found
[0009.379] I> Copying kernel image (36720648 bytes) from 0xa06f0800 to 0x80080000 ... [0009.395] I> Done
[0009.395] I> Move ramdisk (len: 0) from 0xa29f6000 to 0x92000000
[0009.396] I> Updated bpmp info to DTB
[0009.399] I> Ramdisk: Base: 0x92000000; Size: 0x0
[0009.402] I> Updated initrd info to DTB
[0009.406] I> Active rootfs suffix: 
[0009.409] E> tegrabl_linuxboot_add_disp_param, du 0 failed to get display params
[0009.416] E> tegrabl_linuxboot_add_disp_param, du 0 failed to get display params
[0009.424] E> tegrabl_linuxboot_add_disp_param, du 0 failed to get display params
[0009.431] I> Active slot suffix: _b
[0009.434] I> add_boot_slot_suffix: slot_suffix = _b
[0009.439] I> Linux Cmdline: console=ttyTCU0,115200 root=LABEL=resin-rootB ro rootwait rootfstype=ext4 console=ttyTCU0,115200 console=tty0 fb 
[0009.478] I> Updated bootarg info to DTB
[0009.482] W> MAC addr invalid!
[0009.485] E> Failed to get WIFI MAC address
[0009.489] W> MAC addr invalid!
[0009.492] E> Failed to get Bluetooth MAC address
[0009.496] I> eeprom_get_mac_addr: MAC (type: 2): 00:04:4b:cb:a3:2f
[0009.503] W> "plugin-manager" doesn't exist, creating
[0009.507] I> Adding /chosen/plugin-manager/cvm
[0009.511] W> "chip-id" doesn't exist, creating
[0009.516] I> Adding /chosen/plugin-manager/chip-id
[0009.520] W> "configs" doesn't exist, creating
[0009.525] I> Adding /chosen/plugin-manager/configs
[0009.529] W> "ids" doesn't exist, creating
[0009.533] I> Adding /chosen/plugin-manager/ids
[0009.538] W> "odm-data" doesn't exist, creating
[0009.542] I> Adding /chosen/plugin-manager/odm-data
[0009.549] W> "memory" doesn't exist, creating
[0009.551] I> [0] START: 0x80000000, END: 0xac000000
[0009.555] I> [1] START: 0xac004000, END: 0xf0ad0000
[0009.560] I> [2] START: 0xf0adc000, END: 0xf0ae0000
[0009.565] I> dram_block larger than 80000000
[0009.569] I> [3] START: 0x100000000, END: 0x480000000
[0009.574] I> added [base:0x80000000, size:0x2c000000] to /memory
[0009.580] I> added [base:0xac200000, size:0x44800000] to /memory
[0009.586] I> added [base:0x100000000, size:0x380000000] to /memory
[0009.593] I> Updated memory info to DTB
[0009.596] E> add_disp_param: failed to get display params for du=0
[0009.602] W> "reset" doesn't exist, creating
[0009.606] I> Adding ecid(00000001645003c3200000000e0501c0) to DT
[0009.612] I> NVG: Logical CPU: 0; MPIDR: 0x80000000
[0009.616] I> NVG: Logical CPU: 1; MPIDR: 0x80000001
[0009.621] I> NVG: Logical CPU: 2; MPIDR: 0x80000100
[0009.626] I> NVG: Logical CPU: 3; MPIDR: 0x80000101
[0009.630] I> NVG: Logical CPU: 4; MPIDR: 0x80000200
[0009.635] I> NVG: Logical CPU: 5; MPIDR: 0x80000201
[0009.640] I> NVG: Logical CPU: 6; MPIDR: 0x80000300
[0009.644] I> NVG: Logical CPU: 7; MPIDR: 0x80000301
[0009.651] W> "misc-data" doesn't exist, creating
[0009.654] I> Boot-device: eMMC
[0009.656] I> Add boot-sdmmc to plugin-manager/misc-data
[0009.662] I> Add storage-sdmmc to plugin-manager/misc-data
[0009.667] W> Unknown storage device
[0009.671] I> Add serial number:0423418004011 as DT property
[0009.677] I> Plugin-manager override starting
[0009.680] I> node /plugin-manager/fragement-tegra-wdt-en matches
[0009.688] I> node /plugin-manager/fragement-soft-wdt matches
[0009.695] I> node /plugin-manager/fragment-pcie-c5-rp matches
[0009.699] I> node /plugin-manager/fragment-tegra-ufs-lane10 matches
[0009.713] I> Disable plugin-manager status in FDT
[0009.714] I> Plugin-manager override finished successfully
[0009.714] I> tegrabl_load_kernel_and_dtb: Done
[0009.717] I> SMD partition is updated.
[0009.745] E> tegrabl_display_clear: display is not initialized
[0009.745] W> Boot logo display failed...
[0009.746] I> Kernel EP: 0x80080000, DTB: 0x90000000
[    1.260979] ERROR: could not get clock /spi@c260000:osc(2)
[    1.260979] ERROR: could not get clock /spi@c260000:osc(2)
[    1.261679] ERROR: could not get clock /spi@c260000:osc(2)
[    1.261679] ERROR: could not get clock /spi@c260000:osc(2)
Starting version 249.3+
[   55.683508] Kernel panic - not syncing: Attempted to kill init! exitcode=0x00000100 <--- induced kernel panic to simulate failed boot
[   55.683508] 
[   55.683897] CPU: 5 PID: 1 Comm: switch_root Not tainted 4.9.253-l4t-r32.6 #1 
[   55.684088] Hardware name: Jetson-AGX (DT) 
[   55.684209] Call trace:
[   55.684334] [<ffffff800808ba10>] dump_backtrace+0x0/0x1a4
[   55.684507] [<ffffff800808bbcc>] show_stack+0x18/0x2c
[   55.684664] [<ffffff8008e2e1a4>] dump_stack+0xa0/0xc8
[   55.684811] [<ffffff8008e2b74c>] panic+0x130/0x294
[   55.684959] [<ffffff80080b35cc>] forget_original_parent+0x308/0x310
[   55.685130] [<ffffff80080b3628>] exit_notify+0x54/0x1bc
[   55.685277] [<ffffff80080b4cd4>] do_exit+0x184/0x3c0
[   55.685419] [<ffffff80080b4f88>] do_group_exit+0x38/0xa0
[   55.685581] [<ffffff80080b5004>] __wake_up_parent+0x0/0x3c
[   55.685733] [<ffffff8008083900>] el0_svc_naked+0x34/0x38
[   55.685892] SMP: stopping secondary CPUs
[   55.686067] Kernel Offset: disabled
[   55.686172] Memory Limit: none
[   55.686270] trusty-log panic notifier - trusty version Built: 12:20:34 Jul 26 2021 [   55.686799] Rebooting in 1 seconds..
����Shutdown state requested 1
Rebooting system ...
��
[0000.054] W> RATCHET: MB1 binary ratchet value 4 is too large than ratchet level 1 from HW fuses.
[0000.063] I> MB1 (prd-version: 1.5.1.7-t194-41334769-98030a79)
[0000.068] I> Boot-mode: Coldboot
[0000.071] I> Chip revision : A02 
[0000.074] I> Bootrom patch version : 7 (correctly patched)
[0000.079] I> ATE fuse revision : 0x200
[0000.083] I> Ram repair fuse : 0x0
[0000.086] I> Ram Code : 0x0
[0000.088] I> rst_source : 0xb
[0000.091] I> rst_level : 0x1
[0000.095] I> Boot-device: eMMC
[0000.110] I> sdmmc DDR50 mode
[0000.114] I> Active Boot chain : 0
[0000.117] I> Boot-device: eMMC
[0000.121] W> MB1_PLATFORM_CONFIG: device prod data is empty in MB1 BCT.
[0000.127] I> Temperature = 34000
[0000.130] W> Skipping boost for clk: BPMP_CPU_NIC
[0000.134] W> Skipping boost for clk: BPMP_APB
[0000.138] W> Skipping boost for clk: AXI_CBB
[0000.142] W> Skipping boost for clk: AON_CPU_NIC
[0000.147] W> Skipping boost for clk: CAN1
[0000.150] W> Skipping boost for clk: CAN2
[0000.155] I> Boot-device: eMMC
[0000.157] I> Boot-device: eMMC
[0000.167] I> Sdmmc: HS400 mode enabled
[0000.171] I> ECC region[0]: Start:0x0, End:0x0
[0000.175] I> ECC region[1]: Start:0x0, End:0x0
[0000.179] I> ECC region[2]: Start:0x0, End:0x0
[0000.184] I> ECC region[3]: Start:0x0, End:0x0
[0000.188] I> ECC region[4]: Start:0x0, End:0x0
[0000.192] I> Non-ECC region[0]: Start:0x80000000, End:0x100000000
[0000.198] I> Non-ECC region[1]: Start:0x0, End:0x0
[0000.202] I> Non-ECC region[2]: Start:0x0, End:0x0
[0000.206] I> Non-ECC region[3]: Start:0x0, End:0x0
[0000.211] I> Non-ECC region[4]: Start:0x0, End:0x0
[0000.216] E> FAILED: Thermal config
[0000.224] E> FAILED: MEMIO rail config
[0000.237] I> Boot-device: eMMC
[0000.246] I> sdmmc bdev is already initialized
[0001.790] E> WP-1 ACK pending
[0001.793] E> Error: 19 
[0001.795] E> Task 72 failed (err: 0x32320006)
[0001.799] E> Top caller module: CPUINIT, error module: CPUINIT, reason: 0x06, aux_info: 0x00
[0001.807] I> MB1(1.5.1.7-t194-41334769-98030a79) BIT boot status dump :
0000000000011111111110111111111111111111111100111111101110011111111011011000000000000000000000000000000000000000000000000000000011111011000000
[0001.837] I> Reset to recovery mode
madisongh commented 2 years ago

@acostach I'm not sure I understand. cboot has supported A/B slot selection for fixed boot devices for quite a while, so no patches to that code path are needed. It was only the removable devices that didn't have that support.

[0008.572] I> A/B: bin_type (37) slot 1 <-- Should have loaded from slot 0

That slot number is read from a register, and should match up with the slot number reported by the earlier bootloaders (e.g. MB1).

(i.e started from 32.5.1, updated to 32.6.1 but failed to boot in 32.6.1 enough times so fallback to loading 32.5.1 dtb and kernel). It looks like after the retries number is reached, the bootloaders enter recovery mode.

The reversion to recovery mode is a drawback of NVIDIA's boot count/priority implementation, which is why for the Mender integration we mark the boot as successful in the initramfs and use a separate boot counter to track OS boot failures.

How did you implement your updates? Is it not a full boot chain/kernel/rootfs per boot slot? I'm not sure how the fallback isn't pairing the 32.5.x bootloader with your 32.5.x kernel/dtb/etc.

acostach commented 2 years ago

Hi @madisongh and thank you for your reply, I'll try to provide a more detailed explanation of the update process on the AGX:

1) Start from a 32.5.1 based system 2) Update MB1_b, MB1_BCT_b, spe-fw_b, mb2_b, mts-preboot_b, smd_b, MEM_BCT_b inside /dev/mmcblk0boot0 (I write 32.6.1 new signed binaries at their _b offset, leaving slots _a inside mmcblk0boot0 intact. 3) Write mts_b, mts-proper_b, cboot_b, bootloader-dtb_b, tos_b etc .kernel_b with 32.6.1 signed binaries insider their mmcblk0pX_b partitions. 4) run tegra-boot-control -e and tegra-boot-control -a 1 and then check with tegra-boot-control -s that slot 1 (_b) has been activated, then reboot 5) on the next boot (32.6.1) I have a rootfs that causes the new kernel to panic, so that I can check redundant boot. For normal boot cases, I use tegra-boot-control -m in the next rootfs boot (root_b) to mark the current slot as successful.

Unfortunately after 7 failed boots, I'm seeing the MB1 from 32.6.1 running and putting the system in recovery mode, while I was expecting MB1 from 32.5.1 to run, because slots _a were not updated inside /dev/mmcblk0boot0, and nor were any /dev/mmcblk0pX_a partitions updated.

Also, if at step 2) I update both _a and _b slots inside mmcblk0boot0 with 32.6.1 signed binaries (so not only _b slots), I'm seeing the exact same problem, MB1 from 32.6.1 puts the device in recovery mode after 7 failed attempts. This doesn't happen on the Xavier NX though, when jumping from 32.5.1 to 32.6.1.

Next, if at step 2) I update only slots _b inside mmcblk0boot0 with 32.6.1 signed binaries and leave slots _a on 32.5.1 and don't use tegra-boot-control -a 1 to switch to slot _b, the system will reboot into the same 32.5.1 OS without problems, by running MB1 from 32.5.1. This confirms that updating only slots _a or _b inside mmcblk0boot0 works as expected, and does not affect booting 32.5.1, nor 32.6.1.

Finally, if I do perform the same steps above but update from 32.6.1 to 32.6.1, so just switching between slots _a and _b that both have the same 32.6.1 binaries and just a rootfs that fails to mark the current boot as successful (kernel panic), the system falls back to slot _a instead of going into recovery mode.

Thank you

acostach commented 2 years ago

Ok, seems that I found a solution for the AGX, when starting from 32.5.1 I have to update both _a and _b slots of the raw partitions ( xusb-fw, secure_os, cpu-bootloader etc) to 32.6.1 and leave the old kernel and kerner-dtb partitions on 32.5.1.

This way MB1, while still at the version from 32.6.1, will successfully fallback to the old slot and not enter debug mode. To me this seems a like a potential bug in MB1, given that only the inactive slots would need to be updated in theory. Either way, updating all is enough to boot the old OS and do a full recovery to 32.5.1. Thanks again for looking into this!