Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

usb_serial_generic_read_bulk_callback - urb stopped: -32 (on bullseye) #5541

Closed
mgrouch opened this issue Jul 14, 2023 · 14 comments
Closed

usb_serial_generic_read_bulk_callback - urb stopped: -32 (on bullseye) #5541

mgrouch opened this issue Jul 14, 2023 · 14 comments

Comments

@mgrouch
Copy link

mgrouch commented Jul 14, 2023

Describe the bug


[   14.719713] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
[   14.722708] bcmgenet fd580000.ethernet eth0: Link is Down
[   18.647145] Bluetooth: Core ver 2.22
[   18.647252] NET: Registered PF_BLUETOOTH protocol family
[   18.647258] Bluetooth: HCI device and connection manager initialized
[   18.647275] Bluetooth: HCI socket layer initialized
[   18.647284] Bluetooth: L2CAP socket layer initialized
[   18.647298] Bluetooth: SCO socket layer initialized
[   18.655642] Bluetooth: HCI UART driver ver 2.3
[   18.655672] Bluetooth: HCI UART protocol H4 registered
[   18.655763] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   18.655956] Bluetooth: HCI UART protocol Broadcom registered
[   18.814494] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[   18.814542] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   19.093818] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   19.099946] Bluetooth: BNEP filters: protocol multicast
[   19.099978] Bluetooth: BNEP socket layer initialized
[   19.120661] Bluetooth: MGMT ver 1.22
[   19.140521] NET: Registered PF_ALG protocol family
[   21.890450] Bluetooth: RFCOMM TTY layer initialized
[   21.890485] Bluetooth: RFCOMM socket layer initialized
[   21.890513] Bluetooth: RFCOMM ver 1.11
[   28.585253] rfkill: input handler disabled
[   38.897875] input: Simulated Right Button as /devices/virtual/input/input8
[   86.301768] can: controller area network core
[   86.301909] NET: Registered PF_CAN protocol family
[   86.328507] can: raw protocol
[   90.539304] v3d fec00000.v3d: MMU error from client CLE (4) at 0xce61000, pte invalid
[  441.771555] ch341-uart ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[  707.566140] ftdi_sio ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
[ 1006.500017] ch341-uart ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[ 1322.843036] ftdi_sio ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32

Steps to reproduce the behaviour

Plugin USB to serial with FTDI chipset

Device (s)

Raspberry Pi 4 Mod. B

System

user@lysmarine:~ $ cat /etc/rpi-issue
Raspberry Pi reference 2023-05-03
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 7c750947a959fb626a70c09fd17c65815df192ac, stage2

user@lysmarine:~ $ vcgencmd version
Mar 17 2023 10:51:33 
Copyright (c) 2012 Broadcom
version 82f3750a65fadae9a38077e3c2e217ad158c8d54 (clean) (release) (start_x)

user@lysmarine:~ $ uname -a
Linux lysmarine 6.1.21-v8+ #1642 SMP PREEMPT Mon Apr  3 17:24:16 BST 2023 aarch64 GNU/Linux

Logs

No response

Additional context

No response
@mgrouch
Copy link
Author

mgrouch commented Jul 14, 2023 •
edited
Loading

After that it seems Linux rebuilds

/dev/tty*

devices and all programs that have them open
stop reading them.

It happens too often on various systems.
it didn’t happen in late buster versions.

It seems there is something not quite right with usb subsystem in bullseye (at least on arm64)

I see resets of usb ports followed by
rebuild of /dev/ttyUSB*

and programs using usb stopping working.

In some cases mouse stops working.
keyboard.

Serial to usb adapters. USB thumb drives.

I’m not convinced it’s power supply issue as it happens in rather different set ups with different hardware.

nothing is plugged or unplugged when this happens.

Any ideas?

thanks

@mgrouch mgrouch mentioned this issue Jul 14, 2023
Closed
@P33M
Copy link
Contributor

P33M commented Jul 14, 2023

What's the output of sudo setpci -s 01:00.0 0x50.L?

@mgrouch
Copy link
Author

mgrouch commented Jul 14, 2023

@P33M

user@lysmarine:~ $ sudo setpci -s 01:00.0 0x50.L
000138a1

@mgrouch
Copy link
Author

