Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP

Loading…

random "Forcing shutdown of VM" through provisioning process #516

Closed
LarsFronius opened this Issue · 89 comments
@LarsFronius

If I run "vagrant up" and have a puppet provisioner configured, the provisioning process sometimes gets abborted by the following message. I think this happens more often if I run puppet in the foreground - being done with puppet.options = ["--test"] in the Vagrantfile.

[avm01] Forcing shutdown of VM...
[avm01] Destroying VM and associated drives...
[avm01] Destroying unused networking interface...
/usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:22:in `select': closed stream (IOError)
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:22:in `io_select'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/transport/packet_stream.rb:73:in `available_for_read?'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/transport/packet_stream.rb:85:in `next_packet'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/transport/session.rb:169:in `block in poll_message'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/transport/session.rb:164:in `loop'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/transport/session.rb:164:in `poll_message'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/connection/session.rb:451:in `dispatch_incoming_packets'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/connection/session.rb:213:in `preprocess'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/connection/session.rb:197:in `process'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/connection/session.rb:161:in `block in loop'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/connection/session.rb:161:in `loop'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/connection/session.rb:161:in `loop'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/net-ssh-2.1.4/lib/net/ssh/connection/channel.rb:269:in `wait'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/ssh/session.rb:55:in `sudo!'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/provisioners/puppet_server.rb:47:in `block in run_puppetd_client'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/ssh.rb:119:in `execute'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/provisioners/puppet_server.rb:46:in `run_puppetd_client'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/provisioners/puppet_server.rb:24:in `provision!'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/provision.rb:22:in `block in call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/provision.rb:20:in `each'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/provision.rb:20:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/warden.rb:30:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/forward_ports.rb:95:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/warden.rb:30:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/clear_forwarded_ports.rb:21:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/warden.rb:30:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/clean_machine_folder.rb:17:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/warden.rb:30:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/check_guest_additions.rb:30:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/warden.rb:30:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/match_mac_address.rb:21:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/warden.rb:30:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/import.rb:26:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/warden.rb:30:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/vm/check_box.rb:23:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/warden.rb:30:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action/builder.rb:120:in `call'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action.rb:134:in `block (2 levels) in run'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/util/busy.rb:19:in `busy'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action.rb:134:in `block in run'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/environment.rb:364:in `block in lock'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/environment.rb:354:in `open'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/environment.rb:354:in `lock'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/action.rb:133:in `run'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/vm.rb:140:in `up'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/command/up.rb:13:in `block in execute'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/command/up.rb:8:in `each'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/command/up.rb:8:in `execute'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/task.rb:22:in `run'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/invocation.rb:118:in `invoke_task'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/invocation.rb:124:in `block in invoke_all'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/invocation.rb:124:in `each'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/invocation.rb:124:in `map'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/invocation.rb:124:in `invoke_all'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/group.rb:226:in `dispatch'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/invocation.rb:109:in `invoke'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/lib/vagrant/cli.rb:45:in `block in register'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/task.rb:22:in `run'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/invocation.rb:118:in `invoke_task'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor.rb:263:in `dispatch'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/thor-0.14.6/lib/thor/base.rb:389:in `start'
    from /usr/local/Cellar/ruby/1.9.2-p290/lib/ruby/gems/1.9.1/gems/vagrant-0.8.7/bin/vagrant:21:in `<top (required)>'
    from /usr/local/Cellar/ruby/1.9.2-p290/bin/vagrant:19:in `load'
    from /usr/local/Cellar/ruby/1.9.2-p290/bin/vagrant:19:in `<main>'

I think this doesn't fail when I only run 'vagrant provision' after I created a VM without a provisioner configured in the Vagrantfile when created with 'vagrant up'.

I run ruby 1.9.2 with vagrant 0.8.7 on a Mac OS 10.7.1 in iTerm 2 - if this is relevant for the "closed stream (IOError)" in the first ruby error line. But I have also heard from a colleague who runs Ubuntu, that he has the same issue. He uses puppetfiles from his local machine and I use a remote puppet server. From that point of view I can say that I hardly believe this is a general problem, rather than a Mac OS or iTerm specific or a problem with that I use a remote puppet server.

This is my Vagrantfile btw.
Vagrant::Config.run do |config|
config.vm.define :avm01 do |config|
config.vm.box = "squeeze-pxe-vbox4.1.4-v3"
config.vm.network "33.33.33.10"
config.vm.customize do |vm|
vm.memory_size = 1024
end
end
config.vm.provision :puppet_server do |puppet|
puppet.puppet_server = "puppet.fq.dn"
puppet.puppet_node = "avm01.vagrant.internal"
puppet.options = ["--test"]
end
end

@briandailey

I run into the same error, but with me it always happens during a long running process (in my case running pip install requirements on a guest).

[default] [Wed, 19 Oct 2011 05:56:39 -0700] INFO: execute[install requirements] sh(. /home/vagrant/dev-env/bin/activate && pip install -r /vagrant/requirements.txt)
 : stdout
[default] [Wed, 19 Oct 2011 05:58:41 -0700] ERROR: execute[install requirements] (main::dev line 8) has had an error
 : stdout
[default] Forcing shutdown of VM...
[default] Destroying VM and associated drives...
/usr/lib/ruby/gems/1.8/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:33:in `select': closed stream (IOError)

I can re-run it without making any changes and it'll run just fine. Appears to be completely random. I'm wondering if it has something to do with available memory or network problems.

@jstallings

FWIW I ran into the same issue as well on long running actions. In my case it is running chef. I as well can rerun and it will continue

