Does vm.IsRunning lie?

172 views
Skip to first unread message

Colin Campbell

unread,
Oct 10, 2014, 10:48:06 AM10/10/14
to vmwar...@googlegroups.com
I've got a little VM monitoring app that I've been working on, and one of his jobs is to keep a file up to date in a VM.  It periodically checks to see if it should upload a file to the VM and if it needs to, it does.  But over time the app will often crash.  Usually due to checking to see if the VM.IsRunning, and if that returns false, then it tries to VM.PowerOn.  But there are a number of times where IsRunning (seemingly in error) is returning false, so when I try to power on the machine, I get the following error.  Is there a power management setting I'm missing in the VM, or a non-blocking call I should be waiting for, maybe I should just increase the timeout?  Thoughts?

System.Exception: Failed to power on virtual machine: powerOnOptions=512 timeoutInSeconds=300 ---> Vestris.VMWareLib.VMWareException: Unknown error
   at Vestris.VMWareLib.VMWareInterop.Check(UInt64 errCode)
   at Vestris.VMWareLib.VMWareJob.Wait(Int32 timeoutInSeconds)
   at Vestris.VMWareLib.VMWareVirtualMachine.PowerOn(Int32 powerOnOptions, Int32 timeoutInSeconds)
   --- End of inner exception stack trace ---
   at Vestris.VMWareLib.VMWareVirtualMachine.PowerOn(Int32 powerOnOptions, Int32 timeoutInSeconds)
   at Vestris.VMWareLib.VMWareVirtualMachine.PowerOn(Int32 timeoutInSeconds)
...

Daniel Doubrovkine

