Server 'crashing' or disconnecting?

Hey Michael,

A couple days ago I updated a few things on my RPi and now VH has started dropping out. When it does so, all devices are obviously disconnected and the two devices that have auto-use enabled are shown as (In use by  (windowsPCname) at ::) and when I right-click on one, it says "In use elsewhere..." so it seems that it's getting 'locked up'.

Does the server or client store a log file so we can see what may have occurred to cause this drop-out?

I'm running RPi server v 4.6.7 and Windows client is 5.7.6.

 

All the best,
Dax.

#2

Hi Dax, what USB device is it? And also what is the name of the virtualhere server binary you are running on your pi?  I have a new build that might fix the issue.

#4

To update do this:

ssh to the pi then type

systemctl stop virtualhere

wget https://www.virtualhere.com/sites/default/files/usbserver/test/vhusbdarmpi4

sudo cp ./vhusbdarmpi4 /usr/local/sbin

systemctl start virtualhere

Then in the virtualhere client when you see the server appear, right click on it and select Properties and check the version is 4.6.8

Then let me know if it still causes the issue or not

 

 

#5

Did you try this, is it all working ok now?

#6

Hey Michael,
Sorry, I didn't get a chacen to check this week as I thought I would.

I have just now executed the commands and (next week) will give it a good test and get back to you.
I can confirm it's now running v4.6.8

 

#7

No issues today, I will tentatively say this is solved, but will keep an eye on it and report back the moment I have another dropout where it displays (In use by  (windowsPCname) at ::)

Thanks as always for your fast work, Michael!

All the best,

Dax.

#8

Thats great news, ill give it a few more days to see if you have the issue then i will roll this fix into the main virtualhere build.

#9

I will say that it's certainly not hurting anything. Seems stable enough for main build.

#10

Yes good idea, i have updated the main build now and released 4.6.8 of the server

#11

Hey Michael,
Just wanted to let you know that the bug seems solved with 4.6.8.
Great job, once again!

All the best,
Dax.

#12

Hey Michael,
Sorry to say, but I've just noticed the problem again.

1) Davinci Resolve dongle (In use by SYSTEM at ::)
2) WIBU CodeMeter (In use by you)
2) iLok - this was completely disconnected.
 

This time, it wasn't all 3 USB devices that got messed up, only the first one, but the iLok was disconnected (without user intervention).

Any ideas? Is there a log file I can send you?

Cheers,
Dax.

#13

Can you stop and exit the virtualhere client (if its running as a service uninstall it by right clicking USB Servers->Uninstall service)

  1. Update the server like this

ssh to the pi then type

systemctl stop virtualhere

wget https://www.virtualhere.com/sites/default/files/usbserver/test/vhusbdarmpi4

sudo cp ./vhusbdarmpi4 /usr/local/sbin

systemctl start virtualhere

Then in the virtualhere client when you see the server appear, right click on it and select Properties and check the version is 4.7.0

2. Download and run this new client here https://www.virtualhere.com/sites/default/files/usbclient/test/vhui64.exe

Now when it occurs again, let me know because there will be error messages either written to the server log (if there is a server bug) or to the client if there is a client bug.

#14

Can do. You'll have to let me know how to access the server logs, though.

#15

BTW, I killed the service using the Details tab of Task Manager. 

 

I wonder if this has anything to do with recently enabling authentication requirement to start/stop services? (There was a tutorial I was following to install something and they said it was recommended to enable this security feature.)

Client is v5.7.8
Server is 4.6.8 ... hmmm, that's not right, I guess. I copy/pasted each step you requested.

 

#16

No should shouldnt kill the service with taskmanager as that is not supported. You probably should reboot and then try again

#17

I've done the steps exactly as you said, server still v4.6.8

In the directory /usr/local/sbin I can see vhusbdarm  vhusbdarmpi4
Should vhusbdarm be removed?

Update: I elevated to su, stopped the VH service again and deleted vhusbdarm. I then started the VH service and checked in the client and it's still showing 4.6.8.
Is it possible that the link you provided is to 4.6.8 not 4.7.0?

#19

Tried that, changing all vhusbdarmpi4 references to vhusbdarm, but I get this:
Job for virtualhere.service failed because the control process exited with error code.
See "systemctl status virtualhere.service" and "journalctl -xe" for details.

