Hello Nvidia-team,
I am going through a similar USB firmware controller crash issue when I connect a Plantronics USB Speaker to Jetson Nano and reboot the system. Fyi, the kernel version on Jetson Nano is 4.9.
The same works on a Nuc with kernel version 4.15
Please find the Jetson Nano boot log below -
.
.
.
[ 6.395018] nvgpu: 57000000.gpu gm20b_init_clk_setup_sw:1268 [INFO] GPCPLL initial settings: NA mode, M=1, N=34, P=3 (id = 1)
[ 6.531702] systemd-journald[1889]: Received request to flush runtime journal from PID 1
[ 7.209391] tegra-xusb 70090000.xusb: cannot find firmware…retry after 1 second
[ 7.282138] nvs_dsm nvs_dsm: dsm_probe
[ 7.282161] nvs_dsm nvs_dsm: dsm_remove
[ 7.282164] nvs_dsm nvs_dsm: dsm_probe done
[ 8.226646] tegra-xusb 70090000.xusb: Firmware timestamp: 2017-11-03 13:36:19 UTC, Version: 50.20 release
[ 8.226684] tegra-xusb 70090000.xusb: xHCI Host Controller
[ 8.226702] tegra-xusb 70090000.xusb: new USB bus registered, assigned bus number 1
[ 8.227572] tegra-xusb 70090000.xusb: hcc params 0x0184f525 hci version 0x100 quirks 0x00050010
[ 8.227603] tegra-xusb 70090000.xusb: irq 61, io mem 0x70090000
[ 8.227720] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 8.227724] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 8.227727] usb usb1: Product: xHCI Host Controller
[ 8.227730] usb usb1: Manufacturer: Linux 4.9.140-tegra xhci-hcd
[ 8.227733] usb usb1: SerialNumber: 70090000.xusb
[ 8.228217] hub 1-0:1.0: USB hub found
[ 8.228279] hub 1-0:1.0: 5 ports detected
[ 8.228679] tegra-xusb 70090000.xusb: xHCI Host Controller
[ 8.228688] tegra-xusb 70090000.xusb: new USB bus registered, assigned bus number 2
[ 8.228760] usb usb2: We don’t know the algorithms for LPM for this host, disabling LPM.
[ 8.228832] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003
[ 8.228836] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 8.228839] usb usb2: Product: xHCI Host Controller
[ 8.228841] usb usb2: Manufacturer: Linux 4.9.140-tegra xhci-hcd
[ 8.228844] usb usb2: SerialNumber: 70090000.xusb
[ 8.229193] hub 2-0:1.0: USB hub found
[ 8.229251] hub 2-0:1.0: 4 ports detected
[ 8.330897] tegra-xusb-padctl 7009f000.xusb_padctl: power on UTMI pads 1
[ 8.331104] usb usb2: usb_suspend_both: status 0
[ 8.554826] usb 1-2: new high-speed USB device number 2 using tegra-xusb
[ 8.593892] usb 1-2: New USB device found, idVendor=0bda, idProduct=5411
[ 8.593897] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 8.593901] usb 1-2: Product: 4-Port USB 2.1 Hub
[ 8.593905] usb 1-2: Manufacturer: Generic
[ 8.596575] hub 1-2:1.0: USB hub found
[ 8.597669] hub 1-2:1.0: 4 ports detected
[ 8.703911] usb 2-1: new SuperSpeed USB device number 2 using tegra-xusb
[ 8.739538] usb 2-1: New USB device found, idVendor=0bda, idProduct=0411
[ 8.739544] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 8.739548] usb 2-1: Product: 4-Port USB 3.1 Hub
[ 8.739551] usb 2-1: Manufacturer: Generic
[ 8.744164] hub 2-1:1.0: USB hub found
[ 8.745587] hub 2-1:1.0: 4 ports detected
[ 8.886810] usb 1-2.3: new full-speed USB device number 3 using tegra-xusb
[ 8.902807] usb 2-1: usb_suspend_both: status 0
[ 8.902986] usb usb2: usb_suspend_both: status 0
[ 8.917225] usb 1-2.3: New USB device found, idVendor=047f, idProduct=014c
[ 8.917231] usb 1-2.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 8.917235] usb 1-2.3: Product: Plantronics Calisto 3200
[ 8.917238] usb 1-2.3: Manufacturer: Plantronics
[ 8.917241] usb 1-2.3: SerialNumber: 6dc67eaff1db18ae9246b3fd4bf94220
[ 8.949852] usb 1-2.3: current rate 16000 is different from the runtime rate 48000
[ 9.279803] random: crng init done
[ 9.283211] random: 7 urandom warning(s) missed due to ratelimiting
[ 9.373156] using random self ethernet address
[ 9.377648] using random host ethernet address
[ 9.396826] Mass Storage Function, version: 2009/09/11
[ 9.396832] LUN: removable file: (no medium)
[ 9.401465] using random self ethernet address
[ 9.406043] using random host ethernet address
[ 9.418604] rndis0: HOST MAC ca:2b:42:45:1a:6c
[ 9.418657] rndis0: MAC ca:2b:42:45:1a:6d
[ 9.420273] usb0: HOST MAC ca:2b:42:45:1a:6e
[ 9.420407] usb0: MAC ca:2b:42:45:1a:6f
[ 9.420437] tegra-xudc-new 700d0000.xudc: ep 0 (type: 0, dir: out) enabled
[ 9.459971] l4tbr0: port 1(rndis0) entered blocking state
[ 9.459976] l4tbr0: port 1(rndis0) entered disabled state
[ 9.460127] device rndis0 entered promiscuous mode
[ 9.464868] IPv6: ADDRCONF(NETDEV_UP): rndis0: link is not ready
[ 9.468940] l4tbr0: port 2(usb0) entered blocking state
[ 9.468945] l4tbr0: port 2(usb0) entered disabled state
[ 9.469091] device usb0 entered promiscuous mode
[ 9.475018] IPv6: ADDRCONF(NETDEV_UP): usb0: link is not ready
[ 9.475025] l4tbr0: port 2(usb0) entered blocking state
[ 9.475028] l4tbr0: port 2(usb0) entered forwarding state
[ 9.715728] android_work: did not send uevent (0 0 (null))
[ 9.786544] android_work: sent uevent USB_STATE=CONNECTED
[ 9.845720] android_work: sent uevent USB_STATE=DISCONNECTED
[ 9.934634] android_work: sent uevent USB_STATE=CONNECTED
[ 9.936768] configfs-gadget gadget: high-speed config #1: c
[ 9.936797] tegra-xudc-new 700d0000.xudc: ep 5 (type: 3, dir: in) enabled
[ 9.936814] tegra-xudc-new 700d0000.xudc: ep 3 (type: 2, dir: in) enabled
[ 9.936829] tegra-xudc-new 700d0000.xudc: ep 2 (type: 2, dir: out) enabled
[ 9.936907] tegra-xudc-new 700d0000.xudc: ep 9 (type: 3, dir: in) enabled
[ 9.936922] tegra-xudc-new 700d0000.xudc: ep 7 (type: 2, dir: in) enabled
[ 9.936935] tegra-xudc-new 700d0000.xudc: ep 4 (type: 2, dir: out) enabled
[ 9.936963] tegra-xudc-new 700d0000.xudc: ep 15 (type: 3, dir: in) enabled
[ 9.936979] tegra-xudc-new 700d0000.xudc: ep 11 (type: 2, dir: in) enabled
[ 9.936998] tegra-xudc-new 700d0000.xudc: ep 6 (type: 2, dir: out) enabled
[ 9.937044] IPv6: ADDRCONF(NETDEV_CHANGE): rndis0: link becomes ready
[ 9.937124] l4tbr0: port 1(rndis0) entered blocking state
[ 9.937130] l4tbr0: port 1(rndis0) entered forwarding state
[ 9.937222] android_work: sent uevent USB_STATE=CONFIGURED
[ 9.945389] tegra-xudc-new 700d0000.xudc: ep 13 (type: 2, dir: in) enabled
[ 9.945405] tegra-xudc-new 700d0000.xudc: ep 8 (type: 2, dir: out) enabled
[ 9.945490] IPv6: ADDRCONF(NETDEV_CHANGE): usb0: link becomes ready
[ 12.846545] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 12.847880] eth0: 0xffffff800a35e000, 00:04:4b:e5:50:59, IRQ 404
[ 12.902007] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 13.859736] tegra-xusb 70090000.xusb: controller firmware hang
[ 13.865657] tegra-xusb 70090000.xusb: hcd_reinit is disabled or in progress
[ 35.199225] INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 35.202847] INFO: rcu_sched detected stalls on CPUs/tasks:
[ 35.202934] 2-…: (0 ticks this GP) idle=205/140000000000000/0 softirq=7476/7476 fqs=2531
[ 35.202947]
[ 35.202979] (detected by 0, t=5252 jiffies, g=233, c=232, q=833)
[ 35.202997] Task dump for CPU 2:
[ 35.203019] kworker/2:1 R
[ 35.203031] running task
[ 35.203058] 0 637 2 0x00000002
[ 35.203187] Workqueue: events xhci_handle_command_timeout
[ 35.203209] Call trace:
[ 35.203266] [] __switch_to+0x9c/0xc0
[ 35.203294] [] 0xffffffc0ecfec29c
[ 35.220679] 2-…: (0 ticks this GP) idle=205/140000000000000/0 softirq=7476/7476 fqs=2500
[ 35.229224] (detected by 3, t=5252 jiffies, g=730, c=729, q=18351)
[ 35.235644] Task dump for CPU 2:
[ 35.235669] kworker/2:1 R running task 0 637 2 0x00000002
[ 35.235832] Workqueue: events xhci_handle_command_timeout
[ 35.235872] Call trace:
[ 35.235928] [] __switch_to+0x9c/0xc0
[ 35.235963] [] 0xffffffc0ecfec29c
[ 36.263172] Watchdog detected hard LOCKUP on cpu 2
[ 36.263260] ------------[ cut here ]------------
[ 36.268140] WARNING: CPU: 1 PID: 0 at /dvs/git/dirty/git-master_linux/kernel/kernel-4.9/kernel/watchdog_hld.c:143 watchdog_check_hardlockup_other_cpu+0xf8/0x120
[ 36.282618] Modules linked in: overlay nvs nvgpu bluedroid_pm ip_tables x_tables
[ 36.282816] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.9.140-tegra #1
[ 36.282840] Hardware name: jetson-nano (DT)
[ 36.282870] task: ffffffc0fa7baa00 task.stack: ffffffc0fa7c8000
[ 36.282928] PC is at watchdog_check_hardlockup_other_cpu+0xf8/0x120
[ 36.282976] LR is at watchdog_check_hardlockup_other_cpu+0xf8/0x120
[ 36.283010] pc : [] lr : [] pstate: 604001c5
[ 36.283031] sp : ffffffc0fefecd20
[ 36.283055] x29: ffffffc0fefecd20 x28: ffffff800a134db8
[ 36.283115] x27: ffffff80097fb000 x26: ffffff800a134000
[ 36.283170] x25: ffffff8009e26000 x24: 0000000000000000
[ 36.283223] x23: 000000000000001e x22: ffffff8009e27000
[ 36.283275] x21: 0000000000000002 x20: ffffff8009e28c30
[ 36.283327] x19: ffffff80097fb760 x18: 0000000000000000
[ 36.283377] x17: 000000000000a44f x16: 0000000000000000
[ 36.283427] x15: ffffffffffffffff x14: ffffff800a104240
[ 36.283478] x13: ffffff800a103e86 x12: 0000000034d5d91d
[ 36.283528] x11: 000000000000000b x10: 0000000000000313
[ 36.283581] x9 : ffffff8009e44380 x8 : 6e6f2050554b434f
[ 36.283633] x7 : 0000000000000026 x6 : ffffff800a103146
[ 36.283684] x5 : 00ffffffffffffff x4 : 0000000000000006
[ 36.283735] x3 : 0000000000000000 x2 : 0000000000000000
[ 36.283784] x1 : ffffffc0fa7baa00 x0 : 0000000000000026
[ 36.283857] —[ end trace 28219bfc8a03479d ]—
[ 36.288578] Call trace:
[ 36.288642] [] watchdog_check_hardlockup_other_cpu+0xf8/0x120
[ 36.288693] [] watchdog_timer_fn+0x98/0x2c0
[ 36.288743] [] __hrtimer_run_queues+0xd8/0x360
[ 36.288784] [] hrtimer_interrupt+0xa8/0x1e0
[ 36.288834] [] tegra210_timer_isr+0x38/0x48
[ 36.288881] [] __handle_irq_event_percpu+0x68/0x288
[ 36.288920] [] handle_irq_event_percpu+0x28/0x60
[ 36.288958] [] handle_irq_event+0x50/0x80
[ 36.289003] [] handle_fasteoi_irq+0xc8/0x1b8
[ 36.289040] [] generic_handle_irq+0x34/0x50
[ 36.289076] [] __handle_domain_irq+0x68/0xc0
[ 36.289115] [] gic_handle_irq+0x5c/0xb0
[ 36.289152] [] el1_irq+0xe8/0x18c
[ 36.289211] [] cpuidle_enter_state+0xb8/0x380
[ 36.289260] [] cpuidle_enter+0x34/0x48
[ 36.289302] [] call_cpuidle+0x44/0x70
[ 36.289338] [] cpu_startup_entry+0x1b0/0x200
[ 36.289385] [] secondary_start_kernel+0x190/0x1f8
[ 36.289416] [<0000000080f441a4>] 0x80f441a4
[ 41.893917] tegra-xusb 70090000.xusb: Stopped the command ring failed, maybe the host is dead
[ 41.938817] tegra-xusb 70090000.xusb: Host not halted after 16000 microseconds.
[ 41.946114] tegra-xusb 70090000.xusb: Abort command ring failed
[ 41.963639] r8168: eth0: link up
[ 41.964030] tegra-xusb 70090000.xusb: Timeout while waiting for configure endpoint command
[ 41.972440] usb 1-2.3: Not enough bandwidth for altsetting 0
[ 41.972654] usb 1-2.3: Not enough bandwidth for altsetting 1
[ 41.972796] usb 1-2.3: 3:1: cannot set freq 16000 to ep 0x83
[ 41.978561] usb 1-2.3: Not enough bandwidth for altsetting 0
[ 41.978795] usb 1-2.3: 6:1: cannot get min/max values for control 2 (id 6)
[ 41.985857] tegra-xusb 70090000.xusb: HC died; cleaning up
[ 41.991528] tegra-xusb 70090000.xusb: hcd_reinit is disabled or in progress
[ 41.992031] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 41.994002] usb 1-2: USB disconnect, device number 2
[ 41.994010] usb 1-2.3: USB disconnect, device number 3
[ 41.995701] usb 2-1: USB disconnect, device number 2
[ 43.105092] tegradc tegradc.0: blank - powerdown
[ 43.105101] tegradc tegradc.1: blank - powerdown
[ 43.551095] tegradc tegradc.0: blank - powerdown
[ 43.551108] tegradc tegradc.1: blank - powerdown
[ 43.559175] tegradc tegradc.0: blank - powerdown
[ 44.034871] tegradc tegradc.0: blank - powerdown
[ 44.034880] tegradc tegradc.1: blank - powerdown
[ 47.218780] tegra-xusb 70090000.xusb: xHCI host not responding to stop endpoint command.
[ 47.226897] tegra-xusb 70090000.xusb: Assuming host is dying, halting host.
[ 47.276442] tegra-xusb 70090000.xusb: Host not halted after 16000 microseconds.
[ 47.283811] tegra-xusb 70090000.xusb: Non-responsive xHCI host is not halting.
[ 47.291047] tegra-xusb 70090000.xusb: Completing active URBs anyway.
[ 47.297546] tegra-xusb 70090000.xusb: HC died; cleaning up
[ 47.303049] tegra-xusb 70090000.xusb: hcd_reinit is disabled or in progress
raj@raj-jetson:~$