mgrouch commented Jul 14, 2023

I've updated bootloader now using raspi-config and it updated vl805 firmware as well.
However same issue happens even with 000138c0 firmware.

user@lysmarine:~ $ sudo rpi-eeprom-update
BOOTLOADER: up to date
   CURRENT: Thu 11 May 06:26:03 UTC 2023 (1683786363)
    LATEST: Thu 11 May 06:26:03 UTC 2023 (1683786363)
   RELEASE: stable (/lib/firmware/raspberrypi/bootloader/stable)
            Use raspi-config to change the release.

  VL805_FW: Using bootloader EEPROM
     VL805: up to date
   CURRENT: 000138c0
    LATEST: 000138c0


[   19.703904] NET: Registered PF_BLUETOOTH protocol family
[   19.703911] Bluetooth: HCI device and connection manager initialized
[   19.703936] Bluetooth: HCI socket layer initialized
[   19.703948] Bluetooth: L2CAP socket layer initialized
[   19.703967] Bluetooth: SCO socket layer initialized
[   19.724199] Bluetooth: HCI UART driver ver 2.3
[   19.724225] Bluetooth: HCI UART protocol H4 registered
[   19.724309] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   19.724521] Bluetooth: HCI UART protocol Broadcom registered
[   20.246129] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   20.246152] Bluetooth: BNEP filters: protocol multicast
[   20.246169] Bluetooth: BNEP socket layer initialized
[   20.255947] Bluetooth: MGMT ver 1.22
[   20.279120] NET: Registered PF_ALG protocol family
[   21.955686] Bluetooth: RFCOMM TTY layer initialized
[   21.955747] Bluetooth: RFCOMM socket layer initialized
[   21.955776] Bluetooth: RFCOMM ver 1.11
[   28.029390] rfkill: input handler disabled
[   36.758046] input: Simulated Right Button as /devices/virtual/input/input8
[  551.148870] ftdi_sio ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
[  990.191928] ch341-uart ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[ 1151.025592] ch341-uart ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32

@mgrouch
Copy link
Author

mgrouch commented Jul 14, 2023

Is this related?
#5088

@mgrouch
Copy link
Author

mgrouch commented Jul 14, 2023 •
edited
Loading

I have replaced powered usb hub, usb cable, power supply to usb hub and same issues persist.

When I plugin the device raising errors into pi4 USB 2.0 socket, it works without errors.

Any ideas?
Thanks

@mgrouch
Copy link
Author

mgrouch commented Jul 20, 2023

On DeskPi Pro I've added (required to enable front usb ports)

dtoverlay=dwc2,dr_mode=host

into /boot/config.txt

I'm still seeing same issues, plus additional messages in dmesg:

[   19.936921] NET: Registered PF_ALG protocol family
[   23.339387] Bluetooth: RFCOMM TTY layer initialized
[   23.339438] Bluetooth: RFCOMM socket layer initialized
[   23.339489] Bluetooth: RFCOMM ver 1.11
[   30.267848] rfkill: input handler disabled
[   38.679180] input: Simulated Right Button as /devices/virtual/input/input7
[  112.682330] ftdi_sio ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
[  313.620738] can: controller area network core
[  313.620879] NET: Registered PF_CAN protocol family
[  313.637916] can: raw protocol
[  492.142560] ftdi_sio ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
[  578.254156] ftdi_sio ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[  890.675568] usb 2-2: reset SuperSpeed USB device number 3 using xhci_hcd
[ 1375.701343] ftdi_sio ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[ 2973.216132] ftdi_sio ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[ 3142.049230] ftdi_sio ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[14963.478115] usb 2-2: reset SuperSpeed USB device number 3 using xhci_hcd
[23378.440266] usb 2-2: reset SuperSpeed USB device number 3 using xhci_hcd
[23643.465924] usb 2-2: reset SuperSpeed USB device number 3 using xhci_hcd
[34882.165694] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[34890.269745] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[34901.506306] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[34912.798986] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[34937.546128] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[34955.326010] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[34958.525291] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[34979.965547] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[34995.038841] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[34999.869881] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35016.510616] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35030.461820] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35042.814884] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35055.679424] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35057.278018] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35070.110144] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35074.942099] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35088.926263] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35090.526342] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35094.847391] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35103.947440] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35123.199777] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35129.727907] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35162.431256] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35171.046898] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35178.095501] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35179.711000] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35193.664411] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35209.663208] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35221.983239] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35232.255360] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35255.841360] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35256.940544] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35263.967972] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35279.967611] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35287.521029] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35309.504550] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35322.303773] ftdi_sio ttyUSB1: usb_serial_generic_write_bulk_callback - nonzero urb status: -71
[35327.131968] ftdi_sio ttyUSB0: usb_serial_generic_write_bulk_callback - nonzero urb status: -71