[default] [Wed, 19 Oct 2011 17:02:41 +0200] INFO: Storing updated cookbooks/apache2/recipes/mod_proxy.rb in the cache.
: stdout
[default] [Wed, 19 Oct 2011 17:03:01 +0200] ERROR: Running exception handlers
: stdout
[default] Forcing shutdown of VM...
[default] Destroying VM and associated drives...
/Library/Ruby/Gems/1.8/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:33:in `select': closed stream (IOError)
from /Library/Ruby/Gems/1.8/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:33:in `io_select'
from /Library/Ruby/Gems/1.8/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:32:in `synchronize'
from /Library/Ruby/Gems/1.8/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:32:in `io_select'
from /Library/Ruby/Gems/1.8/gems/net-ssh-2.1.4/lib/net/ssh/transport/packet_stream.rb:73:in `available_for_read?'
from /Library/Ruby/Gems/1.8/gems/net-ssh-2.1.4/lib/net/ssh/transport/packet_stream.rb:85:in `next_packet'
from /Library/Ruby/Gems/1.8/gems/net-ssh-2.1.4/lib/net/ssh/transport/session.rb:169:in `poll_message'
from /Library/Ruby/Gems/1.8/gems/net-ssh-2.1.4/lib/net/ssh/transport/session.rb:164:in `loop'

I also have modified my ssh parameters to be as follows with no benefit:

  config.ssh.max_tries = 100
  config.ssh.timeout = 600
@nickpeirson

I'm seeing this with Chef as well:

...
[default] [Thu, 27 Oct 2011 09:26:03 +0000] INFO: execute[upgrade-pear-with-pear] ran successfully
: stdout
[default] Forcing shutdown of VM...
[default] Destroying VM and associated drives...
[default] Destroying unused networking interface...
/usr/local/rvm/gems/ruby-1.9.2-p290/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:22:in `select': closed stream (IOError)
...

Everything seems to be going well, then it stops and tears down the VM.

@hedgehog hedgehog referenced this issue from a commit in hedgehog/vagrant
@hedgehog hedgehog ssh shared connections. closes GH issue #391, #455, etc.
        Should fix the ssh connection refused error.
         - Banner connection error handled.
         - Vagrant bails when orphaned Vagrant ssh sessions are around
         - Multiplexing SSH conecctions
         - Establish remote shell session is responsive before proceeding
         - Net::SSH and Net::Scp are removed
         - Use Aruba/ChildProcess to manage sessions (no threading)
         - tested on Ubuntu Lucid +chef-solo (0.10.4)
         - Distribution config variable + others (no parsing ssh output)
        TODO
         - Confirm with other provisioners.
         - Confirm on other distributions.

    Likely addresses issues:

    GH issue #391, GH issue #410, GH issue #424, GH issue #443, GH issue #455, GH issue #493

    Possibly addresses/affects issues:

    GH issue #516, GH issue #353

    Overview

    Essentially between 1%-2% of reloads psuedo-fail.
    I say psuedo-fail in the sense of current behavior.
    Specifically, now running `vagrant reload` after a 'banner exchange exit' will succeed.

    I've run reload 100 times under 1.9.2 and 1.8.7.  Results are below.
    I've run provision 100 times under 1.9.2 and 1.8.7, with full success.

    One thing to think about in the code review is auto-triggering a reload when
    the banner exchange error occurs.
    Otherwise I think less faultly up and reloading will have to wait bootstrapping
    via a serial console.

    Command

        rm up-reload-1.8.log; vagrant halt th_ci_runner_6; vagrant up th_ci_runner_6 2>&1|tee up-reload-1.8.log; for ((n=0;n<100;n++)); do time vagrant reload th_ci_runner_6 2>&1|tee -a up-reload-1.8.log; done

    Total 101

    success (DEBUG: Exiting) (count: 1.9.2 = 100, 1.8.7 = 99)
    banner exchange failed (count: 1.9.2 = 1, 1.8.7 = 2)
    orphan master control (count: 1.9.2 = 14, 1.8.7 = 5)

    Attempt counts:

    1 (count: 1.9.2 = 155, 1.8.7 = 161)
    2 (count: 1.9.2 = 311, 1.8.7 = 317)
    3 (count: 1.9.2 = 34,  1.8.7 = 17)
    4 (count: 1.9.2 = 168, 1.8.7 = 167)
    5 (count: 1.9.2 = 31,  1.8.7 = 32)
    6 (count: 1.9.2 = 1,   1.8.7 = 96)
    7 (count: 1.9.2 = 0,   1.8.7=)
0a0cb76
@xuru xuru referenced this issue from a commit in xuru/vagrant
@hedgehog hedgehog ssh shared connections. closes GH issue #391, #455, etc.
        Should fix the ssh connection refused error.
         - Banner connection error handled.
         - Vagrant bails when orphaned Vagrant ssh sessions are around
         - Multiplexing SSH conecctions
         - Establish remote shell session is responsive before proceeding
         - Net::SSH and Net::Scp are removed
         - Use Aruba/ChildProcess to manage sessions (no threading)
         - tested on Ubuntu Lucid +chef-solo (0.10.4)
         - Distribution config variable + others (no parsing ssh output)
        TODO
         - Confirm with other provisioners.
         - Confirm on other distributions.

    Likely addresses issues:

    GH issue #391, GH issue #410, GH issue #424, GH issue #443, GH issue #455, GH issue #493

    Possibly addresses/affects issues:

    GH issue #516, GH issue #353

    Overview

    Essentially between 1%-2% of reloads psuedo-fail.
    I say psuedo-fail in the sense of current behavior.
    Specifically, now running `vagrant reload` after a 'banner exchange exit' will succeed.

    I've run reload 100 times under 1.9.2 and 1.8.7.  Results are below.
    I've run provision 100 times under 1.9.2 and 1.8.7, with full success.

    One thing to think about in the code review is auto-triggering a reload when
    the banner exchange error occurs.
    Otherwise I think less faultly up and reloading will have to wait bootstrapping
    via a serial console.

    Command

        rm up-reload-1.8.log; vagrant halt th_ci_runner_6; vagrant up th_ci_runner_6 2>&1|tee up-reload-1.8.log; for ((n=0;n<100;n++)); do time vagrant reload th_ci_runner_6 2>&1|tee -a up-reload-1.8.log; done

    Total 101

    success (DEBUG: Exiting) (count: 1.9.2 = 100, 1.8.7 = 99)
    banner exchange failed (count: 1.9.2 = 1, 1.8.7 = 2)
    orphan master control (count: 1.9.2 = 14, 1.8.7 = 5)

    Attempt counts:

    1 (count: 1.9.2 = 155, 1.8.7 = 161)
    2 (count: 1.9.2 = 311, 1.8.7 = 317)
    3 (count: 1.9.2 = 34,  1.8.7 = 17)
    4 (count: 1.9.2 = 168, 1.8.7 = 167)
    5 (count: 1.9.2 = 31,  1.8.7 = 32)
    6 (count: 1.9.2 = 1,   1.8.7 = 96)
    7 (count: 1.9.2 = 0,   1.8.7=)
cb1f08c
@mitchellh
Owner

I've seen this as well. Not sure yet how to work around this but marking as a bug.

@hedgehog hedgehog referenced this issue from a commit in hedgehog/vagrant
@hedgehog hedgehog ssh shared connections. closes GH issue #391, #455
    Should fix the ssh connection refused error.
     - Banner connection error handled.
     - Vagrant bails when orphaned Vagrant ssh sessions are around
     - Multiplexing SSH conecctions
     - Establish remote shell session is responsive before proceeding
     - Net::SSH and Net::Scp are removed
     - Use Aruba/ChildProcess to manage sessions (no threading)
     - tested on Ubuntu Lucid +chef-solo (0.10.4)
     - Distribution config variable + others (no parsing ssh output)
    TODO
     - Confirm with other provisioners.
     - Confirm on other distributions.

Likely addresses issues:

GH issue #391, GH issue #410, GH issue #424, GH issue #443, GH issue #455, GH issue #493

Possibly addresses/affects issues:

GH issue #516, GH issue #353

Overview

Essentially between 1%-2% of reloads psuedo-fail.
I say psuedo-fail in the sense of current behavior.
Specifically, now running `vagrant reload` after a 'banner exchange exit' will succeed.

I've run reload 100 times under 1.9.2 and 1.8.7.  Results are below.
I've run provision 100 times under 1.9.2 and 1.8.7, with full success.

One thing to think about in the code review is auto-triggering a reload when
the banner exchange error occurs.
Otherwise I think less faultly up and reloading will have to wait bootstrapping
via a serial console.

Command

    rm up-reload-1.8.log; vagrant halt th_ci_runner_6; vagrant up th_ci_runner_6 2>&1|tee up-reload-1.8.log; for ((n=0;n<100;n++)); do time vagrant reload th_ci_runner_6 2>&1|tee -a up-reload-1.8.log; done

Total 101

success (DEBUG: Exiting) (count: 1.9.2 = 100, 1.8.7 = 99)
banner exchange failed (count: 1.9.2 = 1, 1.8.7 = 2)
orphan master control (count: 1.9.2 = 14, 1.8.7 = 5)

Attempt counts:

1 (count: 1.9.2 = 155, 1.8.7 = 161)
2 (count: 1.9.2 = 311, 1.8.7 = 317)
3 (count: 1.9.2 = 34,  1.8.7 = 17)
4 (count: 1.9.2 = 168, 1.8.7 = 167)
5 (count: 1.9.2 = 31,  1.8.7 = 32)
6 (count: 1.9.2 = 1,   1.8.7 = 96)
7 (count: 1.9.2 = 0,   1.8.7=)
3478eac
@mitchellh
Owner

Looks like I can do client side keep-alive on connections that take a long time: http://net-ssh.github.com/net-ssh/classes/Net/SSH/Connection/Session.html#M000091

Unfortunately I don't think this will work in this case because we're waiting on a command to finish... Hm.

@mitchellh
Owner

Also looks like there is this keep-alive setting, but I'm not sure if I can set it for net-ssh: http://www.fettesps.com/enable-ssh-keep-alive/

@dickbrouwer

Same here:

[default] Forcing shutdown of VM...
[default] Destroying VM and associated drives...
/Users/dikbrouwer/.rvm/gems/ruby-1.9.2-p290/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:22:in `select': closed stream (IOError)
from /Users/dikbrouwer/.rvm/gems/ruby-1.9.2-p290/gems/net-ssh-2.1.4/lib/net/ssh/ruby_compat.rb:22:in `io_select'
from /Users/dikbrouwer/.rvm/gems/ruby-1.9.2-p290/gems/net-ssh-2.1.4/lib/net/ssh/transport/packet_stream.rb:73:in `available_for_read?

