5.1.26 won't start Ubuntu VM headless

[EricL]

Hi,
I have been unable to use the latest version of VirtualBox (Version 5.1.26 r117224 (Qt5.6.2)) on my MacBook Pro (Retina, 15-inch, Mid 2015) with the latest patches (10.12.6 (16G29)).
I had been using VB as part of our Chef/Test Kitchen/Vagrant development for several months without any issues.
If I revert to 5.1.18, everything works like a charm.

So far, what I can find is that the very VM that can't start with

kitchen converge

, can start just fine in normal mode. However, even using VB's GUI, I can't start that VM in headless mode.
I also tried to create a plain/blank VM and it shows the same issues. Here is what I did:

• New VM (name: test, Type: Linux, Version: Ubuntu (64-bit), RAM: 1024MB, Create VHD now, VDI, Dynamically Allocated, 10GB, create)
• normal start the VM
• it prompts me to insert a media, which is fine, I don't care
• do the same steps as above, but:
• headless start the VM
• I get the following error:

  Result Code: 
  NS_ERROR_FAILURE (0x80004005)
  Component: 
  MachineWrap
  Interface: 
  IMachine {b2547866-a0a1-4391-8b86-6952d82efaa0}

It is pretty much the same error I get when using Vagrant/Test Kitchen:

Code: Select all

-----> Starting Kitchen (v1.15.0)
WARN: Unresolved specs during Gem::Specification.reset:
      ffi (>= 1.0.1)
WARN: Clearing out unresolved specs.
Please report a bug if this causes problems.
-----> Creating <default-ubuntu-1404>...
       Bringing machine 'default' up with 'virtualbox' provider...
       ==> default: Checking if box 'bento/ubuntu-14.04' is up to date...
       ==> default: Clearing any previously set forwarded ports...
       ==> default: Clearing any previously set network interfaces...
       ==> default: Preparing network interfaces based on configuration...
           default: Adapter 1: nat
       ==> default: Forwarding ports...
           default: 3003 (guest) => 4004 (host) (adapter 1)
           default: 22 (guest) => 2222 (host) (adapter 1)
       ==> default: Booting VM...
       There was an error while executing `VBoxManage`, a CLI used by Vagrant
       for controlling VirtualBox. The command and stderr is shown below.

       Command: ["startvm", "38818bc5-f59e-4d4c-ab7d-645b2a620891", "--type", "headless"]

       Stderr: VBoxManage: error: The virtual machine 'kitchen-access_tool_api-default-ubuntu-1404_default_1502996132995_50117' has terminated unexpectedly during startup with exit code 1 (0x1)
       VBoxManage: error: Details: code NS_ERROR_FAILURE (0x80004005), component MachineWrap, interface IMachine
>>>>>> ------Exception-------
>>>>>> Class: Kitchen::ActionFailed
>>>>>> Message: 1 actions failed.
>>>>>>     Failed to complete #create action: [Expected process to exit with [0], but received '1'
---- Begin output of vagrant up --no-provision --provider virtualbox ----
STDOUT: Bringing machine 'default' up with 'virtualbox' provider...
==> default: Checking if box 'bento/ubuntu-14.04' is up to date...
==> default: Clearing any previously set forwarded ports...
==> default: Clearing any previously set network interfaces...
==> default: Preparing network interfaces based on configuration...
    default: Adapter 1: nat
==> default: Forwarding ports...
    default: 3003 (guest) => 4004 (host) (adapter 1)
    default: 22 (guest) => 2222 (host) (adapter 1)
==> default: Booting VM...
STDERR: There was an error while executing `VBoxManage`, a CLI used by Vagrant
for controlling VirtualBox. The command and stderr is shown below.

Command: ["startvm", "38818bc5-f59e-4d4c-ab7d-645b2a620891", "--type", "headless"]

Stderr: VBoxManage: error: The virtual machine 'kitchen-access_tool_api-default-ubuntu-1404_default_1502996132995_50117' has terminated unexpectedly during startup with exit code 1 (0x1)
VBoxManage: error: Details: code NS_ERROR_FAILURE (0x80004005), component MachineWrap, interface IMachine
---- End output of vagrant up --no-provision --provider virtualbox ----
Ran vagrant up --no-provision --provider virtualbox returned 1] on default-ubuntu-1404
>>>>>> ----------------------
>>>>>> Please see .kitchen/logs/kitchen.log for more details
>>>>>> Also try running `kitchen diagnose --all` for configuration