unread,
Oct 11, 2014, 8:16:55 AM10/11/14
to vmwar...@googlegroups.com
Does this happen after a certain amount of (fixed) time? VixCOM is known to have all kinds of complicated connection pooling and other things, so try re-connecting every time (re-create all objects for each test, don't reuse a VirtualMachine instance) and see if that changes anything. 

--
You received this message because you are subscribed to the Google Groups "vmwaretasks" group.
To unsubscribe from this group and stop receiving emails from it, send an email to vmwaretasks...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.



--

dB. | Moscow - Geneva - Seattle - New York
code.dblock.org - @dblockdotorg - artsy.net - github/dblock

Colin Campbell

unread,
Oct 16, 2014, 1:27:25 PM10/16/14
to vmwar...@googlegroups.com
Thanks for the reply.  So far, it's been different from client to client with some machines have no problems for a week where others crash nightly.  I changed the code to dispose the virtual machines and the hosts as quickly as possible.  Thanks again

Colin Campbell

unread,
Oct 17, 2014, 10:28:55 AM10/17/14
to vmwar...@googlegroups.com
Hmm, so that didn't fix it, but I have new information.

The VM logs show VIX errors suggesting me connections aren't being properly cleaned up at the same time as the VM management program crashes.

VMWare Workstation logs:
2014-10-16T23:35:06.968-04:00| vmx| I120: SOCKET 504 (1744) recv error 10053: An established connection was aborted by the software in your host machine
2014-10-16T23:35:06.968-04:00| vmx| I120: Vix: [7080 mainDispatch.c:2777]: VMAutomation: Connection Error (1) on connection 503.
2014-10-16T23:35:07.125-04:00| vmx| I120: SOCKET 505 (1744) recv detected client closed connection
2014-10-16T23:35:07.125-04:00| vmx| I120: Vix: [7080 mainDispatch.c:2777]: VMAutomation: Connection Error (4) on connection 504.
2014-10-16T23:40:08.055-04:00| vmx| I120: Vix: [7080 mainDispatch.c:1583]: VMAutomation: Cannot accept new connections, already have 31 open connections (PR 497789)
2014-10-16T23:40:08.175-04:00| vmx| I120: Vix: [7080 mainDispatch.c:1583]: VMAutomation: Cannot accept new connections, already have 31 open connections (PR 497789)
2014-10-16T23:40:08.380-04:00| vmx| I120: Vix: [7080 mainDispatch.c:1583]: VMAutomation: Cannot accept new connections, already have 31 open connections (PR 497789)
2014-10-16T23:40:17.472-04:00| mks| I120: MKS-SWB: Number of MKSWindows changed: 1 rendering MKSWindow(s) of total 2.

And the management app logs:
DEBUG 2014/10/16 23:40:08.091 - |   |   VM is not running, starting it up
DEBUG 2014/10/16 23:40:08.169 - |   |   O---->> [VirtualMachineHost.StartUp]
DEBUG 2014/10/16 23:40:08.169 - |   |   |   Connecting to VMWare Workstation
DEBUG 2014/10/16 23:40:08.169 - |   |   |   Opening .vmx file in host
DEBUG 2014/10/16 23:40:08.205 - |   |   |   Powering on VM
DEBUG 2014/10/16 23:40:08.933 - |   |   |   UNHANDLED AppDomain.Exception OCCURED:
DEBUG 2014/10/16 23:40:09.348 - System.Exception: Failed to power on virtual machine: powerOnOptions=512 timeoutInSeconds=300 ---> Vestris.VMWareLib.VMWareException: Unknown error
   at Vestris.VMWareLib.VMWareInterop.Check(UInt64 errCode)
   at Vestris.VMWareLib.VMWareJob.Wait(Int32 timeoutInSeconds)
   at Vestris.VMWareLib.VMWareVirtualMachine.PowerOn(Int32 powerOnOptions, Int32 timeoutInSeconds)
   --- End of inner exception stack trace ---
   at Vestris.VMWareLib.VMWareVirtualMachine.PowerOn(Int32 powerOnOptions, Int32 timeoutInSeconds)
   at Vestris.VMWareLib.VMWareVirtualMachine.PowerOn(Int32 timeoutInSeconds)
...

But all my VirtualMachineHosts and VMWareVirtualMachines are wrapped in usings, and I'm not using snapshots for anything.  Maybe there's something else IDisposable that I missed?  I'm not seeing it.
Any thoughts?

Daniel Doubrovkine

unread,
Oct 17, 2014, 11:49:56 AM10/17/14
to vmwar...@googlegroups.com
It could also be a limit reached by something else, or a bug in VixCOM? Which version are you using?

Colin Campbell

unread,
Oct 17, 2014, 12:30:44 PM10/17/14
to vmwar...@googlegroups.com
That's a thought..  I thought the only other actor involved was VMWare Workstation, but maybe no.  VixCOM Version is whatever came with Workstation 9.0.4, looks like VixCOM.dll file version is 1.12.4.  Will try updating to 1.13 next.  Thanks!

Colin Campbell

unread,
Oct 17, 2014, 3:07:12 PM10/17/14
to vmwar...@googlegroups.com
Humm... well it's not a VIX 1.12 v 1.13 thing.

Daniel Doubrovkine

unread,
Oct 18, 2014, 9:15:30 AM10/18/14
to vmwar...@googlegroups.com
I would try and run this in a loop quickly and start taking code out until you can for example connect an infinite amount of times, then check for something, etc. Basically try to reproduce the error without waiting a day.

Colin Campbell

unread,
Oct 20, 2014, 10:44:38 AM10/20/14
to vmwar...@googlegroups.com
Good call!  Okay, I've now run this following code on a Windows 8.1 guest, as well as a Windows 7 guest with the same result -- eventually VMAutomation can no longer accept new connections (maxed out at 31) and starts lying about vm.IsRunning (which just returns false).

        private void Blitz()
        {
            for (int i = 0; i < 100; ++i)
            {
                using (var host = new Vestris.VMWareLib.VMWareVirtualHost())
                {
                    host.ConnectToVMWareWorkstation();
                    using (var vm = host.Open(@"D:\VMs\Sifu\Sifu.vmx"))
                    {
                        vm.LoginInGuest("User", "acadis");
                        vm.RunProgramInGuest(@"C:\Users\User\timeout.bat", string.Empty);
                        vm.LogoutFromGuest();
                    }
                }
            }
        }

Takes 10-20 seconds before it throws.  Going to try varying .NET versions next.

Daniel Doubrovkine

unread,
Oct 20, 2014, 11:12:47 AM10/20/14
to vmwar...@googlegroups.com
I think this is pretty clear. Try without the var vm = ... so just ConnectToVMWareWorkstation. 

Then try to explicitly disconnect with host.Disconnect.

Colin Campbell

unread,
Oct 20, 2014, 12:11:41 PM10/20/14
to vmwar...@googlegroups.com
it must be one of the interactions (Login, RunProgram, or Logout) with the VM -- the following code works with no exceptions (even after I bumped it up to 1000 iterations).  For completeness, it works just fine with or without the ConnectTo and it works just fine with or without the .Disconnect.

        private void Blitz()
        {
            for (int i = 0; i < 1000; ++i)
            {
                using (var host = new Vestris.VMWareLib.VMWareVirtualHost())
                {
                    host.ConnectToVMWareWorkstation();
                    using (var vm = host.Open(@"D:\VMs\Sifu\Sifu.vmx"))
                        ;
                    host.Disconnect();
                }
            }
        }


--
You received this message because you are subscribed to a topic in the Google Groups "vmwaretasks" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/vmwaretasks/feqT76cpV5o/unsubscribe.
To unsubscribe from this group and all its topics, send an email to vmwaretasks...@googlegroups.com.

Colin Campbell

unread,
Oct 20, 2014, 1:39:33 PM10/20/14
to vmwar...@googlegroups.com
Alright, so just putting the login/logout lines back in makes it start to fail again.  Is there something asynchronous I need to wait on when the program is logging into the guest?  Maybe a semaphore I can check to see that it's safe to make the next call to the VM?
To unsubscribe from this group and stop receiving emails from it, send an email to vmwaretasks+unsubscribe@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to a topic in the Google Groups "vmwaretasks" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/vmwaretasks/feqT76cpV5o/unsubscribe.
To unsubscribe from this group and all its topics, send an email to vmwaretasks+unsubscribe@googlegroups.com.

Daniel Doubrovkine

unread,
Oct 20, 2014, 3:03:25 PM10/20/14
to vmwar...@googlegroups.com
TBH I don't know. In theory, no.

Colin Campbell

unread,
Oct 22, 2014, 10:30:17 AM10/22/14
to vmwar...@googlegroups.com
For curious people dropping by in the future, it appears that my issue is resolved by adding a Thread.Sleep after the call to LogoutFromGuest.  Looking at the implementation in VMWareTasks/VMWareLib it certainly looks like it's appropriately waiting for VIX's job completed callback so I'm not sure what problem this .Sleep() hackery is working around, but it solved my problem for the time being.

        private void Blitz()
        {
            for (int i = 0; i < 1000; ++i)
            {
                using (var host = new Vestris.VMWareLib.VMWareVirtualHost())
                {
                    host.ConnectToVMWareWorkstation();
                    using (var vm = host.Open(@"T:\VMs\VM\VM.vmx"))
                    {
                        vm.LoginInGuest("User", "1");
                        vm.LogoutFromGuest();
                        Thread.Sleep(100);
                    }
                    host.Disconnect();

--
You received this message because you are subscribed to a topic in the Google Groups "vmwaretasks" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/vmwaretasks/feqT76cpV5o/unsubscribe.
To unsubscribe from this group and all its topics, send an email to vmwaretasks...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "vmwaretasks" group.
To unsubscribe from this group and stop receiving emails from it, send an email to vmwaretasks...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
Reply all
Reply to author
Forward
0 new messages