Any suggestions for a temporary workaround? I'm unable to provision the VM at all as it happens every time for me (Ubuntu 11.10 if that matters, I thought I wasn't seeing it before).

@gregormelhorn

same here. This is a blocker...

@chalfant

Can we disable the forced shutdown and destroy during the provision step? Where would I look in the code to do this?

@mitchellh
Owner

Interesting. Can anyone else that can consistently cause this problem reproduce @chalfant's results?

@dickbrouwer
@nickpeirson

@mitchellh Was that with reference to the comment about this issue being related to ruby 1.8.7 (which now appears to be removed)?

I'm seeing this with ruby version "1.9.2p290 (2011-07-09 revision 32553) [x86_64-darwin10.8.0]" so not a Ruby 1.8.7 problem as far as I can tell.

@mitchellh
Owner

Ah, it must have been deleted. :)

Yeah I figured this would affect every version. Sigh. I'm still not sure how to fix this since it appears to be a Net::SSH bug but Net::SSH is in maintenance mode and only accepting pull requests, and I'm not sure where to begin in there. :-\ I'll continue thinking.

@gregormelhorn

yes, I was too slow in deleting. I noticed I did some changes that would cause my command generate some output from time to time. In this case, the error does not happen, though output is only shown in the end.

@mitchellh
Owner

