Jetson Nano HID devices sporadic boot time

I have developed a custom carrier board for the Jetson Nano. It follows the design for the B01 carrier board very closely with the addition of a USB2.0 7-port hub and several USB devices connected directly. Due to the similarity, I have not yet made any changes to the device tree. I am using a B01 Jetson Nano with a microSD card.

For a while, the boot process was fine. However, recently I have noticed that the boot takes an exceptionally long time to occur. Looking at the UART2 debug output shows that it takes ~13 seconds to reach the step to set the vdd-core regulator to 1.125V, but can take anywhere from 3-10 minutes to fail to get HID devices.

I am interfacing with the device only through ssh over ethernet. There are no mouse/keyboard inputs anywhere on the board.

Any information would be greatly appreciated.

[0000.125] [L4T TegraBoot] (version 00.00.2018.01-l4t-80a468da)
[0000.131] Processing in cold boot mode Bootloader 2
[0000.135] A02 Bootrom Patch rev = 1023
[0000.139] Power-up reason: pmc por
[0000.142] No Battery Present
[0000.145] pmic max77620 reset reason
[0000.148] pmic max77620 NVERC : 0x40
[0000.151] RamCode = 0
[0000.154] Platform has DDR4 type RAM
[0000.157] max77620 disabling SD1 Remote Sense
[0000.161] Setting DDR voltage to 1125mv
[0000.165] Serial Number of Pmic Max77663: 0x2f29e9
[0000.173] Entering ramdump check
[0000.176] Get RamDumpCarveOut = 0x0
[0000.179] RamDumpCarveOut=0x0,  RamDumperFlag=0xe59ff3f8
[0000.184] Last reboot was clean, booting normally!
[0000.189] Sdram initialization is successful 
[0000.193] SecureOs Carveout Base=0x00000000ff800000 Size=0x00800000
[0000.199] Lp0 Carveout Base=0x00000000ff780000 Size=0x00001000
[0000.205] BpmpFw Carveout Base=0x00000000ff700000 Size=0x00080000
[0000.211] GSC1 Carveout Base=0x00000000ff600000 Size=0x00100000
[0000.216] GSC2 Carveout Base=0x00000000ff500000 Size=0x00100000
[0000.222] GSC4 Carveout Base=0x00000000ff400000 Size=0x00100000
[0000.228] GSC5 Carveout Base=0x00000000ff300000 Size=0x00100000
[0000.234] GSC3 Carveout Base=0x000000017f300000 Size=0x00d00000
[0000.250] RamDump Carveout Base=0x00000000ff280000 Size=0x00080000
[0000.256] Platform-DebugCarveout: 0
[0000.259] Nck Carveout Base=0x00000000ff080000 Size=0x00200000
[0000.265] Non secure mode, and RB not enabled.
[0000.270] Read GPT from (4:0)
[0000.399] Csd NumOfBlocks=62333952
[0000.404] Set High speed to 1
[0000.407] Error mask set in wait for cmd complete with error 0x3 in HwSdmmcWaitForCommandComplete func at 278 line 
[0000.417] Command complete wait failed with error 0x3 Interrupt 0x18001
[0000.424] Number of retries left 4
[0000.436] Using GPT Primary to query partitions
[0000.440] Loading Tboot-CPU binary
[0000.449] Verifying TBC in OdmNonSecureSBK mode
[0000.459] Bootloader load address is 0xa0000000, entry address is 0xa0000258
[0000.466] Bootloader downloaded successfully.
[0000.471] Downloaded Tboot-CPU binary to 0xa0000258
[0000.476] MAX77620_GPIO5 configured
[0000.479] CPU power rail is up
[0000.482] CPU clock enabled
[0000.486] Performing RAM repair
[0000.488] Updating A64 Warmreset Address to 0xa00002e9
[0000.494] Loading NvTbootBootloaderDTB
[0000.520] Verifying NvTbootBootloaderDTB in OdmNonSecureSBK mode
[0000.585] Bootloader DTB Load Address: 0x83000000
[0000.590] Loading NvTbootKernelDTB
[0000.616] Verifying NvTbootKernelDTB in OdmNonSecureSBK mode
[0000.681] Kernel DTB Load Address: 0x83100000
[0000.688] Loading cboot binary
[0000.717] Verifying EBT in OdmNonSecureSBK mode
[0000.759] Bootloader load address is 0x92c00000, entry address is 0x92c00258
[0000.766] Bootloader downloaded successfully.
[0000.770] Read PT from (2:0)
[0000.786] Using BFS PT to query partitions 
[0000.790] PT: Partition NCT NOT found ! 
[0000.793] Warning: Find Partition via PT Failed
[0000.798] Next binary entry address: 0x92c00258 
[0000.802] BoardId: 3448
[0000.807] Overriding pmu board id with proc board id
[0000.812] Display board id is not available 
[0000.842] Verifying SC7EntryFw in OdmNonSecureSBK mode
[0000.894] /bpmp deleted
[0000.896] SC7EntryFw header found loaded at 0xff700000
[0001.086] OVR2 PMIC
[0001.088] Bpmp FW successfully loaded
[0001.094] WB0 init successfully at 0xff780000
[0001.098] Set NvDecSticky Bits
[0001.102] GSC2 address ff53fffc value c0edbbcc
[0001.108] GSC MC Settings done
[0001.113] TOS Image length 53680
[0001.116]  Monitor size 53680
[0001.119]  OS size 0
[0001.128] Secure Os AES-CMAC Verification Success!
[0001.133] TOS image cipher info: plaintext
[0001.137] Loading and Validation of Secure OS Successful
[0001.153] SC7 Entry Firmware - 0xff700000, 0x4000
[0001.157] NvTbootPackSdramParams: start. 
[0001.162] NvTbootPackSdramParams: done. 
[0001.166] Tegraboot started after 52318 us
[0001.170] Basic modules init took 783689 us
[0001.174] Sec Bootdevice Read Time = 12 ms, Read Size = 65 KB
[0001.180] Sec Bootdevice Write Time = 0 ms, Write Size = 0 KB
[0001.185] Storage Device Read Time = 124 ms, Read Size = 2241 KB
[0001.191] Storage Device Write Time = 0 ms, Write Size = 0 KB
[0001.196] Next stage binary read took 26379 us
[0001.201] Carveout took -38064 us
[0001.204] CPU initialization took 370137 us
[0001.208] Total time taken by TegraBoot 1142141 us