@mgrouch
Copy link
Author

mgrouch commented Jul 21, 2023 •
edited
Loading

I think (hope) I've found something.
I use deskpi-pro and installed its drivers.

I noticed that /dev/ttyUSB0 is opened by a process called pwmFanControl64.

ttyUSB0 is FTDI USB to serial adapter which has nothing to do with deskpi pro!
Absolutely unrelated device.


lrwxrwxrwx  1 root root          7 Jul 21 01:33 /dev/ttyLYS_ftdi_AO009078 -> ttyUSB0


user@lysmarine:~ $ sudo lsof /dev/ttyUSB0
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
      Output information may be incomplete.
lsof: WARNING: can't stat() fuse.portal file system /run/user/1000/doc
      Output information may be incomplete.
COMMAND    PID USER   FD   TYPE DEVICE SIZE/OFF NODE NAME
pwmFanCon 1509 root    3u   CHR  188,0      0t0  442 /dev/ttyUSB0

I think it was sending fan control commands into it without checking what device is on that port. And that was overflowing some buffers because nothing reads from that port at the moment. Not sure why second FTDI device on separate /dev/ttyUSB1 port was affected too though.

I've opened related issue:

DeskPi-Team/deskpi#153

@mgrouch
Copy link
Author

mgrouch commented Jul 21, 2023

After I solved this issue with /dev/ttyUSB0

the issue with /dev/ttyUSB1 still exists:

[   43.398293] v3d fec00000.v3d: MMU error from client L2T (0) at 0x2f81000, pte invalid
[  194.413859] ftdi_sio ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[  229.132963] ftdi_sio ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[ 1053.793620] usb 2-2: reset SuperSpeed USB device number 3 using xhci_hcd
[ 2281.686171] usb 2-2: reset SuperSpeed USB device number 3 using xhci_hcd

serial device is getting reset and rebuilt

in my case the process that reads it is SignalK 2.0.0 (https://signalk.org/):

user@lysmarine:~ $ sudo lsof /dev/ttyUSB1
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
      Output information may be incomplete.
lsof: WARNING: can't stat() fuse.portal file system /run/user/1000/doc
      Output information may be incomplete.
COMMAND  PID    USER   FD   TYPE DEVICE SIZE/OFF NODE NAME
node    1063 signalk   51uW  CHR  188,1      0t0  453 /dev/ttyUSB1

which is NodeJs program which reads serial using NodeJs serialport (version 11)

https://www.npmjs.com/package/serialport

and after that parses data using CanboatJS
(non native JS version using C canboat leads to the same error)

@mgrouch
Copy link
Author

mgrouch commented Jul 21, 2023

Another program which was messing it up turned out to be

autoadb (https://github.com/rom1v/autoadb)

which I was starting at desktop startup as:

autoadb scrcpy -s '{}'

After I disabled it my USB errors seem disapeared.

Thanks

@pelwell
Copy link
Contributor

pelwell commented Jul 21, 2023

So you'll be closing this issue then?

@mgrouch
Copy link
Author

mgrouch commented Jul 21, 2023

I think it can be closed

@mgrouch mgrouch closed this as completed Jul 21, 2023
@mgrouch
Copy link
Author

mgrouch commented Jul 21, 2023

Why it only happened with USB 3.0 ports?
If I plug into USB 2.0 it worked.
Could it be still bug in kernel for USB 3.0 support?
Thanks

@P33M
Copy link
Contributor

P33M commented Jul 21, 2023

There is no electrical difference between the USB3.0 and 2.0 ports as far as USB full-speed hardware is concerned - they both connect to the same hub, and ignore the USB3.0 pairs.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@P33M @mgrouch @pelwell