So I think I may have a way to fix this. Can anyone post a Vagrantfile/puppet recipe that can consistently show this bug? I'm having trouble repo-ing it.

@gregormelhorn

I did not try this out, but something like

execute "sleep" do
command "sleep 3600"
end

should do it.

@syelle

@mitchellh We can reproduce often (although not consistently) but it's on a chef provision that connects to our chef server. It usually fails when trying to install mysql via apt-get on Ubuntu 10.04.

@dickbrouwer
@kumar303

This reproduces it every single time for me on Ruby 1.8.7 and vagrant 0.8.10 (I also tried with vagrant 0.9.2 and I think it happens there too).

git clone -n git://github.com/mozilla/zamboni.git
cd zamboni
git checkout 0bbef8533575875e7240c142957e8d09a797ee26
git submodule update --init --recursive
vagrant up

I am desperately trying to find a workaround for this :( As others have commented, the exception is triggered during pip install -r requirements/compiled.txt which often takes a long time.

@syelle

We've worked around this by not relying on vagrant up to perform provisioning.

After vagrant up has created the box and right as it starts to provision our box with chef-client, I use ctrl+c to bail out of vagrant up. Then I run vagrant ssh to get into the box and run chef-client manually from there. This circumvents the troublesome timeout in our case since chef is not relying on vagrant to establish connections anymore.

@kumar303

Ugh. This is pretty hard to work around. I packaged up my provisioned machine which cut down on long running commands but we need our users to periodically run database migrations via puppet. These can run long.

Any ideas on how to fix the SSH timeout?

At the very least is there a way to rescue the IOError so that the command can fail without causing the VM to shut down?

@kumar303

Here are some more clues. I think it's more than just an SSH timeout. It appears that the VM is actually losing all connectivity to the network.

To workaround the problem I installed screen and set up /home/vagrant/.profile so it starts a screen session when you log in and runs a script to download everything it needs when you SSH in. I see the same kind of error where it says

Connection to 127.0.0.1 closed by remote host.

When I ssh back in to resume the screen session, I see an exception in my Python script (that was running) showing that it lost connectivity. This has happened several times now.

If this were merely some kind of SSH timeout then in theory the screen session would have continued running in the background. Also, I went nuts and reconfigured /etc/ssh/sshd_config so that it could not possibly timeout. That did not have any affect.

I can reproduce this consistently. How can I help debug the source of the problem? I'm on IRC, freenode and irc.mozilla.org as kumar

@jdunck

Possibly related:
https://www.virtualbox.org/ticket/6559

Though I'll note I'm using VirtualBox 4.1.4 and am still having this issue.

@jdunck

I'm w/ @kumar303 in that it doesn't seem to be just an ssh issue.

I checked ulimit -a and noted that it had 1024 files-per-proc so thought that might be being hit - no, it doesn't appear so, nor OOM. Quite frustrating :-/

@mattd

Is there any update on this issue? I'm seeing the same thing running a chef_client provision. I lose connection right around the time that my cookbooks have finished downloading.

@mattd

After a bunch of research, my top candidate for the cause of this bug is this:

https://www.virtualbox.org/ticket/4870

It's an old ticket, but matches what we seem to be experiencing to a T.

@jdunck

Supposedly fixed in 3.0.8 and I'm running 4.1.4. They closed the ticket because nobody responded to the most recent request for info, but it seems unlikely it was actually fixed. Hmmph.

@dcarley

At last, I found other people with the same issue!

I too hit this with a large pip install. My suspicion is that the quantity of outbound connections chokes VB's NAT connection tracking. The only other way I've reproduced it is by really hammering DNS lookups. If the OP's provisioner is pulling in lots of packages from external sources then it could produce the same effect.

I gave up trying to register for an "Oracle account" and just put findings in a Gist. I've got some host and guest network captures kicking around too.

https://gist.github.com/1716454

@mitchellh
Owner

Ah, this is super helpful!I think in the future the best thing would be to allow non-NAT interfaces to SSH.

@jdunck

@mitchellh If I understand correctly, the NAT interface is always set up for vagrant to do the ssh into, and any calls to config.vm.network make additional interfaces. And since the NAT interface is eth0, it's being used for the provisioning.

Would it be reasonable as a short-term workaround to have the NAT interface been the last interface rather that the first one?

@dcarley

You can try working around it with a different adapter type. I've had some success with:

config.vm.customize(["modifyvm", :id, "--nictype1", "Am79C973"])
@kumar303

Is everyone who is having trouble here using ubuntu? I am.

@dickbrouwer
@kumar303

Actually, heh, a better question is: Does anyone hit the symptoms of this bug in a non-ubuntu VM? In talking with others I found someone with a Cent OS vm who has never seen this.

@LarsFronius

Yeah, the actual bug report I was coming up with was made, whilst provisioning a Debian VM.

@dcarley

CentOS guests on Ubuntu hosts, here.

@mattd

FWIW, dcarley's solution mentioned above worked for me on an Ubuntu Lucid guest box.

Why? No idea. :)

@jdunck

@mattd @dcarley Where exactly are you putting the line?

I'm assuming it must be within
Vagrant::Config.run do |config| / end

but no matter where I put it in my Vagrantfile, vagrant up hangs trying to talk to the VM:

[default] Booting VM...
[default] Waiting for VM to boot. This can take a few minutes.

@dcarley

Looks like a lot of DNS requests alone are enough to reproduce it.

I've created a Vagrant environment to reproduce it. There's also an example of how modifyvm is being used:

https://github.com/dcarley/vbox_natbug

@xuru

@dcarley Great information. Thanks for putting this together!

@acrmp acrmp referenced this issue in jedi4ever/veewee
Closed

Ubuntu package installation fails - nictype #253

@EslamElHusseiny

any updates,
i updated my vagrant version to 1.0.3 but error "/var/lib/gems/1.8/gems/net-ssh-2.2.2/lib/net/ssh/ruby_compat.rb:33:in `select': closed stream (IOError) " still appears in step of install pips

