libvirtError: Error while building firewall: Some rules could not be created for interface

[Matt Riedemann]

http://logs.openstack.org/20/223320/3/check/gate-tempest-dsvm-nova-v20-api/ce04943/logs/screen-n-cpu.txt.gz?level=TRACE#_2015-09-29_21_38_32_631

2015-09-29 21:38:32.631 ERROR nova.compute.manager [req-f57dc3ad-e960-4a18-8290-b01ab46b256b tempest-SecurityGroupsTestJSON-816336435 tempest-SecurityGroupsTestJSON-717971163] [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] Instance failed to spawn
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] Traceback (most recent call last):
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/opt/stack/new/nova/nova/compute/manager.py", line 2155, in _build_resources
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] yield resources
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/opt/stack/new/nova/nova/compute/manager.py", line 2009, in _build_and_run_instance
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] block_device_info=block_device_info)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 2444, in spawn
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] block_device_info=block_device_info)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 4516, in _create_domain_and_network
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] xml, pause=pause, power_on=power_on)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 4446, in _create_domain
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] guest.launch(pause=pause)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/opt/stack/new/nova/nova/virt/libvirt/guest.py", line 141, in launch
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] self._encoded_xml, errors='ignore')
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195, in __exit__
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] six.reraise(self.type_, self.value, self.tb)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/opt/stack/new/nova/nova/virt/libvirt/guest.py", line 136, in launch
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] return self._domain.createWithFlags(flags)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 183, in doit
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] result = proxy_call(self._autowrap, f, *args, **kwargs)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 141, in proxy_call
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] rv = execute(f, *args, **kwargs)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 122, in execute
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] six.reraise(c, e, tb)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 80, in tworker
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] rv = meth(*args, **kwargs)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] File "/usr/local/lib/python2.7/dist-packages/libvirt.py", line 900, in createWithFlags
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91] libvirtError: Error while building firewall: Some rules could not be created for interface vnet3: Failure to execute command '$EBT -t nat -A libvirt-J-vnet3 -p 0x0800 -j J-vnet3-ipv4' : 'Illegal target name 'J-vnet3-ipv4'.'.
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91]
2015-09-29 21:38:32.631 24733 ERROR nova.compute.manager [instance: 00a32e3b-4fb9-4c95-951e-febc02c1ba91]

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwibGlidmlydEVycm9yOiBFcnJvciB3aGlsZSBidWlsZGluZyBmaXJld2FsbDogU29tZSBydWxlcyBjb3VsZCBub3QgYmUgY3JlYXRlZCBmb3IgaW50ZXJmYWNlXCIgQU5EIG1lc3NhZ2U6XCJJbGxlZ2FsIHRhcmdldCBuYW1lXCIgQU5EIHRhZ3M6XCJzY3JlZW4tbi1jcHUudHh0XCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjYwNDgwMCIsImdyYXBobW9kZSI6ImNvdW50IiwidGltZSI6eyJ1c2VyX2ludGVydmFsIjowfSwic3RhbXAiOjE0NDM2MjM3MjY1MDV9

10 hits in 7 days, check and gate, all failures. Looks like this is starting to spike.

[Jordan Pittier (jordan-pittier)]

On juno, the message seems different.

libvirtError: Error while building firewall: Some rules could not be created for interface vnet0: Failure to execute command '$EBT -t nat -A libvirt-J-vnet0 -j J-vnet0-mac' : 'Chain 'libvirt-J-vnet0' doesn't exist.'

Maybe it's a different bug...

Seen here : http://logs.openstack.org/82/219382/10/check/gate-tempest-dsvm-full-juno/2a7e246/logs/screen-n-cpu.txt.gz#_2015-10-01_01_38_37_166

[Hans Lindgren (hanlind)]

Similar error but without the 'Illegal target name' part, instead has 'Unable to update the kernel.':

http://logs.openstack.org/41/216241/9/check/gate-tempest-dsvm-full/841feff/logs/screen-n-cpu.txt.gz?level=TRACE#_2015-10-01_07_35_52_565

[Matt Riedemann (mriedem)]

Bug 1501558 was originally reported for Juno. These might be duplicates now. It was also noted that the fix for related bug 1316621 to have a retry in the nova code was only made in Kilo, so might explain why we are possibly seeing different failures in Juno.

[Chuck Carmack (chuckcarmack75)]

@mriedem: I believe that the error in comment #2 has the same cause as I mention in comments 11 and 12 of bug 1501558. Ie. libvirt should be at version 1.2.11 or later.

I looked at the libvirt log for the comment #2 error:
http://logs.openstack.org/41/216241/9/check/gate-tempest-dsvm-full/841feff/logs/libvirt/libvirtd.txt.gz#_2015-10-01_07_35_52_429
Looks the same as the kilo error in bug 1501558 comments 11 and 12.

