Debug log for https://github.com/audiolize/vagrant-softlayer/issues/58

vagrant-softlayer-issue-58-debug.log

 INFO global: Vagrant version: 1.7.2
 INFO global: Ruby version: 2.0.0
 INFO global: RubyGems version: 2.0.14
 INFO global: VAGRANT_EXECUTABLE="/opt/vagrant/bin/../embedded/gems/gems/vagrant-1.7.2/bin/vagrant"
 INFO global: VAGRANT_LOG="debug"
 INFO global: VAGRANT_INSTALLER_EMBEDDED_DIR="/opt/vagrant/bin/../embedded"
 INFO global: VAGRANT_INSTALLER_VERSION="2"
 INFO global: VAGRANT_DETECTED_OS="Linux"
 INFO global: VAGRANT_INSTALLER_ENV="1"
 INFO global: VAGRANT_INTERNAL_BUNDLERIZED="1"
 INFO global: Plugins:
 INFO global:   - bundler = 1.7.11
 INFO global:   - configparser = 0.1.3
 INFO global:   - json = 1.8.2
 INFO global:   - mime-types = 1.25.1
 INFO global:   - rdoc = 4.2.0
 INFO global:   - rest-client = 1.6.8
 INFO global:   - softlayer_api = 3.0.2
 INFO global:   - vagrant-berkshelf = 4.0.3
 INFO global:   - vagrant-omnibus = 1.4.1
 INFO global:   - vagrant-share = 1.1.3
 INFO global:   - vagrant-softlayer = 0.4.0
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/file/plugin.rb
 INFO manager: Registered plugin: file
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/shell/plugin.rb
 INFO manager: Registered plugin: shell
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/cfengine/plugin.rb
 INFO manager: Registered plugin: CFEngine Provisioner
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/chef/plugin.rb
 INFO manager: Registered plugin: chef
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/puppet/plugin.rb
 INFO manager: Registered plugin: puppet
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/salt/plugin.rb
 INFO manager: Registered plugin: salt
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/docker/plugin.rb
 INFO manager: Registered plugin: docker
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/ansible/plugin.rb
 INFO manager: Registered plugin: ansible
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/pushes/atlas/plugin.rb
 INFO manager: Registered plugin: atlas
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/pushes/ftp/plugin.rb
 INFO manager: Registered plugin: ftp
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/pushes/local-exec/plugin.rb
 INFO manager: Registered plugin: local-exec
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/pushes/noop/plugin.rb
 INFO manager: Registered plugin: noop
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/pushes/heroku/plugin.rb
 INFO manager: Registered plugin: heroku
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/communicators/winrm/plugin.rb
 INFO manager: Registered plugin: winrm communicator
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/communicators/ssh/plugin.rb
 INFO manager: Registered plugin: ssh communicator
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/synced_folders/rsync/plugin.rb
 INFO manager: Registered plugin: RSync synced folders
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/synced_folders/nfs/plugin.rb
 INFO manager: Registered plugin: NFS synced folders
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/synced_folders/smb/plugin.rb
 INFO manager: Registered plugin: SMB synced folders
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/smartos/plugin.rb
 INFO manager: Registered plugin: SmartOS guest.
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/netbsd/plugin.rb
 INFO manager: Registered plugin: NetBSD guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/redhat/plugin.rb
 INFO manager: Registered plugin: RedHat guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/arch/plugin.rb
 INFO manager: Registered plugin: Arch guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/pld/plugin.rb
 INFO manager: Registered plugin: PLD Linux guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/ubuntu/plugin.rb
 INFO manager: Registered plugin: Ubuntu guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/coreos/plugin.rb
 INFO manager: Registered plugin: CoreOS guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/suse/plugin.rb
 INFO manager: Registered plugin: SUSE guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/tinycore/plugin.rb
 INFO manager: Registered plugin: TinyCore Linux guest.
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/esxi/plugin.rb
 INFO manager: Registered plugin: ESXi guest.
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/omnios/plugin.rb
 INFO manager: Registered plugin: OmniOS guest.
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/darwin/plugin.rb
 INFO manager: Registered plugin: Darwin guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/solaris/plugin.rb
 INFO manager: Registered plugin: Solaris guest.
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/solaris11/plugin.rb
 INFO manager: Registered plugin: Solaris 11 guest.
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/gentoo/plugin.rb
 INFO manager: Registered plugin: Gentoo guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/fedora/plugin.rb
 INFO manager: Registered plugin: Fedora guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/linux/plugin.rb
 INFO manager: Registered plugin: Linux guest.
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/windows/plugin.rb
 INFO manager: Registered plugin: Windows guest.
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/openbsd/plugin.rb
 INFO manager: Registered plugin: OpenBSD guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/funtoo/plugin.rb
 INFO manager: Registered plugin: Funtoo guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/mint/plugin.rb
 INFO manager: Registered plugin: Mint guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/debian/plugin.rb
 INFO manager: Registered plugin: Debian guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/freebsd/plugin.rb
 INFO manager: Registered plugin: FreeBSD guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/guests/nixos/plugin.rb
 INFO manager: Registered plugin: NixOS guest
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/kernel_v2/plugin.rb
 INFO manager: Registered plugin: kernel
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/ssh_config/plugin.rb
 INFO manager: Registered plugin: ssh-config command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/halt/plugin.rb
 INFO manager: Registered plugin: halt command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/version/plugin.rb
 INFO manager: Registered plugin: version command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/plugin/plugin.rb
 INFO manager: Registered plugin: plugin command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/up/plugin.rb
 INFO manager: Registered plugin: up command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/help/plugin.rb
 INFO manager: Registered plugin: help command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/suspend/plugin.rb
 INFO manager: Registered plugin: suspend command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/box/plugin.rb
 INFO manager: Registered plugin: box command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/destroy/plugin.rb
 INFO manager: Registered plugin: destroy command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/global-status/plugin.rb
 INFO manager: Registered plugin: global-status command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/rdp/plugin.rb
 INFO manager: Registered plugin: rdp command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/list-commands/plugin.rb
 INFO manager: Registered plugin: list-commands command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/package/plugin.rb
 INFO manager: Registered plugin: package command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/provision/plugin.rb
 INFO manager: Registered plugin: provision command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/reload/plugin.rb
 INFO manager: Registered plugin: reload command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/login/plugin.rb
 INFO manager: Registered plugin: vagrant-login
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/ssh/plugin.rb
 INFO manager: Registered plugin: ssh command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/resume/plugin.rb
 INFO manager: Registered plugin: resume command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/push/plugin.rb
 INFO manager: Registered plugin: push command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/status/plugin.rb
 INFO manager: Registered plugin: status command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/commands/init/plugin.rb
 INFO manager: Registered plugin: init command
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/redhat/plugin.rb
 INFO manager: Registered plugin: Red Hat host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/arch/plugin.rb
 INFO manager: Registered plugin: Arch host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/suse/plugin.rb
 INFO manager: Registered plugin: SUSE host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/darwin/plugin.rb
 INFO manager: Registered plugin: Mac OS X host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/gentoo/plugin.rb
 INFO manager: Registered plugin: Gentoo host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/linux/plugin.rb
 INFO manager: Registered plugin: Linux host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/bsd/plugin.rb
 INFO manager: Registered plugin: BSD host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/windows/plugin.rb
 INFO manager: Registered plugin: Windows host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/slackware/plugin.rb
 INFO manager: Registered plugin: Slackware host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/null/plugin.rb
 INFO manager: Registered plugin: null host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/hosts/freebsd/plugin.rb
 INFO manager: Registered plugin: FreeBSD host
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/kernel_v1/plugin.rb
 INFO manager: Registered plugin: kernel
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/providers/hyperv/plugin.rb
 INFO manager: Registered plugin: Hyper-V provider
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/providers/docker/plugin.rb
 INFO manager: Registered plugin: docker-provider
