Bug 1199493 - "vagrant up" backtraces with "undefined method `ip_command' for nil:NilClass"
Summary: "vagrant up" backtraces with "undefined method `ip_command' for nil:NilClass"
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: vagrant
Version: 22
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Josef Stribny
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-03-06 13:41 UTC by Bohuslav "Slavek" Kabrda
Modified: 2016-01-04 05:54 UTC (History)
7 users (show)

Fixed In Version: vagrant-libvirt-0.0.25-1.fc22
Clone Of:
Environment:
Last Closed: 2015-04-21 18:27:45 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Bohuslav "Slavek" Kabrda 2015-03-06 13:41:05 UTC
Description of problem:
Vagrant backtraces on "vagrant up" (see Actual results)


Version-Release number of selected component (if applicable):
vagrant-1.7.2-3.fc22.noarch
vagrant-libvirt-0.0.24-3.fc21.noarch
rubygem-fog and rubygem-fog-core in versions from 1.22 to 1.27


How reproducible:
Always


Steps to Reproduce:
1. vagrant init
2. change "config.vm.box" to a libvirt box, e.g. "gildub/fedora20"
3. vagrant up


Actual results:
/usr/share/gems/gems/fog-core-1.23.0/lib/fog/core/collection.rb:148: warning: circular argument reference - filters
/usr/share/gems/gems/fog-1.23.0/lib/fog/rackspace/mock_data.rb:42: warning: duplicated key at line 80 ignored: "name"
/usr/share/gems/gems/fog-1.23.0/lib/fog/libvirt/models/compute/server.rb:215: warning: circular argument reference - service
Bringing machine 'default' up with 'libvirt' provider...
==> default: Creating image (snapshot of base box volume).
==> default: Creating domain with the following settings...
==> default:  -- Name:              foo_default
==> default:  -- Domain type:       kvm
==> default:  -- Cpus:              1
==> default:  -- Memory:            512M
==> default:  -- Base box:          gildub/fedora20
==> default:  -- Storage pool:      default
==> default:  -- Image:             /var/lib/libvirt/images/foo_default.img
==> default:  -- Volume Cache:      default
==> default:  -- Kernel:            
==> default:  -- Initrd:            
==> default:  -- Graphics Type:     vnc
==> default:  -- Graphics Port:     5900
==> default:  -- Graphics IP:       127.0.0.1
==> default:  -- Graphics Password: Not defined
==> default:  -- Video Type:        cirrus
==> default:  -- Video VRAM:        9216
==> default:  -- Command line : 
==> default: Starting domain.
==> default: Waiting for domain to get an IP address...
==> default: Removing domain...
/usr/share/gems/gems/fog-1.23.0/lib/fog/libvirt/models/compute/server.rb:221:in `addresses': undefined method `ip_command' for nil:NilClass (NoMethodError)
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/wait_till_up.rb:39:in `block (3 levels) in call'
	from /usr/share/gems/gems/fog-core-1.23.0/lib/fog/core/model.rb:68:in `instance_eval'
	from /usr/share/gems/gems/fog-core-1.23.0/lib/fog/core/model.rb:68:in `block in wait_for'
	from /usr/share/gems/gems/fog-core-1.23.0/lib/fog/core/wait_for.rb:6:in `wait_for'
	from /usr/share/gems/gems/fog-core-1.23.0/lib/fog/core/model.rb:65:in `wait_for'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/wait_till_up.rb:38:in `block (2 levels) in call'
	from /usr/share/vagrant/lib/vagrant/util/retryable.rb:17:in `retryable'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/wait_till_up.rb:33:in `block in call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/util/timer.rb:9:in `time'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/wait_till_up.rb:31:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/start_domain.rb:26:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/builtin/synced_folders.rb:84:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/builtin/synced_folder_cleanup.rb:28:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/plugins/synced_folders/nfs/action_cleanup.rb:25:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/prepare_nfs_valid_ids.rb:12:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/create_network_interfaces.rb:102:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/create_networks.rb:76:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/builtin/provision.rb:80:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/create_domain.rb:137:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/create_domain_volume.rb:51:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/handle_box_image.rb:38:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/builtin/handle_box.rb:56:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/handle_storage_pool.rb:21:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/set_name_of_domain.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/builder.rb:116:in `call'
	from /usr/share/vagrant/lib/vagrant/action/runner.rb:66:in `block in run'
	from /usr/share/vagrant/lib/vagrant/util/busy.rb:19:in `busy'
	from /usr/share/vagrant/lib/vagrant/action/runner.rb:66:in `run'
	from /usr/share/vagrant/lib/vagrant/action/builtin/call.rb:53:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/gems/gems/vagrant-libvirt-0.0.24/lib/vagrant-libvirt/action/connect_libvirt.rb:18:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/builtin/config_validate.rb:25:in `call'
	from /usr/share/vagrant/lib/vagrant/action/warden.rb:34:in `call'
	from /usr/share/vagrant/lib/vagrant/action/builder.rb:116:in `call'
	from /usr/share/vagrant/lib/vagrant/action/runner.rb:66:in `block in run'
	from /usr/share/vagrant/lib/vagrant/util/busy.rb:19:in `busy'
	from /usr/share/vagrant/lib/vagrant/action/runner.rb:66:in `run'
	from /usr/share/vagrant/lib/vagrant/machine.rb:214:in `action_raw'
	from /usr/share/vagrant/lib/vagrant/machine.rb:191:in `block in action'
	from /usr/share/vagrant/lib/vagrant/environment.rb:516:in `lock'
	from /usr/share/vagrant/lib/vagrant/machine.rb:178:in `call'
	from /usr/share/vagrant/lib/vagrant/machine.rb:178:in `action'
	from /usr/share/vagrant/lib/vagrant/batch_action.rb:82:in `block (2 levels) in run'



Expected results:
Virtual machine is run without a backtrace.


Additional info:
I experimented with various versions of rubygem-fog and rubygem-fog-core from 1.22 to 1.27. The backtrace is the same for all of them. Currently, all my gems are:

$ rpm -qa | grep rubygem- | sort
rubygem-bigdecimal-1.2.6-9.fc22.x86_64
rubygem-builder-3.2.2-2.fc21.noarch
rubygem-bundler-1.7.8-2.fc22.noarch
rubygem-celluloid-0.15.2-2.fc22.noarch
rubygem-childprocess-0.5.3-1.fc22.noarch
rubygem-erubis-2.7.0-8.fc22.noarch
rubygem-excon-0.39.6-1.fc22.noarch
rubygem-ffi-1.9.3-5.fc22.x86_64
rubygem-fog-1.22.1-1.fc21.noarch
rubygem-fog-brightbox-0.0.2-1.fc21.noarch
rubygem-fog-core-1.22.0-2.fc21.noarch
rubygem-fog-json-1.0.0-1.fc21.noarch
rubygem-fog-softlayer-0.3.18-1.fc22.noarch
rubygem-formatador-0.2.4-6.fc21.noarch
rubygem-hashicorp-checkpoint-0.1.4-1.fc22.noarch
rubygem-i18n-0.7.0-1.fc22.noarch
rubygem-io-console-0.4.3-9.fc22.x86_64
rubygem-ipaddress-0.8.0-8.fc21.noarch
rubygem-json-1.8.2-100.fc22.x86_64
rubygem-listen-2.7.11-1.fc22.noarch
rubygem-log4r-1.1.10-2.fc22.noarch
rubygem-mime-types-1.25.1-1.fc21.noarch
rubygem-multi_json-1.8.4-2.fc21.noarch
rubygem-net-http-persistent-2.9.4-3.fc21.noarch
rubygem-netrc-0.7.7-6.fc21.noarch
rubygem-net-scp-1.2.1-1.fc21.noarch
rubygem-net-sftp-2.1.2-1.fc22.noarch
rubygem-net-ssh-2.9.1-1.fc21.noarch
rubygem-nokogiri-1.6.6.2-1.fc22.x86_64
rubygem-psych-2.0.8-9.fc22.x86_64
rubygem-rb-inotify-0.9.5-1.fc22.noarch
rubygem-rdoc-4.2.0-9.fc22.noarch
rubygem-rest-client-1.6.7-4.fc21.noarch
rubygem-ruby-libvirt-0.4.0-9.fc22.x86_64
rubygem-thor-0.19.1-1.fc22.noarch
rubygem-timers-1.1.0-3.fc20.noarch

Comment 1 Bohuslav "Slavek" Kabrda 2015-03-06 14:12:43 UTC
So it seems that downgrading Ruby to ruby-2.1.5-26.fc22.x86_64 fixes the backtrace, but now "vagrant up" is hanging on

==> default: Waiting for domain to get an IP address...

If run with "--debug", vagrant prints these lines indefinitely:

 INFO retryable: Retryable exception raised: #<Fog::Errors::TimeoutError: The specified wait_for timeout (2 seconds) was exceeded>

Comment 2 Josef Stribny 2015-03-09 07:37:40 UTC
The first issue (why downgrading worked) is a Ruby 2.2 compatibility issue with fog and can be easily fixed.

The second is trickier. Apparently vagrant-libvirt gets the IP addresses from the *.leases files of libvirt's dnsmasq based on the VM mac address:

$ cat /var/lib/libvirt/dnsmasq/vagrant-libvirt.leases
1425888338 52:54:00:e2:4f:97 192.168.121.162 * *
1425888010 52:54:00:56:4e:dc 192.168.121.231 * *
1425886758 52:54:00:a0:b2:17 192.168.121.166 * *
1425887877 52:54:00:fe:f8:8d 192.168.121.43 * *

and in your case the files are blank and never populated by correct IP addresses. I will try to look more into in.

Comment 3 Fedora Update System 2015-03-10 10:04:54 UTC
rubygem-fog-1.23.0-2.fc22 has been submitted as an update for Fedora 22.
https://admin.fedoraproject.org/updates/rubygem-fog-1.23.0-2.fc22

Comment 4 Peter Krempa 2015-03-10 16:33:54 UTC
Libvirt changed the place where the lease file data is stored from dnsmasq lease files to a database that is stored via a helper program in a different file.

Since both the DNSMASQ files and the new implementation is in a internal path it should not be used directly. At the time the change happened, libvirt added a new API that is used to determine the lease information directly via libvirt.

Please see:
http://libvirt.org/html/libvirt-libvirt-network.html#virNetworkGetDHCPLeases

Comment 5 Josef Stribny 2015-03-11 06:51:08 UTC
Thanks for clarification Peter! At the time of the update submission I already found out. Luckily this was already fixed upstream so the update contains latest version of vagrant-libvirt.

Comment 6 Josef Stribny 2015-03-11 08:41:51 UTC
The update for both is now at:

https://admin.fedoraproject.org/updates/rubygem-fog-1.23.0-3.fc22,vagrant-libvirt-0.0.25-1.fc22

since I also patched fog to fix runtime warning today.

Comment 7 Fedora Update System 2015-03-13 16:59:27 UTC
Package vagrant-libvirt-0.0.25-1.fc22, rubygem-fog-1.23.0-3.fc22:
* should fix your issue,
* was pushed to the Fedora 22 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing vagrant-libvirt-0.0.25-1.fc22 rubygem-fog-1.23.0-3.fc22'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2015-3626/rubygem-fog-1.23.0-3.fc22,vagrant-libvirt-0.0.25-1.fc22
then log in and leave karma (feedback).

Comment 8 Fedora Update System 2015-04-21 18:27:45 UTC
vagrant-libvirt-0.0.25-1.fc22, rubygem-fog-1.23.0-3.fc22 has been pushed to the Fedora 22 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.