[0001.212] Starting CPU & Halting co-processor 

64NOTICE:  BL31: v1.3(release):41d46a9cf
NOTICE:  BL31: Built : 21:18:12, Jun 25 2020
ERROR:   Error initializing runtime service trusty_fast
[0001.335] RamCode = 0
[0001.339] LPDDR4 Training: Read DT: Number of tables = 2
[0001.344] EMC Training (SRC-freq: 204000; DST-freq: 1600000)
[0001.357] EMC Training Successful
[0001.360] 408000 not found in DVFS table
[0001.367] RamCode = 0
[0001.370] DT Write: emc-table@204000 succeeded
[0001.375] DT Write: emc-table@1600000 succeeded
[0001.380] LPDDR4 Training: Write DT: Number of tables = 2
[0001.422] 
[0001.423] Debug Init done
[0001.425] Marked DTB cacheable
[0001.428] Bootloader DTB loaded at 0x83000000
[0001.433] Marked DTB cacheable
[0001.436] Kernel DTB loaded at 0x83100000
[0001.440] DeviceTree Init done
[0001.453] Pinmux applied successfully
[0001.457] gicd_base: 0x50041000
[0001.461] gicc_base: 0x50042000
[0001.464] Interrupts Init done
[0001.468] Using base:0x60005090 & irq:208 for tick-timer
[0001.473] Using base:0x60005098 for delay-timer
[0001.477] platform_init_timer: DONE
[0001.481] Timer(tick) Init done
[0001.484] osc freq = 38400 khz
[0001.489] 
[0001.490] Welcome to L4T Cboot
[0001.493] 
[0001.494] Cboot Version: 00.00.2018.01-t210-3a7ad565
[0001.499] calling constructors
[0001.502] initializing heap
[0001.504] initializing threads
[0001.507] initializing timers
[0001.510] creating bootstrap completion thread
[0001.515] top of bootstrap2()
[0001.518] CPU: ARM Cortex A57
[0001.520] CPU: MIDR: 0x411FD071, MPIDR: 0x80000000
[0001.525] initializing platform
[0001.533] Manufacturer: MF = 0xc2, ID MSB = 0x25
[0001.537] ID LSB = 0x36, ID-CFI len = 194 bytes
[0001.542] Macronix QSPI chip present
[0001.545] SPI device register
[0001.548] init boot device
[0001.551] allocating memory for boot device(SPI)
[0001.555] registering boot device
[0001.575] sdmmc node status = okay
[0001.578] sdcard instance = 0
[0001.581] sdcard gpio handle 0x56
[0001.584] sdcard gpio pin 0xc9
[0001.587] sdcard gpio flags 0x0
[0001.590] vmmc-supply 0x99
[0001.592] Instance: 0
[0001.595] Allocating memory for context
[0001.598] enabling clock
[0001.601] sd card init
[0001.603] Check card present and stable
[0001.607] Send command 0
[0001.631] Send command 3
[0001.636] Set RCA for the card
[0001.639] Query card specific data by command 9
[0001.645] Parse CSD data
[0001.647] Send command 7
[0001.658] Calling sd device register
[0001.661] Init sdcard
[0001.663] Allocating memory for boot device
[0001.667] Registering user device
[0001.681] Enable APE clock
[0001.683] Un-powergate APE partition
[0001.687] of_register: registering tegra_udc to of_hal
[0001.692] of_register: registering inv20628-driver to of_hal
[0001.697] of_register: registering ads1015-driver to of_hal
[0001.703] of_register: registering lp8557-bl-driver to of_hal
[0001.709] of_register: registering bq2419x_charger to of_hal
[0001.714] of_register: registering bq27441_fuel_gauge to of_hal
[0001.726] gpio framework initialized
[0001.729] of_register: registering tca9539_gpio to of_hal
[0001.735] of_register: registering tca9539_gpio to of_hal
[0001.740] of_register: registering i2c_bus_driver to of_hal
[0001.746] of_register: registering i2c_bus_driver to of_hal
[0001.751] of_register: registering i2c_bus_driver to of_hal
[0001.757] pmic framework initialized
[0001.760] of_register: registering max77620_pmic to of_hal
[0001.766] regulator framework initialized
[0001.770] of_register: registering tps65132_bl_driver to of_hal
[0001.776] initializing target
[0001.781] gpio_driver_register: register 'tegra_gpio_driver' driver
[0001.790] board ID = D78, board SKU = 0
[0001.793] Skipping Z3!
[0001.798] fixed regulator driver initialized
[0001.816] initializing OF layer
[0001.818] NCK carveout not present
[0001.822] Skipping dts_overrides
[0001.826] of_children_init: Ops found for compatible string nvidia,tegra210-i2c
[0001.843] I2C Bus Init done
[0001.845] of_children_init: Ops found for compatible string nvidia,tegra210-i2c
[0001.856] I2C Bus Init done
[0001.858] of_children_init: Ops found for compatible string nvidia,tegra210-i2c
[0001.869] I2C Bus Init done
[0001.871] of_children_init: Ops found for compatible string nvidia,tegra210-i2c
[0001.882] I2C Bus Init done
[0001.884] of_children_init: Ops found for compatible string nvidia,tegra210-i2c
[0001.895] I2C Bus Init done
[0001.897] of_children_init: Ops found for compatible string maxim,max77620
[0001.908] max77620_init using irq 118
[0001.913] register 'maxim,max77620' pmic
[0001.917] gpio_driver_register: register 'max77620-gpio' driver
[0001.923] of_children_init: Ops found for compatible string nvidia,tegra210-i2c
[0001.934] I2C Bus Init done
[0001.937] NCK carveout not present
[0001.947] Find /i2c@7000c000's alias i2c0
[0001.951] get eeprom at 1-a0, size 256, type 0
[0001.960] Find /i2c@7000c500's alias i2c2
[0001.964] get eeprom at 3-a0, size 256, type 0
[0001.968] get eeprom at 3-ae, size 256, type 0
[0001.973] pm_ids_update: Updating 1,a0, size 256, type 0
[0001.978] I2C slave not started
[0001.981] I2C write failed
[0001.984] Writing offset failed
[0001.987] eeprom_init: EEPROM read failed
[0001.991] pm_ids_update: eeprom init failed
[0001.995] pm_ids_update: Updating 3,a0, size 256, type 0
[0002.025] pm_ids_update: The pm board id is 3448-0000-400
[0002.031] Adding plugin-manager/ids/3448-0000-400=/i2c@7000c500:module@0x50
[0002.039] pm_ids_update: pm id update successful
[0002.044] pm_ids_update: Updating 3,ae, size 256, type 0
[0002.049] I2C slave not started
[0002.052] I2C write failed
[0002.055] Writing offset failed
[0002.058] eeprom_init: EEPROM read failed
[0002.062] pm_ids_update: eeprom init failed
[0002.092] eeprom_get_mac: EEPROM invalid MAC address (all 0xff)
[0002.098] shim_eeprom_update_mac:267: Failed to update 0 MAC address in DTB
[0002.106] eeprom_get_mac: EEPROM invalid MAC address (all 0xff)
[0002.112] shim_eeprom_update_mac:267: Failed to update 1 MAC address in DTB
[0002.121] updating /chosen/nvidia,ethernet-mac node 00:04:4b:e7:43:86
[0002.127] Plugin Manager: Parse ODM data 0x00094000
[0002.137] shim_cmdline_install: /chosen/bootargs: earlycon=uart8250,mmio32,0x70006000 
[0002.152] Find /i2c@7000c000's alias i2c0
[0002.156] get eeprom at 1-a0, size 256, type 0
[0002.165] Find /i2c@7000c500's alias i2c2
[0002.168] get eeprom at 3-a0, size 256, type 0
[0002.173] get eeprom at 3-ae, size 256, type 0
[0002.177] pm_ids_update: Updating 1,a0, size 256, type 0
[0002.183] I2C slave not started
[0002.186] I2C write failed
[0002.188] Writing offset failed
[0002.191] eeprom_init: EEPROM read failed
[0002.195] pm_ids_update: eeprom init failed
[0002.199] pm_ids_update: Updating 3,a0, size 256, type 0
[0002.229] pm_ids_update: The pm board id is 3448-0000-400
[0002.236] Adding plugin-manager/ids/3448-0000-400=/i2c@7000c500:module@0x50
[0002.243] pm_ids_update: pm id update successful
[0002.247] pm_ids_update: Updating 3,ae, size 256, type 0
[0002.253] I2C slave not started
[0002.256] I2C write failed
[0002.258] Writing offset failed
[0002.261] eeprom_init: EEPROM read failed
[0002.265] pm_ids_update: eeprom init failed
[0002.296] Add serial number:1422919167169 as DT property
[0002.303] Applying platform configs
[0002.310] platform-init is not present. Skipping
[0002.315] calling apps_init()
[0002.340] Found 14 GPT partitions in "sd0"
[0002.344] Proceeding to Cold Boot
[0002.347] starting app android_boot_app
[0002.351] Device state: unlocked
[0002.354] display console init
[0002.362] could not find regulator
[0002.386] hdmi cable not connected
[0002.389] is_hdmi_needed: HDMI not connected, returning false
[0002.395] hdmi is not connected
[0002.398] sor0 is not suppDT entry for leds-pwm not found
o[0002.407] rted
[0002.408] display_console_init: no valid display out_type
[0002.416] subnode volume_up is not found !
[0002.420] subnode back is not found !
[0002.424] subnode volume_down is not found !
[0002.428] subnode menu is not found !
[0002.432] Gpio keyboard init success
[0002.477] found decompressor handler: lz4-legacy
[0002.492] decompressing blob (type 1)...
[0002.525] display_resolution: No display init
[0002.529] Failed to retrieve display resolution
[0002.534] Could not load/initialize BMP blob...ignoring
[0002.587] decompressor handler not found
[0002.591] load_firmware_blob: Firmware blob loaded, entries=2
[0002.597] -------> se_aes_verify_sbk_clear: 747
[0002.601] se_aes_verify_sbk_clear: Error
[0002.605] bl_battery_charging: connected to external power supply
[0002.612] xusb is supported
[0002.618] error while finding nvidia,portmap
[0003.123] xusb blob version 0 size 124416
[0003.127] firmware size 124416
[0003.131] Firmware timestamp: 0x5da88fc3, Version: 50.25 release
[0003.140] xhci0: 64 bytes context size, 32-bit DMA
[0003.180] usbus0: 5.0Gbps Super Speed USB v3.0
[0003.200] uhub0: <Nvidia XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0
[0003.850] uhub0: 9 ports with 9 removable, self powered
[0004.890] uhub1: <vendor 0x0424 product 0x2517, class 9/0, rev 2.00/0.02, addr 1> on usbus0
[0004.910] uhub1: MTT enabled
[0006.110] uhub1: 7 ports with 7 removable, self powered
[0013.180] get polling status timeout
[0013.184] failed to init xhci or no usb device attached
[0013.191] display_console_ioctl: No display init
[0013.196] switch_backlight failed
[0013.202] device_query_partition_size: failed to open partition sd0:MSC !
[0013.209] MSC Partition not found
[0013.215] device_query_partition_size: failed to open partition sd0:USP !
[0013.222] USP partition read failed!
[0013.225] blob_init: blob-partition USP header read failed
[0013.231] android_boot Unable to update recovery partition
[0013.236] kfs_getpartname: name = LNX
[0013.240] Loading kernel from LNX
[0013.338] load kernel from storage
[0013.349] decompressor handler not found
[0013.406] Successfully loaded kernel and ramdisk images
[0013.413] display_resolution: No display init
[0013.417] Failed to retrieve display resolution
[0013.422] bmp blob is not loaded and initialized
[0013.426] Failed to display boot-logo
[0013.430] NCK carveout not present
[0013.433] Skipping dts_overrides
[0013.436] NCK carveout not present
[0013.446] Find /i2c@7000c000's alias i2c0
[0013.450] get eeprom at 1-a0, size 256, type 0
[0013.459] Find /i2c@7000c500's alias i2c2
[0013.463] get eeprom at 3-a0, size 256, type 0
[0013.467] get eeprom at 3-ae, size 256, type 0
[0013.472] pm_ids_update: Updating 1,a0, size 256, type 0
[0013.477] I2C slave not started
[0013.480] I2C write failed
[0013.483] Writing offset failed
[0013.486] eeprom_init: EEPROM read failed
[0013.490] pm_ids_update: eeprom init failed
[0013.494] pm_ids_update: Updating 3,a0, size 256, type 0
[0013.524] pm_ids_update: The pm board id is 3448-0000-400
[0013.530] Adding plugin-manager/ids/3448-0000-400=/i2c@7000c500:module@0x50
[0013.538] pm_ids_update: pm id update successful
[0013.543] pm_ids_update: Updating 3,ae, size 256, type 0
[0013.548] I2C slave not started
[0013.551] I2C write failed
[0013.554] Writing offset failed
[0013.557] eeprom_init: EEPROM read failed
[0013.561] pm_ids_update: eeprom init failed
[0013.591] eeprom_get_mac: EEPROM invalid MAC address (all 0xff)
[0013.597] shim_eeprom_update_mac:267: Failed to update 0 MAC address in DTB
[0013.605] eeprom_get_mac: EEPROM invalid MAC address (all 0xff)
[0013.611] shim_eeprom_update_mac:267: Failed to update 1 MAC address in DTB
[0013.619] updating /chosen/nvidia,ethernet-mac node 00:04:4b:e7:43:86
[0013.626] Plugin Manager: Parse ODM data 0x00094000
[0013.636] shim_cmdline_install: /chosen/bootargs: earlycon=uart8250,mmio32,0x70006000 
[0013.644] Add serial number:1422919167169 as DT property
[0013.653] "bpmp" doesn't exist, creating 
[0013.658] Updated bpmp info to DTB
[0013.663] Updated initrd info to DTB
[0013.667] "proc-board" doesn't exist, creating 
[0013.672] Updated board info to DTB
[0013.676] "pmu-board" doesn't exist, creating 
[0013.681] Updated board info to DTB
[0013.685] "display-board" doesn't exist, creating 
[0013.690] Updated board info to DTB
[0013.694] "reset" doesn't exist, creating 
[0013.698] Updated reset info to DTB
[0013.702] display_console_ioctl: No display init
[0013.706] display_console_ioctl: No display init
[0013.711] display_console_ioctl: No display init
[0013.715] Cmdline: tegraid=21.1.2.0.0 ddr_die=4096M@2048M section=512M memtype=0 vpr_resize usb_port_owner_info=0 lane_owner_info=0 emc_max_dvfs=0 touch_id=0@63 video=tegrafb no_console_suspend=1 console=ttyS0,115200n8 debug_uartport=lsport,2 earlyprintk=uart8250-32bit,0x70006000 maxcpus=4 usbcore.old_scheme_first=1 lp0_vec=0x1000@0xff780000 core_edp_mv=1125 core_edp_ma=4000 
[0013.749] DTB cmdline: earlycon=uart8250,mmio32,0x70006000 
[0013.755] boot image cmdline: root=/dev/mmcblk0p1 rw rootwait rootfstype=ext4 console=ttyS0,115200n8 console=tty0 fbcon=map:0 net.ifnames=0 
[0013.768] Updated bootarg info to DTB
[0013.772] Adding uuid 00000001644568070c00000013fb8300 to DT
[0013.777] Adding eks info 0 to DT
[0013.783] WARNING: Failed to pass NS DRAM ranges to TOS, err: -7
[0013.789] Updated memory info to DTB
[0013.797] set vdd_core voltage to 1125 mv
[0013.801] setting 'vdd-core' regulator to 1125000 micro volts
[0290.902] failed to get HID devices
[0290.922] Found secure-pmc; disable BPMP