@bgreenlee

I'm seeing the same issue as @EslamElHusseiny. I get to the point where I install my pip-requirements via pip install -r and it dies. In my case: /Users/brad/.rvm/gems/ruby-1.9.3-p125/gems/net-ssh-2.2.2/lib/net/ssh/ruby_compat.rb:22:inselect': closed stream (IOError)`

I'm running vagrant 1.0.3 and VirtualBox 4.1.14

Update: I have the nictype fix (config.vm.customize(["modifyvm", :id, "--nictype1", "Am79C973"]), and if I go in through the host-only networking IP, it takes longer to fail, but still fails eventually.

Update 2: Not sure of the relevance, but it always seems to fail while installing python-memcached via pip. Seems related to pypa/pip#205

@skottler

I can reproduce this bug over and over. It also happens to me when installing python-memcached and the workaround does not help mitigate the effects of the issue.

@mikeywaites

@bgreenlee im seeing the exact same problem and always as it tries to install python-memcache. did you find a fix?

@bgreenlee

@mikeywaites My workaround was to download python-memcached manually and run pip install directly on the tar file.

@jtopper

I've seen this happening on a CentOS 6 box, running a sizeable puppet run from a shell provisioner. Prior to the stacktrace being thrown, the output from my "vagrant up" run pauses, and a shell opened using "vagrant ssh" also gets stuck, and then usually thrown out with a "connection closed by remote host".

My VM has a host-only network interface configured, and a straight ssh connection to that address continues to work without trouble throughout.

I'm happy to provide you with a copy of my setup if that would help.

@jtopper

This isn't happening repeatably enough for me to be able to have a good run at debugging, but on the occasions when it happens, I'm gathering what data I can. This morning, my "vagrant ssh" initiated sessions all got stuck whilst doing a "vagrant provision". I was able to get in via ssh to my host-only network interface and attach strace to the sshd process. I saw this when attempting to make a new "vagrant ssh" initiated connection:

[pid  5586] getsockopt(3, SOL_IP, IP_OPTIONS, "", [0]) = 0
[pid  5586] getpeername(3, {sa_family=AF_INET, sin_port=htons(54185), sin_addr=inet_addr("10.0.2.2")}, [16]) = 0
[pid  5586] getpeername(3, {sa_family=AF_INET, sin_port=htons(54185), sin_addr=inet_addr("10.0.2.2")}, [16]) = 0
[pid  5586] getsockname(3, {sa_family=AF_INET, sin_port=htons(22), sin_addr=inet_addr("10.0.2.15")}, [16]) = 0
[pid  5586] open("/etc/hosts.allow", O_RDONLY) = 4
[pid  5586] fstat(4, {st_mode=S_IFREG|0644, st_size=370, ...}) = 0
[pid  5586] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fdfe8965000
[pid  5586] read(4, "#\n# hosts.allow\tThis file contai"..., 4096) = 370
[pid  5586] read(4, "", 4096)           = 0
[pid  5586] close(4)                    = 0
[pid  5586] munmap(0x7fdfe8965000, 4096) = 0
[pid  5586] open("/etc/hosts.deny", O_RDONLY) = 4
[pid  5586] fstat(4, {st_mode=S_IFREG|0644, st_size=460, ...}) = 0
[pid  5586] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fdfe8965000
[pid  5586] read(4, "#\n# hosts.deny\tThis file contain"..., 4096) = 460
[pid  5586] read(4, "", 4096)           = 0
[pid  5586] close(4)                    = 0
[pid  5586] munmap(0x7fdfe8965000, 4096) = 0
[pid  5586] rt_sigaction(SIGALRM, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  5586] rt_sigaction(SIGALRM, {0x7fdfe8977300, [], SA_RESTORER|SA_INTERRUPT, 0x7fdfe5cea900}, NULL, 8) = 0
[pid  5586] alarm(120)                  = 0
[pid  5586] write(3, "SSH-2.0-OpenSSH_5.3\r\n", 21) = 21
[pid  5586] read(3,

The ssh connection hits sshd, and then stalls, with sshd waiting on communication from the client. This happens whether I use "vagrant ssh" or use ssh directly from the commandline, and only on the NATed ssh port.

I did have

ControlMaster auto
ControlPath /tmp/ssh_mux_%h_%p_%r

in my ssh client config, but removing this didn't make a difference.

I have my suspicions that that is a VirtualBox bug, but I'm not sure how I'd rule that out.

@dcarley

I'm certain that it is a VB bug. Assuming that all of these issues are indeed the very same thing. I could reproduce the hang of a NAT interface without any Vagrant in the picture.

@jtopper Does your Puppet run hammer the network interface a fair amount?

@jtopper

@dcarley It's relatively heavy, yeah, lots of RPM downloads and such.

@leth

My workaround for this is to double ctrl-c vagrant as soon as it get into the provisioning step of the up command, and then run the provisioning step manually, that way any failures don't trigger the VM deletion.

@mitchellh: Perhaps the problem could be neutralised slightly by reworking the exception handling on the up command. I can see why it makes sense to destroy the VM if the box import etc goes awry, however I don't think an error during the provisioning step of up should necessarily cause the destruction of the VM.

@lucaspottersky

The "`select': closed stream (IOError)" error happens to me whenever I run "vagrant provision" on a host/guest Ubuntu.

I have a very simple recipe that hangs when it tries to "rbenv_gem "rails". I'm unable to provision my vagrant machine. The workaround mentioned (modifyvm nictype1) by @dcarley didn't work for me.