[socratis]

Kitchen is a program that relies on VirtualBox but modifies its configuration files in unknown ways to us. It is not supported on these VirtualBox user forums, they have their own support channels.

If you are having this problem with a standalone version of VirtualBox, then we can continue this discussion. Please read the following: Minimum information needed for assistance.

[EricL]

Hi,
Thanks for your follow-up. While I did discover this issue using Kitchen, I have provided the steps to reproduce it outside of kitchen.
If you check my original post, the list of steps does NOT mention kitchen. It specifically states that I used the VB GUI and was able to reproduce this error.
I have spent hours reading various suggestions (a vast majority from you, thanks) on this forum. None that I could find were able to solve my problem.
If there are additional debug steps I can take to get more info, I would be more than happy to try.

[socratis]

If there are additional debug steps I can take to get more info, I would be more than happy to try.

I already gave you the link to provide the Minimum information needed for assistance. Specifically for the VM log file ("VBox.log.zip"), here's what you do:

1. Start the VM. Not from a saved or paused state. Clean start.
2. Take the steps required to generate/observe the error.
3. Shut down the VM (if it hasn't aborted by itself). Not saved or paused. Completely shut down. If you can't shut it down by normal means, close the VM and select "Power off".
4. Right-click on the VM in the VirtualBox Manager. Select "Show Log..."
5. Save it (only the first VBox.log), ZIP it and attach it to your response (see the "Upload attachment" tab below the reply form).

I would also like to see the "recipe" of the VM, the ".vbox" file:

1. Right-click on the VM in the VirtualBox Manager. Select "Show in Finder/Explorer/Whatever".
2. ZIP the selected ".vbox" file and attach it to your response.

[EricL]

Thanks for the quick response. My bad for missing your steps suggestion to start with.
I upgraded to 5.1.26 again and by following your steps, I did not get any log files (the VM flat out does not start...). If I perform a normal start (instead of headless), it works and the log file is generated.
I am attaching the vbox file.

[socratis]

The .vbox file looks OK. Please try to disable the Audio as a first step. Start the VM headless. Make absolutely sure that there are no VBox.log in the VM folder. Then look for the file "/Users/<you>/Library/VirtualBox/VBoxSVC.log". ZIP that file and attach it.

Also, please post the output of the command:

• ls -alR /tmp/

[EricL]

Audio did not seem to fix the issue. I am attaching the VBoxSVC.log (zipped).
output of command is:

Code: Select all

total 0
drwxrwxrwt  8 root       wheel  272 Aug 22 13:36 .
drwxr-xr-x@ 6 root       wheel  204 Sep 21  2016 ..
-rwxrwxrwx  1 root       wheel    0 Aug 22 10:14 .TeamViewer.lock
-rw-rw-rw-@ 1 eliprandi  wheel    0 Aug 22 10:14 .keystone_install_lock
drwx------  4 eliprandi  wheel  136 Aug 22 13:26 .vbox-eliprandi-ipc
drwx------  3 eliprandi  wheel  102 Aug 22 10:14 com.apple.launchd.k9gJICDIuz
drwx------  3 eliprandi  wheel  102 Aug 22 10:14 com.apple.launchd.sBY6izOb8A
srwx------  1 eliprandi  wheel    0 Aug 22 10:15 mongodb-27017.sock

/tmp//.vbox-eliprandi-ipc:
total 8
drwx------  4 eliprandi  wheel  136 Aug 22 13:26 .
drwxrwxrwt  8 root       wheel  272 Aug 22 13:36 ..
srwx------  1 eliprandi  wheel    0 Aug 22 13:26 ipcd
-rw-------  1 eliprandi  wheel    5 Aug 22 13:26 lock

/tmp//com.apple.launchd.k9gJICDIuz:
total 0
drwx------  3 eliprandi  wheel  102 Aug 22 10:14 .
drwxrwxrwt  8 root       wheel  272 Aug 22 13:36 ..
srw-rw-rw-  1 eliprandi  wheel    0 Aug 22 10:14 Render

/tmp//com.apple.launchd.sBY6izOb8A:
total 0
drwx------  3 eliprandi  wheel  102 Aug 22 10:14 .
drwxrwxrwt  8 root       wheel  272 Aug 22 13:36 ..
srw-rw-rw-  1 eliprandi  wheel    0 Aug 22 10:14 Listeners

[socratis]

I thought that we agreed for you to test a plain vanilla VM. This is not one:

Code: Select all

00:00:00.168132 nspr-2   Loading settings file "/Users/eliprandi/VirtualBox VMs/kitchen-tools_framework-default-ubuntu-1404_default_1503000636148_14788/kitchen-tools_framework-default-ubuntu-1404_default_1503000636148_14788.vbox" with version "1.16-macosx"

[EricL]

Sorry, I must have been confused. There are no VBox.log files in the VM's folder (/Users/<me>/VirtualBox VMs/test4/Logs) as you requested.
However, I do have 1 other vm (generated by kitchen). That is not the one I started. I started the test4 one. The /Users/eliprandi/Library/VirtualBox/VBoxSVC.log seems to be a rolling log file.
I went ahead and deleted that VM and deleted the VBoxSVC.log file. I then called VirtualBox restart.
I then started the VM, headless and it failed. The new VBoxSVC.log is attached.

[socratis]

OK, thanks. Could you please attach "/Users/eliprandi/Library/VirtualBox/VirtualBox.xml". Zip it first because it won't go through the attaching process.

PS. I've seen VMs failing to start Nornal, while starting Headless. Never the other way around...

[EricL]

No pb. Here is the xml file.
Could this be related to some network protection software like "ForcePoint" (Triton AP-Endpoint)?

[socratis]

Thanks again. I don't know what's causing this, honestly. I cannot think of any good (or bad for that matter) reason why a VM would start Normal, but not Headless. Everything looks in order.

There is one last thing you can try (aka a Hail Mary). Quit VirtualBox. Open Activity Monitor » View » All processes » sort by Process Name » make sure that no Virt*, vm* or vbox* processes are running. If they are, give it a minute, they'll quit. If they don't, reboot and don't start anything VirtualBox related.

Open up Terminal. Give the command (and I'll include what you're supposed to see as the output):

VBoxManage startvm "test4" --type gui
Waiting for VM "test4" to power on...
VM "test4" has been successfully started.

That should work, that's the same as launching the VM "Normal". Quit the VM, power it off. Repeat the drill with the Activity Monitor and wait until all the processes that I mentioned before quit. Next, issue the command:

VBoxManage startvm "test4" --type headless

What's the output in the Terminal?

[EricL]

Here is the output of the 2 commands:

FNL-0169:~ eliprandi$ VBoxManage startvm "test4" --type gui
Waiting for VM "test4" to power on...
VM "test4" has been successfully started.
FNL-0169:~ eliprandi$ VBoxManage startvm "test4" --type headless
Waiting for VM "test4" to power on...
VBoxManage: error: The virtual machine 'test4' has terminated unexpectedly during startup with exit code 1 (0x1)
VBoxManage: error: Details: code NS_ERROR_FAILURE (0x80004005), component MachineWrap, interface IMachine

Nothing groundbreaking here unfortunately. Let me know if you think of anything else I can try.

[socratis]

EricL, there is an alternative way to start a VM headless, which I forgot; the "VBoxHeadless" command (duh ). So, please try (in the Terminal again) the following:

• VBoxHeadless --startvm "test4"

You will not see the return to the prompt until the process is done. You can terminate the process with Ctrl-C (the VM will show as Aborted, that's OK). Post the Teminal output please...

[EricL]

Thanks for looking into this.
I tried the VBoxHeadless command and it just sits there...

FNL-0169:~ eliprandi$ VBoxHeadless --startvm "test4"
Oracle VM VirtualBox Headless Interface 5.1.26
(C) 2008-2017 Oracle Corporation
All rights reserved.

^C
FNL-0169:~ eliprandi$