OSX client - connection drops

Submitted by mgabriel_84 on #1

Hi,

I have an intel NUC at home running Ubuntu x64 with a couple Arduinos attached to it. I tried using a combination of openvpn and VirtualHere to push code to those Arduinos remotely. I don't mind the one device limitation however, there's a problem ...

The first time i started the client on my laptop (OS X 10.10.4) it worked like a charm. I could see the USB devices, i could connect to them with a serial monitor, etc. The first time i uploaded code to one of the Arduinos the operation succeeded but the virtual USB device became unusable.

The only thing that fixes this problem is a restart of the laptop. If i don't restart i get this in debug mode:

Aug 17 17:45:09 laptop kernel[0]: USBF: 2445.135 com_virtualhere_vhhcd::handleSetDebugLevelMsg (1439822709061111, 1)
Aug 17 17:45:10 laptop kernel[0]: USBF: 2446.749 com_virtualhere_vhhcd::tx
Aug 17 17:45:10 laptop kernel[0]: USBF: 2446.749 com_virtualhere_vhhcd::handleDeviceBindAckMsg (4, 1)
Aug 17 17:45:10 laptop kernel[0]: USBF: 2446.749 com_virtualhere_vhhcd::bindThreadRoutine
Aug 17 17:45:10 laptop kernel[0]: USBF: 2446.749 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:11 laptop kernel[0]: USBF: 2447.749 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:12 laptop kernel[0]: USBF: 2448.750 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:13 laptop kernel[0]: USBF: 2449.752 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:14 laptop kernel[0]: USBF: 2450.752 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:15 laptop kernel[0]: USBF: 2451.753 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:16 laptop kernel[0]: USBF: 2452.754 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:17 laptop kernel[0]: USBF: 2453.755 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:18 laptop kernel[0]: USBF: 2454.756 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:19 laptop kernel[0]: USBF: 2455.757 WARNING, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting...
Aug 17 17:45:20 laptop kernel[0]: USBF: 2456.758 ERROR, com_virtualhere_vhhcd::gatedBindThreadRoutine device zero maybe stuck, giving up and forcing unbind of new device at address 4
Aug 17 17:45:20 laptop kernel[0]: USBF: 2456.758 com_virtualhere_vhhcd::createUnbindDeviceMsg (id=1316)
Aug 17 17:45:20 laptop kernel[0]: USBF: 2456.760 com_virtualhere_vhhcd::rx
Aug 17 17:45:20 laptop kernel[0]: USBF: 2456.764 com_virtualhere_vhhcd::tx
Aug 17 17:45:20 laptop kernel[0]: USBF: 2456.764 com_virtualhere_vhhcd::handleDeviceUnbindAckMsg
Aug 17 17:45:20 laptop kernel[0]: USBF: 2456.764 com_virtualhere_vhhcd::abortAllPendingRequestsForDevice (rem_addr=4
Aug 17 17:45:30 laptop kernel[0]: USBF: 2466.847 com_virtualhere_vhhcd::tx
Aug 17 17:45:30 laptop kernel[0]: USBF: 2466.847 com_virtualhere_vhhcd::handleSetDebugLevelMsg (1439822709061111, 0)

The TCP_NODELAY flag is set in the openvpn server config but i also tested in the local network at home and whatever is happening is local on the Mac. The linux box is connected to the WiFi router via cable (gigabit connection) and the laptop is connected to the WiFi router via a 5.3Ghz Triband AC WiFi connection. I believe this pretty much rules out any transport layer speed/buffering issues.

I did some further testing, here is a scenario where this happens 100% of the time:
1. virtualhere client connects to USB server (vpn or otherwise)
2. "use" a remote USB port
3. connect a serial monitor to the local virtual USB serial port created by virtualhere
4. "stop using" the remote USB port (without disconnecting the serial monitor)

At this point the behavior i reported initially is exhibited:
- It is no longer possible to "use" any remote USB ports.
- No matter which port i try to "use" no new devices show up in /dev/.
- The debug output is same as before.
- The USB devices get disconnected automatically after a few seconds.
- Restarting the laptop is the only cure.

Submitted by Michael on Wed, 2015/08/19 - 08:37

#4

OK, that does sound like a bug, probably in the client. I will look at this in the next few days and try to get a fix done...

Submitted by mgabriel_84 on Wed, 2015/08/19 - 16:37

#5

Thanks, is there a manual override like a process i can kill/restart in the meantime to avoid having to restart every time?

Btw, this can easily happen if you lose network connectivity while the virtual USB port is in use (it just did for me).

Submitted by Michael on Wed, 2015/08/19 - 21:32

#6

Try sudo kextunload -b com.virtualhere.vhhcd

then

kextload -b com.virtualhere.vhhcd

Submitted by Michael on Fri, 2015/09/04 - 17:41

#8

What brand is your USB->Serial adapter? Im debugging this issue and want to try to reproduce it.

I have tried an FTDI230X device and it works fine stopping device while the serial is open
I also tried a CP2102 device and it does actually panic the kernel if i stop using the device via virtualhere before closing the serial port, I traced the panic and it appears the CP2102 driver from silabs is mishandling a disconnection.
Is your device one of these?

Submitted by mgabriel_84 on Sat, 2015/09/05 - 16:29

#9

The Arduino is a Mega ADK
https://www.arduino.cc/en/Main/ArduinoBoardMegaADK?from=Main.ArduinoBoa…

The USB Host Chip is different on this one, per the link above it's a MAX3421E. To be honest i have not tried this with the other two (those are Arduino Nanos using a FT232RL chip). Ever since i found the problem i tried not to cut the connection before disconnecting the serial monitor.

I will do a test to see if the behavior is the same with the with the FT232RL chips and post the results.

Submitted by mgabriel_84 on Sat, 2015/09/05 - 17:06

#10

Just tested, the FTDI chip on the Nano doesn't have a problem with losing the connection it seems. It's the MAX3421E chip that's causing issues.

Submitted by Michael on Sat, 2015/09/05 - 17:39

#11

OK, thanks for info, I will do some more in-depth investigation about the panic in the cp2102, as sometime might turn up as related to your issue

Submitted by sjgoalie on Sat, 2015/09/26 - 05:53

#12

I'm seeing the exact same issue. So I'll add my data in case it helps. I have the server on a Raspberry Pi2 hosting an OtherMill (https://othermachine.co/othermill/features/). I'm not sure what chip they are using for the serial interface on there, I'll ping them and see.

Submitted by Michael on Sat, 2015/09/26 - 13:58

#14

Hi, are you getting a panic in OSX ? Or, is it just not connecting the usb serial port when the connection drops?

I'm getting the a lot of connection drops and the same message the OP had "com_virtualhere_vhhcd::gatedBindThreadRoutine device zero already exists so cannot connect device at remote address 4, waiting"

I've had one occurrence of the gray screen of death when I tried to manually kext load/unload.

I got an email from Othermill late last night saying they were wrong, their first version had FTDI, in the newer ones they are using UART from the ARM processor. Their code os open source, if I get time today I'll dig into it a little.

Submitted by Michael on Tue, 2015/09/29 - 11:19

#16

I would be surprised if it was FTDI because i test with those most days with no problems Anyway let me know what serial chip they use. Perhaps its also a MAX2442. Anyway the reasons that it says "device zero exists" is because the device jams either on the pi side or on the osx side due to an incompatiblily somewhere. Perhaps i can have remote access to your virtualhere server? So i can trace the problem in more depth at my office? If so just send details to mail [at] virtualhere.com (mail[at]virtualhere[dot]com)

Sorry for the delay. I was in contact with Othermill as well during this time. They were working on serial fixes for El Capitain so I decided to wait and see if they helped with this as well. It looks like they helped with most of it. One thing remains, the original poster's issue happens to me every morning after the mac has woken from sleep.

Submitted by Michael on Tue, 2015/10/27 - 10:01

#18

Can you update the server to 2.5.6 if you havent already, as that fixes a few connection drop issues that occurs under certain circumstances... when sleeping the computer, just make sure to stop using the serial port if you can remember, let me know if that fixes the woken from sleep issue you have...