To mitigate this problem, for now I'm simply logging onto the VM and executing Chef-Solo by hand. Totally defeats the purpose of Vagrant, doesn't it? :( Hope one day this gets fixed somehow...

@anentropic

I agree with @leth 's comment above "I don't think an error during the provisioning step of up should necessarily cause the destruction of the VM"

@leth

A better workaround: vagrant up --no-provision && vagrant provision.

@anentropic

@leth when I try that I get the following error:

"Shared folders that Chef requires are missing on the virtual machine.
This is usually due to configuration changing after already booting the
machine. The fix is to run a vagrant reload so that the proper shared
folders will prepared and mounted on the VM."

this comes at the provision stage

@dcarley

@anentropic What version of Vagrant? There was a change in #803 that made this possible.

@anentropic

@dcarley I'm on:

$ vagrant --version
Vagrant version 1.0.1
@anentropic

ok, my version is too old to have that fix...

@anentropic

cool, works under v1.0.3 :)

although it doesn't alleviate the problem... installing a big pip requirements can still crash the provision step as before, and it often crashes the same way on repeated tries of vagrant provision until you get a run that succeeds.

@jashmenn

@leth 's solution helped but, like @anentropic, I still have issues when I have a vagrant provision that runs more than a couple of minutes.

@pfalcon

I had the same issue, while running pretty complex multi-step provision setup. The same as noted by few folks above, suggestion in #516 (comment) worked for me. While investigating the issue, I also found http://www.virtualbox.org/manual/ch09.html#changenat . Nothing described seems like immediate solution for the problem (I would be looking for something like "NAT port mapping table capacity"), but nonetheless, tweaking network buffer sized and/or DNS modes maybe a good idea for desperate. I didn't have chance to try them, as again, changing NIC type to Am79C973 helped me.

@akoumjian akoumjian referenced this issue in saltstack/salty-vagrant
Closed

Does not run on Ubuntu 12.04(host), Ubuntu 12.04(vm) #51

@nand2

Bitten as well by this (VBox 4.1.24), with long python pip installs; the trick at #516 (comment) seems to fix things .... so far.

@rb2k

For me this happens while compiling php.
This is after the VM already has been provisioned.
The network interface swap didn't fix it.
(VBox 4.2.10)

@JamyGolden

Same problem.

Terminal output: http://pastie.org/7302608
VagrantFile: http://pastie.org/7302638

Operating System: OS X 10.8.3
Vagrant: 1.1.5
VirtualBox: 4.2.10 r84104

Edit: It seems this problem happens on vagrant reload specifically

@mitchellh
Owner

In Vagrant 1.2.0 I send a keep-alive packet every 5 seconds so this should work around this issue. YAY!

@mitchellh mitchellh closed this
@koellcode

Same problem here on my Macbook Air (WLAN), even on Vagrant 1.2.1 . I'm using OS X 10.8.3 and VirtualBox 4.2.12. After some digging, i've found out that it works over a shared Bluetooth Network Connection via my iPhone, and on my Mac Mini - which is connected directly to Ethernet. I've tried some MTU Size tweaking, but no success.

@mig5

Like @koellcode this is still a problem for me:

VirtualBox 4.2.12
Vagrant 1.2.1
Debian 6 box

It occurs just trying to run 'apt-get update' once inside the VM (I first encountered the problem when provisioning via Puppet, but found even without the Puppet provisioning, an apt-get update is all it takes to force this shutdown).

I also tried the config.vm.provision NIC modification from @dcarley but it didn't help.

Also makes no difference over wifi or wired ethernet.

@mig5

FWIW, a new router (or maybe only a reboot of the router) fixed it, which leads me to think it was some sort of network or MTU issue

@koellcode

like @mig5 i've switched my router too. now it works...

@ctheune

Ugh. Being bitten as well. Current vagrant and Virtualbox, OS X 10.8.3.

