USB dongle is not visible by the system on the client.

Submitted by 9081160 on #1

Server – Ubuntu 22.04.3 + VirtualHere Server Version 4.6.2
Client – Win 11 64-bit + VirtualHere Version 5.5.7
I don't use VirtualHere SSL.
USB dongle based on SLE 78CUFX3000PH smart chips from Infineon, based on the M7893 security controller.
The client is connected to the server's IP address, port 7575.

When connected to the client, the USB dongle is visible to the system (in Device Manager) only when connected the fourth or fifth time. The system doesn't see it the first time.
If you physically connect a USB dongle to the client, the system sees it immediately the first time.

It’s strange, but if you use EasyFind, the system sees the key from the first or second connection in the VirtualHere client.

How to find the reason why the USB dongle does not connect the first time?

Submitted by Michael on Fri, 2023/12/22 - 08:55

#2

"connected the fourth or fifth time"

That almost sounds like its a firmware issue inside the dongle. When it doesnt connect and doesnt show in Device Manager on the client side. Have a look on the server side by doing grep vhusbd /var/log/syslog  and see what messages are around that time. What does it show?

Submitted by 9081160 on Fri, 2023/12/22 - 17:45

#3

I have 20 identical dongles connected, I don’t think they all have a problem with the firmware inside the dongle

 

root@s1:~# grep vhusbd /var/log/syslog


 doesn't output anything
 

Submitted by Michael on Fri, 2023/12/22 - 18:51

#4

You must be redirecting the server log to a file instead? check how you start the virtualhere server.

Submitted by 9081160 on Tue, 2024/01/16 - 19:43

#5

Log at the moment when the USB key is not visible in Device Manager

Attempts to use the device

Tue Jan 16 11:26:21 2024 LOG_INFO    Found Full speed device [15cf:0019] "Avtor, SecureToken" at address 11121
Tue Jan 16 11:26:21 2024 LOG_INFO    Found Full speed device [15cf:0019] "Avtor, SecureToken" at address 11122
Tue Jan 16 11:26:38 2024 LOG_INFO    Device 11122 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:26:44 2024 LOG_INFO    Device 11122 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:26:55 2024 LOG_INFO    Device 11122 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:27:01 2024 LOG_INFO    Device 11122 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:27:11 2024 LOG_INFO    Device 11122 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:27:15 2024 LOG_INFO    Device 11122 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:27:24 2024 LOG_INFO    Device 11122 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:27:30 2024 LOG_INFO    Device 11122 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:27:40 2024 LOG_INFO    Device 11122 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:27:44 2024 LOG_INFO    Device 11122 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:27:52 2024 LOG_INFO    Device 11122 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:28:07 2024 LOG_INFO    Device 11121 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:28:12 2024 LOG_INFO    Device 11121 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:28:15 2024 LOG_INFO    Device 11122 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:28:28 2024 LOG_INFO    Device 11122 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:28:40 2024 LOG_INFO    Device 11121 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:28:44 2024 LOG_INFO    Device 11121 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:28:45 2024 LOG_INFO    Device 11122 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:29:00 2024 LOG_INFO    Device 11122 [15cf:0019] BOUND to connection 4
Tue Jan 16 11:29:06 2024 LOG_INFO    Device 11122 [15cf:0019] UNBOUND from connection 4
Tue Jan 16 11:29:06 2024 LOG_WARNING Error 22 discarding urb 0x33360180 for device /sys//devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2.2, Invalid argument (abort endpoint)
Tue Jan 16 11:29:15 2024 LOG_INFO    Unmanaging device 11121 [15cf:0019]
Tue Jan 16 11:29:16 2024 LOG_INFO    Unmanaging device 11122 [15cf:0019]

 

 

run uname -a  

Linux localhost 5.15.0-1044-raspi #47-Ubuntu SMP PREEMPT Tue Nov 21 11:33:46 UTC 2023 aarch64 aarch64 aarch64 GNU/Linux
 

 

 

Submitted by 9081160 on Tue, 2024/01/16 - 20:22

#6

Error rarely appears:

LOG_WARNING Error 22 discarding urb 0x33360180 for device /sys//devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2.2, Invalid argument (abort endpoint)

Submitted by Michael on Tue, 2024/01/16 - 20:49

#7

I think you should update your kernel to 6.1 on your pi.

Submitted by 9081160 on Wed, 2024/01/17 - 11:02

#8

Linux localhost 6.2.0-1018-raspi #20-Ubuntu SMP PREEMPT Tue Nov 21 13:32:12 UTC 2023 aarch64 aarch64 aarch64 GNU/Linux

Updating the kernel did not solve the problem.

I guess the problem might be due to high latency between server and client = 38ms

 

Submitted by 9081160 on Wed, 2024/01/17 - 11:02

#9

Linux localhost 6.2.0-1018-raspi #20-Ubuntu SMP PREEMPT Tue Nov 21 13:32:12 UTC 2023 aarch64 aarch64 aarch64 GNU/Linux

Updating the kernel did not solve the problem.

I guess the problem might be due to high latency between server and client = 38ms

 

Submitted by 9081160 on Wed, 2024/01/17 - 11:02

#10

Linux localhost 6.2.0-1018-raspi #20-Ubuntu SMP PREEMPT Tue Nov 21 13:32:12 UTC 2023 aarch64 aarch64 aarch64 GNU/Linux

Updating the kernel did not solve the problem.

I guess the problem might be due to high latency between server and client = 38ms

 

Submitted by Michael on Wed, 2024/01/17 - 11:52

#11

OK i suspect then its the firmware inside the dongle. I think you need to power cycle the dongle, either by removing it manually and reinserting or getting a hub that supports per-port-power cycling.

Submitted by 9081160 on Wed, 2024/01/17 - 12:57

#12

It's already there. USB dongles are connected via a hub with separate power supply

Submitted by Michael on Thu, 2024/01/18 - 06:43

#13

"Log at the moment when the USB key is not visible in Device Manager"


Next time, could you post the part of /var/log/syslog when the usb key is not visible in Device manager. I see you posted the virtualhere server log at this point thanks, but also syslog would be helpful here too because it will show hardware errors.

Submitted by 9081160 on Thu, 2024/01/18 - 17:28

#14

2024-01-18T09:22:07.440841+02:00 localhost kernel: [29336.997093] usb 2-1.1.2.7: new full-speed USB device number 33 using xhci_hcd
2024-01-18T09:22:07.565006+02:00 localhost  kernel: [29337.121746] usb 2-1.1.2.7: New USB device found, idVendor=15cf, idProduct=0019, bcdDevice= 3.35
2024-01-18T09:22:07.565048+02:00 localhost kernel: [29337.121769] usb 2-1.1.2.7: New USB device strings: Mfr=1, Product=2, SerialNumber=0
2024-01-18T09:22:07.565051+02:00 localhost kernel: [29337.121777] usb 2-1.1.2.7: Product: SecureToken
2024-01-18T09:22:07.565053+02:00 localhost kernel: [29337.121784] usb 2-1.1.2.7: Manufacturer: Avtor
2024-01-18T09:22:07.603877+02:00 localhost mtp-probe: checking bus 2, device 33: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1.1/2-1.1.2/2-1.1.2.7"
2024-01-18T09:22:07.605142+02:00 localhost mtp-probe: bus: 2, device: 33 was not an MTP device
2024-01-18T09:22:07.614986+02:00 localhost fwupd[9843]: 07:22:07.614 FuEngine             failed to probe device usb:02:00:01:01:02:07: USB error on device 15cf:0019 : Entity not found [-5]
2024-01-18T09:22:18.720909+02:00 localhost kernel: [29348.277561] usb 2-1.1.2.7: reset full-speed USB device number 33 using xhci_hcd
2024-01-18T09:22:19.188898+02:00 localhost kernel: [29348.745553] usb 2-1.1.2.7: reset full-speed USB device number 33 using xhci_hcd
2024-01-18T09:22:24.976901+02:00 localhost kernel: [29354.536471] usb 2-1.1.2.7: usbfs: process 35326 (op21127) did not claim interface 0 before use
2024-01-18T09:22:31.300904+02:00 localhost kernel: [29360.858073] usb 2-1.1.2.7: reset full-speed USB device number 33 using xhci_hcd
2024-01-18T09:22:31.784914+02:00 localhost kernel: [29361.341980] usb 2-1.1.2.7: reset full-speed USB device number 33 using xhci_hcd
2024-01-18T09:22:36.752879+02:00 localhost kernel: [29366.310773] usb 2-1.1.2.7: usbfs: process 35326 (op21127) did not claim interface 0 before use
2024-01-18T09:22:43.136903+02:00 localhost kernel: [29372.694241] usb 2-1.1.2.7: reset full-speed USB device number 33 using xhci_hcd
2024-01-18T09:22:43.616894+02:00 localhost kernel: [29373.174157] usb 2-1.1.2.7: reset full-speed USB device number 33 using xhci_hcd
2024-01-18T09:22:51.668847+02:00 localhost kernel: [29381.225842] usb 2-1.1.2.7: usbfs: process 35326 (op21127) did not claim interface 0 before use
2024-01-18T09:22:57.872904+02:00 localhost kernel: [29387.430464] usb 2-1.1.2.7: reset full-speed USB device number 33 using xhci_hcd
2024-01-18T09:22:58.364957+02:00 localhost kernel: [29387.922392] usb 2-1.1.2.7: reset full-speed USB device number 33 using xhci_hcd