DEBUG global: Loading core plugin: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/providers/virtualbox/plugin.rb
 INFO manager: Registered plugin: VirtualBox provider
 INFO global: Loading plugins!
 INFO manager: Registered plugin: vagrant-share
 INFO root: Version requirements from Vagrantfile: ["~> 1.5"]
 INFO root:   - Version requirements satisfied!
 INFO manager: Registered plugin: berkshelf
 INFO manager: Registered plugin: vagrant-omnibus
 INFO manager: Registered plugin: SoftLayer
 INFO vagrant: `vagrant` invoked: ["up", "--provider", "softlayer"]
DEBUG vagrant: Creating Vagrant environment
 INFO environment: Environment initialized (#<Vagrant::Environment:0x00000001455690>)
 INFO environment:   - cwd: /home/riethm/cookbooks/kp-projects/vagrant-softlayer-test
 INFO environment: Home path: /home/riethm/.vagrant.d
 INFO environment: Local data path: /home/riethm/cookbooks/kp-projects/vagrant-softlayer-test/.vagrant
DEBUG environment: Creating: /home/riethm/cookbooks/kp-projects/vagrant-softlayer-test/.vagrant
 INFO environment: Running hook: environment_plugins_loaded
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 2 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x00000001a97760>
 INFO environment: Running hook: environment_load
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 2 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x00000001c15c40>
 INFO cli: CLI: [] "up" ["--provider", "softlayer"]
DEBUG cli: Invoking command class: VagrantPlugins::CommandUp::Command ["--provider", "softlayer"]
DEBUG command: 'Up' each target VM...
 INFO loader: Set :root = #<Pathname:/home/riethm/cookbooks/kp-projects/vagrant-softlayer-test/Vagrantfile>
DEBUG loader: Populating proc cache for #<Pathname:/home/riethm/cookbooks/kp-projects/vagrant-softlayer-test/Vagrantfile>
DEBUG loader: Load procs for pathname: /home/riethm/cookbooks/kp-projects/vagrant-softlayer-test/Vagrantfile
 INFO loader: Loading configuration in order: [:home, :root]
DEBUG loader: Loading from: root (evaluating)
DEBUG provisioner: Provisioner defined: 
DEBUG loader: Configuration loaded successfully, finalizing and returning
DEBUG push: finalizing
DEBUG command: Getting target VMs for command. Arguments:
DEBUG command:  -- names: ["default"]
DEBUG command:  -- options: {:provider=>"softlayer"}
DEBUG command: Finding machine that match name: default
 INFO environment: Getting machine: default (softlayer)
 INFO environment: Uncached load of machine.
 INFO loader: Set "10256240_machine_default" = []
 INFO loader: Loading configuration in order: [:home, :root, "10256240_machine_default"]
DEBUG loader: Loading from: root (cache)
DEBUG loader: Configuration loaded successfully, finalizing and returning
DEBUG push: finalizing
 INFO loader: Set :"10256240_vm_default_chef/centos-6.6_softlayer" = [["2", #<Proc:0x00000001820428>]]
DEBUG loader: Populating proc cache for ["2", #<Proc:0x00000001820428>]
 INFO loader: Loading configuration in order: [:home, :root, "10256240_machine_default", :"10256240_vm_default_chef/centos-6.6_softlayer"]
DEBUG loader: Loading from: root (cache)
DEBUG loader: Loading from: 10256240_vm_default_chef/centos-6.6_softlayer (evaluating)
DEBUG loader: Configuration loaded successfully, finalizing and returning
DEBUG push: finalizing
 INFO box_collection: Box found: softlayer (softlayer)
 INFO loader: Set :"10256240_vm_default_softlayer_softlayer" = [["2", #<Proc:0x00000001820428>]]
 INFO loader: Loading configuration in order: [:home, :root, "10256240_machine_default", :"10256240_vm_default_softlayer_softlayer"]
ERROR loader: Unknown config sources: [:"10256240_vm_default_chef/centos-6.6_softlayer"]
DEBUG loader: Loading from: root (cache)
DEBUG loader: Loading from: 10256240_vm_default_softlayer_softlayer (cache)
DEBUG loader: Configuration loaded successfully, finalizing and returning
DEBUG push: finalizing
 INFO machine: Initializing machine: default
 INFO machine:   - Provider: VagrantPlugins::SoftLayer::Provider
 INFO machine:   - Box: #<Vagrant::Box:0x00000001ac4058>
 INFO machine:   - Data dir: /home/riethm/cookbooks/kp-projects/vagrant-softlayer-test/.vagrant/machines/default/softlayer
 INFO machine: Calling action: read_state on provider SoftLayer (new VM)
DEBUG environment: Attempting to acquire process-lock: machine-action-b88104a6790a5e4ebd9095c9d2dfe411
DEBUG environment: Attempting to acquire process-lock: dotlock
 INFO environment: Acquired process lock: dotlock
 INFO environment: Released process lock: dotlock
 INFO environment: Acquired process lock: machine-action-b88104a6790a5e4ebd9095c9d2dfe411
 INFO host: Autodetecting host type for [#<Vagrant::Environment: /home/riethm/cookbooks/kp-projects/vagrant-softlayer-test>]
DEBUG host: Trying: redhat
DEBUG host: Trying: arch
DEBUG host: Trying: suse
DEBUG host: Trying: darwin
DEBUG host: Trying: gentoo
DEBUG host: Trying: slackware
DEBUG host: Trying: freebsd
DEBUG host: Trying: linux
 INFO host: Detected: linux!
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 2 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x00000001954060>
 INFO warden: Calling IN action: #<Vagrant::Action::Builtin::ConfigValidate:0x00000001c4dc08>
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::SetupSoftLayer:0x00000001c4dbb8>
 INFO connect_softlayer: Creating the SoftLayer service objects...
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::ReadState:0x00000001c2a488>
 INFO warden: Calling OUT action: #<VagrantPlugins::SoftLayer::Action::ReadState:0x00000001c2a488>
 INFO warden: Calling OUT action: #<VagrantPlugins::SoftLayer::Action::SetupSoftLayer:0x00000001c4dbb8>
 INFO warden: Calling OUT action: #<Vagrant::Action::Builtin::ConfigValidate:0x00000001c4dc08>
 INFO environment: Released process lock: machine-action-b88104a6790a5e4ebd9095c9d2dfe411
DEBUG environment: Attempting to acquire process-lock: dotlock
 INFO environment: Acquired process lock: dotlock
 INFO environment: Released process lock: dotlock
 INFO machine: New machine ID: nil
 INFO command: With machine: default (#<VagrantPlugins::SoftLayer::Provider:0x0000000146b800 @machine=#<Vagrant::Machine: default (VagrantPlugins::SoftLayer::Provider)>, @cap_logger=#<Log4r::Logger:0x0000000146a770 @fullname="vagrant::capability_host::vagrantplugins::softlayer::provider", @outputters=[], @additive=true, @name="provider", @path="vagrant::capability_host::vagrantplugins::softlayer", @parent=#<Log4r::Logger:0x000000010711f0 @fullname="vagrant", @outputters=[#<Log4r::StderrOutputter:0x000000013899c8 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x00000001389928>, @name="stderr", @level=0, @formatter=#<Log4r::DefaultFormatter:0x0000000138e950 @depth=7>, @out=#<IO:<STDERR>>>], @additive=true, @name="vagrant", @path="", @parent=#<Log4r::RootLogger:0x00000001071088 @level=0, @outputters=[]>, @level=1, @trace=false>, @level=1, @trace=false>, @cap_host_chain=[[:softlayer, #<#<Class:0x0000000146b738>:0x00000001844d50>]], @cap_args=[#<Vagrant::Machine: default (VagrantPlugins::SoftLayer::Provider)>], @cap_caps={:hyperv=>#<Vagrant::Registry:0x0000000146b2d8 @items={:public_address=>#<Proc:0x00000001852a90@/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/providers/hyperv/plugin.rb:25>}, @results_cache={}>, :docker=>#<Vagrant::Registry:0x0000000146b170 @items={:public_address=>#<Proc:0x0000000185d120@/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/providers/docker/plugin.rb:54>, :proxy_machine=>#<Proc:0x0000000185d030@/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/providers/docker/plugin.rb:59>}, @results_cache={}>, :virtualbox=>#<Vagrant::Registry:0x0000000146af90 @items={:forwarded_ports=>#<Proc:0x000000018685e8@/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/providers/virtualbox/plugin.rb:27>, :nic_mac_addresses=>#<Proc:0x00000001868520@/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/providers/virtualbox/plugin.rb:32>, :public_address=>#<Proc:0x000000018b0dc0@/opt/vagrant/embedded/gems/gems/vagrant-share-1.1.3/lib/vagrant-share.rb:39>}, @results_cache={}>}>)
 INFO interface: info: Bringing machine 'default' up with 'softlayer' provider...
Bringing machine 'default' up with 'softlayer' provider...
 INFO machine: Calling action: read_state on provider SoftLayer (new VM)
DEBUG environment: Attempting to acquire process-lock: machine-action-b88104a6790a5e4ebd9095c9d2dfe411
DEBUG environment: Attempting to acquire process-lock: dotlock
 INFO environment: Acquired process lock: dotlock
 INFO environment: Released process lock: dotlock
 INFO environment: Acquired process lock: machine-action-b88104a6790a5e4ebd9095c9d2dfe411
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 2 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x00000001467480>
 INFO warden: Calling IN action: #<Vagrant::Action::Builtin::ConfigValidate:0x00000001460130>
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::SetupSoftLayer:0x00000001460108>
 INFO connect_softlayer: Creating the SoftLayer service objects...
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::ReadState:0x0000000140e6a0>
 INFO warden: Calling OUT action: #<VagrantPlugins::SoftLayer::Action::ReadState:0x0000000140e6a0>
 INFO warden: Calling OUT action: #<VagrantPlugins::SoftLayer::Action::SetupSoftLayer:0x00000001460108>
 INFO warden: Calling OUT action: #<Vagrant::Action::Builtin::ConfigValidate:0x00000001460130>
 INFO environment: Released process lock: machine-action-b88104a6790a5e4ebd9095c9d2dfe411
DEBUG environment: Attempting to acquire process-lock: dotlock
 INFO environment: Acquired process lock: dotlock
 INFO environment: Released process lock: dotlock
 INFO batch_action: Enabling parallelization by default.
 INFO batch_action: Disabling parallelization because only executing one action
 INFO batch_action: Batch action will parallelize: false
 INFO batch_action: Starting action: #<Vagrant::Machine:0x000000013ab708> up {:destroy_on_error=>true, :parallel=>true, :provision_ignore_sentinel=>false, :provision_types=>nil, :provider=>"softlayer"}
 INFO machine: Calling action: up on provider SoftLayer (new VM)
DEBUG environment: Attempting to acquire process-lock: machine-action-b88104a6790a5e4ebd9095c9d2dfe411
DEBUG environment: Attempting to acquire process-lock: dotlock
 INFO environment: Acquired process lock: dotlock
 INFO environment: Released process lock: dotlock
 INFO environment: Acquired process lock: machine-action-b88104a6790a5e4ebd9095c9d2dfe411
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x00000000fdbe48>
 INFO warden: Calling IN action: #<Vagrant::Action::Builtin::HandleBox:0x00000000c9a6d0>
 INFO handle_box: Machine already has box. HandleBox will not run.
 INFO warden: Calling IN action: #<Vagrant::Action::Builtin::ConfigValidate:0x00000000e681d8>
 INFO warden: Calling IN action: #<VagrantPlugins::Berkshelf::Action::Check:0x00000000e681b0>
 INFO subprocess: Starting process: ["/usr/bin/berks", "--version", "--format", "json"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: {
  "version": "3.2.3"
}
DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999
DEBUG subprocess: Exit status: 0
 INFO warden: Calling IN action: #<Vagrant::Action::Builtin::EnvSet:0x0000000100f900>
 INFO warden: Calling IN action: #<VagrantPlugins::Berkshelf::Action::Load:0x0000000100ff68>
 INFO interface: detail: The Berkshelf shelf is at "/home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default"
 INFO interface: detail:     default: The Berkshelf shelf is at "/home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default"
    default: The Berkshelf shelf is at "/home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default"
DEBUG load: Persisting datafile share to memory
 INFO warden: Calling IN action: #<VagrantPlugins::Berkshelf::Action::Share:0x000000013a79a0>
 INFO interface: info: Sharing cookbooks with VM
 INFO interface: info: ==> default: Sharing cookbooks with VM
==> default: Sharing cookbooks with VM
DEBUG share: Setting cookbooks_path = [[:host, "/home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default"]]
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::SetupSoftLayer:0x000000013f4e08>
 INFO connect_softlayer: Creating the SoftLayer service objects...
 INFO warden: Calling IN action: #<Vagrant::Action::Builtin::Call:0x0000000145af28>
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x00000001b58370>
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::Is:0x00000001b68518>
 INFO machine: Calling action: read_state on provider SoftLayer (new VM)
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 2 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x00000001bf73d0>
 INFO warden: Calling IN action: #<Vagrant::Action::Builtin::ConfigValidate:0x00000001bf9e28>
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::SetupSoftLayer:0x00000001bf9e00>
 INFO connect_softlayer: Creating the SoftLayer service objects...
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::ReadState:0x00000001c33510>
 INFO warden: Calling OUT action: #<VagrantPlugins::SoftLayer::Action::ReadState:0x00000001c33510>
 INFO warden: Calling OUT action: #<VagrantPlugins::SoftLayer::Action::SetupSoftLayer:0x00000001bf9e00>
 INFO warden: Calling OUT action: #<Vagrant::Action::Builtin::ConfigValidate:0x00000001bf9e28>
 INFO warden: Calling OUT action: #<VagrantPlugins::SoftLayer::Action::Is:0x00000001b68518>
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 3 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Warden:0x00000001afc188>
 INFO warden: Calling IN action: #<Proc:0x000000018672d8@/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:94 (lambda)>
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::SetupSoftLayer:0x00000001afec08>
 INFO connect_softlayer: Creating the SoftLayer service objects...
 INFO warden: Calling IN action: #<VagrantPlugins::Berkshelf::Action::Save:0x00000001900618>
DEBUG save: Saving datafile to disk
 INFO warden: Calling IN action: #<VagrantPlugins::Berkshelf::Action::Install:0x00000001865050>
 INFO interface: info: Updating Vagrant's Berkshelf...
 INFO interface: info: ==> default: Updating Vagrant's Berkshelf...
==> default: Updating Vagrant's Berkshelf...
 INFO subprocess: Starting process: ["/usr/bin/berks", "vendor", "/home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default", "--berksfile", "/home/riethm/cookbooks/kp-projects/vagrant-softlayer-test/Berksfile"]
DEBUG subprocess: Selecting on IO
DEBUG subprocess: stdout: Resolving cookbook dependencies...
DEBUG subprocess: stdout: Fetching 'vagrant-softlayer-test' from source at .
DEBUG subprocess: stdout: Using vagrant-softlayer-test (0.0.1) from source at .
DEBUG subprocess: stdout: Vendoring vagrant-softlayer-test (0.0.1) to /home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default/vagrant-softlayer-test
DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 32000
DEBUG subprocess: Exit status: 0
 INFO interface: output: Resolving cookbook dependencies...
Fetching 'vagrant-softlayer-test' from source at .
Using vagrant-softlayer-test (0.0.1) from source at .
Vendoring vagrant-softlayer-test (0.0.1) to /home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default/vagrant-softlayer-test

 INFO interface: output: ==> default: Resolving cookbook dependencies...
==> default: Fetching 'vagrant-softlayer-test' from source at .
==> default: Using vagrant-softlayer-test (0.0.1) from source at .
==> default: Vendoring vagrant-softlayer-test (0.0.1) to /home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default/vagrant-softlayer-test
==> default: Resolving cookbook dependencies...
==> default: Fetching 'vagrant-softlayer-test' from source at .
==> default: Using vagrant-softlayer-test (0.0.1) from source at .
==> default: Vendoring vagrant-softlayer-test (0.0.1) to /home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default/vagrant-softlayer-test
 INFO warden: Calling IN action: #<VagrantPlugins::Berkshelf::Action::Upload:0x00000001466508>
 INFO upload: Provisioner does need to upload
 INFO warden: Calling IN action: #<Vagrant::Action::Builtin::Provision:0x00000001410978>
 INFO provision: Checking provisioner sentinel file...
 INFO warden: Calling IN action: #<VagrantPlugins::Omnibus::Action::InstallChef:0x000000013b1838>
 INFO warden: Calling IN action: #<Vagrant::Action::Builtin::SyncedFolders:0x00000000c98cb8>
DEBUG host: Searching for cap: nfs_installed
DEBUG host: Checking in: linux
DEBUG host: Found cap: nfs_installed in linux
 INFO host: Execute capability: nfs_installed [#<Vagrant::Environment: /home/riethm/cookbooks/kp-projects/vagrant-softlayer-test>] (linux)
 INFO synced_folders: Synced Folder Implementation: rsync
 INFO synced_folders:   - /vagrant: . => /vagrant
 INFO synced_folders:   - v-csc-1: /home/riethm/.berkshelf/vagrant-berkshelf/shelves/berkshelf20150508-9490-mhfqdm-default => /tmp/vagrant-chef/5e13774b5baf3acd88f85c4af77e6555/cookbooks
 INFO synced_folders: Invoking synced folder prepare for: rsync
 INFO warden: Calling IN action: #<VagrantPlugins::SoftLayer::Action::CreateInstance:0x00000000fb0d10>
 INFO interface: info: Creating a new SoftLayer instance...
 INFO interface: info: ==> default: Creating a new SoftLayer instance...
==> default: Creating a new SoftLayer instance...
ERROR warden: Error occurred: Vagrant returned an exception while calling the SoftLayer API.

Exception class: XMLRPC::FaultException
Exception message: Unable to find image template #0.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: Vagrant returned an exception while calling the SoftLayer API.

Exception class: XMLRPC::FaultException
Exception message: Unable to find image template #0.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: Vagrant returned an exception while calling the SoftLayer API.

Exception class: XMLRPC::FaultException
Exception message: Unable to find image template #0.
 INFO warden: Beginning recovery process...
 INFO warden: Calling recover: #<Vagrant::Action::Builtin::Call:0x0000000145af28>
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO environment: Released process lock: machine-action-b88104a6790a5e4ebd9095c9d2dfe411
 INFO environment: Running hook: environment_unload
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 2 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x007f157ca78b70>
ERROR vagrant: Vagrant experienced an error! Details:
ERROR vagrant: #<VagrantPlugins::SoftLayer::Errors::SLApiError: Vagrant returned an exception while calling the SoftLayer API.

Exception class: XMLRPC::FaultException
Exception message: Unable to find image template #0.>
ERROR vagrant: Vagrant returned an exception while calling the SoftLayer API.

Exception class: XMLRPC::FaultException
Exception message: Unable to find image template #0.
ERROR vagrant: /home/riethm/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/util/warden.rb:31:in `rescue in sl_warden'
/home/riethm/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/util/warden.rb:17:in `sl_warden'
/home/riethm/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/action/create_instance.rb:18:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/builtin/synced_folders.rb:84:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/home/riethm/.vagrant.d/gems/gems/vagrant-omnibus-1.4.1/lib/vagrant-omnibus/action/install_chef.rb:38:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/builtin/provision.rb:80:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/home/riethm/.vagrant.d/gems/gems/vagrant-berkshelf-4.0.3/lib/vagrant-berkshelf/action/upload.rb:23:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/home/riethm/.vagrant.d/gems/gems/vagrant-berkshelf-4.0.3/lib/vagrant-berkshelf/action/install.rb:19:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/home/riethm/.vagrant.d/gems/gems/vagrant-berkshelf-4.0.3/lib/vagrant-berkshelf/action/save.rb:21:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/home/riethm/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/action/setup_softlayer.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/builder.rb:116:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/runner.rb:66:in `block in run'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/util/busy.rb:19:in `busy'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/runner.rb:66:in `run'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/builtin/call.rb:53:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/home/riethm/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/action/setup_softlayer.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/home/riethm/.vagrant.d/gems/gems/vagrant-berkshelf-4.0.3/lib/vagrant-berkshelf/action/share.rb:28:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/home/riethm/.vagrant.d/gems/gems/vagrant-berkshelf-4.0.3/lib/vagrant-berkshelf/action/load.rb:30:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/builtin/env_set.rb:19:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/home/riethm/.vagrant.d/gems/gems/vagrant-berkshelf-4.0.3/lib/vagrant-berkshelf/action/check.rb:18:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/builtin/config_validate.rb:25:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/builtin/handle_box.rb:56:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:34:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/builder.rb:116:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/runner.rb:66:in `block in run'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/util/busy.rb:19:in `busy'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/runner.rb:66:in `run'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/machine.rb:214:in `action_raw'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/machine.rb:191:in `block in action'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/environment.rb:516:in `lock'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/machine.rb:178:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/machine.rb:178:in `action'
/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/batch_action.rb:82:in `block (2 levels) in run'
 INFO interface: error: Vagrant returned an exception while calling the SoftLayer API.

Exception class: XMLRPC::FaultException
Exception message: Unable to find image template #0.
Vagrant returned an exception while calling the SoftLayer API.

Exception class: XMLRPC::FaultException
Exception message: Unable to find image template #0.
 INFO interface: Machine: error-exit ["VagrantPlugins::SoftLayer::Errors::SLApiError", "Vagrant returned an exception while calling the SoftLayer API.\n\nException class: XMLRPC::FaultException\nException message: Unable to find image template #0."]