U-Boot 2016.07-ge6da093be3 (Jun 25 2020 - 21:18:08 -0700)

TEGRA210
Model: NVIDIA P3450-Porg
Board: NVIDIA P3450-PORG
DRAM:  4 GiB
MMC:   Tegra SD/MMC: 0, Tegra SD/MMC: 1
SF: Detected MX25U3235F with page size 256 Bytes, erase size 4 KiB, total 4 MiB

Hi,
Please check if the hub is not powered on or needs additional driver. It looks like it takes some time in initializing the hub and then fails. Seems to hi timeout here.

I am looking into this issue as well, but it is a lower priority as it only delays the boot time by ~7 seconds. I am more interested in the 2-10 minute delay that occurs right before u-boot is initialized:

[0013.789] Updated memory info to DTB
[0013.797] set vdd_core voltage to 1125 mv
[0013.801] setting 'vdd-core' regulator to 1125000 micro volts
[0290.902] failed to get HID devices
[0290.922] Found secure-pmc; disable BPMP

Unless you believe this delay is caused by the 7-port usb hub (USB2517). However, it is currently set to use the default configuration and has no connection to the I2C (shouldn’t need any addition to the device tree as a generic usb hub device I believe).

Thank you

Hi,
So there is no USB device plugged into any one of the 7 ports? The timeout happens before booting to kernel?

The normal boot up log also has

[0003.852] xhci0: 64 bytes context size, 32-bit DMA
[0003.892] usbus0: 5.0Gbps Super Speed USB v3.0
[0003.912] uhub0: <Nvidia XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0
[0004.562] uhub0: 9 ports with 9 removable, self powered
[0005.562] failed to get HID devices
[0005.566] failed to init xhci or no usb device attached

But there is no timeout issue. and also no log from “uhub1”.

[0013.180] get polling status timeout

Could you share the board design? I don’t think you could just 100% leverage original jetpack DTB for your board.

During the start-up there are no USB devices plugged into the ports. The kernel doesn’t boot until the message saying failed to get HID devices

There is no update from you for a period, assuming this is not an issue any more.
Hence we are closing this topic. If need further support, please open a new one.
Thanks

Hi,

Why do you think usb devices on the ports are the cause?

It looks like the hub itself is the cause.

It follows the design for the B01 carrier board very closely with the addition of a USB2.0 7-port hub

Does this hub have any problem after boot up?