Looks like it wants the armpi4 version after all.
 

--
-- A stop job for unit virtualhere.service has begun execution.
--
-- The job identifier is 1508.
Oct 02 01:37:20 raspberrypi avahi-daemon[323]: Files changed, reloading.
Oct 02 01:37:20 raspberrypi avahi-daemon[323]: Service group file /services/vhus
Oct 02 01:37:20 raspberrypi avahi-daemon[323]: No service file found in /etc/ava
Oct 02 01:37:22 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 113 [096e:020
Oct 02 01:37:22 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 11 [2109:3431
Oct 02 01:37:23 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 114 [064f:03e
Oct 02 01:37:24 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 111 [088e:503
Oct 02 01:37:25 raspberrypi vhusbdarmpi4[16833]: >>> Shutdown <<<
Oct 02 01:37:25 raspberrypi systemd[1]: virtualhere.service: Succeeded.
-- Subject: Unit succeeded
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit virtualhere.service has successfully entered the 'dead' state.
Oct 02 01:37:25 raspberrypi systemd[1]: Stopped VirtualHere Server.
-- Subject: A stop job for unit virtualhere.service has finished
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A stop job for unit virtualhere.service has finished.
--
-- The job identifier is 1508 and the job result is done.
Oct 02 01:39:27 raspberrypi systemd[1]: Starting VirtualHere Server...
-- Subject: A start job for unit virtualhere.service has begun execution
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit virtualhere.service has begun execution.
--
-- The job identifier is 1509.
Oct 02 01:39:27 raspberrypi systemd[22494]: virtualhere.service: Failed to execu
Oct 02 01:39:27 raspberrypi systemd[22494]: virtualhere.service: Failed at step
-- Subject: Process /usr/local/sbin/vhusbdarmpi4 could not be executed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The process /usr/local/sbin/vhusbdarmpi4 could not be executed and failed.
--
-- The error number returned by this process is ERRNO.
Oct 02 01:39:27 raspberrypi systemd[1]: virtualhere.service: Control process exi
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- An ExecStart= process belonging to unit virtualhere.service has exited.
--
-- The process' exit code is 'exited' and its exit status is 203.
Oct 02 01:39:27 raspberrypi systemd[1]: virtualhere.service: Failed with result
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit virtualhere.service has entered the 'failed' state with result 'exit
Oct 02 01:39:27 raspberrypi systemd[1]: Failed to start VirtualHere Server.
-- Subject: A start job for unit virtualhere.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit virtualhere.service has finished with a failure.
--
-- The job identifier is 1509 and the job result is failed.
lines 1864-1928/1928 (END)
--
-- A stop job for unit virtualhere.service has begun execution.
--
-- The job identifier is 1508.
Oct 02 01:37:20 raspberrypi avahi-daemon[323]: Files changed, reloading.
Oct 02 01:37:20 raspberrypi avahi-daemon[323]: Service group file /services/vhusbd.service vanished, removing services.
Oct 02 01:37:20 raspberrypi avahi-daemon[323]: No service file found in /etc/avahi/services.
Oct 02 01:37:22 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 113 [096e:0201]
Oct 02 01:37:22 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 11 [2109:3431]
Oct 02 01:37:23 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 114 [064f:03e9]
Oct 02 01:37:24 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 111 [088e:5036]
Oct 02 01:37:25 raspberrypi vhusbdarmpi4[16833]: >>> Shutdown <<<
Oct 02 01:37:25 raspberrypi systemd[1]: virtualhere.service: Succeeded.
-- Subject: Unit succeeded
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit virtualhere.service has successfully entered the 'dead' state.
Oct 02 01:37:25 raspberrypi systemd[1]: Stopped VirtualHere Server.
-- Subject: A stop job for unit virtualhere.service has finished
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A stop job for unit virtualhere.service has finished.
--
-- The job identifier is 1508 and the job result is done.
Oct 02 01:39:27 raspberrypi systemd[1]: Starting VirtualHere Server...
-- Subject: A start job for unit virtualhere.service has begun execution
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit virtualhere.service has begun execution.
--
-- The job identifier is 1509.
Oct 02 01:39:27 raspberrypi systemd[22494]: virtualhere.service: Failed to execute command: No such file or directory
Oct 02 01:39:27 raspberrypi systemd[22494]: virtualhere.service: Failed at step EXEC spawning /usr/local/sbin/vhusbdarm
-- Subject: Process /usr/local/sbin/vhusbdarmpi4 could not be executed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The process /usr/local/sbin/vhusbdarmpi4 could not be executed and failed.
--
-- The error number returned by this process is ERRNO.
Oct 02 01:39:27 raspberrypi systemd[1]: virtualhere.service: Control process exited, code=exited, status=203/EXEC
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- An ExecStart= process belonging to unit virtualhere.service has exited.
--
-- The process' exit code is 'exited' and its exit status is 203.
Oct 02 01:39:27 raspberrypi systemd[1]: virtualhere.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit virtualhere.service has entered the 'failed' state with result 'exit-code'.
Oct 02 01:39:27 raspberrypi systemd[1]: Failed to start VirtualHere Server.
-- Subject: A start job for unit virtualhere.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit virtualhere.service has finished with a failure.
--
-- The job identifier is 1509 and the job result is failed.
~
lines 1864-1928/1928 (END)
--
-- A stop job for unit virtualhere.service has begun execution.
--
-- The job identifier is 1508.
Oct 02 01:37:20 raspberrypi avahi-daemon[323]: Files changed, reloading.
Oct 02 01:37:20 raspberrypi avahi-daemon[323]: Service group file /services/vhusbd.service vanished, removing services.
Oct 02 01:37:20 raspberrypi avahi-daemon[323]: No service file found in /etc/avahi/services.
Oct 02 01:37:22 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 113 [096e:0201]
Oct 02 01:37:22 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 11 [2109:3431]
Oct 02 01:37:23 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 114 [064f:03e9]
Oct 02 01:37:24 raspberrypi vhusbdarmpi4[16833]: Unmanaging device 111 [088e:5036]
Oct 02 01:37:25 raspberrypi vhusbdarmpi4[16833]: >>> Shutdown <<<
Oct 02 01:37:25 raspberrypi systemd[1]: virtualhere.service: Succeeded.
-- Subject: Unit succeeded
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit virtualhere.service has successfully entered the 'dead' state.
Oct 02 01:37:25 raspberrypi systemd[1]: Stopped VirtualHere Server.
-- Subject: A stop job for unit virtualhere.service has finished
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A stop job for unit virtualhere.service has finished.
--
-- The job identifier is 1508 and the job result is done.
Oct 02 01:39:27 raspberrypi systemd[1]: Starting VirtualHere Server...
-- Subject: A start job for unit virtualhere.service has begun execution
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit virtualhere.service has begun execution.
--
-- The job identifier is 1509.
Oct 02 01:39:27 raspberrypi systemd[22494]: virtualhere.service: Failed to execute command: No such file or directory
Oct 02 01:39:27 raspberrypi systemd[22494]: virtualhere.service: Failed at step EXEC spawning /usr/local/sbin/vhusbdarmpi4: No such file or directory
-- Subject: Process /usr/local/sbin/vhusbdarmpi4 could not be executed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The process /usr/local/sbin/vhusbdarmpi4 could not be executed and failed.
--
-- The error number returned by this process is ERRNO.
Oct 02 01:39:27 raspberrypi systemd[1]: virtualhere.service: Control process exited, code=exited, status=203/EXEC
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- An ExecStart= process belonging to unit virtualhere.service has exited.
--
-- The process' exit code is 'exited' and its exit status is 203.
Oct 02 01:39:27 raspberrypi systemd[1]: virtualhere.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit virtualhere.service has entered the 'failed' state with result 'exit-code'.
Oct 02 01:39:27 raspberrypi systemd[1]: Failed to start VirtualHere Server.
-- Subject: A start job for unit virtualhere.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit virtualhere.service has finished with a failure.
--
-- The job identifier is 1509 and the job result is failed.
 

#20

Looking back at message #3 in this thread, I have definitely been using armpi4 version all along.

I have now uninstalled and reinstalled using curl https://raw.githubusercontent.com/virtualhere/script/main/install_server | sudo sh -s - vhusbdarmpi4 and will attempt to add the test version from post #13.

Okay! Rock'n'roll! Server now at v4.7.0.

Can you tell me where to find the logs, please?
I won't be using VH much over the next day or two, but will report back as soon as it crashes out.

 

Thanks, Michael!
-Dax.

#21

OK great, run this to see the logs.

journalctl

To save to file type

sudo journalctl > out.txt

 

 

#22

Aha!! In the famous words of Janine Melnitz: https://www.youtube.com/watch?v=iFmNyxni-0A

 

2024-10-07 20:44:37 INFO  :VirtualHere Client 5.7.8 starting (Compiled: Oct  1 2024 09:16:58)
2024-10-07 20:44:37 INFO  :Client OS is Windows 10 (build 19045), 64-bit edition
2024-10-07 20:44:37 INFO  :Using config at C:\Users\CR1-W10\AppData\Roaming\vhui.ini
2024-10-07 20:44:37 INFO  :IPC available at \\.\pipe\vhclient
2024-10-07 20:44:37 INFO  :Auto-find (Bonjour) on
2024-10-07 20:44:37 INFO  :Auto-find (Bonjour SSL) on
2024-10-07 20:44:43 INFO  :Drivers are up-to-date
2024-10-07 20:44:43 INFO  :Connected to the VirtualHere Client Driver (Version 2)
2024-10-07 21:55:26 INFO  :Connection 1 remotely disconnected gracefully (rx)
2024-10-07 21:55:36 INFO  :Server ping timeout, shutting down connection 1...
2024-10-07 21:55:38 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c
2024-10-07 21:55:38 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c
 

The device tree showed the same as in post #12.
I am not aware of any event that might have caused the connect to drop.

 

By the way, great idea to make this a popup message. Love that.

#23

OK great, could you run this on the pi server and tell me if it outputs anything

journalctl -u virtualhere.service | grep INCONSISTENCY
 

#24

No output at all.

I tried grep'ing for something simple (I) and got output, so can confirm INCONSISTENCY isn't in the log.

#25

I have updated the server again to 4.7.1, could you ssh to the pi then run

cd ~

sudo systemctl stop virtualhere

sudo rm -f ./vhusbdarmpi4

wget https://www.virtualhere.com/sites/default/files/usbserver/test/vhusbdarmpi4

chmod +x ./vhusbdarmpi4

sudo cp ./vhusbdarmpi4 /usr/local/sbin

systemctl start virtualhere

To confirm : in the virtualhere client right click on the server and select Properties and Version should say 4.7.1

It will show a different error when it happens again. Hopefully that new error will provide the final clue. Thanks for your patience.

#26

When I walked in and turned on my PC today, within a moment, I got this and the first two devices (both of which are auto-connect) were showing the :: thing.

2024-10-08 09:55:24 INFO  :VirtualHere Client 5.7.8 starting (Compiled: Oct  1 2024 09:16:58)
2024-10-08 09:55:24 INFO  :Client OS is Windows 10 (build 19045), 64-bit edition
2024-10-08 09:55:24 INFO  :Using config at C:\Users\CR1-W10\AppData\Roaming\vhui.ini
2024-10-08 09:55:24 INFO  :IPC available at \\.\pipe\vhclient
2024-10-08 09:55:24 INFO  :Auto-find (Bonjour) on
2024-10-08 09:55:24 INFO  :Auto-find (Bonjour SSL) on
2024-10-08 09:55:24 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c
2024-10-08 09:55:24 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c
 

I'll update to the newest test version now.
I won't be on my studio PC for a few days, so unfortunately silence doesn't mean it's solved, but I will let you know as soon as I have something for you.

#27

Hey Michael, hope you're well.

Wanted to check in to say that I haven't seen this bug in some time. Consider it solved??

All the best,
Dax.

#28

Ok hopefully:)

#29

Hey mate,
I just walked back in to my PC and found the error report popup. The VH Client window was showing:

1) Davinci Resolve dongle (In use by SYSTEM at ::) - Device is set to auto-use by the PC.
2) WIBU CodeMeter (In use by SYSTEM at ::) - Device is set to auto-use by the PC.
2) iLok - Device was completely disconnected. Device is not set to auto-connect.


