tknerr · June 11, 2013 15:29
diff --git a/log b/log

 D:\Repos\_github\bills-kitchen\target\tmp5>vagrant up
 INFO global: Vagrant version: 1.2.2
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/box/plugin.rb
 INFO manager: Registered plugin: box command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/destroy/plugin.rb
 INFO manager: Registered plugin: destroy command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/halt/plugin.rb
 INFO manager: Registered plugin: halt command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/init/plugin.rb
 INFO manager: Registered plugin: init command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/package/plugin.rb
 INFO manager: Registered plugin: package command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/plugin/plugin.rb
 INFO manager: Registered plugin: plugin command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/provision/plugin.rb
 INFO manager: Registered plugin: provision command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/reload/plugin.rb
 INFO manager: Registered plugin: reload command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/resume/plugin.rb
 INFO manager: Registered plugin: resume command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/ssh/plugin.rb
 INFO manager: Registered plugin: ssh command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/ssh_config/plugin.rb
 INFO manager: Registered plugin: ssh-config command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/status/plugin.rb
 INFO manager: Registered plugin: status command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/suspend/plugin.rb
 INFO manager: Registered plugin: suspend command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/up/plugin.rb
 INFO manager: Registered plugin: up command
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/communicators/ssh/plugin.rb
 INFO manager: Registered plugin: ssh communicator
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/arch/plugin.rb
 INFO manager: Registered plugin: Arch guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/debian/plugin.rb
 INFO manager: Registered plugin: Debian guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/fedora/plugin.rb
 INFO manager: Registered plugin: Fedora guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/freebsd/plugin.rb
 INFO manager: Registered plugin: FreeBSD guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/gentoo/plugin.rb
 INFO manager: Registered plugin: Gentoo guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/linux/plugin.rb
 INFO manager: Registered plugin: Linux guest.
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/openbsd/plugin.rb
 INFO manager: Registered plugin: OpenBSD guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/pld/plugin.rb
 INFO manager: Registered plugin: PLD Linux guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/redhat/plugin.rb
 INFO manager: Registered plugin: RedHat guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/solaris/plugin.rb
 INFO manager: Registered plugin: Solaris guest.
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/suse/plugin.rb
 INFO manager: Registered plugin: SUSE guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/ubuntu/plugin.rb
 INFO manager: Registered plugin: Ubuntu guest
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/hosts/arch/plugin.rb
 INFO manager: Registered plugin: Arch host
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/hosts/bsd/plugin.rb
 INFO manager: Registered plugin: BSD host
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/hosts/fedora/plugin.rb
 INFO manager: Registered plugin: Fedora host
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/hosts/freebsd/plugin.rb
 INFO manager: Registered plugin: FreeBSD host
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/hosts/gentoo/plugin.rb
 INFO manager: Registered plugin: Gentoo host
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/hosts/linux/plugin.rb
 INFO manager: Registered plugin: Linux host
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/hosts/opensuse/plugin.rb
 INFO manager: Registered plugin: OpenSUSE host
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/hosts/windows/plugin.rb
 INFO manager: Registered plugin: Windows host
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/kernel_v1/plugin.rb
 INFO manager: Registered plugin: kernel
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/kernel_v2/plugin.rb
 INFO manager: Registered plugin: kernel
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/plugin.rb
 INFO manager: Registered plugin: VirtualBox provider
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/provisioners/ansible/plugin.rb
 INFO manager: Registered plugin: ansible
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/provisioners/cfengine/plugin.rb
 INFO manager: Registered plugin: CFEngine Provisioner
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/provisioners/chef/plugin.rb
 INFO manager: Registered plugin: chef
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/provisioners/puppet/plugin.rb
 INFO manager: Registered plugin: puppet
 DEBUG global: Loading core plugin: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/provisioners/shell/plugin.rb
 INFO manager: Registered plugin: shell
 INFO vagrant: `vagrant` invoked: ["up"]
 DEBUG vagrant: Creating Vagrant environment
 INFO environment: Environment initialized (#<Vagrant::Environment:0x307a838>)
 INFO environment:   - cwd: D:/Repos/_github/bills-kitchen/target/tmp5
 INFO environment: Home path: D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d
 INFO environment: Local data path: D:/Repos/_github/bills-kitchen/target/tmp5/.vagrant
 DEBUG environment: Creating: D:/Repos/_github/bills-kitchen/target/tmp5/.vagrant
 DEBUG environment: Loading plugins from: D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/plugins.json
 INFO environment: Loading plugin from JSON: vagrant-aws
 INFO manager: Registered plugin: AWS
 INFO environment: Loading plugin from JSON: vagrant-awsinfo
 INFO manager: Registered plugin: Query SSH info from AWS guests.
 INFO environment: Loading plugin from JSON: vagrant-cachier
 INFO manager: Registered plugin: vagrant-cachier
 INFO environment: Loading plugin from JSON: vagrant-managed-servers
 INFO manager: Registered plugin: ManagedServers
 INFO environment: Loading plugin from JSON: vagrant-omnibus
 INFO manager: Registered plugin: Omnibus
 INFO environment: Loading plugin from JSON: vagrant-vbguest
 INFO manager: Registered plugin: vbguest management
 INFO environment: Running hook: environment_load
 INFO environment: Initializing config...
 INFO loader: Set :default = "D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/config/default.rb"
 DEBUG loader: Populating proc cache for "D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/config/default.rb"
 DEBUG loader: Load procs for pathname: D:/Repos/_github/bills-kitchen/target/build/tools/vagrant/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.2.2/config/default.rb
 INFO loader: Set :home = #<Pathname:D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/Vagrantfile>
 DEBUG loader: Populating proc cache for #<Pathname:D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/Vagrantfile>
 DEBUG loader: Load procs for pathname: D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/Vagrantfile
 INFO loader: Set :root = #<Pathname:D:/Repos/_github/bills-kitchen/target/tmp5/Vagrantfile>
 DEBUG loader: Populating proc cache for #<Pathname:D:/Repos/_github/bills-kitchen/target/tmp5/Vagrantfile>
 DEBUG loader: Load procs for pathname: D:/Repos/_github/bills-kitchen/target/tmp5/Vagrantfile
 INFO loader: Loading configuration in order: [:default, :home, :root]
 DEBUG loader: Loading from: default (evaluating)
 DEBUG loader: Loading from: root (evaluating)
 DEBUG loader: Configuration loaded successfully, finalizing and returning
 DEBUG hosts: Host path search classes: [VagrantPlugins::HostWindows::Host, VagrantPlugins::HostOpenSUSE::Host, VagrantPlugins::HostArch::Host, VagrantPlugins::HostFedora::Host, VagrantPlugins::HostFreeBSD::Host, VagrantPlugins::HostGentoo::Host, VagrantPlugins::HostLinux::Host, VagrantPlugins::HostBSD::Host]
 INFO hosts: Host class: VagrantPlugins::HostWindows::Host
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 1 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x3100f68>
 INFO cli: CLI: [] "up" []
 DEBUG cli: Invoking command class: VagrantPlugins::CommandUp::Command []
 DEBUG command: 'Up' each target VM...
 DEBUG command: Getting target VMs for command. Arguments:
 DEBUG command:  -- names: []
 DEBUG command:  -- options: {:provider=>nil}
 DEBUG command: Loading all machines...
 INFO environment: Getting machine: foo (virtualbox)
 INFO environment: Uncached load of machine.
 INFO loader: Set :vm_foo = [["2", #<Proc:0x35c72d0@D:/Repos/_github/bills-kitchen/target/tmp5/Vagrantfile:11>]]
 DEBUG loader: Populating proc cache for ["2", #<Proc:0x35c72d0@D:/Repos/_github/bills-kitchen/target/tmp5/Vagrantfile:11>]
 INFO loader: Loading configuration in order: [:default, :home, :root, :vm_foo]
 DEBUG loader: Loading from: default (cache)
 DEBUG loader: Loading from: root (cache)
 DEBUG loader: Loading from: vm_foo (evaluating)
 DEBUG provisioner: Provisioner defined: chef_solo
 DEBUG loader: Configuration loaded successfully, finalizing and returning
 INFO environment: Provider-supported box formats: [:virtualbox]
 INFO box_collection: Searching for box: opscode_ubuntu-13.04_provisionerless (virtualbox) in D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/boxes/opscode_ubuntu-13.04_provisionerless/virtualbox/metadata.json
 INFO box_collection: Box found: opscode_ubuntu-13.04_provisionerless (virtualbox)
 INFO environment: Box found with format: virtualbox
 INFO environment: Box exists with Vagrantfile. Reloading machine config.
 INFO loader: Set :"box_opscode_ubuntu-13.04_provisionerless_virtualbox" = #<Pathname:D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/boxes/opscode_ubuntu-13.04_provisionerless/virtualbox/Vagrantfile>
 DEBUG loader: Populating proc cache for #<Pathname:D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/boxes/opscode_ubuntu-13.04_provisionerless/virtualbox/Vagrantfile>
 DEBUG loader: Load procs for pathname: D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/boxes/opscode_ubuntu-13.04_provisionerless/virtualbox/Vagrantfile
 INFO loader: Loading configuration in order: [:default, :"box_opscode_ubuntu-13.04_provisionerless_virtualbox", :home, :root, :vm_foo]
 DEBUG loader: Loading from: default (cache)
 DEBUG loader: Loading from: box_opscode_ubuntu-13.04_provisionerless_virtualbox (evaluating)
 DEBUG loader: Upgrading config from version 1 to 2
 DEBUG loader: Upgrading config to version 2
 DEBUG loader: Upgraded to version 2 with 0 warnings and 0 errors
 DEBUG loader: Loading from: root (cache)
 DEBUG loader: Loading from: vm_foo (cache)
 DEBUG loader: Configuration loaded successfully, finalizing and returning
 INFO machine: Initializing machine: foo
 INFO machine:   - Provider: VagrantPlugins::ProviderVirtualBox::Provider
 INFO machine:   - Box: #<Vagrant::Box:0x37e5268>
 INFO machine:   - Data dir: D:/Repos/_github/bills-kitchen/target/tmp5/.vagrant/machines/foo/virtualbox
 DEBUG virtualbox: Instantiating the driver for machine ID: nil
 DEBUG base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 DEBUG base: VBOX_INSTALL_PATH value: C:\Program Files\Oracle\VirtualBox\
 INFO base: VBoxManage path: C:\Program Files\Oracle\VirtualBox\VBoxManage.exe
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "--version"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: 4.2.4r81684
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 DEBUG meta: Finding driver for VirtualBox version: 4.2.4
 INFO meta: Using VirtualBox driver: VagrantPlugins::ProviderVirtualBox::Driver::Version_4_2
 DEBUG base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 DEBUG base: VBOX_INSTALL_PATH value: C:\Program Files\Oracle\VirtualBox\
 INFO base: VBoxManage path: C:\Program Files\Oracle\VirtualBox\VBoxManage.exe
 INFO command: With machine: foo (VirtualBox (new VM))
 INFO interface: info: Bringing machine 'foo' up with 'virtualbox' provider...
 Bringing machine 'foo' up with 'virtualbox' provider...
 INFO batch_action: Enabling parallelization by default.
 INFO batch_action: Disabling parallelization because provider doesn't support it: virtualbox
 INFO batch_action: Batch action will parallelize: false
 INFO batch_action: Starting action: #<Vagrant::Machine:0x2e6f380> up {:parallel=>true, :provision_enabled=>true, :provision_types=>nil}
 INFO machine: Calling action: up on provider VirtualBox (new VM)
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x30e1198>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::CheckVirtualbox:0x35c7fc0>
 DEBUG base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 DEBUG base: VBOX_INSTALL_PATH value: C:\Program Files\Oracle\VirtualBox\
 INFO base: VBoxManage path: C:\Program Files\Oracle\VirtualBox\VBoxManage.exe
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "--version"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: 4.2.4r81684
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG meta: Finding driver for VirtualBox version: 4.2.4
 INFO meta: Using VirtualBox driver: VagrantPlugins::ProviderVirtualBox::Driver::Version_4_2
 DEBUG base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 DEBUG base: VBOX_INSTALL_PATH value: C:\Program Files\Oracle\VirtualBox\
 INFO base: VBoxManage path: C:\Program Files\Oracle\VirtualBox\VBoxManage.exe
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "list", "hostonlyifs"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31997
 DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<Vagrant::Action::Builtin::ConfigValidate:0x35c7fa8>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::Call:0x35c7f60>
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x668dfa8>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::Created:0x668c6b8>
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Warden:0x6670140>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::CheckAccessible:0x66700f8>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::HandleBoxUrl:0x66700e0>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::Import:0x66700c8>
 INFO interface: info: Importing base box 'opscode_ubuntu-13.04_provisionerless'...
 [foo] Importing base box 'opscode_ubuntu-13.04_provisionerless'...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "import", "D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/boxes/opscode_ubuntu-13.04_provisionerless/virtualbox/box.ovf"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stderr: 0%...10%...20%...30%...40%...50%...60%...70%...80%...90%...100%
 Interpreting D:\Repos\_github\bills-kitchen\target\build\home\.vagrant.d\boxes\opscode_ubuntu-13.04_provisionerless\virtualbox\box.ovf...
 OK.
 0%...
 DEBUG subprocess: stderr: 10%...
 DEBUG subprocess: stderr: 20%...30%...
 DEBUG subprocess: stderr: 40%...
 DEBUG subprocess: stderr: 50%...60%...
 DEBUG subprocess: stderr: 70%...
 DEBUG subprocess: stderr: 80%...
 DEBUG subprocess: stderr: 90%...
 DEBUG subprocess: stderr: 100%
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31975
 DEBUG subprocess: Exit status: 0
 DEBUG subprocess: stdout: Disks:  vmdisk1       42949672960     -1      http://www.vmware.com/interfaces/specifications/vmdk.html#streamOptimized       box-disk1.vmdk  -1
 -1
 Virtual system 0:
 0: Suggested OS type: "Ubuntu_64"
    (change with "--vsys 0 --ostype <type>"; use "list ostypes" to list all possible values)
 1: Suggested VM name "ubuntu-13.04"
    (change with "--vsys 0 --vmname <name>")
 2: Number of CPUs: 1
    (change with "--vsys 0 --cpus <n>")
 3: Guest memory: 384 MB
    (change with "--vsys 0 --memory <MB>")
 4: Network adapter: orig NAT, config 3, extra slot=0;type=NAT
 5: CD-ROM
    (disable with "--vsys 0 --unit 5 --ignore")
 6: IDE controller, type PIIX4
    (disable with "--vsys 0 --unit 6 --ignore")
 7: IDE controller, type PIIX4
    (disable with "--vsys 0 --unit 7 --ignore")
 8: SATA controller, type AHCI
    (disable with "--vsys 0 --unit 8 --ignore")
 9: Hard disk image: source image=box-disk1.vmdk, target path=W:\home\VirtualBox VMs\ubuntu-13.04\box-disk1.vmdk, controller=8;channel=0
    (change target path with "--vsys 0 --unit 9 --disk path";
    disable with "--vsys 0 --unit 9 --ignore")
 Successfully imported the appliance.
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "list", "vms"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: "ubuntu-13.04" {70da7ae6-22c5-404e-a81b-a3b771257e15}
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox: Instantiating the driver for machine ID: "70da7ae6-22c5-404e-a81b-a3b771257e15"
 DEBUG base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 DEBUG base: VBOX_INSTALL_PATH value: C:\Program Files\Oracle\VirtualBox\
 INFO base: VBoxManage path: C:\Program Files\Oracle\VirtualBox\VBoxManage.exe
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "--version"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: 4.2.4r81684
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG meta: Finding driver for VirtualBox version: 4.2.4
 INFO meta: Using VirtualBox driver: VagrantPlugins::ProviderVirtualBox::Driver::Version_4_2
 DEBUG base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 DEBUG base: VBOX_INSTALL_PATH value: C:\Program Files\Oracle\VirtualBox\
 INFO base: VBoxManage path: C:\Program Files\Oracle\VirtualBox\VBoxManage.exe
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: Name:            ubuntu-13.04
 Groups:          /
 Guest OS:        Ubuntu (64 bit)
 UUID:            70da7ae6-22c5-404e-a81b-a3b771257e15
 Config file:     W:\home\VirtualBox VMs\ubuntu-13.04\ubuntu-13.04.vbox
 Snapshot folder: W:\home\VirtualBox VMs\ubuntu-13.04\Snapshots
 Log folder:      W:\home\VirtualBox VMs\ubuntu-13.04\Logs
 Hardware UUID:   70da7ae6-22c5-404e-a81b-a3b771257e15
 Memory size:     384MB
 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:     0ms
 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 2013-05-12T22:41:31.000000000)
 Monitor count:   1
 3D Acceleration: off
 2D Video Acceleration: off
 Teleporter Enabled: off
 Teleporter Port: 0
 Teleporter Address:
 Teleporter Password:
 Tracing Enabled: off
 Allow Tracing to Access VM: off
 Tracing Configuration:
 Autostart Enabled: off
 Autostart Delay: 0
 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): Empty
 IDE Controller (1, 0): Empty
 SATA Controller (0, 0): W:\home\VirtualBox VMs\ubuntu-13.04\box-disk1.vmdk (UUID: 786bf345-4ac9-4c9d-95ea-873e2217c593)
 NIC 1:           MAC: 080027647F61, Attachment: NAT, Cable connected: on, Trace: off (file: none), Type: 82540EM, Reported speed: 0 Mbps, Boot priority: 0, Promisc Policy: deny, Bandwidth group: none
 NIC 1 Settings:  MTU: 0, Socket (send: 64, receive: 64), TCP Window (send:64, receive: 64)
 NIC 1 Rule(0):   name = guestssh, protocol = tcp, host ip = , host port = 7222, guest ip = , guest port = 22
 NIC 2:           disabled
 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
 LPT 1:           disabled
 LPT 2:           disabled
 Audio:           disabled
 Clipboard Mode:  disabled
 Drag'n'drop Mode:  disabled
 VRDE:            disabled
 USB:             disabled
 EHCI:            disabled

 USB Device Filters:

 <none>

 Available remote USB devices:

 <none>

 Currently Attached USB Devices:

 <none>

 Bandwidth groups:  <none>

 Shared folders:

 Name: 'veewee-validation', Host path: '/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation' (machine mapping), writable

 VRDE Connection:    not active
 Clients so far:     0

 Guest:

 Configured memory balloon size:      0 MB


 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0

 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::MatchMACAddress:0x66700b0>
 INFO interface: info: Matching MAC address for NAT networking...
 [foo] Matching MAC address for NAT networking...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "modifyvm", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--macaddress1", "080027120563"]
 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: #<VagrantPlugins::ProviderVirtualBox::Action::CheckVirtualbox:0x35c7f30>
 DEBUG base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 DEBUG base: VBOX_INSTALL_PATH value: C:\Program Files\Oracle\VirtualBox\
 INFO base: VBoxManage path: C:\Program Files\Oracle\VirtualBox\VBoxManage.exe
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "--version"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: 4.2.4r81684
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG meta: Finding driver for VirtualBox version: 4.2.4
 INFO meta: Using VirtualBox driver: VagrantPlugins::ProviderVirtualBox::Driver::Version_4_2
 DEBUG base: Windows. Trying VBOX_INSTALL_PATH for VBoxManage
 DEBUG base: VBOX_INSTALL_PATH value: C:\Program Files\Oracle\VirtualBox\
 INFO base: VBoxManage path: C:\Program Files\Oracle\VirtualBox\VBoxManage.exe
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "list", "hostonlyifs"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<Vagrant::Action::Builtin::ConfigValidate:0x35c7f00>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::Call:0x35c7ee8>
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x66e2308>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::IsRunning:0x66e0a18>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="ubuntu-13.04"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\ubuntu-13.04.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\ubuntu-13.04\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 mtu="0"
 sockSnd="64"
 sockRcv="64"
 tcpWndSnd="64"
 tcpWndRcv="64"
 Forwarding(0)="guestssh,tcp,,7222,,22"
 nic2="none"
 nic3="none"
 nic4="none"
 nic5="none"
 nic6="none"
 nic7="none"
 nic8="none"
 hidpointing="ps2mouse"
 hidkeyboard="ps2kbd"
 uart1="off"
 uart2="off"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="veewee-validation"
 SharedFolderPathMachineMapping1="/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Warden:0x66c0bb8>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::Call:0x66c0b70>
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x66a44a8>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::IsSaved:0x66a2bd0>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="ubuntu-13.04"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\ubuntu-13.04.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\ubuntu-13.04\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 mtu="0"
 sockSnd="64"
 sockRcv="64"
 tcpWndSnd="64"
 tcpWndRcv="64"
 Forwarding(0)="guestssh,tcp,,7222,,22"
 nic2="none"
 nic3="none"
 nic4="none"
 nic5="none"
 nic6="none"
 nic7="none"
 nic8="none"
 hidpointing="ps2mouse"
 hidkeyboard="ps2kbd"
 uart1="off"
 uart2="off"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="veewee-validation"
 SharedFolderPathMachineMapping1="/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Warden:0x6681fc0>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::Call:0x6681f78>
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x66646e0>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::IsPaused:0x6662a60>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="ubuntu-13.04"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\ubuntu-13.04.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\ubuntu-13.04\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 mtu="0"
 sockSnd="64"
 sockRcv="64"
 tcpWndSnd="64"
 tcpWndRcv="64"
 Forwarding(0)="guestssh,tcp,,7222,,22"
 nic2="none"
 nic3="none"
 nic4="none"
 nic5="none"
 nic6="none"
 nic7="none"
 nic8="none"
 hidpointing="ps2mouse"
 hidkeyboard="ps2kbd"
 uart1="off"
 uart2="off"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="veewee-validation"
 SharedFolderPathMachineMapping1="/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Warden:0x4d94ae0>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::CheckAccessible:0x4d9e518>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="ubuntu-13.04"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\ubuntu-13.04.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\ubuntu-13.04\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\ubuntu-13.04\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 mtu="0"
 sockSnd="64"
 sockRcv="64"
 tcpWndSnd="64"
 tcpWndRcv="64"
 Forwarding(0)="guestssh,tcp,,7222,,22"
 nic2="none"
 nic3="none"
 nic4="none"
 nic5="none"
 nic6="none"
 nic7="none"
 nic8="none"
 hidpointing="ps2mouse"
 hidkeyboard="ps2kbd"
 uart1="off"
 uart2="off"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="veewee-validation"
 SharedFolderPathMachineMapping1="/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::CleanMachineFolder:0x4d9e470>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "list", "systemproperties"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: API version:                     4_2
 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:          W:\home\VirtualBox VMs
 VRDE auth library:               VBoxAuth
 Webservice auth. library:        VBoxAuth
 Remote desktop ExtPack:          Oracle VM VirtualBox Extension Pack
 Log history count:               3
 Autostart database path:
 Default Guest Additions ISO:     C:\Program Files\Oracle\VirtualBox/VBoxGuestAdditions.iso
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::SetName:0x4d9e3c8>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "list", "vms"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: "ubuntu-13.04" {70da7ae6-22c5-404e-a81b-a3b771257e15}
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO setname: Setting the name of the VM: tmp5_1370963991
 INFO interface: info: Setting the name of the VM...
 [foo] Setting the name of the VM...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "modifyvm", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--name", "tmp5_1370963991"]
 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: #<VagrantPlugins::ProviderVirtualBox::Action::ClearForwardedPorts:0x5f0a450>
 INFO interface: info: Clearing any previously set forwarded ports...
 [foo] Clearing any previously set forwarded ports...
 DEBUG virtualbox_4_2: read_forward_ports: uuid=70da7ae6-22c5-404e-a81b-a3b771257e15 active_only=false
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 mtu="0"
 sockSnd="64"
 sockRcv="64"
 tcpWndSnd="64"
 tcpWndRcv="64"
 Forwarding(0)="guestssh,tcp,,7222,,22"
 nic2="none"
 nic3="none"
 nic4="none"
 nic5="none"
 nic6="none"
 nic7="none"
 nic8="none"
 hidpointing="ps2mouse"
 hidkeyboard="ps2kbd"
 uart1="off"
 uart2="off"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="veewee-validation"
 SharedFolderPathMachineMapping1="/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2:   - [1, "guestssh", 7222, 22]
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "modifyvm", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--natpf1", "delete", "guestssh"]
 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::Builtin::Provision:0x5f0a438>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::ConfigValidate:0x607ebd0>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::Call:0x607ebb8>
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x668b6b0>
 INFO warden: Calling action: #<VagrantPlugins::Omnibus::Action::IsRunningOrActive:0x6689dd8>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="veewee-validation"
 SharedFolderPathMachineMapping1="/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="veewee-validation"
 SharedFolderPathMachineMapping1="/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Warden:0x6655818>
 INFO warden: Calling action: #<VagrantPlugins::Cachier::Action::Install:0x607eb58>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::EnvSet:0x62669e8>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::PrepareForwardedPortCollisionParams:0x6266970>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "list", "vms"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: "tmp5_1370963991" {70da7ae6-22c5-404e-a81b-a3b771257e15}
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2: read_forward_ports: uuid=70da7ae6-22c5-404e-a81b-a3b771257e15 active_only=false
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="veewee-validation"
 SharedFolderPathMachineMapping1="/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<Vagrant::Action::Builtin::HandleForwardedPortCollisions:0x6266940>
 INFO handle_port_collisions: Detecting any forwarded port collisions...
 DEBUG handle_port_collisions: Extra in use: []
 DEBUG handle_port_collisions: Remap: {}
 DEBUG handle_port_collisions: Repair: true
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::PruneNFSExports:0x6496c50>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "list", "vms"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: "tmp5_1370963991" {70da7ae6-22c5-404e-a81b-a3b771257e15}
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<Vagrant::Action::Builtin::NFS:0x6496c38>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::PrepareNFSSettings:0x64a1090>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::ClearSharedFolders:0x64b33f0>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="veewee-validation"
 SharedFolderPathMachineMapping1="/Users/juliandunn/.rbenv/versions/1.9.3-p286/lib/ruby/gems/1.9.1/bundler/gems/veewee-164a10dd246e/validation"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "sharedfolder", "remove", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--name", "veewee-validation"]
 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: #<VagrantPlugins::ProviderVirtualBox::Action::ShareFolders:0x64b33d8>
 INFO interface: info: Creating shared folders metadata...
 [foo] Creating shared folders metadata...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "sharedfolder", "add", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--name", "/vagrant", "--hostpath", "D:/Repos/_github/bills-kitchen/target/tmp5"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "setextradata", "70da7ae6-22c5-404e-a81b-a3b771257e15", "VBoxInternal2/SharedFoldersEnableSymlinksCreate//vagrant", "1"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "sharedfolder", "add", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--name", "/tmp/vagrant-chef-1/chef-solo-1/cookbooks", "--hostpath", "D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "setextradata", "70da7ae6-22c5-404e-a81b-a3b771257e15", "VBoxInternal2/SharedFoldersEnableSymlinksCreate//tmp/vagrant-chef-1/chef-solo-1/cookbooks", "1"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "sharedfolder", "add", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--name", "/tmp/vagrant-cache", "--hostpath", "D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "setextradata", "70da7ae6-22c5-404e-a81b-a3b771257e15", "VBoxInternal2/SharedFoldersEnableSymlinksCreate//tmp/vagrant-cache", "1"]
 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: #<VagrantPlugins::ProviderVirtualBox::Action::ClearNetworkInterfaces:0x64bd5a8>
 INFO interface: info: Clearing any previously set network interfaces...
 [foo] Clearing any previously set network interfaces...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "modifyvm", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--nic2", "none", "--nic3", "none", "--nic4", "none", "--nic5", "none", "--nic6", "none", "--nic7", "none", "--nic8", "none"]
 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: #<VagrantPlugins::ProviderVirtualBox::Action::Network:0x64bd590>
 DEBUG network: Available slots for high-level adapters: #<Set: {2, 3, 4, 5, 6, 7, 8}>
 INFO network: Determining network adapters required for high-level configuration...
 INFO network: Determining adapters and compiling network configuration...
 INFO network: Network slot 1. Type: nat.
 DEBUG network: Normalized configuration: {:auto_config=>false, :adapter=>1}
 DEBUG network: Adapter configuration: {:adapter=>1, :type=>:nat}
 INFO network: Enabling adapters...
 INFO interface: info: Preparing network interfaces based on configuration...
 [foo] Preparing network interfaces based on configuration...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "modifyvm", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--nic1", "nat"]
 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: #<VagrantPlugins::ProviderVirtualBox::Action::ForwardPorts:0x64cefd8>
 INFO interface: info: Forwarding ports...
 [foo] Forwarding ports...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="off"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="poweroff"
 VMStateChangeTime="2013-05-12T22:41:31.000000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO interface: info: -- 22 => 2222 (adapter 1)
 [foo] -- 22 => 2222 (adapter 1)
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "modifyvm", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--natpf1", "ssh,tcp,,2222,,22"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 INFO warden: Calling action: #<Vagrant::Action::Builtin::SetHostname:0x64cefc0>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::SaneDefaults:0x64cefa8>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "storagectl", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--name", "SATA Controller", "--hostiocache", "on"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO sanedefaults: Enabling the Host I/O cache on the SATA controller... (exit status = 0)
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "modifyvm", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--rtcuseutc", "on"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO sanedefaults: Enabling rtcuseutc... (exit status = 0)
 INFO sanedefaults: Automatically figuring out whether to enable/disable NAT DNS proxy...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "modifyvm", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--natdnsproxy1", "on"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO sanedefaults: Enable the NAT DNS proxy on adapter 1... (exit status = 0)
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::Customize:0x64d8f68>
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::Boot:0x64d8f50>
 INFO interface: info: Booting VM...
 [foo] Booting VM...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "startvm", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--type", "headless"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: Waiting for VM "70da7ae6-22c5-404e-a81b-a3b771257e15" to power on...
 VM "70da7ae6-22c5-404e-a81b-a3b771257e15" has been successfully started.
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO interface: info: Waiting for VM to boot. This can take a few minutes.
 [foo] Waiting for VM to boot. This can take a few minutes.
 DEBUG ssh: Checking whether SSH is ready...
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Ubuntu_64"
 GuestAdditionsRunLevel=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2: Searching for SSH port: 22
 DEBUG virtualbox_4_2: read_forward_ports: uuid=70da7ae6-22c5-404e-a81b-a3b771257e15 active_only=false
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Ubuntu_64"
 GuestAdditionsRunLevel=0
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2:   - [1, "ssh", 2222, 22]
 INFO ssh: Attempting SSH. Retries: 100. Timeout: 30
 INFO ssh: Attempting to connect to SSH...
 INFO ssh:   - Host: 127.0.0.1
 INFO ssh:   - Port: 2222
 INFO ssh:   - Username: vagrant
 INFO ssh:   - Key Path: D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/insecure_private_key
 DEBUG ssh: == Net-SSH connection debug-level log START ==
 DEBUG ssh: D, [2013-06-11T17:19:58.016084 #8212] DEBUG -- net.ssh.transport.session[2724384]: establishing connection to 127.0.0.1:2222
 D, [2013-06-11T17:19:58.017084 #8212] DEBUG -- net.ssh.transport.session[2724384]: connection established
 I, [2013-06-11T17:19:58.017084 #8212]  INFO -- net.ssh.transport.server_version[2780a18]: negotiating protocol version
 D, [2013-06-11T17:20:16.281904 #8212] DEBUG -- net.ssh.transport.server_version[2780a18]: remote is `SSH-2.0-OpenSSH_6.1p1 Debian-4'
 D, [2013-06-11T17:20:16.282404 #8212] DEBUG -- net.ssh.transport.server_version[2780a18]: local is `SSH-2.0-Ruby/Net::SSH_2.6.7 i386-mingw32'
 D, [2013-06-11T17:20:16.284904 #8212] DEBUG -- tcpsocket[27515b8]: read 912 bytes
 D, [2013-06-11T17:20:16.285404 #8212] DEBUG -- tcpsocket[27515b8]: received packet nr 0 type 20 len 908
 I, [2013-06-11T17:20:16.285404 #8212]  INFO -- net.ssh.transport.algorithms[2ee0b58]: got KEXINIT from server
 I, [2013-06-11T17:20:16.285904 #8212]  INFO -- net.ssh.transport.algorithms[2ee0b58]: sending KEXINIT
 D, [2013-06-11T17:20:16.286404 #8212] DEBUG -- tcpsocket[27515b8]: queueing packet nr 0 type 20 len 1620
 D, [2013-06-11T17:20:16.286904 #8212] DEBUG -- tcpsocket[27515b8]: sent 1624 bytes
 I, [2013-06-11T17:20:16.286904 #8212]  INFO -- net.ssh.transport.algorithms[2ee0b58]: negotiating algorithms
 D, [2013-06-11T17:20:16.287905 #8212] DEBUG -- net.ssh.transport.algorithms[2ee0b58]: 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, [2013-06-11T17:20:16.287905 #8212] DEBUG -- net.ssh.transport.algorithms[2ee0b58]: exchanging keys
 D, [2013-06-11T17:20:16.288405 #8212] DEBUG -- tcpsocket[27515b8]: queueing packet nr 1 type 34 len 20
 D, [2013-06-11T17:20:16.288905 #8212] DEBUG -- tcpsocket[27515b8]: sent 24 bytes
 D, [2013-06-11T17:20:16.298906 #8212] DEBUG -- tcpsocket[27515b8]: read 152 bytes
 D, [2013-06-11T17:20:16.298906 #8212] DEBUG -- tcpsocket[27515b8]: received packet nr 1 type 31 len 148

 DEBUG ssh: == Net-SSH connection debug-level log END ==
 INFO retryable: Retryable exception raised: #<Timeout::Error: execution expired>
 INFO ssh: Attempting to connect to SSH...
 INFO ssh:   - Host: 127.0.0.1
 INFO ssh:   - Port: 2222
 INFO ssh:   - Username: vagrant
 INFO ssh:   - Key Path: D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/insecure_private_key
 DEBUG ssh: == Net-SSH connection debug-level log START ==
 DEBUG ssh: D, [2013-06-11T17:20:33.467086 #8212] DEBUG -- net.ssh.transport.session[24d9860]: establishing connection to 127.0.0.1:2222
 D, [2013-06-11T17:20:33.467586 #8212] DEBUG -- net.ssh.transport.session[24d9860]: connection established
 I, [2013-06-11T17:20:33.467586 #8212]  INFO -- net.ssh.transport.server_version[24dbb04]: negotiating protocol version
 D, [2013-06-11T17:20:33.478087 #8212] DEBUG -- net.ssh.transport.server_version[24dbb04]: remote is `SSH-2.0-OpenSSH_6.1p1 Debian-4'
 D, [2013-06-11T17:20:33.478587 #8212] DEBUG -- net.ssh.transport.server_version[24dbb04]: local is `SSH-2.0-Ruby/Net::SSH_2.6.7 i386-mingw32'
 D, [2013-06-11T17:20:33.521093 #8212] DEBUG -- tcpsocket[24dd070]: read 912 bytes
 D, [2013-06-11T17:20:33.521093 #8212] DEBUG -- tcpsocket[24dd070]: received packet nr 0 type 20 len 908
 I, [2013-06-11T17:20:33.521093 #8212]  INFO -- net.ssh.transport.algorithms[24ea63c]: got KEXINIT from server
 I, [2013-06-11T17:20:33.521593 #8212]  INFO -- net.ssh.transport.algorithms[24ea63c]: sending KEXINIT
 D, [2013-06-11T17:20:33.521593 #8212] DEBUG -- tcpsocket[24dd070]: queueing packet nr 0 type 20 len 1620
 D, [2013-06-11T17:20:33.522093 #8212] DEBUG -- tcpsocket[24dd070]: sent 1624 bytes
 I, [2013-06-11T17:20:33.522093 #8212]  INFO -- net.ssh.transport.algorithms[24ea63c]: negotiating algorithms
 D, [2013-06-11T17:20:33.522593 #8212] DEBUG -- net.ssh.transport.algorithms[24ea63c]: 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, [2013-06-11T17:20:33.523093 #8212] DEBUG -- net.ssh.transport.algorithms[24ea63c]: exchanging keys
 D, [2013-06-11T17:20:33.523093 #8212] DEBUG -- tcpsocket[24dd070]: queueing packet nr 1 type 34 len 20
 D, [2013-06-11T17:20:33.523593 #8212] DEBUG -- tcpsocket[24dd070]: sent 24 bytes
 D, [2013-06-11T17:20:33.533594 #8212] DEBUG -- tcpsocket[24dd070]: read 152 bytes
 D, [2013-06-11T17:20:33.533594 #8212] DEBUG -- tcpsocket[24dd070]: received packet nr 1 type 31 len 148
 D, [2013-06-11T17:20:33.540595 #8212] DEBUG -- tcpsocket[24dd070]: queueing packet nr 2 type 32 len 140
 D, [2013-06-11T17:20:33.541095 #8212] DEBUG -- tcpsocket[24dd070]: sent 144 bytes
 D, [2013-06-11T17:20:33.551097 #8212] DEBUG -- tcpsocket[24dd070]: read 720 bytes
 D, [2013-06-11T17:20:33.551097 #8212] DEBUG -- tcpsocket[24dd070]: received packet nr 2 type 33 len 700
 D, [2013-06-11T17:20:33.558598 #8212] DEBUG -- tcpsocket[24dd070]: queueing packet nr 3 type 21 len 20
 D, [2013-06-11T17:20:33.558598 #8212] DEBUG -- tcpsocket[24dd070]: sent 24 bytes
 D, [2013-06-11T17:20:33.559098 #8212] DEBUG -- tcpsocket[24dd070]: received packet nr 3 type 21 len 12
 D, [2013-06-11T17:20:33.559598 #8212] DEBUG -- net.ssh.authentication.session[1c164fc]: beginning authentication of `vagrant'
 D, [2013-06-11T17:20:33.559598 #8212] DEBUG -- tcpsocket[24dd070]: queueing packet nr 4 type 5 len 28
 D, [2013-06-11T17:20:33.559598 #8212] DEBUG -- tcpsocket[24dd070]: sent 52 bytes
 D, [2013-06-11T17:20:33.570099 #8212] DEBUG -- tcpsocket[24dd070]: read 52 bytes
 D, [2013-06-11T17:20:33.570099 #8212] DEBUG -- tcpsocket[24dd070]: received packet nr 4 type 6 len 28
 D, [2013-06-11T17:20:33.570599 #8212] DEBUG -- net.ssh.authentication.session[1c164fc]: trying none
 D, [2013-06-11T17:20:33.570599 #8212] DEBUG -- net.ssh.authentication.session[1c164fc]: Mechanism none was requested, but isn't a known type.  Ignoring it.
 D, [2013-06-11T17:20:33.570599 #8212] DEBUG -- net.ssh.authentication.session[1c164fc]: trying publickey
 D, [2013-06-11T17:20:33.571599 #8212] DEBUG -- net.ssh.authentication.agent[2177e5c]: connecting to ssh-agent
 D, [2013-06-11T17:20:33.572599 #8212] DEBUG -- net.ssh.authentication.agent[2177e5c]: sending agent request 1 len 44
 D, [2013-06-11T17:20:33.573099 #8212] DEBUG -- net.ssh.authentication.agent[2177e5c]: received agent packet 2 len 5
 D, [2013-06-11T17:20:33.573099 #8212] DEBUG -- net.ssh.authentication.agent[2177e5c]: sending agent request 11 len 0
 D, [2013-06-11T17:20:33.574100 #8212] DEBUG -- net.ssh.authentication.agent[2177e5c]: received agent packet 12 len 306
 D, [2013-06-11T17:20:33.574100 #8212] DEBUG -- net.ssh.authentication.methods.publickey[2173830]: trying publickey (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6)
 D, [2013-06-11T17:20:33.574600 #8212] DEBUG -- tcpsocket[24dd070]: queueing packet nr 5 type 50 len 348
 D, [2013-06-11T17:20:33.574600 #8212] DEBUG -- tcpsocket[24dd070]: sent 372 bytes
 D, [2013-06-11T17:20:33.595602 #8212] DEBUG -- tcpsocket[24dd070]: read 324 bytes
 D, [2013-06-11T17:20:33.596102 #8212] DEBUG -- tcpsocket[24dd070]: received packet nr 5 type 60 len 300
 D, [2013-06-11T17:20:33.610604 #8212] DEBUG -- tcpsocket[24dd070]: queueing packet nr 6 type 50 len 620
 D, [2013-06-11T17:20:33.610604 #8212] DEBUG -- tcpsocket[24dd070]: sent 644 bytes
 D, [2013-06-11T17:20:33.621106 #8212] DEBUG -- tcpsocket[24dd070]: read 36 bytes
 D, [2013-06-11T17:20:33.621106 #8212] DEBUG -- tcpsocket[24dd070]: received packet nr 6 type 52 len 12
 D, [2013-06-11T17:20:33.621606 #8212] DEBUG -- net.ssh.authentication.methods.publickey[2173830]: publickey succeeded (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6)

 DEBUG ssh: == Net-SSH connection debug-level log END ==
 INFO ssh: SSH is ready!
 INFO interface: info: VM booted and ready for use!
 [foo] VM booted and ready for use!
 INFO warden: Calling action: #<VagrantVbguest::Middleware:0x64d8f38>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::ConfigValidate:0x64d8f20>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::Call:0x64d8f08>
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x663f270>
 INFO warden: Calling action: #<VagrantPlugins::Omnibus::Action::IsRunningOrActive:0x663d7b8>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Warden:0x6612018>
 INFO warden: Calling action: #<VagrantPlugins::Omnibus::Action::ReadChefVersion:0x6611fd0>
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: echo $(chef-solo --v | awk "{print \$2}" || "")
 (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: stdout:

 DEBUG ssh: stderr: bash: line 2: chef-solo: command not found

 INFO warden: Calling action: #<VagrantPlugins::Omnibus::Action::InstallChef:0x6611fb8>
 INFO interface: info: Ensuring Chef is installed at requested version of 11.4.4.
 [foo] Ensuring Chef is installed at requested version of 11.4.4.
 INFO interface: info: Chef 11.4.4 Omnibus package is not installed...installing now.
 [foo] Chef 11.4.4 Omnibus package is not installed...installing now.
 INFO warden: Calling action: #<Vagrant::Action::Builtin::SSHRun:0x6611f70>
 DEBUG ssh_run: Executing command: if command -v wget &>/dev/null; then
  wget -qO- https://www.opscode.com/chef/install.sh | sudo bash -s -- -v 11.4.4
 elif command -v curl &>/dev/null; then
  curl -L https://www.opscode.com/chef/install.sh -v 11.4.4 | sudo bash
 else
  echo "Neither wget nor curl found. Please install one and try again." >&2
  exit 1
 fi

 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: if command -v wget &>/dev/null; then
  wget -qO- https://www.opscode.com/chef/install.sh | sudo bash -s -- -v 11.4.4
 elif command -v curl &>/dev/null; then
  curl -L https://www.opscode.com/chef/install.sh -v 11.4.4 | sudo bash
 else
  echo "Neither wget nor curl found. Please install one and try again." >&2
  exit 1
 fi
 (sudo=false)
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: Downloading Chef 11.4.4 for ubuntu...

 INFO interface: info: Downloading Chef 11.4.4 for ubuntu...

 Downloading Chef 11.4.4 for ubuntu...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: Installing Chef 11.4.4

 INFO interface: info: Installing Chef 11.4.4

 Installing Chef 11.4.4
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: Selecting previously unselected package chef.

 INFO interface: info: Selecting previously unselected package chef.

 Selecting previously unselected package chef.
 DEBUG ssh: stdout: (Reading database ...
 INFO interface: info: (Reading database ...
 (Reading database ... DEBUG ssh: stdout: 58970 files and directories currently installed.)

 INFO interface: info: 58970 files and directories currently installed.)

 58970 files and directories currently installed.)
 DEBUG ssh: stdout: Unpacking chef (from .../chef_11.4.4_amd64.deb) ...

 INFO interface: info: Unpacking chef (from .../chef_11.4.4_amd64.deb) ...

 Unpacking chef (from .../chef_11.4.4_amd64.deb) ...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: Setting up chef (11.4.4-2.ubuntu.11.04) ...

 INFO interface: info: Setting up chef (11.4.4-2.ubuntu.11.04) ...

 Setting up chef (11.4.4-2.ubuntu.11.04) ...
 DEBUG ssh: stdout: Thank you for installing Chef!

 INFO interface: info: Thank you for installing Chef!

 Thank you for installing Chef!
 DEBUG ssh: Exit status: 0
 INFO warden: Calling action: #<VagrantPlugins::ProviderVirtualBox::Action::CheckGuestAdditions:0x64d8ed8>
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "guestproperty", "get", "70da7ae6-22c5-404e-a81b-a3b771257e15", "/VirtualBox/GuestAdd/Version"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: Value: 4.2.12
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 INFO interface: info: Configuring and enabling network interfaces...
 [foo] Configuring and enabling network interfaces...
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 INFO guest: Detect guest for machine: #<Vagrant::Machine:0x2e6f380>
 DEBUG guest: Trying: fedora
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: grep 'Fedora release 1[678]' /etc/redhat-release (sudo=false)
 DEBUG ssh: stderr: grep:
 DEBUG ssh: stderr: /etc/redhat-release
 DEBUG ssh: stderr: : No such file or directory
 DEBUG ssh: stderr:

 DEBUG ssh: Exit status: 2
 DEBUG guest: Trying: pld
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: cat /etc/pld-release (sudo=false)
 DEBUG ssh: stderr: cat:
 DEBUG ssh: stderr: /etc/pld-release
 DEBUG ssh: stderr: : No such file or directory
 DEBUG ssh: stderr:

 DEBUG ssh: Exit status: 1
 DEBUG guest: Trying: suse
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: cat /etc/SuSE-release (sudo=false)
 DEBUG ssh: stderr: cat:
 DEBUG ssh: stderr: /etc/SuSE-release
 DEBUG ssh: stderr: : No such file or directory
 DEBUG ssh: stderr:

 DEBUG ssh: Exit status: 1
 DEBUG guest: Trying: ubuntu
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: cat /proc/version | grep 'Ubuntu' (sudo=false)
 DEBUG ssh: stdout: Linux version 3.8.0-19-generic (buildd@allspice) (gcc version 4.7.3 (Ubuntu/Linaro 4.7.3-1ubuntu1) ) #30-Ubuntu SMP Wed May 1 16:35:23 UTC 2013

 DEBUG ssh: Exit status: 0
 INFO guest: Detected: ubuntu!
 INFO guest: Full guest chain: [[:ubuntu, #<VagrantPlugins::GuestUbuntu::Guest:0x380ba10>], [:debian, #<VagrantPlugins::GuestDebian::Guest:0x4975cc8>], [:linux, #<VagrantPlugins::GuestLinux::Guest:0x4975b78>]]
 INFO guest: Execute capability: configure_networks (ubuntu)
 DEBUG guest: Searching for cap: configure_networks
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Found cap: configure_networks in debian
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: sed -e '/^#VAGRANT-BEGIN/,/^#VAGRANT-END/ d' /etc/network/interfaces > /tmp/vagrant-network-interfaces (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: su -c 'cat /tmp/vagrant-network-interfaces > /etc/network/interfaces' (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: rm /tmp/vagrant-network-interfaces (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Uploading: C:/Users/tkn/AppData/Local/Temp/vagrant20130611-8212-2fzux8 to /tmp/vagrant-network-entry
 DEBUG ssh: Re-using SSH connection.
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: cat /tmp/vagrant-network-entry >> /etc/network/interfaces (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: rm /tmp/vagrant-network-entry (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 INFO interface: info: Mounting shared folders...
 [foo] Mounting shared folders...
 INFO interface: info: -- /vagrant
 [foo] -- /vagrant
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2: Searching for SSH port: 22
 DEBUG virtualbox_4_2: read_forward_ports: uuid=70da7ae6-22c5-404e-a81b-a3b771257e15 active_only=false
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2:   - [1, "ssh", 2222, 22]
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 INFO guest: Execute capability: mount_virtualbox_shared_folder (ubuntu)
 DEBUG guest: Searching for cap: mount_virtualbox_shared_folder
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG guest: Found cap: mount_virtualbox_shared_folder in linux
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 INFO guest: Execute capability: shell_expand_guest_path (ubuntu)
 DEBUG guest: Searching for cap: shell_expand_guest_path
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG guest: Found cap: shell_expand_guest_path in linux
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: printf /vagrant (sudo=false)
 DEBUG ssh: stdout: /vagrant
 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mkdir -p /vagrant (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mount -t vboxsf -o uid=`id -u vagrant`,gid=`id -g vagrant` /vagrant /vagrant (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: chown `id -u vagrant`:`id -g vagrant` /vagrant (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 INFO interface: info: -- /tmp/vagrant-cache
 [foo] -- /tmp/vagrant-cache
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2: Searching for SSH port: 22
 DEBUG virtualbox_4_2: read_forward_ports: uuid=70da7ae6-22c5-404e-a81b-a3b771257e15 active_only=false
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2:   - [1, "ssh", 2222, 22]
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 INFO guest: Execute capability: mount_virtualbox_shared_folder (ubuntu)
 DEBUG guest: Searching for cap: mount_virtualbox_shared_folder
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG guest: Found cap: mount_virtualbox_shared_folder in linux
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 INFO guest: Execute capability: shell_expand_guest_path (ubuntu)
 DEBUG guest: Searching for cap: shell_expand_guest_path
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG guest: Found cap: shell_expand_guest_path in linux
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: printf /tmp/vagrant-cache (sudo=false)
 DEBUG ssh: stdout: /tmp/vagrant-cache
 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mkdir -p /tmp/vagrant-cache (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mount -t vboxsf -o uid=`id -u vagrant`,gid=`id -g vagrant` /tmp/vagrant-cache /tmp/vagrant-cache (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: chown `id -u vagrant`:`id -g vagrant` /tmp/vagrant-cache (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 INFO interface: info: -- /tmp/vagrant-chef-1/chef-solo-1/cookbooks
 [foo] -- /tmp/vagrant-chef-1/chef-solo-1/cookbooks
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2: Searching for SSH port: 22
 DEBUG virtualbox_4_2: read_forward_ports: uuid=70da7ae6-22c5-404e-a81b-a3b771257e15 active_only=false
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2:   - [1, "ssh", 2222, 22]
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 INFO guest: Execute capability: mount_virtualbox_shared_folder (ubuntu)
 DEBUG guest: Searching for cap: mount_virtualbox_shared_folder
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG guest: Found cap: mount_virtualbox_shared_folder in linux
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 INFO guest: Execute capability: shell_expand_guest_path (ubuntu)
 DEBUG guest: Searching for cap: shell_expand_guest_path
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG guest: Found cap: shell_expand_guest_path in linux
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: printf /tmp/vagrant-chef-1/chef-solo-1/cookbooks (sudo=false)
 DEBUG ssh: stdout: /tmp/vagrant-chef-1/chef-solo-1/cookbooks
 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mkdir -p /tmp/vagrant-chef-1/chef-solo-1/cookbooks (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mount -t vboxsf -o uid=`id -u vagrant`,gid=`id -g vagrant` /tmp/vagrant-chef-1/chef-solo-1/cookbooks /tmp/vagrant-chef-1/chef-solo-1/cookbooks (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: chown `id -u vagrant`:`id -g vagrant` /tmp/vagrant-chef-1/chef-solo-1/cookbooks (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 DEBUG guest: Searching for cap: apt_cache_dir
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Found cap: apt_cache_dir in debian
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 DEBUG guest: Searching for cap: gemdir
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG guest: Found cap: gemdir in linux
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 DEBUG guest: Searching for cap: pacman_cache_dir
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 DEBUG guest: Searching for cap: yum_cache_dir
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 INFO interface: info: Configuring cache buckets...
 [foo] Configuring cache buckets...
 DEBUG install: Installing apt with configs {}
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 DEBUG guest: Searching for cap: apt_cache_dir
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Found cap: apt_cache_dir in debian
 INFO guest: Execute capability: apt_cache_dir (ubuntu)
 DEBUG guest: Searching for cap: apt_cache_dir
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Found cap: apt_cache_dir in debian
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mkdir -p /tmp/vagrant-cache/apt (sudo=false)
 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: test -L /var/cache/apt/archives (sudo=false)
 DEBUG ssh: Exit status: 1
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: rm -rf /var/cache/apt/archives (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mkdir -p `dirname /var/cache/apt/archives` (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: ln -s /tmp/vagrant-cache/apt /var/cache/apt/archives (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 DEBUG install: Installing gem with configs {}
 DEBUG ssh: Checking whether SSH is ready...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: SSH is ready!
 DEBUG guest: Searching for cap: gemdir
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG guest: Found cap: gemdir in linux
 INFO guest: Execute capability: gemdir (ubuntu)
 DEBUG guest: Searching for cap: gemdir
 DEBUG guest: Checking in: ubuntu
 DEBUG guest: Checking in: debian
 DEBUG guest: Checking in: linux
 DEBUG guest: Found cap: gemdir in linux
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: which gem (sudo=false)
 DEBUG ssh: Exit status: 1
 INFO interface: info: Running provisioner: chef_solo...
 [foo] Running provisioner: chef_solo...
 DEBUG chef_solo: Checking for shared folder: /tmp/vagrant-chef-1/chef-solo-1/cookbooks
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: test -d /tmp/vagrant-chef-1/chef-solo-1/cookbooks (sudo=false)
 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: which chef-solo (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: stdout: /usr/bin/chef-solo

 DEBUG ssh: Exit status: 0
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mkdir -p /tmp/vagrant-chef-1 (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2: Searching for SSH port: 22
 DEBUG virtualbox_4_2: read_forward_ports: uuid=70da7ae6-22c5-404e-a81b-a3b771257e15 active_only=false
 INFO subprocess: Starting process: ["C:\\Program Files\\Oracle\\VirtualBox\\VBoxManage.exe", "showvminfo", "70da7ae6-22c5-404e-a81b-a3b771257e15", "--machinereadable"]
 DEBUG subprocess: Selecting on IO
 DEBUG subprocess: stdout: name="tmp5_1370963991"
 groups="/"
 ostype="Ubuntu (64 bit)"
 UUID="70da7ae6-22c5-404e-a81b-a3b771257e15"
 CfgFile="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\tmp5_1370963991.vbox"
 SnapFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Snapshots"
 LogFldr="W:\\home\\VirtualBox VMs\\tmp5_1370963991\\Logs"
 hardwareuuid="70da7ae6-22c5-404e-a81b-a3b771257e15"
 memory=384
 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"
 Time offset=0rtcuseutc="on"
 hwvirtex="on"
 hwvirtexexcl="off"
 nestedpaging="on"
 largepages="on"
 vtxvpid="on"
 VMState="running"
 VMStateChangeTime="2013-06-11T15:19:56.961000000"
 monitorcount=1
 accelerate3d="off"
 accelerate2dvideo="off"
 teleporterenabled="off"
 teleporterport=0
 teleporteraddress=""
 teleporterpassword=""
 tracing-enabled="off"
 tracing-allow-vm-access="off"
 tracing-config=""
 autostart-enabled="off"
 autostart-delay=0
 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"="emptydrive"
 "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"="W:\home\VirtualBox VMs\tmp5_1370963991\box-disk1.vmdk"
 "SATA Controller-ImageUUID-0-0"="786bf345-4ac9-4c9d-95ea-873e2217c593"
 natnet1="nat"
 macaddress1="080027120563"
 cableconnected1="on"
 nic1="nat"
 nictype1="82540EM"
 nicspeed1="0"
 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"
 lpt1="off"
 lpt2="off"
 audio="none"
 clipboard="disabled"
 draganddrop="disabled"
 VideoMode="640,480,32"
 vrde="off"
 usb="off"
 ehci="off"
 SharedFolderNameMachineMapping1="/vagrant"
 SharedFolderPathMachineMapping1="D:/Repos/_github/bills-kitchen/target/tmp5"
 SharedFolderNameMachineMapping2="/tmp/vagrant-chef-1/chef-solo-1/cookbooks"
 SharedFolderPathMachineMapping2="D:/Repos/_github/bills-kitchen/target/tmp5/cookbooks"
 SharedFolderNameMachineMapping3="/tmp/vagrant-cache"
 SharedFolderPathMachineMapping3="D:/Repos/_github/bills-kitchen/target/build/home/.vagrant.d/cache/opscode_ubuntu-13.04_provisionerless"
 VRDEActiveConnection="off"
 VRDEClients=0
 GuestMemoryBalloon=0
 GuestOSType="Linux26_64"
 GuestAdditionsRunLevel=2
 GuestAdditionsVersion="4.2.12 r84980"
 GuestAdditionsFacility_VirtualBox Base Driver=50,1370964007934
 GuestAdditionsFacility_VirtualBox System Service=50,1370964012323
 GuestAdditionsFacility_Seamless Mode=0,1370964007934
 GuestAdditionsFacility_Graphics Mode=0,1370964007934
 DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
 DEBUG subprocess: Exit status: 0
 DEBUG virtualbox_4_2:   - [1, "ssh", 2222, 22]
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: chown -R vagrant /tmp/vagrant-chef-1 (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: Exit status: 0
 INFO interface: info: Generating chef JSON and uploading...
 Generating chef JSON and uploading...
 DEBUG ssh: Uploading: C:/Users/tkn/AppData/Local/Temp/vagrant20130611-8212-lvuqlx to /tmp/vagrant-chef-1/dna.json
 DEBUG ssh: Re-using SSH connection.
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: rm /tmp/vagrant-chef-1/solo.rb (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 DEBUG ssh: stderr: rm:
 DEBUG ssh: stderr: cannot remove ���/tmp/vagrant-chef-1/solo.rb���
 DEBUG ssh: stderr: : No such file or directory
 DEBUG ssh: stderr:

 DEBUG ssh: Exit status: 1
 DEBUG ssh: Uploading: C:/Users/tkn/AppData/Local/Temp/vagrant20130611-8212-al99kp to /tmp/vagrant-chef-1/solo.rb
 DEBUG ssh: Re-using SSH connection.
 INFO interface: info: Running chef-solo...
 Running chef-solo...
 DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: chef-solo -c /tmp/vagrant-chef-1/solo.rb -j /tmp/vagrant-chef-1/dna.json  (sudo=true)
 DEBUG ssh: stderr: stdin: is not a tty

 INFO interface: info: stdin: is not a tty
 stdin: is not a tty
 DEBUG ssh: stdout: [2013-06-11T15:21:18+00:00] INFO: *** Chef 11.4.4 ***

 INFO interface: info: [2013-06-11T15:21:18+00:00] INFO: *** Chef 11.4.4 ***
 [2013-06-11T15:21:18+00:00] INFO: *** Chef 11.4.4 ***
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] INFO: Setting the run_list to ["recipe[apt]", "recipe[apache2]"] from JSON

 INFO interface: info: [2013-06-11T15:21:19+00:00] INFO: Setting the run_list to ["recipe[apt]", "recipe[apache2]"] from JSON
 [2013-06-11T15:21:19+00:00] INFO: Setting the run_list to ["recipe[apt]", "recipe[apache2]"] from JSON
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] INFO: Run List is [recipe[apt], recipe[apache2]]

 INFO interface: info: [2013-06-11T15:21:19+00:00] INFO: Run List is [recipe[apt], recipe[apache2]]
 [2013-06-11T15:21:19+00:00] INFO: Run List is [recipe[apt], recipe[apache2]]
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] INFO: Run List expands to [apt, apache2]

 INFO interface: info: [2013-06-11T15:21:19+00:00] INFO: Run List expands to [apt, apache2]
 [2013-06-11T15:21:19+00:00] INFO: Run List expands to [apt, apache2]
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] INFO: Starting Chef Run for vagrant.vm

 INFO interface: info: [2013-06-11T15:21:19+00:00] INFO: Starting Chef Run for vagrant.vm
 [2013-06-11T15:21:19+00:00] INFO: Starting Chef Run for vagrant.vm
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] INFO: Running start handlers

 INFO interface: info: [2013-06-11T15:21:19+00:00] INFO: Running start handlers
 [2013-06-11T15:21:19+00:00] INFO: Running start handlers
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] INFO: Start handlers complete.

 INFO interface: info: [2013-06-11T15:21:19+00:00] INFO: Start handlers complete.
 [2013-06-11T15:21:19+00:00] INFO: Start handlers complete.
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] WARN: Cloning resource attributes for service[apache2] from prior resource (CHEF-3694)

 INFO interface: info: [2013-06-11T15:21:19+00:00] WARN: Cloning resource attributes for service[apache2] from prior resource (CHEF-3694)
 [2013-06-11T15:21:19+00:00] WARN: Cloning resource attributes for service[apache2] from prior resource (CHEF-3694)
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] WARN: Previous service[apache2]: /tmp/vagrant-chef-1/chef-solo-1/cookbooks/apache2/recipes/default.rb:24:in `from_file'

 INFO interface: info: [2013-06-11T15:21:19+00:00] WARN: Previous service[apache2]: /tmp/vagrant-chef-1/chef-solo-1/cookbooks/apache2/recipes/default.rb:24:in `from_file'
 [2013-06-11T15:21:19+00:00] WARN: Previous service[apache2]: /tmp/vagrant-chef-1/chef-solo-1/cookbooks/apache2/recipes/default.rb:24:in `from_file'
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] WARN: Current  service[apache2]: /tmp/vagrant-chef-1/chef-solo-1/cookbooks/apache2/recipes/default.rb:221:in `from_file'

 INFO interface: info: [2013-06-11T15:21:19+00:00] WARN: Current  service[apache2]: /tmp/vagrant-chef-1/chef-solo-1/cookbooks/apache2/recipes/default.rb:221:in `from_file'
 [2013-06-11T15:21:19+00:00] WARN: Current  service[apache2]: /tmp/vagrant-chef-1/chef-solo-1/cookbooks/apache2/recipes/default.rb:221:in `from_file'
 DEBUG ssh: stdout: [2013-06-11T15:21:19+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)

 INFO interface: info: [2013-06-11T15:21:19+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)
 [2013-06-11T15:21:19+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: [2013-06-11T15:21:39+00:00] INFO: execute[apt-get-update] ran successfully

 INFO interface: info: [2013-06-11T15:21:39+00:00] INFO: execute[apt-get-update] ran successfully
 [2013-06-11T15:21:39+00:00] INFO: execute[apt-get-update] ran successfully
 DEBUG ssh: stdout: [2013-06-11T15:21:39+00:00] INFO: Processing execute[apt-get update] action nothing (apt::default line 29)

 INFO interface: info: [2013-06-11T15:21:39+00:00] INFO: Processing execute[apt-get update] action nothing (apt::default line 29)
 [2013-06-11T15:21:39+00:00] INFO: Processing execute[apt-get update] action nothing (apt::default line 29)
 DEBUG ssh: stdout: [2013-06-11T15:21:39+00:00] INFO: Processing execute[apt-get autoremove] action nothing (apt::default line 36)

 INFO interface: info: [2013-06-11T15:21:39+00:00] INFO: Processing execute[apt-get autoremove] action nothing (apt::default line 36)
 [2013-06-11T15:21:39+00:00] INFO: Processing execute[apt-get autoremove] action nothing (apt::default line 36)
 DEBUG ssh: stdout: [2013-06-11T15:21:39+00:00] INFO: Processing execute[apt-get autoclean] action nothing (apt::default line 42)

 INFO interface: info: [2013-06-11T15:21:39+00:00] INFO: Processing execute[apt-get autoclean] action nothing (apt::default line 42)
 [2013-06-11T15:21:39+00:00] INFO: Processing execute[apt-get autoclean] action nothing (apt::default line 42)
 DEBUG ssh: stdout: [2013-06-11T15:21:39+00:00] INFO: Processing package[update-notifier-common] action install (apt::default line 48)

 INFO interface: info: [2013-06-11T15:21:39+00:00] INFO: Processing package[update-notifier-common] action install (apt::default line 48)
 [2013-06-11T15:21:39+00:00] INFO: Processing package[update-notifier-common] action install (apt::default line 48)
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: [2013-06-11T15:21:43+00:00] INFO: package[update-notifier-common] sending run action to execute[apt-get-update] (immediate)

 INFO interface: info: [2013-06-11T15:21:43+00:00] INFO: package[update-notifier-common] sending run action to execute[apt-get-update] (immediate)
 [2013-06-11T15:21:43+00:00] INFO: package[update-notifier-common] sending run action to execute[apt-get-update] (immediate)
 DEBUG ssh: stdout: [2013-06-11T15:21:43+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)

 INFO interface: info: [2013-06-11T15:21:43+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)
 [2013-06-11T15:21:43+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: execute[apt-get-update] ran successfully

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: execute[apt-get-update] ran successfully
 [2013-06-11T15:22:02+00:00] INFO: execute[apt-get-update] ran successfully
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: Processing execute[apt-get-update-periodic] action run (apt::default line 52)

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: Processing execute[apt-get-update-periodic] action run (apt::default line 52)
 [2013-06-11T15:22:02+00:00] INFO: Processing execute[apt-get-update-periodic] action run (apt::default line 52)
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: Processing directory[/var/cache/local] action create (apt::default line 62)

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: Processing directory[/var/cache/local] action create (apt::default line 62)
 [2013-06-11T15:22:02+00:00] INFO: Processing directory[/var/cache/local] action create (apt::default line 62)
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] created directory /var/cache/local

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] created directory /var/cache/local
 [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] created directory /var/cache/local
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] owner changed to 0

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] owner changed to 0
 [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] owner changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] group changed to 0

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] group changed to 0
 [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] group changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] mode changed to 755

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] mode changed to 755
 [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local] mode changed to 755
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: Processing directory[/var/cache/local/preseeding] action create (apt::default line 62)

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: Processing directory[/var/cache/local/preseeding] action create (apt::default line 62)
 [2013-06-11T15:22:02+00:00] INFO: Processing directory[/var/cache/local/preseeding] action create (apt::default line 62)
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] created directory /var/cache/local/preseeding

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] created directory /var/cache/local/preseeding
 [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] created directory /var/cache/local/preseeding
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] owner changed to 0

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] owner changed to 0
 [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] owner changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] group changed to 0

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] group changed to 0
 [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] group changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] mode changed to 755

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] mode changed to 755
 [2013-06-11T15:22:02+00:00] INFO: directory[/var/cache/local/preseeding] mode changed to 755
 DEBUG ssh: stdout: [2013-06-11T15:22:02+00:00] INFO: Processing package[apache2] action install (apache2::default line 20)

 INFO interface: info: [2013-06-11T15:22:02+00:00] INFO: Processing package[apache2] action install (apache2::default line 20)
 [2013-06-11T15:22:02+00:00] INFO: Processing package[apache2] action install (apache2::default line 20)
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: Processing service[apache2] action enable (apache2::default line 24)

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: Processing service[apache2] action enable (apache2::default line 24)
 [2013-06-11T15:22:10+00:00] INFO: Processing service[apache2] action enable (apache2::default line 24)
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: Processing directory[/etc/apache2/ssl] action create (apache2::default line 131)

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: Processing directory[/etc/apache2/ssl] action create (apache2::default line 131)
 [2013-06-11T15:22:10+00:00] INFO: Processing directory[/etc/apache2/ssl] action create (apache2::default line 131)
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] created directory /etc/apache2/ssl

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] created directory /etc/apache2/ssl
 [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] created directory /etc/apache2/ssl
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] owner changed to 0

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] owner changed to 0
 [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] owner changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] group changed to 0

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] group changed to 0
 [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] group changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] mode changed to 755

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] mode changed to 755
 [2013-06-11T15:22:10+00:00] INFO: directory[/etc/apache2/ssl] mode changed to 755
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: Processing directory[/etc/apache2/conf.d] action create (apache2::default line 137)

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: Processing directory[/etc/apache2/conf.d] action create (apache2::default line 137)
 [2013-06-11T15:22:10+00:00] INFO: Processing directory[/etc/apache2/conf.d] action create (apache2::default line 137)
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: Processing directory[/var/cache/apache2] action create (apache2::default line 143)

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: Processing directory[/var/cache/apache2] action create (apache2::default line 143)
 [2013-06-11T15:22:10+00:00] INFO: Processing directory[/var/cache/apache2] action create (apache2::default line 143)
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: directory[/var/cache/apache2] owner changed to 0

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: directory[/var/cache/apache2] owner changed to 0
 [2013-06-11T15:22:10+00:00] INFO: directory[/var/cache/apache2] owner changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: directory[/var/cache/apache2] group changed to 0

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: directory[/var/cache/apache2] group changed to 0
 [2013-06-11T15:22:10+00:00] INFO: directory[/var/cache/apache2] group changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: Processing template[/etc/sysconfig/httpd] action create (apache2::default line 150)

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: Processing template[/etc/sysconfig/httpd] action create (apache2::default line 150)
 [2013-06-11T15:22:10+00:00] INFO: Processing template[/etc/sysconfig/httpd] action create (apache2::default line 150)
 DEBUG ssh: stdout: [2013-06-11T15:22:10+00:00] INFO: Processing template[apache2.conf] action create (apache2::default line 159)

 INFO interface: info: [2013-06-11T15:22:10+00:00] INFO: Processing template[apache2.conf] action create (apache2::default line 159)
 [2013-06-11T15:22:10+00:00] INFO: Processing template[apache2.conf] action create (apache2::default line 159)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] backed up to /var/chef/backup/etc/apache2/apache2.conf.chef-20130611152211

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] backed up to /var/chef/backup/etc/apache2/apache2.conf.chef-20130611152211
 [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] backed up to /var/chef/backup/etc/apache2/apache2.conf.chef-20130611152211
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] updated content

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] updated content
 [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] updated content
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] owner changed to 0

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] owner changed to 0
 [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] owner changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] group changed to 0

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] group changed to 0
 [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] group changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] mode changed to 644

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] mode changed to 644
 [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] mode changed to 644
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[apache2-conf-security] action create (apache2::default line 175)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[apache2-conf-security] action create (apache2::default line 175)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[apache2-conf-security] action create (apache2::default line 175)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] updated content

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] updated content
 [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] updated content
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] owner changed to 0

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] owner changed to 0
 [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] owner changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] group changed to 0

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] group changed to 0
 [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] group changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] mode changed to 644

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] mode changed to 644
 [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] mode changed to 644
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 [2013-06-11T15:22:11+00:00] INFO: template[apache2-conf-security] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[apache2-conf-charset] action create (apache2::default line 185)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[apache2-conf-charset] action create (apache2::default line 185)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[apache2-conf-charset] action create (apache2::default line 185)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/ports.conf] action create (apache2::default line 195)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/ports.conf] action create (apache2::default line 195)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/ports.conf] action create (apache2::default line 195)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] backed up to /var/chef/backup/etc/apache2/ports.conf.chef-20130611152211

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] backed up to /var/chef/backup/etc/apache2/ports.conf.chef-20130611152211
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] backed up to /var/chef/backup/etc/apache2/ports.conf.chef-20130611152211
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] updated content

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] updated content
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] updated content
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] owner changed to 0

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] owner changed to 0
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] owner changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] group changed to 0

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] group changed to 0
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] group changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] mode changed to 644

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] mode changed to 644
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] mode changed to 644
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/ports.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/sites-available/default] action create (apache2::default line 204)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/sites-available/default] action create (apache2::default line 204)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/sites-available/default] action create (apache2::default line 204)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] backed up to /var/chef/backup/etc/apache2/sites-available/default.chef-20130611152211

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] backed up to /var/chef/backup/etc/apache2/sites-available/default.chef-20130611152211
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] backed up to /var/chef/backup/etc/apache2/sites-available/default.chef-20130611152211
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] updated content

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] updated content
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] updated content
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] owner changed to 0

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] owner changed to 0
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] owner changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] group changed to 0

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] group changed to 0
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] group changed to 0
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] mode changed to 644

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] mode changed to 644
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] mode changed to 644
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/sites-available/default] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/status.conf] action create (apache2::mod_status line 21)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/status.conf] action create (apache2::mod_status line 21)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/status.conf] action create (apache2::mod_status line 21)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] backed up to /var/chef/backup/etc/apache2/mods-available/status.conf.chef-20130611152211

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] backed up to /var/chef/backup/etc/apache2/mods-available/status.conf.chef-20130611152211
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] backed up to /var/chef/backup/etc/apache2/mods-available/status.conf.chef-20130611152211
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] updated content

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] updated content
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] updated content
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] mode changed to 644

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] mode changed to 644
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] mode changed to 644
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/status.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod status] action run (apache2::mod_status line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod status] action run (apache2::mod_status line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod status] action run (apache2::mod_status line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/alias.conf] action create (apache2::mod_alias line 21)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/alias.conf] action create (apache2::mod_alias line 21)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/alias.conf] action create (apache2::mod_alias line 21)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] backed up to /var/chef/backup/etc/apache2/mods-available/alias.conf.chef-20130611152211

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] backed up to /var/chef/backup/etc/apache2/mods-available/alias.conf.chef-20130611152211
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] backed up to /var/chef/backup/etc/apache2/mods-available/alias.conf.chef-20130611152211
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] updated content

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] updated content
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] updated content
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] mode changed to 644

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] mode changed to 644
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] mode changed to 644
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] not queuing delayed action restart on service[apache2] (delayed), as
 it's already been queued
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/alias.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod alias] action run (apache2::mod_alias line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod alias] action run (apache2::mod_alias line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod alias] action run (apache2::mod_alias line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod auth_basic] action run (apache2::mod_auth_basic line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod auth_basic] action run (apache2::mod_auth_basic line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod auth_basic] action run (apache2::mod_auth_basic line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authn_file] action run (apache2::mod_authn_file line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authn_file] action run (apache2::mod_authn_file line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authn_file] action run (apache2::mod_authn_file line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_default] action run (apache2::mod_authz_default line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_default] action run (apache2::mod_authz_default line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_default] action run (apache2::mod_authz_default line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_groupfile] action run (apache2::mod_authz_groupfile line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_groupfile] action run (apache2::mod_authz_groupfile line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_groupfile] action run (apache2::mod_authz_groupfile line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_host] action run (apache2::mod_authz_host line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_host] action run (apache2::mod_authz_host line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_host] action run (apache2::mod_authz_host line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_user] action run (apache2::mod_authz_user line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_user] action run (apache2::mod_authz_user line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod authz_user] action run (apache2::mod_authz_user line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/autoindex.conf] action create (apache2::mod_autoindex line 21)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/autoindex.conf] action create (apache2::mod_autoindex line 21)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/autoindex.conf] action create (apache2::mod_autoindex line 21)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod autoindex] action run (apache2::mod_autoindex line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod autoindex] action run (apache2::mod_autoindex line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod autoindex] action run (apache2::mod_autoindex line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/dir.conf] action create (apache2::mod_dir line 21)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/dir.conf] action create (apache2::mod_dir line 21)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/dir.conf] action create (apache2::mod_dir line 21)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod dir] action run (apache2::mod_dir line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod dir] action run (apache2::mod_dir line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod dir] action run (apache2::mod_dir line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod env] action run (apache2::mod_env line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod env] action run (apache2::mod_env line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod env] action run (apache2::mod_env line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/mime.conf] action create (apache2::mod_mime line 21)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/mime.conf] action create (apache2::mod_mime line 21)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/mime.conf] action create (apache2::mod_mime line 21)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] backed up to /var/chef/backup/etc/apache2/mods-available/mime.conf.chef-20130611152211

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] backed up to /var/chef/backup/etc/apache2/mods-available/mime.conf.chef-20130611152211
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] backed up to /var/chef/backup/etc/apache2/mods-available/mime.conf.chef-20130611152211
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] updated content

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] updated content
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] updated content
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] mode changed to 644

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] mode changed to 644
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] mode changed to 644
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] not queuing delayed action restart on service[apache2] (delayed), as it's
 already been queued

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/mime.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod mime] action run (apache2::mod_mime line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod mime] action run (apache2::mod_mime line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod mime] action run (apache2::mod_mime line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/negotiation.conf] action create (apache2::mod_negotiation line 21)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/negotiation.conf] action create (apache2::mod_negotiation line 21)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/negotiation.conf] action create (apache2::mod_negotiation line 21)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod negotiation] action run (apache2::mod_negotiation line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod negotiation] action run (apache2::mod_negotiation line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod negotiation] action run (apache2::mod_negotiation line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/setenvif.conf] action create (apache2::mod_setenvif line 21)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/setenvif.conf] action create (apache2::mod_setenvif line 21)
 [2013-06-11T15:22:11+00:00] INFO: Processing template[/etc/apache2/mods-available/setenvif.conf] action create (apache2::mod_setenvif line 21)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] backed up to /var/chef/backup/etc/apache2/mods-available/setenvif.conf.chef-20130611152211

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] backed up to /var/chef/backup/etc/apache2/mods-available/setenvif.conf.chef-20130611152211
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] backed up to /var/chef/backup/etc/apache2/mods-available/setenvif.conf.chef-20130611152211
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] updated content

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] updated content
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] updated content
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] mode changed to 644

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] mode changed to 644
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] mode changed to 644
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] not queuing delayed action restart on service[apache2] (delayed),
 as it's already been queued
 [2013-06-11T15:22:11+00:00] INFO: template[/etc/apache2/mods-available/setenvif.conf] not queuing delayed action restart on service[apache2] (delayed), as it's already been queued
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod setenvif] action run (apache2::mod_setenvif line 38)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod setenvif] action run (apache2::mod_setenvif line 38)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2enmod setenvif] action run (apache2::mod_setenvif line 38)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2dissite default] action run (apache2::default line 34)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2dissite default] action run (apache2::default line 34)
 [2013-06-11T15:22:11+00:00] INFO: Processing execute[a2dissite default] action run (apache2::default line 34)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: execute[a2dissite default] ran successfully

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: execute[a2dissite default] ran successfully
 [2013-06-11T15:22:11+00:00] INFO: execute[a2dissite default] ran successfully
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing service[apache2] action start (apache2::default line 221)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing service[apache2] action start (apache2::default line 221)
 [2013-06-11T15:22:11+00:00] INFO: Processing service[apache2] action start (apache2::default line 221)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] sending restart action to service[apache2] (delayed)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] sending restart action to service[apache2] (delayed)
 [2013-06-11T15:22:11+00:00] INFO: template[apache2.conf] sending restart action to service[apache2] (delayed)
 DEBUG ssh: stdout: [2013-06-11T15:22:11+00:00] INFO: Processing service[apache2] action restart (apache2::default line 221)

 INFO interface: info: [2013-06-11T15:22:11+00:00] INFO: Processing service[apache2] action restart (apache2::default line 221)
 [2013-06-11T15:22:11+00:00] INFO: Processing service[apache2] action restart (apache2::default line 221)
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: [2013-06-11T15:22:15+00:00] INFO: service[apache2] restarted

 INFO interface: info: [2013-06-11T15:22:15+00:00] INFO: service[apache2] restarted
 [2013-06-11T15:22:15+00:00] INFO: service[apache2] restarted
 DEBUG ssh: stdout: [2013-06-11T15:22:15+00:00] INFO: execute[a2dissite default] sending restart action to service[apache2] (delayed)

 INFO interface: info: [2013-06-11T15:22:15+00:00] INFO: execute[a2dissite default] sending restart action to service[apache2] (delayed)
 [2013-06-11T15:22:15+00:00] INFO: execute[a2dissite default] sending restart action to service[apache2] (delayed)
 DEBUG ssh: stdout: [2013-06-11T15:22:15+00:00] INFO: Processing service[apache2] action restart (apache2::default line 24)

 INFO interface: info: [2013-06-11T15:22:15+00:00] INFO: Processing service[apache2] action restart (apache2::default line 24)
 [2013-06-11T15:22:15+00:00] INFO: Processing service[apache2] action restart (apache2::default line 24)
 DEBUG ssh: Sending SSH keep-alive...
 DEBUG ssh: stdout: [2013-06-11T15:22:18+00:00] INFO: service[apache2] restarted

 INFO interface: info: [2013-06-11T15:22:18+00:00] INFO: service[apache2] restarted
 [2013-06-11T15:22:18+00:00] INFO: service[apache2] restarted
 DEBUG ssh: stdout: [2013-06-11T15:22:18+00:00] INFO: Chef Run complete in 59.1443895 seconds

 INFO interface: info: [2013-06-11T15:22:18+00:00] INFO: Chef Run complete in 59.1443895 seconds
 [2013-06-11T15:22:18+00:00] INFO: Chef Run complete in 59.1443895 seconds
 DEBUG ssh: stdout: [2013-06-11T15:22:18+00:00] INFO: Running report handlers

 INFO interface: info: [2013-06-11T15:22:18+00:00] INFO: Running report handlers
 [2013-06-11T15:22:18+00:00] INFO: Running report handlers
 DEBUG ssh: stdout: [2013-06-11T15:22:18+00:00] INFO: Report handlers complete

 INFO interface: info: [2013-06-11T15:22:18+00:00] INFO: Report handlers complete
 [2013-06-11T15:22:18+00:00] INFO: Report handlers complete
 DEBUG ssh: Exit status: 0
 INFO environment: Running hook: environment_unload
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 1 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x4c403a0>