Submitted by Michael on Thu, 2024/01/18 - 18:40

#15

Try this

  1. Stop the virtualhere server process
  2. Edit the server config.ini file usually in /usr/local/etc/virtualhere/config.ini
  3. Add the line ClaimPorts=1
  4. Reboot the server

Submitted by 9081160 on Thu, 2024/01/18 - 19:32

#16

It doesn't work, apparently because I have a hub connected

Thu Jan 18 11:30:11 2024 LOG_DEBUG   Hub /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1.4/2-1.4.1 just plugged into claimed port for /dev/bus/usb/002/005, this is not supported!
Thu Jan 18 11:30:12 2024 LOG_DEBUG   Hub /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1.4/2-1.4.2 just plugged into claimed port for /dev/bus/usb/002/005, this is not supported!
Thu Jan 18 11:30:22 2024 LOG_DEBUG   Hub /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1.4/2-1.4.1 just plugged into claimed port for /dev/bus/usb/002/005, this is not supported!
Thu Jan 18 11:30:23 2024 LOG_DEBUG   Hub /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1.4/2-1.4.2 just plugged into claimed port for /dev/bus/usb/002/005, this is not supported!

Submitted by Michael on Thu, 2024/01/18 - 19:40

#17

OK reverse the change to config.ini (remove ClaimPorts=1) and restart the server so it enumerates correctly again.

"I have 20 identical dongles connected..."

What about if you connect less dongles e.g 8 does it still happen?

Submitted by 9081160 on Thu, 2024/01/18 - 19:46

#18

yes, I tried it with only one dongle, there is a problem

Submitted by 9081160 on Thu, 2024/01/18 - 19:47

#19

I think the problem is latency between client and server.


I tested it on different clients located remotely in different places:

A client with approximately a delay of more than 28ms = USB dongles are connected approximately from the fourth to fifth time. ( that is, visible in the system in the device manager).

A client with approximately a delay of more than 38ms = USB dongles do not want to connect at all (not visible in the system in device manager)

A client whose latency is approximately less than 25ms = the problem has disappeared, the USB dongles are connected the first time. (That is, it is immediately visible in the system in the device manager)

Submitted by 9081160 on Thu, 2024/01/18 - 19:51

#20

It's strange, but this problem is only with USB dongles .

If you connect a USB flash drive to all these clients, for example, it is visible in the system without any problems.

Submitted by Michael on Thu, 2024/01/18 - 20:26

#21

OK not much can be done about latency...

Submitted by 9081160 on Thu, 2024/01/18 - 20:42

#22

Thanks for answers. It's a pity that the problem cannot be solved.