2024-12-09 19:49:30 INFO  :VirtualHere Client 5.7.8 starting (Compiled: Oct  1 2024 09:16:58)
2024-12-09 19:49:30 INFO  :Client OS is Windows 10 (build 19045), 64-bit edition
2024-12-09 19:49:30 INFO  :Using config at C:\Users\CR1-W10\AppData\Roaming\vhui.ini
2024-12-09 19:49:30 INFO  :IPC available at \\.\pipe\vhclient
2024-12-09 19:49:31 INFO  :Auto-find (Bonjour) on
2024-12-09 19:49:31 INFO  :Auto-find (Bonjour SSL) on
2024-12-09 19:49:31 INFO  :Drivers are up-to-date
2024-12-09 19:49:31 INFO  :Connected to the VirtualHere Client Driver (Version 2)
2024-12-10 01:05:16 INFO  :Connection 1 remotely disconnected gracefully (rx)
2024-12-10 01:05:28 INFO  :Server ping timeout, shutting down connection 1...
2024-12-10 01:05:48 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c
2024-12-10 01:05:48 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c

#30

Powered up my PC this afternoon, but didn't sit down at it until now. Saw this message. I had not connected to the iLok (as I had only just sat down).

2024-12-10 18:14:11 INFO  :VirtualHere Client 5.7.8 starting (Compiled: Oct  1 2024 09:16:58)
2024-12-10 18:14:11 INFO  :Client OS is Windows 10 (build 19045), 64-bit edition
2024-12-10 18:14:11 INFO  :Using config at C:\Users\CR1-W10\AppData\Roaming\vhui.ini
2024-12-10 18:14:11 INFO  :IPC available at \\.\pipe\vhclient
2024-12-10 18:14:11 INFO  :Auto-find (Bonjour) on
2024-12-10 18:14:11 INFO  :Auto-find (Bonjour SSL) on
2024-12-10 18:14:11 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c
2024-12-10 18:14:11 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c
2024-12-10 18:14:14 INFO  :Connection 1 receiving msg size didnt complete due to error 10053, 
2024-12-10 18:14:23 INFO  :assert:../src/common/event.cpp,1981,SearchDynamicEventTable,nNew != dynamicEvents.size(),
2024-12-10 18:14:23 INFO  :Server ping timeout, shutting down connection 1...
2024-12-10 18:14:42 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c
2024-12-10 18:14:42 ERROR :Device Info INCONSISTENCY connected and bound but no boundConnectionUUID from server 10000000e66ba63c

