Firmware transaction timeout, then USB disconnect

[thetravellor]

Under normal use (I was watching netflix) the Raspberry Pi 5 running Raspberry Pi OS 64bit desktop throws and error as described from dmesg below and all USB HID devices disconnect. The device must be rebooted over SSH, or manually power cycled to become usable.

[49237.531668] input: Logitech USB Receiver System Control as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-1/3-1.4/3-1.4:1.1/0003:046D:C548.0014/input/input33
[49237.531739] hid-generic 0003:046D:C548.0014: input,hidraw1: USB HID v1.11 Mouse [Logitech USB Receiver] on usb-xhci-hcd.1-1.4/input1
[49237.537558] hid-generic 0003:046D:C548.0015: hiddev96,hidraw2: USB HID v1.11 Device [Logitech USB Receiver] on usb-xhci-hcd.1-1.4/input2
[49237.633834] input: "Drop" "ALT" as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-1/3-1.3/3-1.3.2/3-1.3.2:1.0/0003:04D8:EED3.0016/input/input34
[49237.696166] hid-generic 0003:04D8:EED3.0016: input,hidraw3: USB HID v1.10 Keyboard ["Drop" "ALT"] on usb-xhci-hcd.1-1.3.2/input0
[49237.697345] hid-generic 0003:04D8:EED3.0017: hiddev97,hidraw4: USB HID v1.10 Device ["Drop" "ALT"] on usb-xhci-hcd.1-1.3.2/input1
[49237.729005] input: "Drop" "ALT" Mouse as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-1/3-1.3/3-1.3.2/3-1.3.2:1.2/0003:04D8:EED3.0018/input/input35
[49237.729190] input: "Drop" "ALT" System Control as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-1/3-1.3/3-1.3.2/3-1.3.2:1.2/0003:04D8:EED3.0018/input/input36
[49237.787726] input: "Drop" "ALT" Consumer Control as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-1/3-1.3/3-1.3.2/3-1.3.2:1.2/0003:04D8:EED3.0018/input/input37
[49237.787924] input: "Drop" "ALT" Keyboard as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-1/3-1.3/3-1.3.2/3-1.3.2:1.2/0003:04D8:EED3.0018/input/input38
[49237.788443] hid-generic 0003:04D8:EED3.0018: input,hidraw5: USB HID v1.10 Mouse ["Drop" "ALT"] on usb-xhci-hcd.1-1.3.2/input2
[49530.169952] pcm512x 1-004c: No SCLK, using BCLK: -2
[50071.763851] ------------[ cut here ]------------
[50071.763860] Firmware transaction timeout
[50071.763878] WARNING: CPU: 3 PID: 203281 at drivers/firmware/raspberrypi.c:67 rpi_firmware_property_list+0x1dc/0x238
[50071.763893] Modules linked in: rfcomm snd_seq_dummy snd_hrtimer snd_seq snd_seq_device wireguard libchacha20poly1305 chacha_neon poly1305_neon ip6_udp_tunnel udp_tunnel libcurve25519_generic libchacha algif_hash algif_skcipher af_alg bnep binfmt_misc snd_soc_pcm512x_i2c snd_soc_pcm512x regmap_i2c spidev aes_ce_blk aes_ce_cipher ghash_ce gf128mul sha2_ce sha256_arm64 sha1_ce snd_soc_iqaudio_dac hci_uart btbcm raspberrypi_hwmon bluetooth vc4 sg ecdh_generic snd_soc_hdmi_codec drm_display_helper ecc cec joydev libaes drm_dma_helper designware_i2s i2c_brcmstb drm_kms_helper spi_bcm2835 snd_soc_core brcmfmac rpivid_hevc(C) snd_compress brcmutil snd_pcm_dmaengine pisp_be v4l2_mem2mem videobuf2_dma_contig videobuf2_memops snd_pcm cfg80211 videobuf2_v4l2 videobuf2_common fb_sys_fops snd_timer syscopyarea videodev sysfillrect v3d gpio_keys rfkill sysimgblt mc gpu_sched snd drm_shmem_helper pwm_fan rp1_adc i2c_designware_platform raspberrypi_gpiomem i2c_designware_core nvmem_rmem uio_pdrv_genirq
[50071.763992] uio i2c_dev drm dm_mod drm_panel_orientation_quirks fuse backlight ip_tables x_tables ipv6
[50071.764007] CPU: 3 PID: 203281 Comm: kworker/3:2 Tainted: G C 6.1.62-v8_16k+ #1697
[50071.764011] Hardware name: Raspberry Pi 5 Model B Rev 1.0 (DT)
[50071.764015] Workqueue: events dbs_work_handler
[50071.764022] pstate: 40400009 (nZcv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[50071.764025] pc : rpi_firmware_property_list+0x1dc/0x238
[50071.764029] lr : rpi_firmware_property_list+0x1dc/0x238
[50071.764033] sp : ffffc0000c17b9d0
[50071.764034] x29: ffffc0000c17b9d0 x28: ffffd0000d65eda8 x27: 00000000ffffff92
[50071.764039] x26: ffffc000084c8008 x25: ffff800063e30980 x24: 0000000000004000
[50071.764044] x23: 0000000000000018 x22: ffffd0000cf99cd8 x21: ffff800002511d00
[50071.764048] x20: ffffc000084c8000 x19: ffffd0000d65ecc0 x18: 0000000000000000
[50071.764053] x17: 0000000000000000 x16: 0000000000000000 x15: 00007fffa8e6dad8
[50071.764058] x14: 0000000000000000 x13: 74756f656d697420 x12: ffffd0000d54f7a8
[50071.764062] x11: 0000000000000003 x10: 0000000000000001 x9 : ffffd0000c0f57c4
[50071.764067] x8 : 0000000000017fe8 x7 : c0000000ffffefff x6 : ffffd0000d537768
[50071.764071] x5 : ffff8000ffd42a10 x4 : 0000000000000000 x3 : ffffb000f2bd0000
[50071.764076] x2 : ffff8000e31ed900 x1 : 47bd7b500da89000 x0 : 0000000000000000
[50071.764080] Call trace:
[50071.764081] rpi_firmware_property_list+0x1dc/0x238
[50071.764085] rpi_firmware_property+0x78/0x110
[50071.764088] raspberrypi_fw_set_rate+0x5c/0xd8
[50071.764093] clk_change_rate+0xdc/0x528
[50071.764096] clk_core_set_rate_nolock+0x1d0/0x230
[50071.764099] clk_set_rate+0x40/0xb0
[50071.764102] _opp_config_clk_single+0x38/0xb8
[50071.764107] _set_opp+0x154/0x360
[50071.764112] dev_pm_opp_set_rate+0x6c/0x190
[50071.764114] set_target+0x38/0x48
[50071.764119] __cpufreq_driver_target+0x184/0x2b8
[50071.764123] od_dbs_update+0xc0/0x1b0
[50071.764128] dbs_work_handler+0x48/0x80
[50071.764132] process_one_work+0x208/0x480
[50071.764138] worker_thread+0x50/0x428
[50071.764142] kthread+0x114/0x120
[50071.764146] ret_from_fork+0x10/0x20
[50071.764151] ---[ end trace 0000000000000000 ]---
[50071.764162] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110
[50073.423844] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[50073.423853] ieee80211 phy0: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST failed, err=-110
[50073.823835] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110
[50075.095887] xhci-hcd xhci-hcd.1: Abort failed to stop command ring: -110
[50075.116065] xhci-hcd xhci-hcd.1: xHCI host controller not responding, assume dead
[50075.116084] xhci-hcd xhci-hcd.1: HC died; cleaning up
[50075.119072] xhci-hcd xhci-hcd.1: Timeout waiting for reset device command
[50075.129489] usb 3-1: USB disconnect, device number 17
[50075.129510] usb 3-1.3: USB disconnect, device number 18
[50075.129515] usb 3-1.3.2: USB disconnect, device number 20
[50075.531823] usb 4-1: device not accepting address 8, error -22
[50075.531849] hub 4-1:1.0: set hub depth failed
[50075.592371] usb 3-1.4: USB disconnect, device number 19
[50075.639825] usb 4-1: Runtime PM usage count underflow!
[50075.639837] usb 4-1: USB disconnect, device number 8
stephencooper@five ~>

1. Disks

USB Samsung SSD

ive ~ [127]> lsblk
NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINTS
sda 8:0 0 931.5G 0 disk
├─sda1 8:1 0 512M 0 part /boot/firmware
└─sda2 8:2 0 931G 0 part /
mmcblk0 179:0 0 28.9G 0 disk
├─mmcblk0p1 179:1 0 512M 0 part /media/stephencooper/bootfs
└─mmcblk0p2 179:2 0 28.4G 0 part /media/stephencooper/rootfs

2. Computer

Raspberry Pi 5 4gb

3. HATS

IQAudio Dac Pro

4. Monitor

Benq Aorus 3140x2160 HDMI

5. uname -a
Linux five 6.1.62-v8_16k+ #1697 SMP PREEMPT Fri Nov 17 17:38:54 GMT 2023 aarch64 GNU/Linux

6. vcgencmd version
2023/10/30 16:45:10
Copyright (c) 2012 Broadcom
version 30de0ba5 (release) (embedded)
sudo rpi-eeprom-update
*** UPDATE AVAILABLE ***
BOOTLOADER: update available
   CURRENT: Mon 30 Oct 16:45:10 UTC 2023 (1698684310)
    LATEST: Mon 20 Nov 19:40:17 UTC 2023 (1700509217)
   RELEASE: default (/lib/firmware/raspberrypi/bootloader-2712/default)
            Use raspi-config to change the release.

7. vcgencmd bootloader_version
2023/10/30 16:45:10
version 30de0ba51efcdfe5aebfb3068e0d5278647611cc (release)
timestamp 1698684310
update-time 1700871030
capabilities 0x0000007f

[thetravellor (cooperstephenjames)]

Ive tried this also

sudo rpi-updtae
sudo: rpi-updtae: command not found
stephencooper@five ~ [1]> sudo rpi-update
 *** Raspberry Pi firmware updater by Hexxeh, enhanced by AndrewS and Dom
 *** Performing self-update
 *** Relaunching after update
 *** Raspberry Pi firmware updater by Hexxeh, enhanced by AndrewS and Dom
FW_REV:3ba5755e72052dc7c5232a8e2a65bb9b12692f8e
WANT_32BIT:0 WANT_64BIT:1 WANT_PI4:1 WANT_PI5:1
#############################################################
WARNING: This update bumps to rpi-6.1.y linux tree
See: https://forums.raspberrypi.com/viewtopic.php?t=344246

'rpi-update' should only be used if there is a specific
reason to do so - for example, a request by a Raspberry Pi
engineer or if you want to help the testing effort
and are comfortable with restoring if there are regressions.

DO NOT use 'rpi-update' as part of a regular update process.
##############################################################
Would you like to proceed? (y/N)
 *** Downloading specific firmware revision (this will take a few minutes)
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
  0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0
100 144M 100 144M 0 0 17.4M 0 0:00:08 0:00:08 --:--:-- 18.7M
 *** Updating firmware
 *** Updating kernel modules
 *** depmod 6.1.63-v8+
 *** depmod 6.1.63-v8-16k+
 *** Updating VideoCore libraries
 *** Using SoftFP libraries
 *** Updating SDK
 *** Running ldconfig
 *** Storing current firmware revision
 *** Deleting downloaded files
 *** Syncing changes to disk
 *** If no errors appeared, your firmware was successfully updated to 3ba5755e72052dc7c5232a8e2a65bb9b12692f8e
 *** A reboot is needed to activate the new firmware