I even saw the box die randomly when logged in with SSH interactively. :(

@nkaviani nkaviani referenced this issue in Altoros/cf-vagrant-installer
Closed

vagrant up fails after trying to download warden rootfs #46

@henning

Had the problem yesterday and had to fiddle with Vagrant and Virtualbox for half of the night.
Ubuntu Precise 12.04
Vagrant was at 1.22 the whole time.
Been using the Virtualbox in Ubuntu (4.1.12), but also Oracle Virtualbox didn't work.
It finally worked when switching off VT Extensions in the VM Config. At least once, I currently do not dare to run the process one more time as I fear to be unable to work again if it turns out to happen again...
Not sure if that is really a Vagrant or a Virtualbox issue, also.

@aknrdureegaesr

I had this problem also: Host Debian Wheezy, guest homegrown CentOs 6.4 Vagrant box, both 64 Bit, Vagrant 1.2.3, Virtualbox 4.2.16.

My Vagrant run would execute, via a shell provisioner, the command yum list installed pretty much first thing. This yum list installed hammers the network some trying to find fastesmirror. This yum list installed would also crash about half the time.

Here, "crash" means "Vagrant destroys the virtual machine". Typically last words from such a run:

[default] Destroying VM and associated drives...
/opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/ruby_compat.rb:30:in `select': closed stream (IOError)
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/ruby_compat.rb:30:in `io_select'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/transport/packet_stream.rb:73:in `available_for_read?'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/transport/packet_stream.rb:85:in `next_packet'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/transport/session.rb:172:in `block in poll_message'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/transport/session.rb:167:in `loop'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/transport/session.rb:167:in `poll_message'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/connection/session.rb:454:in `dispatch_incoming_packets'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/connection/session.rb:216:in `preprocess'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/connection/session.rb:200:in `process'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/connection/session.rb:164:in `block in loop'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/connection/session.rb:164:in `loop'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/connection/session.rb:164:in `loop'
    from /opt/vagrant/embedded/gems/gems/net-ssh-2.6.8/lib/net/ssh/connection/channel.rb:269:in `wait'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/communicators/ssh/communicator.rb:318:in `shell_execute'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/communicators/ssh/communicator.rb:61:in `block in execute'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/communicators/ssh/communicator.rb:139:in `connect'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/communicators/ssh/communicator.rb:60:in `execute'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/communicators/ssh/communicator.rb:80:in `sudo'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/provisioners/shell/provisioner.rb:31:in `block (2 levels) in provision'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/provisioners/shell/provisioner.rb:14:in `tap'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/provisioners/shell/provisioner.rb:14:in `block in provision'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/provisioners/shell/provisioner.rb:78:in `with_script_file'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/provisioners/shell/provisioner.rb:12:in `provision'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/provision.rb:65:in `run_provisioner'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/provision.rb:53:in `block in call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/provision.rb:49:in `each'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/provision.rb:49:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/providers/virtualbox/action/clear_forwarded_ports.rb:13:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/providers/virtualbox/action/set_name.rb:35:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/providers/virtualbox/action/clean_machine_folder.rb:17:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/providers/virtualbox/action/check_accessible.rb:18:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/runner.rb:61:in `block in run'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/util/busy.rb:19:in `busy'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/runner.rb:61:in `run'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/call.rb:51:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/runner.rb:61:in `block in run'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/util/busy.rb:19:in `busy'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/runner.rb:61:in `run'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/call.rb:51:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/runner.rb:61:in `block in run'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/util/busy.rb:19:in `busy'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/runner.rb:61:in `run'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/call.rb:51:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/config_validate.rb:25:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/providers/virtualbox/action/check_virtualbox.rb:17:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/call.rb:57:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builtin/config_validate.rb:25:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/plugins/providers/virtualbox/action/check_virtualbox.rb:17:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/warden.rb:34:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/builder.rb:116:in `call'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/runner.rb:61:in `block in run'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/util/busy.rb:19:in `busy'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/action/runner.rb:61:in `run'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/machine.rb:147:in `action'
    from /opt/vagrant/embedded/gems/gems/vagrant-1.2.3/lib/vagrant/batch_action.rb:63:in `block (2 levels) in run'

I would appreciate if I could make Vagrant to not destroy the machine, so I can sift through the remaining rubble.

This is a Heisenbug: When I set VAGRANT_LOG=debug, the problem disappears.

I have also been able to once or twice reproduce the crash by removing that shell provisioner from my Vagrantfile and instead using my hosts's native ssh command to connect to the guest, sudo -s there and then execute yum list installed manually. In that case, "crash" means the machine is stopped, according to the Virtualbox GUI.

For me, the problem frequency seemed to decrease when I enlarged VirtualBox's socket buffers from their standard value of 64 kB and also the memory that guest gets:

config.vm.provider "virtualbox" do |vbox|
  vbox.customize ["modifyvm", :id, "--memory", "2048", "--natsettings1", "0,400,400,0,0" ]
end

But, through several attempts at fiddling these values, I could not make the problem go away completely. Also, the provisioning process would frequently fail at a later stage.

How do I re-open this issue?

@koellcode

It's not fixed yet, so reopening the ticket would be great..

@diranged

Please re-open this bug. I've seen you're comments in #2010, but honestly this is still an ongoing issue. We see this about 30% of the time during our Puppet provisioning process. For what its worth, I think in our case this happens when Puppet does a quick reload of the networking stack after making some changes. I'm not sure if that helps diagnose the issue.

Since this is clearly an outstanding issue, I suggest leaving the bug open until it can be resolved. It sends an odd message closing the but without any resolution.

@troygoode

I think I have a reproducible scenario. This Vagrantfile is meant to stand up an instance of Docker and then load this Dockerfile, but it consistently (100% of the time on my machine after multiple runs) breaks with the error found in this ticket. Tested on Vagrant 1.2.7. Halp?

@mitchellh mitchellh reopened this
@mitchellh
Owner

@TroyGoode I was able to reproduce using your setup. Looking into it. THANK YOU!

@troygoode

:+1: glad my noobishness could be of some help!

@mitchellh
Owner

This is fixed in master.

@mitchellh mitchellh closed this
@troygoode

great news. thanks @mitchellh. any idea when master'll be cut into a new release?

@mitchellh
Owner

Not at the moment, but "soon"

@bascht

Just to be sure - did the fix for #516 make it into Vagrant 1.3.2/1.3.3? I couldn't find anything in the Changelog.

@aknrdureegaesr

I experience this problem with Vagrant 1.3.3, VirtualBox 4.2.18 r88780 on Debian Wheezy.

@malvim

Same problem here, same versions as @aknrdureegaesr, on OSX 10.8.4.

@make

Maybe this has something to do with net-ssh/net-ssh#102.

@aknrdureegaesr

@make: Could be. Two but-s:

But 1 The Vagrant + Virtualbox Setup that showed the problem didn't do anything multithreading, at least none I'm aware of.

But 2 My previous observation:

I have also been able to once or twice reproduce the crash by removing that shell provisioner from my Vagrantfile and instead using my hosts's native ssh command to connect to the guest, sudo -s there and then execute yum list installed manually.

I may be wrong, but my finger tentatively points to the Virtualbox side of things. Virtualbox may have a race condition in its network code.

Personally, I have since moved over to KVM, controlled by home-grown-rake. (If Vagrant works for you, that's not a path you want to follow. But, on the other hand, it is navigable.)

@arnaudlawson

We have been experiencing a very similar issue. We upgraded from vagrant 1.1.0 to 1.2.2 (running VitualBox 4.2.16r86992) and ever since the upgrade whenever we try to start up a VM that has a second (eth1) host-only NIC adapter vagrant throws an error while provisioning this second NIC:
"[default] Configuring and enabling network interfaces...
/opt/vagrant/embedded/lib/ruby/1.9.1/tempfile.rb:346:in `rmdir': No such file or directory - /tmp/vagrant20131017-30789-11m1r7h.lock (Errno::ENOENT)"
This never happened before the upgrade (so we even degraded back to vagrant 1.1.0 but then experienced the same issue so now we are back to using vagrant 1.2.2 with the same issue). Any help on how to resolve this issue [[Vagrant fails during the provisioning of the second host-only Virtual NIC]] would help. Thanks.

Here is the stack trace.

root@centos5.os.com:/opt/sociocast/operations/vagrant/vms/Centos64BoxyHostonly_test] vagrant reload
[default] Attempting graceful shutdown of VM...
[default] Setting the name of the VM...
[default] Clearing any previously set forwarded ports...
[default] Creating shared folders metadata...
[default] Clearing any previously set network interfaces...
[default] Preparing network interfaces based on configuration...
[default] Forwarding ports...
[default] -- 22 => 2222 (adapter 1)
[default] Booting VM...
[default] Waiting for VM to boot. This can take a few minutes.
[default] VM booted and ready for use!
[default] Configuring and enabling network interfaces...
/opt/vagrant/embedded/lib/ruby/1.9.1/tempfile.rb:346:in rmdir': No such file or directory - /tmp/vagrant20131017-30789-11m1r7h.lock (Errno::ENOENT)
from /opt/vagrant/embedded/lib/ruby/1.9.1/tempfile.rb:346:in
rmdir'
from /opt/vagrant/embedded/lib/ruby/1.9.1/tempfile.rb:338:in ensure in locking'
from /opt/vagrant/embedded/lib/ruby/1.9.1/tempfile.rb:338:in
locking'
from /opt/vagrant/embedded/lib/ruby/1.9.1/tempfile.rb:144:in block in initialize'
from /opt/vagrant/embedded/lib/ruby/1.9.1/tmpdir.rb:133:in
create'
from /opt/vagrant/embedded/lib/ruby/1.9.1/tempfile.rb:134:in initialize'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/redhat/cap/configure_networks.rb:36:in
new'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/redhat/cap/configure_networks.rb:36:in block in configure_networks'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/redhat/cap/configure_networks.rb:21:in
each'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/guests/redhat/cap/configure_networks.rb:21:in configure_networks'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/guest.rb:130:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/guest.rb:130:in capability'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/network.rb:115:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/clear_network_interfaces.rb:26:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/share_folders.rb:25:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/clear_shared_folders.rb:12:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/prepare_nfs_settings.rb:11:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/nfs.rb:28:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/prune_nfs_exports.rb:15:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/handle_forwarded_port_collisions.rb:118:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/prepare_forwarded_port_collision_params.rb:30:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/env_set.rb:19:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/provision.rb:45:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/clear_forwarded_ports.rb:13:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/set_name.rb:35:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/clean_machine_folder.rb:17:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/check_accessible.rb:18:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in
block in run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/util/busy.rb:19:in busy'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in
run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/call.rb:51:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in block in run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/util/busy.rb:19:in
busy'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/call.rb:51:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in
block in run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/util/busy.rb:19:in busy'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in
run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/call.rb:51:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/config_validate.rb:25:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/check_virtualbox.rb:17:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/call.rb:57:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/check_virtualbox.rb:17:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/config_validate.rb:25:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in block in run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/util/busy.rb:19:in
busy'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builtin/call.rb:51:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/providers/virtualbox/action/check_virtualbox.rb:17:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/warden.rb:34:in call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/builder.rb:116:in
call'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in block in run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/util/busy.rb:19:in
busy'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/action/runner.rb:61:in run'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/machine.rb:147:in
action'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/reload/command.rb:29:in block in execute'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/plugin/v2/command.rb:182:in
block in with_target_vms'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/plugin/v2/command.rb:180:in each'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/plugin/v2/command.rb:180:in
with_target_vms'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/plugins/commands/reload/command.rb:28:in execute'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/cli.rb:46:in
execute'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/lib/vagrant/environment.rb:467:in cli'
from /opt/vagrant/embedded/gems/gems/vagrant-1.2.2/bin/vagrant:84:in
'
from /opt/vagrant/bin/../embedded/gems/bin/vagrant:23:in load'
from /opt/vagrant/bin/../embedded/gems/bin/vagrant:23:in