#31

OK i have another idea to debug this, i will post here again soon with the instructions...

#32

On the pi, can you run the command below and post the output here

uname -a

 

#33

Linux raspberrypi 5.10.103-v7l+ #1529 SMP Tue Mar 8 12:24:00 GMT 2022 armv7l GNU/Linux

#34

I do think its worth updating to the latest pi firmware if you want, because it might be the problem.

Can you do:

 sudo apt update;sudo apt upgrade

#35

I wish! There's a problem that I cannot seem to find a solution to that is preventing me from upgrading to version 6.

I would be more than happy to, if you have any suggestions on it. (I know it's outside of the scope of VH support, but any ideas would be great.)

#37

Yeah, but I have a lot of other things set up including Unifi Controller (which is the worst) and Node-RED. I clean install is going to take me forever to get back to an operational state.

#38

This is the error, BTW:

I've barely been able to find anything about it online, let alone how to solve it.

dpkg: error processing package raspberrypi-kernel-headers (--configure):
package is in a very bad inconsistent state; you should
reinstall it before attempting configuration
 

Despite that scary-sounding warning, I've had no issues of failure, crashes or data loss and it's been like this for probably a year (I'd guess). Except for VH, everything is working fine.

#39

Ok unfortunately its not possible to debug such a kernel because i cannot install this on an existing pi to get the stack trace. IF you could somehow update your pi to the latest then it could be debuggable. In the meantime you will have to reboot if the issue occurs.

 

#40

No worries, I understand.

Incidentally, I don't think I needed to reboot the pi after experiencing the error? I'll keep an eye on that, too, though. (Would hate to give you misinformation.)

Would it be a good idea to say that VH is supported on PiOS v6 and higher?

#41

I managed to get the debug build working.

I put beta build 4.7.3 of the server at the test link, could you repeat the steps in post #25 (https://www.virtualhere.com/comment/13334#comment-13334)

When it detects a logic error, it will write a file in root directory / called core. Could you email me that file when its generated. Zip it first because it might be big.

Note the version will be 4.7.3 with this new build.

 

#42

Hey Michael,
Great, thanks, it's now installed. I'll let you know next time it happens.