USB devices and PCIe "freeze", lsusb -t hangs

0

I have a PC running RaspbianOS (I have to) that has a PCIe card connected to it, the PCIe card has 4 USB controllers for 4 ports(StarTech PEXUSB3S44V).

I have a Sipolar industrial 10 port USB hub connected to 1 port and then I connect 10 Huawei 4G USB modems to the hub. I reboot all of the modems every minute using a script I wrote, using their WebUI.

When I connect the hub into 1 particular port, it works flawlessly, however, when I connect the hub to a different port, some modems disappear after a few hours (around 20) of rebooting.

This is the part in my /var/log/messages that stands out since it never appears for 20 hours and after it appears some of the modems never come back again.

Jun 15 20:15:21 raspberry root: usb_modeswitch: switched to 12d1:14dc on 007/054
Jun 15 20:15:22 raspberry kernel: [103515.410586] scsi 12:0:0:0: Direct-Access     HUAWEI   TF CARD Storage  2.31 PQ: 0 ANSI: 2
Jun 15 20:15:22 raspberry kernel: [103515.410804] sd 12:0:0:0: Attached scsi generic sg7 type 0
Jun 15 20:15:22 raspberry kernel: [103515.411063] sd 12:0:0:0: Power-on or device reset occurred
Jun 15 20:15:22 raspberry kernel: [103515.411777] sd 12:0:0:0: [sdh] Attached SCSI removable disk
Jun 15 20:16:01 raspberry kernel: [103553.992762] kworker/2:1     D    0 20394      2 0x80000000
Jun 15 20:16:01 raspberry kernel: [103553.992796] Workqueue: usb_hub_wq hub_event [usbcore]
Jun 15 20:16:01 raspberry kernel: [103553.992799] Call Trace:
Jun 15 20:16:01 raspberry kernel: [103553.992812]  ? __schedule+0x2a2/0x870
Jun 15 20:16:01 raspberry kernel: [103553.992818]  schedule+0x28/0x80
Jun 15 20:16:01 raspberry kernel: [103553.992824]  schedule_preempt_disabled+0xa/0x10
Jun 15 20:16:01 raspberry kernel: [103553.992830]  __mutex_lock.isra.8+0x2b5/0x4a0
Jun 15 20:16:01 raspberry kernel: [103553.992837]  disk_block_events+0x2c/0x90
Jun 15 20:16:01 raspberry kernel: [103553.992842]  del_gendisk+0x37/0x2e0
Jun 15 20:16:01 raspberry kernel: [103553.992850]  sd_remove+0x5d/0xd0 [sd_mod]
Jun 15 20:16:01 raspberry kernel: [103553.992860]  device_release_driver_internal+0x183/0x250
Jun 15 20:16:01 raspberry kernel: [103553.992866]  bus_remove_device+0xe5/0x150
Jun 15 20:16:01 raspberry kernel: [103553.992871]  device_del+0x164/0x380
Jun 15 20:16:01 raspberry kernel: [103553.992876]  ? mutex_lock+0xe/0x30
Jun 15 20:16:01 raspberry kernel: [103553.992904]  ? ata_tlink_match+0x30/0x30 [libata]
Jun 15 20:16:01 raspberry kernel: [103553.992924]  __scsi_remove_device+0x115/0x150 [scsi_mod]
Jun 15 20:16:01 raspberry kernel: [103553.992940]  scsi_forget_host+0x57/0x60 [scsi_mod]
Jun 15 20:16:01 raspberry kernel: [103553.992954]  scsi_remove_host+0x72/0x100 [scsi_mod]
Jun 15 20:16:01 raspberry kernel: [103553.992964]  usb_stor_disconnect+0x45/0xc0 [usb_storage]
Jun 15 20:16:01 raspberry kernel: [103553.992985]  usb_unbind_interface+0x78/0x260 [usbcore]
Jun 15 20:16:01 raspberry kernel: [103553.992994]  device_release_driver_internal+0x183/0x250
Jun 15 20:16:01 raspberry kernel: [103553.993000]  bus_remove_device+0xe5/0x150
Jun 15 20:16:01 raspberry kernel: [103553.993004]  device_del+0x164/0x380
Jun 15 20:16:01 raspberry kernel: [103553.993024]  usb_disable_device+0x93/0x240 [usbcore]
Jun 15 20:16:01 raspberry kernel: [103553.993042]  usb_disconnect+0xbc/0x250 [usbcore]
Jun 15 20:16:01 raspberry kernel: [103553.993057]  ? set_port_feature+0x30/0x40 [usbcore]
Jun 15 20:16:01 raspberry kernel: [103553.993074]  hub_event+0xc91/0x15b0 [usbcore]
Jun 15 20:16:01 raspberry kernel: [103553.993084]  process_one_work+0x1a7/0x3a0
Jun 15 20:16:01 raspberry kernel: [103553.993090]  worker_thread+0x30/0x390
Jun 15 20:16:01 raspberry kernel: [103553.993096]  ? create_worker+0x1a0/0x1a0
Jun 15 20:16:01 raspberry kernel: [103553.993100]  kthread+0x112/0x130
Jun 15 20:16:01 raspberry kernel: [103553.993105]  ? kthread_bind+0x30/0x30
Jun 15 20:16:01 raspberry kernel: [103553.993109]  ret_from_fork+0x35/0x40
Jun 15 20:16:01 raspberry kernel: [103553.993129] systemd-udevd   D    0 30592    385 0x20020124
Jun 15 20:16:01 raspberry kernel: [103553.993133] Call Trace:
Jun 15 20:16:01 raspberry kernel: [103553.993140]  ? __schedule+0x2a2/0x870
Jun 15 20:16:01 raspberry kernel: [103553.993145]  schedule+0x28/0x80
Jun 15 20:16:01 raspberry kernel: [103553.993151]  schedule_timeout+0x26d/0x390
Jun 15 20:16:01 raspberry kernel: [103553.993159]  ? enqueue_task_fair+0x7d/0x360
Jun 15 20:16:01 raspberry kernel: [103553.993165]  wait_for_completion+0x11f/0x190
Jun 15 20:16:01 raspberry kernel: [103553.993168]  ? wake_up_q+0x70/0x70
Jun 15 20:16:01 raspberry kernel: [103553.993174]  __flush_work+0x130/0x1e0
Jun 15 20:16:01 raspberry kernel: [103553.993179]  ? worker_attach_to_pool+0x90/0x90
Jun 15 20:16:01 raspberry kernel: [103553.993185]  ? get_work_pool+0x40/0x40
Jun 15 20:16:01 raspberry kernel: [103553.993190]  __cancel_work_timer+0x10a/0x190
Jun 15 20:16:01 raspberry kernel: [103553.993194]  ? disk_map_sector_rcu+0x70/0x70
Jun 15 20:16:01 raspberry kernel: [103553.993199]  ? kobj_lookup+0xf1/0x160
Jun 15 20:16:01 raspberry kernel: [103553.993203]  disk_block_events+0x6f/0x90
Jun 15 20:16:01 raspberry kernel: [103553.993208]  __blkdev_get+0x70/0x540
Jun 15 20:16:01 raspberry kernel: [103553.993213]  ? blkdev_get_by_dev+0x40/0x40
Jun 15 20:16:01 raspberry kernel: [103553.993216]  blkdev_get+0x107/0x310
Jun 15 20:16:01 raspberry kernel: [103553.993219]  ? bdget+0x12d/0x150
Jun 15 20:16:01 raspberry kernel: [103553.993222]  ? blkdev_get_by_dev+0x40/0x40
Jun 15 20:16:01 raspberry kernel: [103553.993226]  ? blkdev_get_by_dev+0x40/0x40
Jun 15 20:16:01 raspberry kernel: [103553.993232]  do_dentry_open+0x13d/0x370
Jun 15 20:16:01 raspberry kernel: [103553.993239]  path_openat+0x2d9/0x1480
Jun 15 20:16:01 raspberry kernel: [103553.993247]  ? seccomp_run_filters+0x5c/0xb0
Jun 15 20:16:01 raspberry kernel: [103553.993253]  do_filp_open+0x93/0x100
Jun 15 20:16:01 raspberry kernel: [103553.993259]  ? __sys_recvmsg+0x54/0xa0
Jun 15 20:16:01 raspberry kernel: [103553.993265]  ? __check_object_size+0x162/0x173
Jun 15 20:16:01 raspberry kernel: [103553.993272]  do_sys_open+0x186/0x210
Jun 15 20:16:01 raspberry kernel: [103553.993279]  do_fast_syscall_32+0x98/0x1dd
Jun 15 20:16:01 raspberry kernel: [103553.993284]  entry_SYSENTER_compat+0x7f/0x91
Jun 15 20:16:09 raspberry kernel: [103562.266534] usb 7-1.3.1: USB disconnect, device number 48
Jun 15 20:16:09 raspberry kernel: [103562.268725] cdc_ether 7-1.3.1:1.0 eth1: unregister 'cdc_ether' usb-0000:04:00.0-1.3.1, CDC Ethernet Device
Jun 15 20:16:09 raspberry kernel: [103562.456530] usb 7-1.1: USB disconnect, device number 49
Jun 15 20:16:09 raspberry kernel: [103562.460791] cdc_ether 7-1.1:1.0 eth2: unregister 'cdc_ether' usb-0000:04:00.0-1.1, CDC Ethernet Device
Jun 15 20:16:10 raspberry kernel: [103562.505912] usb 7-1.3.2: USB disconnect, device number 50
Jun 15 20:16:10 raspberry kernel: [103562.507910] cdc_ether 7-1.3.2:1.0 eth3: unregister 'cdc_ether' usb-0000:04:00.0-1.3.2, CDC Ethernet Device
Jun 15 20:16:10 raspberry kernel: [103562.718024] usb 7-1.4: USB disconnect, device number 54
Jun 15 20:16:10 raspberry kernel: [103562.719798] cdc_ether 7-1.4:1.0 eth6: unregister 'cdc_ether' usb-0000:04:00.0-1.4, CDC Ethernet Device
Jun 15 20:16:10 raspberry kernel: [103562.762016] usb 7-1.3.4: USB disconnect, device number 52
Jun 15 20:16:10 raspberry kernel: [103562.764541] cdc_ether 7-1.3.4:1.0 eth5: unregister 'cdc_ether' usb-0000:04:00.0-1.3.4, CDC Ethernet Device
Jun 15 20:16:10 raspberry kernel: [103563.026040] usb 7-1.3.3: USB disconnect, device number 51
Jun 15 20:16:10 raspberry kernel: [103563.027176] cdc_ether 7-1.3.3:1.0 eth4: unregister 'cdc_ether' usb-0000:04:00.0-1.3.3, CDC Ethernet Device
Jun 15 20:16:16 raspberry kernel: [103568.964715] usb 7-1.3.1: new high-speed USB device number 55 using xhci_hcd
Jun 15 20:16:16 raspberry kernel: [103569.070681] usb 7-1.3.1: New USB device found, idVendor=12d1, idProduct=1f01, bcdDevice= 1.02
Jun 15 20:16:16 raspberry kernel: [103569.070687] usb 7-1.3.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Jun 15 20:16:16 raspberry kernel: [103569.070691] usb 7-1.3.1: Product: HUAWEI_MOBILE
Jun 15 20:16:16 raspberry kernel: [103569.070694] usb 7-1.3.1: Manufacturer: HUAWEI_MOBILE
Jun 15 20:16:16 raspberry kernel: [103569.070697] usb 7-1.3.1: SerialNumber: 0123456789ABCDEF
Jun 15 20:16:16 raspberry kernel: [103569.078917] usb-storage 7-1.3.1:1.0: USB Mass Storage device detected

Some things to note:

  1. lsusb works, lsusb -t hands forever, can't even ctl-c to stop, have to close terminal window and open a new one.
  2. I have tried resetting the PCI using echo 1/0 to/reset and /power, the commands hangs with the same behavior as lsusb -t.
  3. Restarting the PC makes the missing modems come back.
  4. Tools like hub-ctl, usb-reset and uhubctl hang with the same behavior as the rest.

At first, I thought it was the specific USB controller that this port belongs to, but the rest of the modems work fine and they are connected to the same controller, this makes me believe that this is actually a software problem.

Any ideas?

linux
usb
drivers
kernel
linux-kernel
asked on Super User Jun 16, 2020 by roee klinger

0 Answers

Nobody has answered this question yet.


User contributions licensed under CC BY-SA 3.0