search

hashicorp / vagrant

Vagrant is a tool for building and distributing development environments.
https://www.vagrantup.com
Other
26.27k stars 4.43k forks source link

`vagrant up` hangs at "Waiting for VM to boot. This can take a few minutes" #1066

Closed brandondrew closed 12 years ago

brandondrew commented 12 years ago

The really odd thing is that sometimes it gets past this point and hangs at "Configuring and enabling network interfaces...". It doesn't exactly alternate between the two, but it seems random whether it will hang at one or the other. In the case where it doesn't get past "Waiting for VM to boot." it eventually ends in a stack trace. In the case of hanging on the other line, it just hangs there forever. (Well, at least it'll sit there overnight without dying with a stack trace.)

I was suspecting that the problem was with shared folders (since it never gets to that) but I disabled all the shared folders in my Vagrantfile and that made no difference.

Here are the results of attempting to do this with logging set at DEBUG.

I'm running on a Windows host with a CentOS 6.2 guest. 

$ VAGRANT_LOG=DEBUG vagrant up
 INFO global: Vagrant version: 1.0.2
 INFO vagrant: `vagrant` invoked: ["up"]
DEBUG vagrant: Creating Vagrant environment
 INFO environment: Environment initialized (#<Vagrant::Environment:0x2d83cd0>)
 INFO environment:   - cwd: c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com
 INFO environment: Home path: c:/Users/BZISAD0/.vagrant.d
 INFO plugin: Searching and loading any available plugins...
 INFO plugin: Loading plugin: vagrant-vbguest (0.3.5)
 INFO plugin: Loaded 1 plugins.
DEBUG vagrant: Loading environment
 INFO environment: Loading configuration...
DEBUG loader: Set :default = "c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/co
nfig/default.rb"
DEBUG loader: Populating proc cache for "c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagra
nt-1.0.2/config/default.rb"
DEBUG loader: Load procs for pathname: #<Pathname:c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/g
ems/vagrant-1.0.2/config/default.rb>
DEBUG loader: Set :root = #<Pathname:c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/Vagrant
file>
DEBUG loader: Populating proc cache for #<Pathname:c:/Users/BZISAD0/Code/Drupal/www.spartanstor
es.com/Vagrantfile>
DEBUG loader: Load procs for pathname: #<Pathname:c:/Users/BZISAD0/Code/Drupal/www.spartanstore
s.com/Vagrantfile>
DEBUG loader: Loading configuration in order: [:default, :box, :home, :root, :vm]
DEBUG loader: Loading from: default (evaluating)
DEBUG loader: Loading from: root (evaluating)
DEBUG provisioner: Provisioner config: chef_solo
 INFO provisioner: Provisioner class: Vagrant::Provisioners::ChefSolo
DEBUG provisioner: Configuring provisioner with: Vagrant::Provisioners::ChefSolo::Config
DEBUG loader: Configuration loaded successfully
DEBUG environment: Loading configuration for VM: www
DEBUG loader: Set :default = "c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/co
nfig/default.rb"
DEBUG loader: Set :root = #<Pathname:c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/Vagrant
file>
DEBUG loader: Set :vm = []
DEBUG loader: Loading configuration in order: [:default, :box, :home, :root, :vm]
DEBUG loader: Loading from: default (cache)
DEBUG loader: Loading from: root (cache)
DEBUG loader: Configuration loaded successfully
DEBUG loader: Set :default = "c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/co
nfig/default.rb"
DEBUG loader: Set :box = #<Pathname:c:/Users/BZISAD0/.vagrant.d/boxes/vagrant-centos6-drupal.6/
Vagrantfile>
DEBUG loader: Populating proc cache for #<Pathname:c:/Users/BZISAD0/.vagrant.d/boxes/vagrant-ce
ntos6-drupal.6/Vagrantfile>
DEBUG loader: Load procs for pathname: #<Pathname:c:/Users/BZISAD0/.vagrant.d/boxes/vagrant-cen
tos6-drupal.6/Vagrantfile>
DEBUG loader: Set :root = #<Pathname:c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/Vagrant
file>
DEBUG loader: Set :vm = []
DEBUG loader: Loading configuration in order: [:default, :box, :home, :root, :vm]
DEBUG loader: Loading from: default (cache)
DEBUG loader: Loading from: box (evaluating)
DEBUG loader: Loading from: root (cache)
DEBUG loader: Configuration loaded successfully
 INFO cli: CLI: [] "up" []
DEBUG cli: Invoking command class: Vagrant::Command::Up []
DEBUG up: 'Up' each target VM...
 INFO datastore: Created: c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/.vagrant
DEBUG virtualbox_base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 INFO virtualbox_base: VBoxManage path: C:\Applications\VirtualBox\VBoxManage.exe
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "--version
"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: 4.1.18r78361

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
DEBUG virtualbox: Finding driver for VirtualBox version: 4.1.18
 INFO virtualbox: Using VirtualBox driver: Vagrant::Driver::VirtualBox_4_1
DEBUG virtualbox_base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 INFO virtualbox_base: VBoxManage path: C:\Applications\VirtualBox\VBoxManage.exe
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "6d42d3fc-3a8f-4851-8281-d6896049ad99"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: Name:            www.spartanstores.com
Guest OS:        Red Hat (64 bit)
UUID:            6d42d3fc-3a8f-4851-8281-d6896049ad99
Config file:     C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\www.spartanstores.com.vb
ox
Snapshot folder: C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots
Log folder:      C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Logs
Hardware UUID:   6d42d3fc-3a8f-4851-8281-d6896049ad99
Memory size:     512MB
Page Fusion:     off
VRAM size:       8MB
CPU exec cap:    100%
HPET:            off
Chipset:         piix3
Firmware:        BIOS
Number of CPUs:  1
Synthetic Cpu:   off
CPUID overrides: None
Boot menu mode:  message and menu
Boot Device (1): HardDisk
Boot Device (2): DVD
Boot Device (3): Not Assigned
Boot Device (4): Not Assigned
ACPI:            on
IOAPIC:          on
PAE:             on
Time offset:     0 ms
RTC:             local time
Hardw. virt.ext: on
Hardw. virt.ext exclusive: off
Nested Paging:   on
Large Pages:     on
VT-x VPID:       on
State:           powered off (since 2012-08-10T15:35:10.000000000)
Monitor count:   1
3D Acceleration: off
2D Video Acceleration: off
Teleporter Enabled: off
Teleporter Port: 0
Teleporter Address:
Teleporter Password:
Storage Controller Name (0):            IDE Controller
Storage Controller Type (0):            PIIX4
Storage Controller Instance Number (0): 0
Storage Controller Max Port Count (0):  2
Storage Controller Port Count (0):      2
Storage Controller Bootable (0):        on
Storage Controller Name (1):            SATA Controller
Storage Controller Type (1):            IntelAhci
Storage Controller Instance Number (1): 0
Storage Controller Max Port Count (1):  30
Storage Controller Port Count (1):      1
Storage Controller Bootable (1):        on
IDE Controller (0, 0): C:\Applications\VirtualBox\VBoxGuestAdditions.iso (UUID: e0d67cff-f8e9-4
39b-8de9-486d7e029e61)
IDE Controller (1, 0): Empty
SATA Controller (0, 0): C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots\{0576f4
c9-3072-4576-863c-5adc53b893c2}.vmdk (UUID: 0576f4c9-3072-4576-863c-5adc53b893c2)
NIC 1:           MAC: 080027E49DD9, Attachment: NAT, Cable connected: on, Trace: off (file: non
e), Type: 82540EM, Reported speed: 0 Mbps, Boot priority: 0, Promisc Policy: deny
NIC 1 Settings:  MTU: 0, Socket (send: 64, receive: 64), TCP Window (send:64, receive: 64)
NIC 1 Rule(0):   name = 2g-7sg, protocol = tcp, host ip = , host port = 8080, guest ip = , gues
t port = 80
NIC 1 Rule(1):   name = 37a-37a, protocol = tcp, host ip = , host port = 3306, guest ip = , gue
st port = 3306
NIC 1 Rule(2):   name = dr-4ah, protocol = tcp, host ip = , host port = 4433, guest ip = , gues
t port = 443
NIC 1 Rule(3):   name = m-25e, protocol = tcp, host ip = , host port = 2222, guest ip = , guest
 port = 22
NIC 2:           MAC: 080027D1AB25, Attachment: Host-only Interface 'VirtualBox Host-Only Ether
net Adapter #2', Cable connected: on, Trace: off (file: none), Type: 82540EM, Reported speed: 0
 Mbps, Boot priority: 0, Promisc Policy: deny
NIC 3:           disabled
NIC 4:           disabled
NIC 5:           disabled
NIC 6:           disabled
NIC 7:           disabled
NIC 8:           disabled
Pointing Device: PS/2 Mouse
Keyboard Device: PS/2 Keyboard
UART 1:          disabled
UART 2:          disabled
Audio:           disabled
Clipboard Mode:  Bidirectional
VRDE:            disabled
USB:             disabled

USB Device Filters:

<none>

Available remote USB devices:

<none>

Currently Attached USB Devices:

<none>

Shared folders:

Name: 'v-root', Host path: 'c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com' (machine mappin
g), writable
Name: 'v-csc-1', Host path: 'c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/cookbooks' (mac
hine mapping), writable
Name: 'v-csc-2', Host path: 'c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/recipebox' (mac
hine mapping), writable
Name: 'v-csr-3', Host path: 'c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/roles' (machine
 mapping), writable
Name: 'v-csdb-4', Host path: 'c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/data' (machine
 mapping), writable

VRDE Connection:    not active
Clients so far:     0

Guest:

Configured memory balloon size:      0 MB
OS type:                             RedHat_64
Additions run level:                 0
Additions version:                   4.1.18

Guest Facilities:

No active facilities.

Snapshots:

   Name: failing_to_boot_1 (UUID: 4492fac3-9e45-40f4-b9f1-2c12ce00673a) *
      Name: added test file (UUID: 9870481a-869f-47ad-aef5-fefdf70f8f5b)
      Name: before restoring 'failing_to_boot_1' (UUID: 35c14999-3c6b-431a-9387-d446ad693648)

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
DEBUG subprocess: Exit status: 0
 INFO vm: Loading guest: linux
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "6d42d3fc-3a8f-4851-8281-d6896049ad99", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="www.spartanstores.com"
ostype="RedHat_64"
UUID="6d42d3fc-3a8f-4851-8281-d6896049ad99"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\www.spartanstores.com.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Logs"
hardwareuuid="6d42d3fc-3a8f-4851-8281-d6896049ad99"
memory=512
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="on"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-08-10T15:35:10.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="1"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="C:\Applications\VirtualBox\VBoxGuestAdditions.iso"
"IDE Controller-ImageUUID-0-0"="e0d67cff-f8e9-439b-8de9-486d7e029e61"
"IDE Controller-tempeject"="off"
"IDE Controller-IsEjected"="off"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots\{0576f4c
9-3072-4576-863c-5adc53b893c2}.vmdk"
"SATA Controller-ImageUUID-0-0"="0576f4c9-3072-4576-863c-5adc53b893c2"
natnet1="nat"
macaddress1="080027E49DD9"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="2g-7sg,tcp,,8080,,80"
Forwarding(1)="37a-37a,tcp,,3306,,3306"
Forwarding(2)="dr-4ah,tcp,,4433,,443"
Forwarding(3)="m-25e,tcp,,2222,,22"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter #2"
macaddress2="080027D1AB25"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com"
SharedFolderNameMachineMapping2="v-csc-1"
SharedFolderPathMachineMapping2="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/cookbooks"
SharedFolderNameMachineMapping3="v-csc-2"
SharedFolderPathMachineMapping3="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/recipebox"
SharedFolderNameMachineMapping4="v-csr-3"
SharedFolderPathMachineMapping4="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/roles"
SharedFolderNameMachineMapping5="v-csdb-4"
SharedFolderPathMachineMapping5="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/data"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="RedHat_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.18"
SnapshotName="failing_to_boot_1"
SnapshotUUID="4492fac3-9e45-40f4-b9f1-2c12ce00673a"
SnapshotName-1="added test file"
SnapshotUUID-1="9870481a-869f-47ad-aef5-fefdf70f8f5b"
SnapshotName-2="before restoring 'failing_to_boot_1'"
SnapshotUUID-2="35c14999-3c6b-431a-9387-d446ad693648"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
 INFO up: Booting: www
 INFO interface: info: VM already created. Booting if it's not already running...
[www] VM already created. Booting if it's not already running...
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "6d42d3fc-3a8f-4851-8281-d6896049ad99", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="www.spartanstores.com"
ostype="RedHat_64"
UUID="6d42d3fc-3a8f-4851-8281-d6896049ad99"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\www.spartanstores.com.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Logs"
hardwareuuid="6d42d3fc-3a8f-4851-8281-d6896049ad99"
memory=512
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="on"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-08-10T15:35:10.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="1"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="C:\Applications\VirtualBox\VBoxGuestAdditions.iso"
"IDE Controller-ImageUUID-0-0"="e0d67cff-f8e9-439b-8de9-486d7e029e61"
"IDE Controller-tempeject"="off"
"IDE Controller-IsEjected"="off"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots\{0576f4c
9-3072-4576-863c-5adc53b893c2}.vmdk"
"SATA Controller-ImageUUID-0-0"="0576f4c9-3072-4576-863c-5adc53b893c2"
natnet1="nat"
macaddress1="080027E49DD9"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="2g-7sg,tcp,,8080,,80"
Forwarding(1)="37a-37a,tcp,,3306,,3306"
Forwarding(2)="dr-4ah,tcp,,4433,,443"
Forwarding(3)="m-25e,tcp,,2222,,22"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter #2"
macaddress2="080027D1AB25"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com"
SharedFolderNameMachineMapping2="v-csc-1"
SharedFolderPathMachineMapping2="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/cookbooks"
SharedFolderNameMachineMapping3="v-csc-2"
SharedFolderPathMachineMapping3="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/recipebox"
SharedFolderNameMachineMapping4="v-csr-3"
SharedFolderPathMachineMapping4="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/roles"
SharedFolderNameMachineMapping5="v-csdb-4"
SharedFolderPathMachineMapping5="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/data"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="RedHat_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.18"
SnapshotName="failing_to_boot_1"
SnapshotUUID="4492fac3-9e45-40f4-b9f1-2c12ce00673a"
SnapshotName-1="added test file"
SnapshotUUID-1="9870481a-869f-47ad-aef5-fefdf70f8f5b"
SnapshotName-2="before restoring 'failing_to_boot_1'"
SnapshotUUID-2="35c14999-3c6b-431a-9387-d446ad693648"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "6d42d3fc-3a8f-4851-8281-d6896049ad99", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
DEBUG subprocess: name="www.spartanstores.com"
ostype="RedHat_64"
UUID="6d42d3fc-3a8f-4851-8281-d6896049ad99"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\www.spartanstores.com.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Logs"
hardwareuuid="6d42d3fc-3a8f-4851-8281-d6896049ad99"
memory=512
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="on"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-08-10T15:35:10.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="1"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="C:\Applications\VirtualBox\VBoxGuestAdditions.iso"
"IDE Controller-ImageUUID-0-0"="e0d67cff-f8e9-439b-8de9-486d7e029e61"
"IDE Controller-tempeject"="off"
"IDE Controller-IsEjected"="off"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots\{0576f4c
9-3072-4576-863c-5adc53b893c2}.vmdk"
"SATA Controller-ImageUUID-0-0"="0576f4c9-3072-4576-863c-5adc53b893c2"
natnet1="nat"
macaddress1="080027E49DD9"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="2g-7sg,tcp,,8080,,80"
Forwarding(1)="37a-37a,tcp,,3306,,3306"
Forwarding(2)="dr-4ah,tcp,,4433,,443"
Forwarding(3)="m-25e,tcp,,2222,,22"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter #2"
macaddress2="080027D1AB25"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com"
SharedFolderNameMachineMapping2="v-csc-1"
SharedFolderPathMachineMapping2="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/cookbooks"
SharedFolderNameMachineMapping3="v-csc-2"
SharedFolderPathMachineMapping3="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/recipebox"
SharedFolderNameMachineMapping4="v-csr-3"
SharedFolderPathMachineMapping4="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/roles"
SharedFolderNameMachineMapping5="v-csdb-4"
SharedFolderPathMachineMapping5="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/data"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="RedHat_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.18"
SnapshotName="failing_to_boot_1"
SnapshotUUID="4492fac3-9e45-40f4-b9f1-2c12ce00673a"
SnapshotName-1="added test file"
SnapshotUUID-1="9870481a-869f-47ad-aef5-fefdf70f8f5b"
SnapshotName-2="before restoring 'failing_to_boot_1'"
SnapshotUUID-2="35c14999-3c6b-431a-9387-d446ad693648"

DEBUG hosts: Host path search classes: [Vagrant::Hosts::Windows, Vagrant::Hosts::Arch, Vagrant:
:Hosts::Gentoo, Vagrant::Hosts::Fedora, Vagrant::Hosts::OpenSUSE, Vagrant::Hosts::FreeBSD, Vagr
ant::Hosts::Linux, Vagrant::Hosts::BSD]
 INFO hosts: Host class: Vagrant::Hosts::Windows
 INFO runner: Running action: start
 INFO warden: Calling action: #<Vagrant::Action::General::CheckVirtualbox:0x362fb38>
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "list", "h
ostonlyifs"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: Name:            VirtualBox Host-Only Ethernet Adapter #2
GUID:            41d2ae3d-61e5-4f72-a33e-c94e96589013
Dhcp:            Disabled
IPAddress:       192.168.11.1
NetworkMask:     255.255.255.0
IPV6Address:
IPV6NetworkMaskPrefixLength: 0
HardwareAddress: 08:00:27:00:44:16
MediumType:      Ethernet
Status:          Up
VBoxNetworkName: HostInterfaceNetworking-VirtualBox Host-Only Ethernet Adapter #2

Name:            VirtualBox Host-Only Ethernet Adapter
GUID:            ad7d0473-8eae-46ba-9e45-b4966b42f62e
Dhcp:            Disabled
IPAddress:       192.168.56.1
NetworkMask:     255.255.255.0
IPV6Address:
IPV6NetworkMaskPrefixLength: 0
HardwareAddress: 08:00:27:00:18:ea
MediumType:      Ethernet
Status:          Up
VBoxNetworkName: HostInterfaceNetworking-VirtualBox Host-Only Ethernet Adapter

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31998
DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<Vagrant::Action::General::Validate:0x362fb20>
 INFO warden: Calling action: #<Vagrant::Action::VM::CheckAccessible:0x362fb08>
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "6d42d3fc-3a8f-4851-8281-d6896049ad99", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="www.spartanstores.com"
ostype="RedHat_64"
UUID="6d42d3fc-3a8f-4851-8281-d6896049ad99"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\www.spartanstores.com.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Logs"
hardwareuuid="6d42d3fc-3a8f-4851-8281-d6896049ad99"
memory=512
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="on"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-08-10T15:35:10.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="1"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="C:\Applications\VirtualBox\VBoxGuestAdditions.iso"
"IDE Controller-ImageUUID-0-0"="e0d67cff-f8e9-439b-8de9-486d7e029e61"
"IDE Controller-tempeject"="off"
"IDE Controller-IsEjected"="off"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots\{0576f4c
9-3072-4576-863c-5adc53b893c2}.vmdk"
"SATA Controller-ImageUUID-0-0"="0576f4c9-3072-4576-863c-5adc53b893c2"
natnet1="nat"
macaddress1="080027E49DD9"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="2g-7sg,tcp,,8080,,80"
Forwarding(1)="37a-37a,tcp,,3306,,3306"
Forwarding(2)="dr-4ah,tcp,,4433,,443"
Forwarding(3)="m-25e,tcp,,2222,,22"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter #2"
macaddress2="080027D1AB25"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com"
SharedFolderNameMachineMapping2="v-csc-1"
SharedFolderPathMachineMapping2="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/cookbooks"
SharedFolderNameMachineMapping3="v-csc-2"
SharedFolderPathMachineMapping3="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/recipebox"
SharedFolderNameMachineMapping4="v-csr-3"
SharedFolderPathMachineMapping4="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/roles"
SharedFolderNameMachineMapping5="v-csdb-4"
SharedFolderPathMachineMapping5="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/data"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="RedHat_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.18"
SnapshotName="failing_to_boot_1"
SnapshotUUID="4492fac3-9e45-40f4-b9f1-2c12ce00673a"
SnapshotName-1="added test file"
SnapshotUUID-1="9870481a-869f-47ad-aef5-fefdf70f8f5b"
SnapshotName-2="before restoring 'failing_to_boot_1'"
SnapshotUUID-2="35c14999-3c6b-431a-9387-d446ad693648"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<Vagrant::Action::VM::CleanMachineFolder:0x362faf0>
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "list", "s
ystemproperties"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: API version:                     4_1
Minimum guest RAM size:          4 Megabytes
Maximum guest RAM size:          2097152 Megabytes
Minimum video RAM size:          1 Megabytes
Maximum video RAM size:          256 Megabytes
Minimum guest CPU count:         1
Maximum guest CPU count:         32
Virtual disk limit (info):       2199022206976 Bytes
Maximum Serial Port count:       2
Maximum Parallel Port count:     2
Maximum Boot Position:           4
Maximum PIIX3 Network Adapter count:   8
Maximum ICH9 Network Adapter count:   36
Maximum PIIX3 IDE Controllers:   1
Maximum ICH9 IDE Controllers:    1
Maximum IDE Port count:          2
Maximum Devices per IDE Port:    2
Maximum PIIX3 SATA Controllers:  1
Maximum ICH9 SATA Controllers:   8
Maximum SATA Port count:         30
Maximum Devices per SATA Port:   1
Maximum PIIX3 SCSI Controllers:  1
Maximum ICH9 SCSI Controllers:   8
Maximum SCSI Port count:         16
Maximum Devices per SCSI Port:   1
Maximum SAS PIIX3 Controllers:   1
Maximum SAS ICH9 Controllers:    8
Maximum SAS Port count:          8
Maximum Devices per SAS Port:    1
Maximum PIIX3 Floppy Controllers:1
Maximum ICH9 Floppy Controllers: 1
Maximum Floppy Port count:       1
Maximum Devices per Floppy Port: 2
Default machine folder:          C:\Users\bzisad0\VirtualBox VMs
VRDE auth library:               VBoxAuth
Webservice auth. library:        VBoxAuth
Remote desktop ExtPack:          Oracle VM VirtualBox Extension Pack
Log history count:               3

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<Vagrant::Action::VM::ClearForwardedPorts:0x362fad8>
 INFO interface: info: Clearing any previously set forwarded ports...
[www] Clearing any previously set forwarded ports...
DEBUG virtualbox_4_1: read_forward_ports: uuid=6d42d3fc-3a8f-4851-8281-d6896049ad99 active_only
=false
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "6d42d3fc-3a8f-4851-8281-d6896049ad99", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
DEBUG subprocess: Exit status: 0
DEBUG subprocess: name="www.spartanstores.com"
ostype="RedHat_64"
UUID="6d42d3fc-3a8f-4851-8281-d6896049ad99"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\www.spartanstores.com.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Logs"
hardwareuuid="6d42d3fc-3a8f-4851-8281-d6896049ad99"
memory=512
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="on"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-08-10T15:35:10.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="1"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="C:\Applications\VirtualBox\VBoxGuestAdditions.iso"
"IDE Controller-ImageUUID-0-0"="e0d67cff-f8e9-439b-8de9-486d7e029e61"
"IDE Controller-tempeject"="off"
"IDE Controller-IsEjected"="off"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots\{0576f4c
9-3072-4576-863c-5adc53b893c2}.vmdk"
"SATA Controller-ImageUUID-0-0"="0576f4c9-3072-4576-863c-5adc53b893c2"
natnet1="nat"
macaddress1="080027E49DD9"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="2g-7sg,tcp,,8080,,80"
Forwarding(1)="37a-37a,tcp,,3306,,3306"
Forwarding(2)="dr-4ah,tcp,,4433,,443"
Forwarding(3)="m-25e,tcp,,2222,,22"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter #2"
macaddress2="080027D1AB25"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com"
SharedFolderNameMachineMapping2="v-csc-1"
SharedFolderPathMachineMapping2="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/cookbooks"
SharedFolderNameMachineMapping3="v-csc-2"
SharedFolderPathMachineMapping3="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/recipebox"
SharedFolderNameMachineMapping4="v-csr-3"
SharedFolderPathMachineMapping4="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/roles"
SharedFolderNameMachineMapping5="v-csdb-4"
SharedFolderPathMachineMapping5="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/data"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="RedHat_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.18"
SnapshotName="failing_to_boot_1"
SnapshotUUID="4492fac3-9e45-40f4-b9f1-2c12ce00673a"
SnapshotName-1="added test file"
SnapshotUUID-1="9870481a-869f-47ad-aef5-fefdf70f8f5b"
SnapshotName-2="before restoring 'failing_to_boot_1'"
SnapshotUUID-2="35c14999-3c6b-431a-9387-d446ad693648"

DEBUG virtualbox_4_1:   - [1, "2g-7sg", 8080, 80]
DEBUG virtualbox_4_1:   - [1, "37a-37a", 3306, 3306]
DEBUG virtualbox_4_1:   - [1, "dr-4ah", 4433, 443]
DEBUG virtualbox_4_1:   - [1, "m-25e", 2222, 22]
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "modifyvm"
, "6d42d3fc-3a8f-4851-8281-d6896049ad99", "--natpf1", "delete", "2g-7sg", "--natpf1", "delete",
 "37a-37a", "--natpf1", "delete", "dr-4ah", "--natpf1", "delete", "m-25e"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<Vagrant::Action::Env::Set:0x362fac0>
 INFO warden: Calling action: #<Vagrant::Action::VM::CheckPortCollisions:0x362fa90>
DEBUG virtualbox_4_1: read_forward_ports: uuid=6d42d3fc-3a8f-4851-8281-d6896049ad99 active_only
=false
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "6d42d3fc-3a8f-4851-8281-d6896049ad99", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="www.spartanstores.com"
ostype="RedHat_64"
UUID="6d42d3fc-3a8f-4851-8281-d6896049ad99"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\www.spartanstores.com.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Logs"
hardwareuuid="6d42d3fc-3a8f-4851-8281-d6896049ad99"
memory=512
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="on"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-08-10T15:35:10.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="1"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="C:\Applications\VirtualBox\VBoxGuestAdditions.iso"
"IDE Controller-ImageUUID-0-0"="e0d67cff-f8e9-439b-8de9-486d7e029e61"
"IDE Controller-tempeject"="off"
"IDE Controller-IsEjected"="off"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com\Snapshots\{0576f4c
9-3072-4576-863c-5adc53b893c2}.vmdk"
"SATA Controller-ImageUUID-0-0"="0576f4c9-3072-4576-863c-5adc53b893c2"
natnet1="nat"
macaddress1="080027E49DD9"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter #2"
macaddress2="080027D1AB25"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com"
SharedFolderNameMachineMapping2="v-csc-1"
SharedFolderPathMachineMapping2="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/cookbooks"
SharedFolderNameMachineMapping3="v-csc-2"
SharedFolderPathMachineMapping3="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/recipebox"
SharedFolderNameMachineMapping4="v-csr-3"
SharedFolderPathMachineMapping4="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/roles"
SharedFolderNameMachineMapping5="v-csdb-4"
SharedFolderPathMachineMapping5="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/data"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="RedHat_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.18"
SnapshotName="failing_to_boot_1"
SnapshotUUID="4492fac3-9e45-40f4-b9f1-2c12ce00673a"
SnapshotName-1="added test file"
SnapshotUUID-1="9870481a-869f-47ad-aef5-fefdf70f8f5b"
SnapshotName-2="before restoring 'failing_to_boot_1'"
SnapshotUUID-2="35c14999-3c6b-431a-9387-d446ad693648"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "list", "v
ms"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: "CentOS 6.2 x86" {cc2ce3d4-c5b4-4d09-9966-724ef07755f8}
"vagrant_guide_1327691666" {a9987da2-c764-434d-952b-a6927ca952a6}
"myplanetdigital-spartan-vagrant-b88fc5743514303c02d0cc7936c466fe2d29e027_1328721540" {65347984
-379b-4149-8620-3527ec05abdc}
"Spartan Drupal Sandbox" {1ace1ac0-3c85-47dc-9270-78a2f729552f}
"spartanstores_1336156273" {b72f7fe1-5f80-43ad-9e67-143d73d2342d}
"www.spartanstores.com" {6d42d3fc-3a8f-4851-8281-d6896049ad99}
"ZendServer5.6-OL5.7-XE-11.2" {d4bd2aa9-b3bc-4a0f-92d5-3f3aff9af595}
"www.spartanstores.com Clone" {bb006edc-3e38-4ce3-b252-310047ad7c75}

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
DEBUG virtualbox_4_1: read_forward_ports: uuid=cc2ce3d4-c5b4-4d09-9966-724ef07755f8 active_only
=true
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "cc2ce3d4-c5b4-4d09-9966-724ef07755f8", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="CentOS 6.2 x86"
ostype="RedHat"
UUID="cc2ce3d4-c5b4-4d09-9966-724ef07755f8"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\CentOS 6.2 x86\CentOS 6.2 x86.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\CentOS 6.2 x86\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\CentOS 6.2 x86\Logs"
hardwareuuid="cc2ce3d4-c5b4-4d09-9966-724ef07755f8"
memory=756
pagefusion="off"
vram=64
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="floppy"
boot2="dvd"
boot3="disk"
boot4="none"
acpi="on"
ioapic="off"
pae="on"
biossystemtimeoffset=0
rtcuseutc="on"
hwvirtex="on"
hwvirtexexcl="on"
nestedpaging="on"
largepages="off"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-06-27T23:25:22.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="Controller IDE"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="Controller SATA"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="1"
storagecontrollerbootable1="on"
"Controller IDE-0-0"="none"
"Controller IDE-0-1"="none"
"Controller IDE-1-0"="emptydrive"
"Controller IDE-IsEjected"="off"
"Controller IDE-1-1"="none"
"Controller SATA-0-0"="C:\Users\bzisad0\VirtualBox VMs\CentOS 6.2 x86\CentOS 6.2 x86.vdi"
"Controller SATA-ImageUUID-0-0"="153e109c-8ef2-4a53-a65e-7cc93273ad8a"
natnet1="nat"
macaddress1="080027689087"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="MySQL,tcp,,3306,,3306"
Forwarding(1)="SSH,tcp,,2222,,22"
Forwarding(2)="Web,tcp,,8080,,80"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter"
macaddress2="08002714FD5F"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="dsound"
clipboard="bidirectional"
vrde="off"
usb="on"
SharedFolderNameMachineMapping1="GraphicServicesCart"
SharedFolderPathMachineMapping1="C:\Users\bzisad0\Work\7) Graphic Services Cart"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="RedHat"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.18"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
DEBUG virtualbox_4_1: read_forward_ports: uuid=a9987da2-c764-434d-952b-a6927ca952a6 active_only
=true
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "a9987da2-c764-434d-952b-a6927ca952a6", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="vagrant_guide_1327691666"
ostype="Ubuntu_64"
UUID="a9987da2-c764-434d-952b-a6927ca952a6"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\vagrant_guide_1327691666\vagrant_guide_1327691666.vbox
"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\vagrant_guide_1327691666\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\vagrant_guide_1327691666\Logs"
hardwareuuid="a9987da2-c764-434d-952b-a6927ca952a6"
memory=2000
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="off"
vtxvpid="on"
VMState="aborted"
VMStateChangeTime="2012-07-20T17:13:57.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="30"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="none"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\spartan-vagrant_1322019089\box-disk1.vmd
k"
"SATA Controller-ImageUUID-0-0"="1ba5697f-c700-461a-9aab-4319e14a4290"
"SATA Controller-1-0"="none"
"SATA Controller-2-0"="none"
"SATA Controller-3-0"="none"
"SATA Controller-4-0"="none"
"SATA Controller-5-0"="none"
"SATA Controller-6-0"="none"
"SATA Controller-7-0"="none"
"SATA Controller-8-0"="none"
"SATA Controller-9-0"="none"
"SATA Controller-10-0"="none"
"SATA Controller-11-0"="none"
"SATA Controller-12-0"="none"
"SATA Controller-13-0"="none"
"SATA Controller-14-0"="none"
"SATA Controller-15-0"="none"
"SATA Controller-16-0"="none"
"SATA Controller-17-0"="none"
"SATA Controller-18-0"="none"
"SATA Controller-19-0"="none"
"SATA Controller-20-0"="none"
"SATA Controller-21-0"="none"
"SATA Controller-22-0"="none"
"SATA Controller-23-0"="none"
"SATA Controller-24-0"="none"
"SATA Controller-25-0"="none"
"SATA Controller-26-0"="none"
"SATA Controller-27-0"="none"
"SATA Controller-28-0"="none"
"SATA Controller-29-0"="none"
natnet1="nat"
macaddress1="080027F73B20"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="2g-7sg,tcp,,8080,,80"
Forwarding(1)="ssh,tcp,,2222,,22"
nic2="none"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/vagrant_guide"
SharedFolderNameMachineMapping2="v-csc-1"
SharedFolderPathMachineMapping2="c:/vagrant_guide/cookbooks"
SharedFolderNameMachineMapping3="v-csr-2"
SharedFolderPathMachineMapping3="c:/vagrant_guide/roles"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="Ubuntu_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.4"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
DEBUG subprocess: Exit status: 0
DEBUG virtualbox_4_1: read_forward_ports: uuid=65347984-379b-4149-8620-3527ec05abdc active_only
=true
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "65347984-379b-4149-8620-3527ec05abdc", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="myplanetdigital-spartan-vagrant-b88fc5743514303c02d0cc7936c466f
e2d29e027_1328721540"
ostype="Ubuntu_64"
UUID="65347984-379b-4149-8620-3527ec05abdc"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\myplanetdigital-spartan-vagrant-b88fc5743514303c02d0cc
7936c466fe2d29e027_1328721540\myplanetdigital-spartan-vagrant-b88fc5743514303c02d0cc7936c466fe2
d29e027_1328721540.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\myplanetdigital-spartan-vagrant-b88fc5743514303c02d0c
c7936c466fe2d29e027_1328721540\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\myplanetdigital-spartan-vagrant-b88fc5743514303c02d0cc
7936c466fe2d29e027_1328721540\Logs"
hardwareuuid="65347984-379b-4149-8620-3527ec05abdc"
memory=2000
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=2
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="off"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-04-30T21:35:04.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="30"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="none"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\spartan-vagrant_1322019089\box-disk1_1.v
mdk"
"SATA Controller-ImageUUID-0-0"="81b1d316-3587-406e-9a2e-e7b75d8eb309"
"SATA Controller-1-0"="none"
"SATA Controller-2-0"="none"
"SATA Controller-3-0"="none"
"SATA Controller-4-0"="none"
"SATA Controller-5-0"="none"
"SATA Controller-6-0"="none"
"SATA Controller-7-0"="none"
"SATA Controller-8-0"="none"
"SATA Controller-9-0"="none"
"SATA Controller-10-0"="none"
"SATA Controller-11-0"="none"
"SATA Controller-12-0"="none"
"SATA Controller-13-0"="none"
"SATA Controller-14-0"="none"
"SATA Controller-15-0"="none"
"SATA Controller-16-0"="none"
"SATA Controller-17-0"="none"
"SATA Controller-18-0"="none"
"SATA Controller-19-0"="none"
"SATA Controller-20-0"="none"
"SATA Controller-21-0"="none"
"SATA Controller-22-0"="none"
"SATA Controller-23-0"="none"
"SATA Controller-24-0"="none"
"SATA Controller-25-0"="none"
"SATA Controller-26-0"="none"
"SATA Controller-27-0"="none"
"SATA Controller-28-0"="none"
"SATA Controller-29-0"="none"
natnet1="nat"
macaddress1="080027F73B20"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="2g-7sg,tcp,,8080,,80"
Forwarding(1)="37a-37a,tcp,,3306,,3306"
Forwarding(2)="m-25e,tcp,,2222,,22"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter"
macaddress2="08002774BC28"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/bzisad0/Downloads/myplanetdigital-spartan-vagrant-b88
fc5743514303c02d0cc7936c466fe2d29e027"
SharedFolderNameMachineMapping2="v-data"
SharedFolderPathMachineMapping2="c:/Users/bzisad0/Downloads/vagrant-data"
SharedFolderNameMachineMapping3="v-drush"
SharedFolderPathMachineMapping3="c:/Users/bzisad0/.drush"
SharedFolderNameMachineMapping4="v-csc-1"
SharedFolderPathMachineMapping4="c:/Users/bzisad0/Downloads/myplanetdigital-spartan-vagrant-b88
fc5743514303c02d0cc7936c466fe2d29e027/cookbooks"
SharedFolderNameMachineMapping5="v-csc-2"
SharedFolderPathMachineMapping5="c:/Users/bzisad0/Downloads/myplanetdigital-spartan-vagrant-b88
fc5743514303c02d0cc7936c466fe2d29e027/cookbooks-overrides"
SharedFolderNameMachineMapping6="v-csc-3"
SharedFolderPathMachineMapping6="c:/Users/bzisad0/.cookbooks"
SharedFolderNameMachineMapping7="v-csr-4"
SharedFolderPathMachineMapping7="c:/Users/bzisad0/Downloads/myplanetdigital-spartan-vagrant-b88
fc5743514303c02d0cc7936c466fe2d29e027/roles"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="Ubuntu_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.4"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
DEBUG virtualbox_4_1: read_forward_ports: uuid=1ace1ac0-3c85-47dc-9270-78a2f729552f active_only
=true
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "1ace1ac0-3c85-47dc-9270-78a2f729552f", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="Spartan Drupal Sandbox"
ostype="Ubuntu_64"
UUID="1ace1ac0-3c85-47dc-9270-78a2f729552f"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\Spartan Drupal Sandbox\Spartan Drupal Sandbox.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\Spartan Drupal Sandbox\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\Spartan Drupal Sandbox\Logs"
hardwareuuid="1ace1ac0-3c85-47dc-9270-78a2f729552f"
memory=2048
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="on"
vtxvpid="on"
VMState="aborted"
VMStateChangeTime="2012-07-20T22:27:54.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="30"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="none"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\Spartan Drupal Sandbox\box-disk1.vmdk"
"SATA Controller-ImageUUID-0-0"="b2a2e082-9a99-450c-8ec5-517563452ae8"
"SATA Controller-1-0"="none"
"SATA Controller-2-0"="none"
"SATA Controller-3-0"="none"
"SATA Controller-4-0"="none"
"SATA Controller-5-0"="none"
"SATA Controller-6-0"="none"
"SATA Controller-7-0"="none"
"SATA Controller-8-0"="none"
"SATA Controller-9-0"="none"
"SATA Controller-10-0"="none"
"SATA Controller-11-0"="none"
"SATA Controller-12-0"="none"
"SATA Controller-13-0"="none"
"SATA Controller-14-0"="none"
"SATA Controller-15-0"="none"
"SATA Controller-16-0"="none"
"SATA Controller-17-0"="none"
"SATA Controller-18-0"="none"
"SATA Controller-19-0"="none"
"SATA Controller-20-0"="none"
"SATA Controller-21-0"="none"
"SATA Controller-22-0"="none"
"SATA Controller-23-0"="none"
"SATA Controller-24-0"="none"
"SATA Controller-25-0"="none"
"SATA Controller-26-0"="none"
"SATA Controller-27-0"="none"
"SATA Controller-28-0"="none"
"SATA Controller-29-0"="none"
natnet1="nat"
macaddress1="080027706AA2"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="ssh,tcp,,2222,,22"
nic2="none"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/bzisad0/Code/Vagrant/chef_demo"
SharedFolderNameMachineMapping2="v-csc-1"
SharedFolderPathMachineMapping2="c:/Users/bzisad0/Code/Vagrant/chef_demo/cookbooks"
SharedFolderNameMachineMapping3="v-csc-2"
SharedFolderPathMachineMapping3="c:/Users/bzisad0/Code/Vagrant/chef_demo/house-recipes"
SharedFolderNameMachineMapping4="v-csr-3"
SharedFolderPathMachineMapping4="c:/Users/bzisad0/Code/Vagrant/chef_demo/roles"
SharedFolderNameMachineMapping5="v-csdb-4"
SharedFolderPathMachineMapping5="c:/Users/bzisad0/Code/Vagrant/chef_demo/data"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="Ubuntu_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.0"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
DEBUG virtualbox_4_1: read_forward_ports: uuid=b72f7fe1-5f80-43ad-9e67-143d73d2342d active_only
=true
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "b72f7fe1-5f80-43ad-9e67-143d73d2342d", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="spartanstores_1336156273"
ostype="Ubuntu_64"
UUID="b72f7fe1-5f80-43ad-9e67-143d73d2342d"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\spartanstores_1336156273\spartanstores_1336156273.vbox
"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\spartanstores_1336156273\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\spartanstores_1336156273\Logs"
hardwareuuid="b72f7fe1-5f80-43ad-9e67-143d73d2342d"
memory=2000
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=2
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="off"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-05-04T20:06:56.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="30"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="none"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\spartanstores_1336156273\box-disk1_2.vmd
k"
"SATA Controller-ImageUUID-0-0"="8ab5dbd9-8ed6-4ce5-88ec-5eab857b622b"
"SATA Controller-1-0"="none"
"SATA Controller-2-0"="none"
"SATA Controller-3-0"="none"
"SATA Controller-4-0"="none"
"SATA Controller-5-0"="none"
"SATA Controller-6-0"="none"
"SATA Controller-7-0"="none"
"SATA Controller-8-0"="none"
"SATA Controller-9-0"="none"
"SATA Controller-10-0"="none"
"SATA Controller-11-0"="none"
"SATA Controller-12-0"="none"
"SATA Controller-13-0"="none"
"SATA Controller-14-0"="none"
"SATA Controller-15-0"="none"
"SATA Controller-16-0"="none"
"SATA Controller-17-0"="none"
"SATA Controller-18-0"="none"
"SATA Controller-19-0"="none"
"SATA Controller-20-0"="none"
"SATA Controller-21-0"="none"
"SATA Controller-22-0"="none"
"SATA Controller-23-0"="none"
"SATA Controller-24-0"="none"
"SATA Controller-25-0"="none"
"SATA Controller-26-0"="none"
"SATA Controller-27-0"="none"
"SATA Controller-28-0"="none"
"SATA Controller-29-0"="none"
natnet1="nat"
macaddress1="080027F73B20"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="2g-7sg,tcp,,8080,,80"
Forwarding(1)="37a-37a,tcp,,3306,,3306"
Forwarding(2)="m-25e,tcp,,2222,,22"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter"
macaddress2="0800271E5B40"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/bzisad0/Code/Vagrant/spartanstores"
SharedFolderNameMachineMapping2="v-data"
SharedFolderPathMachineMapping2="c:/Users/bzisad0/Code/Vagrant/vagrant-data"
SharedFolderNameMachineMapping3="v-drush"
SharedFolderPathMachineMapping3="c:/Users/bzisad0/.drush"
SharedFolderNameMachineMapping4="v-csc-1"
SharedFolderPathMachineMapping4="c:/Users/bzisad0/Code/Vagrant/spartanstores/cookbooks"
SharedFolderNameMachineMapping5="v-csc-2"
SharedFolderPathMachineMapping5="c:/Users/bzisad0/Code/Vagrant/spartanstores/cookbooks-override
s"
SharedFolderNameMachineMapping6="v-csr-3"
SharedFolderPathMachineMapping6="c:/Users/bzisad0/Code/Vagrant/spartanstores/roles"
VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="Ubuntu_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.4"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
DEBUG subprocess: Exit status: 0
DEBUG virtualbox_4_1: read_forward_ports: uuid=d4bd2aa9-b3bc-4a0f-92d5-3f3aff9af595 active_only
=true
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "d4bd2aa9-b3bc-4a0f-92d5-3f3aff9af595", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="ZendServer5.6-OL5.7-XE-11.2"
ostype="Oracle_64"
UUID="d4bd2aa9-b3bc-4a0f-92d5-3f3aff9af595"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\ZendServer5.6-OL5.7-XE-11.2\ZendServer5.6-OL5.7-XE-11.
2.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\ZendServer5.6-OL5.7-XE-11.2\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\ZendServer5.6-OL5.7-XE-11.2\Logs"
hardwareuuid="d4bd2aa9-b3bc-4a0f-92d5-3f3aff9af595"
memory=512
pagefusion="off"
vram=12
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="floppy"
boot2="dvd"
boot3="disk"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="on"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="on"
vtxvpid="on"
VMState="saved"
VMStateChangeTime="2012-08-02T22:01:28.000000000"
VMStateFile="C:\Users\bzisad0\VirtualBox VMs\ZendServer5.6-OL5.7-XE-11.2\Snapshots\2012-08-02T2
2-01-25-218747000Z.sav"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="1"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="none"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\ZendServer5.6-OL5.7-XE-11.2\ZS56-OL57-XE
112-disk1.vmdk"
"SATA Controller-ImageUUID-0-0"="3e74b5c5-09a3-4a28-81d5-89b802fbab15"
natnet1="nat"
macaddress1="0800271EF5DA"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
nic2="none"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="dsound"
clipboard="bidirectional"
vrde="off"
usb="on"
VRDEActiveConnection="off"
VRDEClients=0
description="This is a Virtual Box VM that has Zend Server 5.6, Oracle Linux 5.7 and Oracle XE
11.2.  Root password is zend1234"
GuestMemoryBalloon=0
GuestOSType="Oracle_64"
GuestAdditionsRunLevel=0
GuestAdditionsVersion="4.1.18"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
DEBUG virtualbox_4_1: read_forward_ports: uuid=bb006edc-3e38-4ce3-b252-310047ad7c75 active_only
=true
 INFO subprocess: Starting process: ["C:\\Applications\\VirtualBox\\VBoxManage.exe", "showvminf
o", "bb006edc-3e38-4ce3-b252-310047ad7c75", "--machinereadable"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: name="www.spartanstores.com Clone"
ostype="RedHat_64"
UUID="bb006edc-3e38-4ce3-b252-310047ad7c75"
CfgFile="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com Clone\www.spartanstores.com Clon
e.vbox"
SnapFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com Clone\Snapshots"
LogFldr="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com Clone\Logs"
hardwareuuid="bb006edc-3e38-4ce3-b252-310047ad7c75"
memory=512
pagefusion="off"
vram=8
cpuexecutioncap=100
hpet="off"
chipset="piix3"
firmware="BIOS"
cpus=1
synthcpu="off"
bootmenu="messageandmenu"
boot1="disk"
boot2="dvd"
boot3="none"
boot4="none"
acpi="on"
ioapic="on"
pae="on"
biossystemtimeoffset=0
rtcuseutc="off"
hwvirtex="on"
hwvirtexexcl="off"
nestedpaging="on"
largepages="on"
vtxvpid="on"
VMState="poweroff"
VMStateChangeTime="2012-08-10T15:04:18.000000000"
monitorcount=1
accelerate3d="off"
accelerate2dvideo="off"
teleporterenabled="off"
teleporterport=0
teleporteraddress=""
teleporterpassword=""
storagecontrollername0="IDE Controller"
storagecontrollertype0="PIIX4"
storagecontrollerinstance0="0"
storagecontrollermaxportcount0="2"
storagecontrollerportcount0="2"
storagecontrollerbootable0="on"
storagecontrollername1="SATA Controller"
storagecontrollertype1="IntelAhci"
storagecontrollerinstance1="0"
storagecontrollermaxportcount1="30"
storagecontrollerportcount1="1"
storagecontrollerbootable1="on"
"IDE Controller-0-0"="C:\Applications\VirtualBox\VBoxGuestAdditions.iso"
"IDE Controller-ImageUUID-0-0"="e0d67cff-f8e9-439b-8de9-486d7e029e61"
"IDE Controller-tempeject"="off"
"IDE Controller-IsEjected"="off"
"IDE Controller-0-1"="none"
"IDE Controller-1-0"="emptydrive"
"IDE Controller-IsEjected"="off"
"IDE Controller-1-1"="none"
"SATA Controller-0-0"="C:\Users\bzisad0\VirtualBox VMs\www.spartanstores.com Clone\www.spartans
tores.com Clone-disk1.vmdk"
"SATA Controller-ImageUUID-0-0"="49c58d60-0028-427e-bd4a-217a25099159"
natnet1="nat"
macaddress1="0800273F7C63"
cableconnected1="on"
nic1="nat"
mtu="0"
sockSnd="64"
sockRcv="64"
tcpWndSnd="64"
tcpWndRcv="64"
Forwarding(0)="2g-7sg,tcp,,8080,,80"
Forwarding(1)="37a-37a,tcp,,3306,,3306"
Forwarding(2)="dr-4ah,tcp,,4433,,443"
Forwarding(3)="m-25e,tcp,,2222,,22"
hostonlyadapter2="VirtualBox Host-Only Ethernet Adapter #2"
macaddress2="080027DD5CED"
cableconnected2="on"
nic2="hostonly"
nic3="none"
nic4="none"
nic5="none"
nic6="none"
nic7="none"
nic8="none"
hidpointing="ps2mouse"
hidkeyboard="ps2kbd"
uart1="off"
uart2="off"
audio="none"
clipboard="bidirectional"
vrde="off"
usb="off"
SharedFolderNameMachineMapping1="v-root"
SharedFolderPathMachineMapping1="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com"
SharedFolderNameMachineMapping2="v-csc-1"
SharedFolderPathMachineMapping2="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/cookbooks"
SharedFolderNameMachineMapping3="v-csc-2"
SharedFolderPathMachineMapping3="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/recipebox"
SharedFolderNameMachineMapping4="v-csr-3"
SharedFolderPathMachineMapping4="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/roles"
SharedFolderNameMachineMapping5="v-csdb-4"
SharedFolderPathMachineMapping5="c:/Users/BZISAD0/Code/Drupal/www.spartanstores.com/data"
VRDEActive
brandondrew commented 12 years ago

I have the problem with both Ruby 1.9.2 & Vagrant 1.0.2 as well as Ruby 1.9.3 & Vagrant 1.0.3.

brandondrew commented 12 years ago

After skimming through the entire (exhaustively long) DEBUG info, two things stand out to me. The first is that there is a lot of info about _other_ VMs other than the one I'm booting. Is this normal?

The second thing that stands out to me is that "Remaining to timeout:" keeps getting set back up to 32000, even though it occasionally goes down to 31999 or 31998. That seems very strange.

brandondrew commented 12 years ago

The full DEBUG info was cut off. There seems to be a lot of repetition, but here's how it is supposed to end:

VRDEActiveConnection="off"
VRDEClients=0
GuestMemoryBalloon=0
GuestOSType="Linux26_64"
GuestAdditionsRunLevel=2
GuestAdditionsVersion="4.1.18r78361"
GuestAdditionsFacility_VirtualBox Base Driver=50,1344620841213
GuestAdditionsFacility_VirtualBox System Service=50,1344620849710
GuestAdditionsFacility_Seamless Mode=0,1344620841213
GuestAdditionsFacility_Graphics Mode=0,1344620841213
SnapshotName="failing_to_boot_1"
SnapshotUUID="4492fac3-9e45-40f4-b9f1-2c12ce00673a"
SnapshotName-1="added test file"
SnapshotUUID-1="9870481a-869f-47ad-aef5-fefdf70f8f5b"
SnapshotName-2="before restoring 'failing_to_boot_1'"
SnapshotUUID-2="35c14999-3c6b-431a-9387-d446ad693648"

DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
DEBUG ssh: Checking whether SSH is ready...
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
ERROR warden: Error occurred: open failed (1)
c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connection/channel.r
b:524:in `do_open_failed': open failed (1) (Net::SSH::ChannelOpenFailed)
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connect
ion/session.rb:541:in `channel_open_failure'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connect
ion/session.rb:456:in `dispatch_incoming_packets'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connect
ion/session.rb:213:in `preprocess'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connect
ion/session.rb:197:in `process'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connect
ion/session.rb:161:in `block in loop'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connect
ion/session.rb:161:in `loop'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connect
ion/session.rb:161:in `loop'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connect
ion/channel.rb:269:in `wait'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/net-ssh-2.2.2/lib/net/ssh/connect
ion/session.rb:355:in `exec!'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/communi
cation/ssh.rb:100:in `connect'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/communi
cation/ssh.rb:29:in `block in ready?'
        from c:/Languages/Ruby/1.9.2/lib/ruby/1.9.1/timeout.rb:58:in `timeout'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/communi
cation/ssh.rb:28:in `ready?'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/boot.rb:29:in `block in wait_for_boot'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/boot.rb:28:in `times'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/boot.rb:28:in `wait_for_boot'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/boot.rb:15:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/customize.rb:31:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/sane_defaults.rb:39:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/network.rb:62:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/clear_network_interfaces.rb:26:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/host_name.rb:10:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/share_folders.rb:20:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/clear_shared_folders.rb:13:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/nfs.rb:41:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/prune_nfs_exports.rb:15:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/provision.rb:27:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/forward_ports.rb:24:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/check_port_collisions.rb:42:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
env/set.rb:16:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/clear_forwarded_ports.rb:13:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/clean_machine_folder.rb:17:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
vm/check_accessible.rb:18:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
general/validate.rb:13:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
general/check_virtualbox.rb:23:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
warden.rb:33:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
builder.rb:92:in `call'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
runner.rb:49:in `block in run'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/util/bu
sy.rb:19:in `busy'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/action/
runner.rb:49:in `run'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/vm.rb:1
92:in `run_action'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/vm.rb:1
52:in `start'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/command
/up.rb:28:in `block in execute'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/command
/base.rb:116:in `block in with_target_vms'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/command
/base.rb:111:in `each'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/command
/base.rb:111:in `with_target_vms'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/command
/up.rb:24:in `execute'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/cli.rb:
42:in `execute'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/lib/vagrant/environ
ment.rb:167:in `cli'
        from c:/Languages/Ruby/1.9.2/lib/ruby/gems/1.9.1/gems/vagrant-1.0.2/bin/vagrant:43:in `
<top (required)>'
        from c:/Languages/Ruby/1.9.2/bin/vagrant:19:in `load'
        from c:/Languages/Ruby/1.9.2/bin/vagrant:19:in `<main>'
brandondrew commented 12 years ago

On my most recent vagrant up it went past that point and hung after this:

[www] Waiting for VM to boot. This can take a few minutes.
[www] VM booted and ready for use!
[www] Detected Virtualbox Guest Additions 4.1.18 --- OK.
[www] Configuring and enabling network interfaces...
laupiFrpar commented 12 years ago

When the vm is launched, I can't connected manually with ssh. It said ssh: Could not resolve hostname 127.0.0.1:2222: nodename nor servname provided, or not know

brandondrew commented 12 years ago

@laupiFrpar : I'm able to ssh in, so I don't think it's the same issue.

janschumann commented 12 years ago

Despite discussing issues, would you mind me creating a wiki page for hints to workaround this (and relaed) issues?

There are already hints for workarounds distributed over a several similar issues. I would like to sum them up and add my own experience to give the "userland" side a place.

Ok?

brandondrew commented 12 years ago

I don't mind at all.

janschumann commented 12 years ago

I have started a wiki page on this: https://github.com/mitchellh/vagrant/wiki/%60vagrant-up%60-hangs-at-%22Waiting-for-VM-to-boot.-This-can-take-a-few-minutes%22

potix2 commented 12 years ago

Hi, I found the way to reproduce this issue. Default configuration of ssh.timeout is too short to make connection in some environments. I cannot boot centos 6.3 with default configuration but I set ssh.timeout to 20 then the vm can be started.

Also I made a patch to inspect ssh connection, you can get it from here. The following log is outputted by vagrant applied with my patch when I try to boot centos 6.3 with default config:

D, [2012-09-10T04:35:01.078074 #13346] DEBUG -- net.ssh.transport.session[3ff5de1c596c]: establishing connection to 127.0.0.1:2222
D, [2012-09-10T04:35:01.078531 #13346] DEBUG -- net.ssh.transport.session[3ff5de1c596c]: connection established
I, [2012-09-10T04:35:01.078695 #13346]  INFO -- net.ssh.transport.server_version[3ff5de1b8820]: negotiating protocol version
D, [2012-09-10T04:35:01.094239 #13346] DEBUG -- net.ssh.transport.server_version[3ff5de1b8820]: remote is `SSH-2.0-OpenSSH_5.3'
D, [2012-09-10T04:35:01.094356 #13346] DEBUG -- net.ssh.transport.server_version[3ff5de1b8820]: local is `SSH-2.0-Ruby/Net::SSH_2.2.2 x86_64-darwin11.4.0'
D, [2012-09-10T04:35:01.101687 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: read 784 bytes
D, [2012-09-10T04:35:01.101954 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: received packet nr 0 type 20 len 780
I, [2012-09-10T04:35:01.102106 #13346]  INFO -- net.ssh.transport.algorithms[3ff5de1a2944]: got KEXINIT from server
I, [2012-09-10T04:35:01.102372 #13346]  INFO -- net.ssh.transport.algorithms[3ff5de1a2944]: sending KEXINIT
D, [2012-09-10T04:35:01.102639 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: queueing packet nr 0 type 20 len 556
D, [2012-09-10T04:35:01.102791 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: sent 560 bytes
I, [2012-09-10T04:35:01.102859 #13346]  INFO -- net.ssh.transport.algorithms[3ff5de1a2944]: negotiating algorithms
D, [2012-09-10T04:35:01.103326 #13346] DEBUG -- net.ssh.transport.algorithms[3ff5de1a2944]: negotiated:
* kex: diffie-hellman-group-exchange-sha1
* host_key: ssh-rsa
* encryption_server: aes128-cbc
* encryption_client: aes128-cbc
* hmac_client: hmac-sha1
* hmac_server: hmac-sha1
* compression_client: none
* compression_server: none
* language_client:
* language_server:
D, [2012-09-10T04:35:01.103398 #13346] DEBUG -- net.ssh.transport.algorithms[3ff5de1a2944]: exchanging keys
D, [2012-09-10T04:35:01.103873 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: queueing packet nr 1 type 34 len 20
D, [2012-09-10T04:35:01.103999 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: sent 24 bytes
D, [2012-09-10T04:35:01.107799 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: read 152 bytes
D, [2012-09-10T04:35:01.108039 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: received packet nr 1 type 31 len 148
D, [2012-09-10T04:35:01.115223 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: queueing packet nr 2 type 32 len 140
D, [2012-09-10T04:35:01.115412 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: sent 144 bytes
D, [2012-09-10T04:35:01.124867 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: read 720 bytes
D, [2012-09-10T04:35:01.125079 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: received packet nr 2 type 33 len 700
D, [2012-09-10T04:35:01.131097 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: queueing packet nr 3 type 21 len 20
D, [2012-09-10T04:35:01.131240 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: sent 24 bytes
D, [2012-09-10T04:35:01.131374 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: received packet nr 3 type 21 len 12
D, [2012-09-10T04:35:01.131897 #13346] DEBUG -- net.ssh.authentication.session[3ff5de82c1c0]: beginning authentication of `vagrant'
D, [2012-09-10T04:35:01.132111 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: queueing packet nr 4 type 5 len 28
D, [2012-09-10T04:35:01.132205 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: sent 52 bytes
D, [2012-09-10T04:35:01.132964 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: read 52 bytes
D, [2012-09-10T04:35:01.133118 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: received packet nr 4 type 6 len 28
D, [2012-09-10T04:35:01.133278 #13346] DEBUG -- net.ssh.authentication.session[3ff5de82c1c0]: trying publickey
D, [2012-09-10T04:35:01.133780 #13346] DEBUG -- net.ssh.authentication.agent[3ff5de83b184]: connecting to ssh-agent
D, [2012-09-10T04:35:01.133981 #13346] DEBUG -- net.ssh.authentication.agent[3ff5de83b184]: sending agent request 1 len 51
D, [2012-09-10T04:35:01.134156 #13346] DEBUG -- net.ssh.authentication.agent[3ff5de83b184]: received agent packet 2 len 5
D, [2012-09-10T04:35:01.134239 #13346] DEBUG -- net.ssh.authentication.agent[3ff5de83b184]: sending agent request 11 len 0
D, [2012-09-10T04:35:01.134397 #13346] DEBUG -- net.ssh.authentication.agent[3ff5de83b184]: received agent packet 12 len 315
D, [2012-09-10T04:35:01.134949 #13346] DEBUG -- net.ssh.authentication.methods.publickey[3ff5de838164]: trying publickey (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6)
D, [2012-09-10T04:35:01.135218 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: queueing packet nr 5 type 50 len 348
D, [2012-09-10T04:35:01.135337 #13346] DEBUG -- tcpsocket[3ff5de1c0958]: sent 372 bytes
D, [2012-09-10T04:35:11.081637 #13346] DEBUG -- net.ssh.transport.session[3ff5de04b5a0]: establishing connection to 127.0.0.1:2222
D, [2012-09-10T04:35:11.082464 #13346] DEBUG -- net.ssh.transport.session[3ff5de04b5a0]: connection established
I, [2012-09-10T04:35:11.082673 #13346]  INFO -- net.ssh.transport.server_version[3ff5de0167b0]: negotiating protocol version
D, [2012-09-10T04:35:11.090738 #13346] DEBUG -- net.ssh.transport.server_version[3ff5de0167b0]: remote is `SSH-2.0-OpenSSH_5.3'
mitchellh commented 12 years ago

This is a dupe of #391. There is a LOT of info on this bug there. In short: its complicated.

You can see I'm working on various workarounds there. If you have any more to add please add it there. Sorry about this.

brandondrew commented 12 years ago

Actually, in my case it turned out to be caused by something in my vagrant user's .bashrc or .bash_profile. I didn't realize that the boot up process involved ssh'ing in as vagrant (though that should have probably been obvious!) and didn't figure the cause out for a while because of some red herrings. As background: my networking setup is complicated by the fact that I have to deal with a non-standard (Microsoft!) proxy server, and thus need run a local "child" proxy (Cntlm--I couldn't live without it!) on both host and guest operating systems, but everything blew up once when I switching between proxied and unproxied use and forgot to restart my guest OS and VB. It appeared that the problems I was having with Vagrant were related to the networking problems caused by this "blow up" but they were not--they just didn't show up until I had to restart the VM. For an example of the problems that confused matters, my Internet Options on Windows were corrupted, and had to be deleted and replaced before certain networking problems (logging into certain web sites failed even with correct credentials, and other things I can't remember) went away. (Even though the proxy settings I used after recreating the Internet Optoins were the same as those I was using before.) Though these problems were not related, they happened to coincide. So I spent lots of time digging through things that appeared to be related to the problem, but weren't. All of this threw me off the trail of the real problem, which was simply a matter of fixing my login scripts. (The problem with the login scripts didn't prevent interactive logins, making it even less obvious.)

brandondrew commented 12 years ago

So in short: in my case it _wasn't_ a bug in Vagrant. It would, however, be nice if Vagrant did something to detect the sort of problem I had, and give a message explaining to the user what's going on. That would be more helpful than a stacktrace. I can give more info if you're interested in adding that sort of error checking.

janschumann commented 12 years ago

I would give it a try ... What are your plans to release the new version of Vagrant (current master)?

gavD commented 12 years ago

One thing I did that helped diagnose this issue was take a screengrab of the VM:

VBoxManage controlvm vagranttest_1348502727 screenshotpng foo.png
google-chrome foo.png

This brought up a screen on which Vagrant was complaining that I was using a 64 bit VM :

"This kernel requires an x86-64 CPI, but only detected an i686 CPI. Unable to boot - please use a kernel appropriate for your CPU"

Hope this helps someone

janschumann commented 12 years ago

Found another way to reproduce this issue. And a way to workaround.

https://github.com/mitchellh/vagrant/wiki/%60vagrant-up%60-hangs-at-%22Waiting-for-VM-to-boot.-This-can-take-a-few-minutes%22

Would appreciate when adding your experiences there.

marcboivin commented 11 years ago

The suggested scenario to replicate worked for me, but the fix didn't. Changing my base box from Ubuntu 12.04 x86_64 to Lucid x86 did the trick.

guyrt commented 11 years ago

I just got one of these hangs (first in a while) and found a workaround. When I started the VM using VBoxManage, I was asked to run fsck manually. After I did this, shutdown, then used vagrant up, everything appeared to work. This problem was not communicated back through vagrant though.

tl;dr - If it's not a network issue, ensure you can boot and log in to the box with VBoxManage.

acesuares commented 11 years ago

foo

The screenshot method mentioned by gavD gave met this... happens after a vagrant halt && vagrant up... not network related at all?

acesuares commented 11 years ago

And I was under the impression that it didn’t happen with vagrant reload but, after 2 reloads, same picture :-(

acesuares commented 11 years ago

Tried with precise32 and precise64 box, and with ubuntu-server-12042-x64-vbox4210, all the same results... stumped, and going to sleep...

acesuares commented 11 years ago

This totally fixed it. Wow! That's some weirdness.

https://github.com/mitchellh/vagrant/issues/391#issuecomment-12264830

carrison commented 6 years ago

upgrade ps to higher version to fix the issue.

ghost commented 4 years ago

I'm going to lock this issue because it has been closed for 30 days ⏳. This helps our maintainers find and focus on the active issues.

If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.