I'm running into a strange problem with a really simple device - A Tripp-Lite Keyspan USB to Serial Adapter with an RS232 loopback adapter attached to it. On a direct USB connection to a PC, I can use PuTTY to open a connection to it, type in data and then get it right back. But on Windows VirtualHere clients (Windows 10, VirtualHere Client 4.4.8), I get nothing but timeout errors. Interestingly, my Debian 9 client (kernel 4.9.0, VirtualHere Client 4.4.8) works just fine. I ran a direct Ethernet cable from the server and client machines to rule out latency (no change). I also tried out a spare Windows PC as a server in trial mode to see if it helped (no change either). I attached some syslogs from the server where I looked for anything involving vhusbdx86_64 and might have found some useful output. There are some USBDEVFS calls. I'm not familiar with these but a quick search on them makes me wonder if this is some kind of handshake issue. These messages only show up when I use Windows 10 clients
My server is running on VirtualHere USB Server v3.5.4 (Built: Feb 1 2018, 20:32:40).
Here's a successful run from Debian 9.
Apr 6 12:50:06 usbetht1-deb9-64 vhusbdx86_64[769]: 172.28.23.241 connected as connection 17
Apr 6 12:50:38 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] BOUND to connection 17
Apr 6 13:33:54 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] UNBOUND from connection 17
Apr 6 13:40:09 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] BOUND to connection 7
Apr 6 13:40:19 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] UNBOUND from connection 7
Apr 6 13:40:23 usbetht1-deb9-64 vhusbdx86_64[769]: Connection 7 remotely disconnected gracefully (rx msg size)
Apr 6 13:40:30 usbetht1-deb9-64 vhusbdx86_64[769]: Connection 7 successfully removed (reason:timeout)
Apr 6 13:40:56 usbetht1-deb9-64 vhusbdx86_64[769]: 172.28.23.241 connected as connection 20
Apr 6 13:41:02 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] BOUND to connection 20
Here's a failed run from Windows 10
Apr 6 13:59:55 usbetht1-deb9-64 kernel: [254209.344339] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 13:59:55 usbetht1-deb9-64 kernel: [254209.344822] CPU: 5 PID: 791 Comm: vhusbdx86_64 Tainted: P O 4.9.0-5-amd64 #1 Debian 4.9.65-3+deb9u2
Apr 6 13:59:55 usbetht1-deb9-64 kernel: [254209.345109] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 13:59:55 usbetht1-deb9-64 kernel: [254209.531750] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 13:59:55 usbetht1-deb9-64 kernel: [254209.532592] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 13:59:55 usbetht1-deb9-64 kernel: [254209.730898] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 13:59:55 usbetht1-deb9-64 kernel: [254209.731562] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:00:08 usbetht1-deb9-64 kernel: [254222.331099] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:00:08 usbetht1-deb9-64 kernel: [254222.331721] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:00:08 usbetht1-deb9-64 kernel: [254222.368926] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:00:08 usbetht1-deb9-64 kernel: [254222.369460] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:10:25 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] UNBOUND from connection 20
Apr 6 14:10:29 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] BOUND to connection 20
Apr 6 14:10:42 usbetht1-deb9-64 kernel: [254856.460281] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:10:42 usbetht1-deb9-64 kernel: [254856.460888] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:10:52 usbetht1-deb9-64 kernel: [254866.184427] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:10:52 usbetht1-deb9-64 kernel: [254866.185042] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:10:52 usbetht1-deb9-64 kernel: [254866.385500] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:10:52 usbetht1-deb9-64 kernel: [254866.386273] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:10:52 usbetht1-deb9-64 kernel: [254866.563878] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:10:52 usbetht1-deb9-64 kernel: [254866.564568] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:11:01 usbetht1-deb9-64 kernel: [254875.083324] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:11:01 usbetht1-deb9-64 kernel: [254875.084040] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:11:01 usbetht1-deb9-64 kernel: [254875.251892] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:11:01 usbetht1-deb9-64 kernel: [254875.252702] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:11:01 usbetht1-deb9-64 vhusbdx86_64[769]: Warning, Clear halt has 1 inflight urbs when clearing halt on ep 0x82 for device 414
Apr 6 14:11:01 usbetht1-deb9-64 vhusbdx86_64[769]: Warning, resetEP has 1 inflight urbs ep 0x82 for device 414
Apr 6 14:11:01 usbetht1-deb9-64 kernel: [254875.410753] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:11:01 usbetht1-deb9-64 kernel: [254875.411408] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:11:13 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] UNBOUND from connection 20
Apr 6 14:15:29 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] BOUND to connection 20
Apr 6 14:16:41 usbetht1-deb9-64 kernel: [255215.015700] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:16:41 usbetht1-deb9-64 kernel: [255215.016473] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:16:49 usbetht1-deb9-64 kernel: [255223.300267] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:16:49 usbetht1-deb9-64 kernel: [255223.301010] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:16:49 usbetht1-deb9-64 kernel: [255223.494107] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:16:49 usbetht1-deb9-64 kernel: [255223.494906] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:16:49 usbetht1-deb9-64 kernel: [255223.679091] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:16:49 usbetht1-deb9-64 kernel: [255223.679914] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:16:57 usbetht1-deb9-64 kernel: [255231.031846] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:16:57 usbetht1-deb9-64 kernel: [255231.032651] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:16:57 usbetht1-deb9-64 kernel: [255231.205493] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:16:57 usbetht1-deb9-64 kernel: [255231.206222] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:16:57 usbetht1-deb9-64 kernel: [255231.378981] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 6 14:16:57 usbetht1-deb9-64 kernel: [255231.379658] usb 4-1.4: Process 791 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 6 14:17:25 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] UNBOUND from connection 20
Here's another successful run from Debian 9. Nothing extra got written to the syslogs when this succeeded.
Apr 6 14:22:49 usbetht1-deb9-64 vhusbdx86_64[769]: Device 414 [06cd:0121] BOUND to connection 17
Thanks,
Chris
.
I think what is happening is windows is putting the device to sleep. VirtualHere server wont support this. So you need to use the device via virtualhere, then bring up Device Manager and find the serial adapter listed there, then right click Properties -> Power Events -> UNcheck Allow windows to turn off this device to save power
I don't seem to have that
I don't seem to have that option under Device Manager. I can go to Control Panel > Power Options > Edit Plan Settings > USB Settings > USB selective suspend setting > Disabled. (I changed it from Enabled)
Another thing I noticed was that it does look like I can connect through PuTTY to the COM port and it eventually lets me connect to the loopback adapter (anything I type will appear in my connection as expected). I also tried this from a different program (MATLAB) and each time I try to search for serial devices, I always see the same messages show up from the server. Particularly the "Warning, resetEP has 1 inflight urbs ep 0x02 for device 414". Once I try to have MATLAB probe serial devices, it tries to write to the loopback, times out, and then fails. I can get the loopback working with PuTTY again after I disconnect and reconnect through VirtualHere.
Apr 10 11:10:30 usbetht1-deb9-64 vhusbdx86_64[19327]: Device 414 [06cd:0121] BOUND to connection 3
Apr 10 11:10:37 usbetht1-deb9-64 kernel: [589616.171175] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:10:37 usbetht1-deb9-64 kernel: [589616.171883] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 10 11:10:54 usbetht1-deb9-64 kernel: [589632.737453] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x82
Apr 10 11:10:54 usbetht1-deb9-64 kernel: [589632.738366] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:10:54 usbetht1-deb9-64 kernel: [589632.739115] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 10 11:11:41 usbetht1-deb9-64 kernel: [589679.879045] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x82
Apr 10 11:11:41 usbetht1-deb9-64 kernel: [589679.879573] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:11:41 usbetht1-deb9-64 kernel: [589679.880198] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 10 11:11:51 usbetht1-deb9-64 kernel: [589689.752754] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:11:51 usbetht1-deb9-64 kernel: [589689.753475] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 10 11:12:28 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, Clear halt has 1 inflight urbs when clearing halt on ep 0x02 for device 414
Apr 10 11:12:28 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, resetEP has 1 inflight urbs ep 0x02 for device 414
Apr 10 11:12:28 usbetht1-deb9-64 kernel: [589726.885158] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:12:28 usbetht1-deb9-64 kernel: [589726.885703] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 10 11:12:28 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, Clear halt has 1 inflight urbs when clearing halt on ep 0x02 for device 414
Apr 10 11:12:28 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, resetEP has 1 inflight urbs ep 0x02 for device 414
Apr 10 11:12:28 usbetht1-deb9-64 kernel: [589727.031523] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:12:28 usbetht1-deb9-64 kernel: [589727.031838] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 10 11:12:28 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, Clear halt has 1 inflight urbs when clearing halt on ep 0x02 for device 414
Apr 10 11:12:28 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, resetEP has 1 inflight urbs ep 0x02 for device 414
Apr 10 11:12:28 usbetht1-deb9-64 kernel: [589727.205118] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:12:28 usbetht1-deb9-64 kernel: [589727.205846] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 10 11:12:53 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, Clear halt has 1 inflight urbs when clearing halt on ep 0x02 for device 414
Apr 10 11:12:53 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, resetEP has 1 inflight urbs ep 0x02 for device 414
Apr 10 11:12:53 usbetht1-deb9-64 kernel: [589751.440301] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:12:53 usbetht1-deb9-64 kernel: [589751.440772] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 10 11:12:53 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, resetEP has 1 inflight urbs ep 0x02 for device 414
Apr 10 11:12:53 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, Clear halt has 1 inflight urbs when clearing halt on ep 0x02 for device 414
Apr 10 11:12:53 usbetht1-deb9-64 kernel: [589751.485678] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:12:53 usbetht1-deb9-64 kernel: [589751.486261] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
Apr 10 11:14:50 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, resetEP has 1 inflight urbs ep 0x02 for device 414
Apr 10 11:14:50 usbetht1-deb9-64 vhusbdx86_64[19327]: Warning, Clear halt has 1 inflight urbs when clearing halt on ep 0x02 for device 414
Apr 10 11:14:50 usbetht1-deb9-64 kernel: [589868.543822] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_CLEAR_HALT for active endpoint 0x81
Apr 10 11:14:50 usbetht1-deb9-64 kernel: [589868.544232] usb 4-1.4: Process 19350 (vhusbdx86_64) called USBDEVFS_RESETEP for active endpoint 0x81
.
OK, those errors as basically saying that the windows driver is not working as expected or the device is jammed for some reason. Usually this means it is powering down temporarily and cannot wake up via virtualhere. If that specific option under device manager is not available im not its possible to control that settings.
The Tripp-Lite KeySpan uses a TI chipset which im unfamiliar with. I know prolific and ftdi work fine via virtualhere, so i would suggest using a similar device with one of those chipsets instead.
Prolific Adapter seems to work
Michael, thanks for suggesting the Prolific adapter. I was able to get a hold of one and test it. It worked fine with no problems.
I did try out various Windows drivers for the KeySpan adapters but they didn't seem to help. But for now, I think using the Prolific adapters will work.