So I think for juno we need to backport the nova-network bug 1316621 fix (retry logic on the ebtables call) and for both juno and kilo we would need libvirt 1.2.11 to get the libvirt side of the ebtables concurrency fix.

[Matt Riedemann (mriedem)]

Similar but slightly different failure here:

http://logs.openstack.org/66/231166/1/check/gate-tempest-dsvm-full-ceph/4bf48fe/logs/screen-n-cpu.txt.gz?level=TRACE#_2015-10-05_21_15_11_343

2015-10-05 21:15:11.343 ERROR nova.compute.manager [req-27e04cc8-35e4-477f-9278-b8436a384be9 tempest-ImagesNegativeTestJSON-735291181 tempest-ImagesNegativeTestJSON-254370333] [instance: 560c829f-5cb5-4177-adb9-082aea608505] Instance failed to spawn
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] Traceback (most recent call last):
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] File "/opt/stack/new/nova/nova/compute/manager.py", line 2168, in _build_resources
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] yield resources
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] File "/opt/stack/new/nova/nova/compute/manager.py", line 2015, in _build_and_run_instance
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] block_device_info=block_device_info)
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 2444, in spawn
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] block_device_info=block_device_info)
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 4519, in _create_domain_and_network
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] xml, pause=pause, power_on=power_on)
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 4449, in _create_domain
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] guest.launch(pause=pause)
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] File "/opt/stack/new/nova/nova/virt/libvirt/guest.py", line 141, in launch
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] self._encoded_xml, errors='ignore')
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195, in __exit__
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] six.reraise(self.type_, self.value, self.tb)
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082aea608505] File "/opt/stack/new/nova/nova/virt/libvirt/guest.py", line 136, in launch
2015-10-05 21:15:11.343 7756 ERROR nova.compute.manager [instance: 560c829f-5cb5-4177-adb9-082a...

[Markus Zoeller (markus_z) (mzoeller)]

https://review.openstack.org/#/c/242064/1 got hit by that.

[Chet Burgess (cfb-n)]

Simply upgrading to libvirt 1.2.11 isn't sufficient to fix the problem. The nova fix implemented in bug 1316621 only adds retry logic. It doesn't implement support for --concurrent. Without both nova and libvirt using --concurrent we will still get a race.

If we want to support --concurrent we have to update nova to detect the version of libvirt and ebtables and assuming the right version of each is present use --concurrent. Otherwise it should fall back to simply retry.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/246580

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/246581

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/246580
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=103cb6bdc321f1f7fdc09bf8a5b178ff6ecd8f9f
Submitter: Jenkins
Branch: master

commit 103cb6bdc321f1f7fdc09bf8a5b178ff6ecd8f9f
Author: Chet Burgess <email address hidden>
Date: Tue Nov 17 11:43:09 2015 -0800

    Use --concurrent with ebtables

    Update our usage of ebtables to pass the --concurrent flag.

    With --concurrent ebtables will attempt to acquire a lock file
    before making changes. This allows multiple processes, such as
    nova an libvirt, to safely access ebtables at the same time.

    Support for using --concurrent was added in libvirt 1.2.11, since
    we don't know the version of libvirt being used in all
    deployments we still retry the ebtables call several times just
    in case libvirt isn't using --concurrent.

    DocImpact:
     * nova now requires ebtables 2.0.10 or later
     * nova now recommends libvirt 1.2.11 or later

    Change-Id: I00ff805cee9653508f013f8aa6d206362ac0f6cb
    Partial-Bug: #1501366

[Matt Riedemann (mriedem)]

https://github.com/openstack-dev/devstack/commit/7860f2ba3189b0361693c8ee9c65d8d03fb115d6 works around the failure in the gate.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/246581
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=17264ee6a66dd60f9af1aa3a737b17f290fc7e19
Submitter: Jenkins
Branch: master

commit 17264ee6a66dd60f9af1aa3a737b17f290fc7e19
Author: Chet Burgess <email address hidden>
Date: Tue Nov 17 11:55:55 2015 -0800

    ebtables/libvirt workaround

    Idealy nova is run with libvirt 1.2.11 or later to guarantee that
    libvirt is calling ebtables with --concurrent. Since we can't
    always guarantee this we have created this workaround.

    The workaround is extremely hacky and not recommend but for those
    who simply have no other way to address this bug the following
    should be done.

     * Copy /sbin/ebtables to /sbin/ebtables.real
     * Copy the ebtables.workaround script to /sbin/ebtables

    Caution: Future OS level updates and packages way overwrite the
    above changes. Its recommend users upgrade to libvirt 1.2.11.

    The work around script was copied from devstack and originally
    written by sdague.

    Change-Id: Icdffc59d68b73a6df22ce138558d6e23e1c96336
    Closes-Bug: #1501366

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/nova 13.0.0.0b3 development milestone.