Open qrp73 opened 7 months ago
We can't rule out this being a bug in the out-of-tree driver.
- What other hardware do you have attached, including any hubs?
USB sound DAC, keyboard, mouse, flash disk and RTLSDR dongle:
$ lsusb
Bus 002 Device 003: ID 0951:1666 Kingston Technology DataTraveler 100 G3/G4/SE9 G2/50 Kyson
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 007: ID 3302:3352 Synaptics CX31993 384Khz HIFI AUDIO
Bus 001 Device 006: ID 1c4f:0026 SiGma Micro Keyboard
Bus 001 Device 005: ID 046d:c051 Logitech, Inc. G3 (MX518) Optical Mouse
Bus 001 Device 010: ID 0bda:2838 Realtek Semiconductor Corp. RTL2838 DVB-T
Bus 001 Device 003: ID 214b:7250 Huasheng Electronics USB2.0 HUB
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
2. What are the power sources?
I'm using 15W Raspberry Pi PSU
3. What software is active? The GPU looks like it might be busy.
SDR++ it uses RTLSDR dongle
Are you saying that you are powering an external drive, a DAC, a keyboard & mouse, SDR dongle and a hub all from our 15W PSU?
The total power consumption is about 5-7W (the current is 1.0-1.2 Amps). I don't use external drive, I'm using flash disk Kingston DataTraveler Kyson (flash dongle).
I think you are pushing at the limits of what the Pi can power. If you can continue to see these random disconnection when the SDR dongle and flash drive are connected via a powered hub then I'll be more interested.
BTW, I don't make a drive <-> flash distinction - your flash dongle is my flash drive. If I'd said hard drive then you'd have a point.
This issue is not related to power at all and don't related to flash drive. I can approve it 100%. I'm sure that this is software issue.
This issue happens when total power consumption of RPI + all devices don't exceeds 1 Amp (5 Watt), while power supply is genuine 15W and can provide much more power with no issue.
Undervoltage flag is not raised after this issue. I just caught it again:
$ vcgencmd measure_temp pmic && vcgencmd measure_temp && vcgencmd get_throttled && vcgencmd get_config arm_freq && vcgencmd get_config gpu_freq
temp=37.4'C
temp=39.9'C
throttled=0x0
arm_freq=2100
gpu_freq=700
This time it happens with no flash disk connected:
$ lsusb
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 013: ID 3302:3352 Synaptics CX31993 384Khz HIFI AUDIO
Bus 001 Device 012: ID 1c4f:0026 SiGma Micro Keyboard
Bus 001 Device 011: ID 046d:c051 Logitech, Inc. G3 (MX518) Optical Mouse
Bus 001 Device 010: ID 0bda:2838 Realtek Semiconductor Corp. RTL2838 DVB-T
Bus 001 Device 009: ID 214b:7250 Huasheng Electronics USB2.0 HUB
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Here is log file, now it has some new records:
[14291.140700] swiotlb_tbl_map_single: 2 callbacks suppressed
[14291.140715] vc4-drm gpu: swiotlb buffer is full (sz: 421888 bytes), total 32768 (slots), used 156 (slots)
[17394.959312] usb 1-1.4: USB disconnect, device number 3
[17394.959351] usb 1-1.4.1: USB disconnect, device number 4
[17394.963358] usb 1-1.4.4: Unable to submit urb #0: -19 at snd_usb_queue_pending_output_urbs
[17394.964555] usb 1-1.4.2: USB disconnect, device number 8
[17394.968800] usb 1-1.4.4: cannot submit urb 0, error -19: no device
[17394.968823] usb 1-1.4.4: cannot submit urb 0, error -19: no device
[17395.022986] usb 1-1.4.3: USB disconnect, device number 6
[17395.093998] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[17395.336032] usb 1-1.4.4: USB disconnect, device number 7
[17395.636789] usb 1-1.4: new high-speed USB device number 9 using xhci_hcd
[17395.717025] usb 1-1.4: device descriptor read/64, error -71
[17395.929166] usb 1-1.4: New USB device found, idVendor=214b, idProduct=7250, bcdDevice= 1.00
[17395.929184] usb 1-1.4: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[17395.929188] usb 1-1.4: Product: USB2.0 HUB
[17395.930439] hub 1-1.4:1.0: USB hub found
[17395.930546] hub 1-1.4:1.0: 4 ports detected
[17396.220782] usb 1-1.4.1: new high-speed USB device number 10 using xhci_hcd
[17396.332582] usb 1-1.4.1: New USB device found, idVendor=0bda, idProduct=2838, bcdDevice= 1.00
[17396.332599] usb 1-1.4.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[17396.332603] usb 1-1.4.1: Product: RTL2838UHIDIR
[17396.332607] usb 1-1.4.1: Manufacturer: Realtek
[17396.332610] usb 1-1.4.1: SerialNumber: 00000003
[17396.424783] usb 1-1.4.2: new low-speed USB device number 11 using xhci_hcd
[17396.533074] usb 1-1.4.2: New USB device found, idVendor=046d, idProduct=c051, bcdDevice=30.00
[17396.533093] usb 1-1.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[17396.533097] usb 1-1.4.2: Product: USB-PS/2 Optical Mouse
[17396.533100] usb 1-1.4.2: Manufacturer: Logitech
[17396.545409] input: Logitech USB-PS/2 Optical Mouse as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.2/1-1.4.2:1.0/0003:046D:C051.0006/input/input8
[17396.545737] hid-generic 0003:046D:C051.0006: input,hidraw0: USB HID v1.10 Mouse [Logitech USB-PS/2 Optical Mouse] on usb-0000:01:00.0-1.4.2/input0
[17396.624772] usb 1-1.4.3: new low-speed USB device number 12 using xhci_hcd
[17396.733082] usb 1-1.4.3: New USB device found, idVendor=1c4f, idProduct=0026, bcdDevice= 1.10
[17396.733101] usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[17396.733105] usb 1-1.4.3: Product: USB Keyboard
[17396.733108] usb 1-1.4.3: Manufacturer: SIGMACHIP
[17396.741735] input: SIGMACHIP USB Keyboard as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.3/1-1.4.3:1.0/0003:1C4F:0026.0007/input/input9
[17396.801191] hid-generic 0003:1C4F:0026.0007: input,hidraw1: USB HID v1.10 Keyboard [SIGMACHIP USB Keyboard] on usb-0000:01:00.0-1.4.3/input0
[17396.806861] input: SIGMACHIP USB Keyboard Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.3/1-1.4.3:1.1/0003:1C4F:0026.0008/input/input10
[17396.869512] input: SIGMACHIP USB Keyboard System Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.3/1-1.4.3:1.1/0003:1C4F:0026.0008/input/input11
[17396.869723] hid-generic 0003:1C4F:0026.0008: input,hidraw2: USB HID v1.10 Device [SIGMACHIP USB Keyboard] on usb-0000:01:00.0-1.4.3/input1
[17396.948788] usb 1-1.4.4: new high-speed USB device number 13 using xhci_hcd
[17397.066503] usb 1-1.4.4: New USB device found, idVendor=3302, idProduct=3352, bcdDevice= 0.01
[17397.066521] usb 1-1.4.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[17397.066526] usb 1-1.4.4: Product: CX31993 384Khz HIFI AUDIO
[17397.066529] usb 1-1.4.4: Manufacturer: Synaptics
[17397.107052] input: Synaptics CX31993 384Khz HIFI AUDIO Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.4/1-1.4.4:1.2/0003:3302:3352.0009/input/input12
[17397.165336] hid-generic 0003:3302:3352.0009: input,hidraw3: USB HID v1.11 Device [Synaptics CX31993 384Khz HIFI AUDIO] on usb-0000:01:00.0-1.4.4/input2
If you want I can connect lab power supply and attach DMM in CREST mode to detect max and min peak voltage spikes until issue heappens again. But since it is powered with genuine 15W raspberry pi PSU which can provide 3 Amps and actual power consumption is just 1 Amp and there is no undervoltage event flag, this is already clean indication that power is absolutely ok and there is no power issue.
I'm sure for 100% that there is no power limit issue and voltage didn't drop below 5.1V
Previously exactly the same hardware worked well with no issue for a very long time. The only changes are apt upgrade and replace osmocom rtlsdr driver with self compiled rtl-sdr-blog driver.
I suspect it may be related with rtl-sdr-blog driver, I will check it. But this issue happens for all USB devices connected to RPI. I think that running SDR software just increase probability to catch this issue due to many data transfering over USB.
just compared code changes in rtl-sdr-blog and there is nothing suspicious that can raise such issue with all USB devices disconnect.
So, the only root of cause for this issue is a bug in the driver for RPI 4B onboard VIA USB hub. Please fix it, because it happens very often.
I installed original oscmocom driver. After some time I caught this error:
[23575.022834] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 114 (slots)
[23575.380085] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 28 (slots)
[23575.679105] vc4-drm gpu: swiotlb buffer is full (sz: 401408 bytes), total 32768 (slots), used 2 (slots)
[26879.717956] usb 1-1.4.1: USB disconnect, device number 8
[26879.942508] usb 1-1.4.1: new high-speed USB device number 9 using xhci_hcd
[26880.022624] usb 1-1.4.1: device descriptor read/64, error -71
[26880.246600] usb 1-1.4.1: New USB device found, idVendor=0bda, idProduct=2838, bcdDevice= 1.00
[26880.246623] usb 1-1.4.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[26880.246628] usb 1-1.4.1: Product: RTL2838UHIDIR
[26880.246729] usb 1-1.4.1: Manufacturer: Realtek
[26880.246732] usb 1-1.4.1: SerialNumber: 00000003
[29073.904399] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 18 (slots)
[29073.912103] vc4-drm gpu: swiotlb buffer is full (sz: 294912 bytes), total 32768 (slots), used 2 (slots)
it happens when SDR app is not worked and RTLSDR didn't used. Two processes was running: VLC in minimized state playing internet radio and my lightweight OpenGL game. So, it can happens even when USB device is not used...
I run sdr-trunk with my RTL-SDR on my pi5 and do not have any disconnects. It will disconnect if I do not have some modules that are recommended to be blacklisted.
https://sdr-enthusiasts.gitbook.io/ads-b/setting-up-rtl-sdrs/blacklist-kernel-modules
it continue happens, just got this,
[23183.652879] usb 1-1.4: USB disconnect, device number 3
[23183.652899] usb 1-1.4.1: USB disconnect, device number 4
[23183.654197] usb 1-1.4.4: Unable to submit urb #2: -19 at snd_usb_queue_pending_output_urbs
[23183.654318] usb 1-1.4.2: USB disconnect, device number 5
[23183.658684] usb 1-1.4.4: cannot submit urb 0, error -19: no device
[23183.658717] usb 1-1.4.4: cannot submit urb 0, error -19: no device
[23183.659645] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.662058] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.662092] usb 1-1.4.4: uac_clock_source_is_valid(): cannot get clock validity for id 9
[23183.662101] usb 1-1.4.4: clock source 9 is not valid, cannot use
[23183.662112] usb 1-1.4.4: 1:1: cannot get freq (v2/v3): err -19
[23183.662123] usb 1-1.4.4: 1:1: cannot set freq 48000 (v2/v3): err -19
[23183.662885] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.663669] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.663694] usb 1-1.4.4: uac_clock_source_is_valid(): cannot get clock validity for id 9
[23183.663702] usb 1-1.4.4: clock source 9 is not valid, cannot use
[23183.663712] usb 1-1.4.4: 1:1: cannot get freq (v2/v3): err -19
[23183.663723] usb 1-1.4.4: 1:1: cannot set freq 48000 (v2/v3): err -19
[23183.664371] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.665038] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.665055] usb 1-1.4.4: uac_clock_source_is_valid(): cannot get clock validity for id 9
[23183.665063] usb 1-1.4.4: clock source 9 is not valid, cannot use
[23183.665072] usb 1-1.4.4: 1:1: cannot get freq (v2/v3): err -19
[23183.665082] usb 1-1.4.4: 1:1: cannot set freq 48000 (v2/v3): err -19
[23183.665683] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.666686] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.666708] usb 1-1.4.4: uac_clock_source_is_valid(): cannot get clock validity for id 9
[23183.666715] usb 1-1.4.4: clock source 9 is not valid, cannot use
[23183.666724] usb 1-1.4.4: 1:1: cannot get freq (v2/v3): err -19
[23183.666734] usb 1-1.4.4: 1:1: cannot set freq 48000 (v2/v3): err -19
[23183.667394] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.668363] usb 1-1.4.4: 1:0: usb_set_interface failed (-19)
[23183.668380] usb 1-1.4.4: uac_clock_source_is_valid(): cannot get clock validity for id 9
[23183.668387] usb 1-1.4.4: clock source 9 is not valid, cannot use
[23183.668396] usb 1-1.4.4: 1:1: cannot get freq (v2/v3): err -19
[23183.668405] usb 1-1.4.4: 1:1: cannot set freq 48000 (v2/v3): err -19
[23183.706723] usb 1-1.4.3: USB disconnect, device number 6
[23183.986758] usb 1-1.4.4: USB disconnect, device number 7
[23184.302649] usb 1-1.4: new high-speed USB device number 8 using xhci_hcd
[23184.402974] usb 1-1.4: New USB device found, idVendor=214b, idProduct=7250, bcdDevice= 1.00
[23184.402989] usb 1-1.4: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[23184.402993] usb 1-1.4: Product: USB2.0 HUB
[23184.404176] hub 1-1.4:1.0: USB hub found
[23184.404293] hub 1-1.4:1.0: 4 ports detected
[23184.690659] usb 1-1.4.1: new high-speed USB device number 9 using xhci_hcd
[23184.802284] usb 1-1.4.1: New USB device found, idVendor=0bda, idProduct=2838, bcdDevice= 1.00
[23184.802298] usb 1-1.4.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[23184.802302] usb 1-1.4.1: Product: RTL2838UHIDIR
[23184.802305] usb 1-1.4.1: Manufacturer: Realtek
[23184.802308] usb 1-1.4.1: SerialNumber: 00000003
[23184.891218] usb 1-1.4.2: new low-speed USB device number 10 using xhci_hcd
[23184.998609] usb 1-1.4.2: New USB device found, idVendor=046d, idProduct=c051, bcdDevice=30.00
[23184.998623] usb 1-1.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[23184.998627] usb 1-1.4.2: Product: USB-PS/2 Optical Mouse
[23184.998630] usb 1-1.4.2: Manufacturer: Logitech
[23185.006514] input: Logitech USB-PS/2 Optical Mouse as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.2/1-1.4.2:1.0/0003:046D:C051.0005/input/input7
[23185.006912] hid-generic 0003:046D:C051.0005: input,hidraw0: USB HID v1.10 Mouse [Logitech USB-PS/2 Optical Mouse] on usb-0000:01:00.0-1.4.2/input0
[23185.086669] usb 1-1.4.3: new low-speed USB device number 11 using xhci_hcd
[23185.198893] usb 1-1.4.3: New USB device found, idVendor=1c4f, idProduct=0026, bcdDevice= 1.10
[23185.198909] usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[23185.198913] usb 1-1.4.3: Product: USB Keyboard
[23185.198916] usb 1-1.4.3: Manufacturer: SIGMACHIP
[23185.205333] input: SIGMACHIP USB Keyboard as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.3/1-1.4.3:1.0/0003:1C4F:0026.0006/input/input8
[23185.263278] hid-generic 0003:1C4F:0026.0006: input,hidraw1: USB HID v1.10 Keyboard [SIGMACHIP USB Keyboard] on usb-0000:01:00.0-1.4.3/input0
[23185.268893] input: SIGMACHIP USB Keyboard Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.3/1-1.4.3:1.1/0003:1C4F:0026.0007/input/input9
[23185.326910] input: SIGMACHIP USB Keyboard System Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.3/1-1.4.3:1.1/0003:1C4F:0026.0007/input/input10
[23185.327054] hid-generic 0003:1C4F:0026.0007: input,hidraw2: USB HID v1.10 Device [SIGMACHIP USB Keyboard] on usb-0000:01:00.0-1.4.3/input1
[23185.406668] usb 1-1.4.4: new high-speed USB device number 12 using xhci_hcd
[23185.530811] usb 1-1.4.4: New USB device found, idVendor=3302, idProduct=3352, bcdDevice= 0.01
[23185.530833] usb 1-1.4.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[23185.530837] usb 1-1.4.4: Product: CX31993 384Khz HIFI AUDIO
[23185.530840] usb 1-1.4.4: Manufacturer: Synaptics
[23185.561236] input: Synaptics CX31993 384Khz HIFI AUDIO Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.4/1-1.4.4:1.3/0003:3302:3352.0008/input/input11
[23185.622945] hid-generic 0003:3302:3352.0008: input,hidraw3: USB HID v1.11 Device [Synaptics CX31993 384Khz HIFI AUDIO] on usb-0000:01:00.0-1.4.4/input3
I'm not sure, is it possible that this issue happens due to bad support for my USB hub? I'm using this one: https://www.aliexpress.com/item/1005005802405660.html
Previously it worked ok, it starts to happens with some apt update, about month ago or something like that.
I think I'm also having this issue - it just recently with octopi. Redeployed the OS (which upgraded from buster to bullseye) and it still occurs. Seemed to happen after a software update, but can't pinpoint it.
Apr 28 19:46:22 octopi octoprint[381]: #033[31m2024-04-28 19:46:22,581 - octoprint.util.comm - ERROR - Unexpected error while reading from serial port#033[0m
<snip - octoprint erroring>
Apr 28 19:46:22 octopi kernel: [104977.139592] usb 1-1.4: new full-speed USB device number 4 using xhci_hcd
Apr 28 19:46:23 octopi kernel: [104977.285271] usb 1-1.4: New USB device found, idVendor=2c99, idProduct=0002, bcdDevice= 1.30
Apr 28 19:46:23 octopi kernel: [104977.285285] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Apr 28 19:46:23 octopi kernel: [104977.285291] usb 1-1.4: Product: Original Prusa i3 MK3
Apr 28 19:46:23 octopi kernel: [104977.285297] usb 1-1.4: Manufacturer: Prusa Research (prusa3d.com)
Apr 28 19:46:23 octopi kernel: [104977.285302] usb 1-1.4: SerialNumber: CZPX0220X004XK65618
Apr 28 19:46:23 octopi kernel: [104977.288606] cdc_acm 1-1.4:1.0: ttyACM0: USB ACM device
It start to happens last week. First I thought this is just random disconnection, but now this error happens for at least 4 times, so there is something wrong...
I'm using rtl-sdr-blog driver for RTLSDR dongle. It works for some long time, but then unexpectedly disconnected and immediately connected again.
I'm using RPI 4B with VIA USB chip, and previously there was issue in VIA chip driver which prevented normal function for xhci_hcd USB device drivers. It was fixed, but it seems that still something going wrong.
Also I notice strange full system halt with no log records and no way to connect through ssh. It already happens two times. And it started to happens after last updates.
It may be related to this issue: https://github.com/raspberrypi/bookworm-feedback/issues/83
Steps to reproduce the behaviour
1) Connect RTLSDR dongle 2) Install rtl-sdr-blog driver 3) Run SDR++ or other SDR application and wait for a bug. It may take a long time, several hours or something like that.
Device (s)
Raspberry Pi 4 Mod. B
System
Logs
Additional context
No response