'

@mitchellh
Owner

@arnaudlawson Does this happen every time? This is coming out the Ruby standard library...

@arnaudlawson

Yes it is happening every time. It doesn't seem to be a ruby issue. This problem only started after we upgraded from Vagrant 1.1.0 to 1.2.2. We even tried to downgrade back to Vagrant 1.1.0 but then encountered the same issue still. So now we are back on Vagrant 1.2.2 and that is running on CentOS release 5.7 (Final) with VirtualBox 4.2.16r86992. Every time we do 'vagrant up' the problem comes up - and we have several boxes that use the second virtual NIC (eth1) to talk to each other. So any help would be appreciated. Thanks.

@arnaudlawson

@mitchellh

Any thoughts?

@arnaudlawson

@mitchellh

I found the problem, this was because the /tmp directory was full on this server. "A directory can have at most 31998 subdirectories" while using ext3 filesystems. http://en.wikipedia.org/wiki/Ext3#cite_note-0

Vagrant uses the /tmp directory to build boxes so as i cleaned up /tmp i was able to rebuild the box.

@garystafford garystafford referenced this issue in chef/vagrant-omnibus
Closed

Working Mac setup fails on Windows host #49

@joyxu joyxu referenced this issue from a commit in joyxu/lava-deployment-tool-for-linaro-ubuntu
Paul Sokolovsky Use Am79C973 as VirtualBox NIC, which privides more reliable transfers. ee20aa3
@Ikornaselur Ikornaselur referenced this issue from a commit
Commit has since been removed from the repository and is no longer available.
@Ikornaselur Ikornaselur referenced this issue from a commit
Commit has since been removed from the repository and is no longer available.
@morungos morungos referenced this issue from a commit in oicr-ibc/heliotrope
@morungos morungos Fix provisioning with Ubuntu host + Ubuntu guest
See mitchellh/vagrant#516. It’s not actually a Vagrant problem, but a
seemingly long-unfixed Virtualbox one, still in new releases.
df6a8ed
@nikosdion nikosdion referenced this issue in akeeba/vagrant
Closed

Vagrant gets destroyed on up #1

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.