Nova fails to plug port because of missing ipset when calling iptables-restore

[Ihar Hrachyshka]

This is Ocata, linuxbridge.

http://logs.openstack.org/95/466395/3/gate/gate-tempest-dsvm-neutron-linuxbridge-ubuntu-xenial/e5923b4/logs/testr_results.html.gz

  File "tempest/common/compute.py", line 188, in create_test_server
    clients.servers_client, server['id'], wait_until)
  File "tempest/common/waiters.py", line 76, in wait_for_server_status
    server_id=server_id)
tempest.exceptions.BuildErrorException: Server 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d failed to build and is in ERROR status
Details: {u'created': u'2017-05-27T03:00:23Z', u'code': 500, u'message': u'No valid host was found. There are not enough hosts available.'}

The failure in nova-cpu log: http://logs.openstack.org/95/466395/3/gate/gate-tempest-dsvm-neutron-linuxbridge-ubuntu-xenial/e5923b4/logs/screen-n-cpu.txt.gz#_2017-05-27_03_00_21_716

2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [req-06c29149-80d9-4923-b9c4-54591a3f5e7e tempest-ServerActionsTestJSON-1792219232 tempest-ServerActionsTestJSON-1792219232] [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] Instance failed to spawn
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] Traceback (most recent call last):
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/opt/stack/new/nova/nova/compute/manager.py", line 2124, in _build_resources
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] yield resources
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/opt/stack/new/nova/nova/compute/manager.py", line 1930, in _build_and_run_instance
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] block_device_info=block_device_info)
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 2698, in spawn
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] destroy_disks_on_failure=True)
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 5114, in _create_domain_and_network
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] destroy_disks_on_failure)
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] self.force_reraise()
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] six.reraise(self.type_, self.value, self.tb)
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 5077, in _create_domain_and_network
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] self.plug_vifs(instance, network_info)
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 749, in plug_vifs
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] self.vif_driver.plug(instance, vif)
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/opt/stack/new/nova/nova/virt/libvirt/vif.py", line 786, in plug
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] self._plug_os_vif(instance, vif_obj)
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] File "/opt/stack/new/nova/nova/virt/libvirt/vif.py", line 766, in _plug_os_vif
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] raise exception.InternalError(msg)
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] InternalError: Failure running os_vif plugin plug method: Failed to plug VIF VIFBridge(active=False,address=fa:16:3e:16:2c:4d,bridge_name='brq9c933655-e1',has_traffic_filtering=True,id=416d65ee-709e-4b50-a0f1-23d988773b9f,network=Network(9c933655-e176-41b2-9b3a-8e46b13450ca),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tap416d65ee-70'). Got error: Unexpected error while running command.
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] Command: iptables-restore -c
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] Exit code: 2
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] Stdout: u''
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d] Stderr: u"iptables-restore v1.6.0: Set NIPv47e2555da-67d1-4e12-9317- doesn't exist.\n\nError occurred at line: 202\nTry `iptables-restore -h' or 'iptables-restore --help' for more information.\n"
2017-05-27 03:00:21.716 1385 ERROR nova.compute.manager [instance: 2a04ac11-2ec6-4a0d-a8f5-c89d129e881d]

I see neutron l2 agent logging destroying/creating the ipset in span of the job run, including around the time Nova failed to plug:

2017-05-27 03:00:18.250 30306 DEBUG neutron.agent.linux.utils [req-1a4f80b9-372f-4eb4-be1c-f88cadc300ef - -] Running command (rootwrap daemon): ['ipset', 'destroy', 'NIPv47e2555da-67d1-4e12-9317-'] execute_rootwrap_daemon /opt/stack/new/neutron/neutron/agent/linux/utils.py:113

I suspect there is some race between linuxbridge agent and nova compute.

[Ihar Hrachyshka (ihar-hrachyshka)]

In Pike, we now use 'tap' vif type that should avoid any iptables commands on nova-compute side. But the fix is not backportable. Kevin is going to have a look at an alternative means to fix it for Ocata.

[Ihar Hrachyshka (ihar-hrachyshka)]

OK it's fixed in Pike with https://review.openstack.org/#/c/438272/; we probably want to backport.

[Ihar Hrachyshka (ihar-hrachyshka)]

Backports here: https://review.openstack.org/#/q/I19d62a8ac730aba2586b9f8eb08e153746ec2bcb,n,z

[Matt Riedemann (mriedem)]

Fixed in 1.5.0 in Pike: https://review.openstack.org/#/c/438272/

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/469616
Committed: https://git.openstack.org/cgit/openstack/os-vif/commit/?id=a267c1d2a9be36d00290b319357e72c9720f823a
Submitter: Jenkins
Branch: stable/ocata

commit a267c1d2a9be36d00290b319357e72c9720f823a
Author: Kevin Benton <email address hidden>
Date: Sun Feb 26 07:56:45 2017 -0800

    Don't install iptables rules if neutron is filtering

    Don't setup iptables rules in the Linux Bridge driver
    if Neutron is providing security groups filtering.
    When neutron is providing filtering, it handles everything
    ranging from security-group enforcement to anti-spoofing
    rules so Nova/os-vif shouldn't need to do anything on plug.

    Closes-Bug: #1694769

    Change-Id: I19d62a8ac730aba2586b9f8eb08e153746ec2bcb
    (cherry picked from commit 10e6b6bd1b2b71bf18341719428d68a3f30cb2e9)

[OpenStack Infra (hudson-openstack)]

Change abandoned by Tony Breeds (<email address hidden>) on branch: stable/newton
Review: https://review.openstack.org/469617
Reason: This branch (stable/newton) is at End Of Life

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/os-vif ocata-eol release.