native ovsdb seems to return before finishing adding/removing port

[Kevin Benton]

When using AddPortCommand and DelPortCommand, there seems to be a delay in when the DB returns and when the actual interface is visible for use in the system.

In this failure, we can see an AddPortCommand completes and then an ip link call is made on the tap device which fails because it does not exist yet:

2016-07-20 12:18:18.555 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Running txn command(idx=0): AddPortCommand(bridge=test-brca25db6d, port=qr-10df58c6-8a, may_exist=False) do_commit neutron/agent/ovsdb/impl_idl.py:83
2016-07-20 12:18:18.556 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Running txn command(idx=1): DbSetCommand(table=Interface, record=qr-10df58c6-8a, col_values=(('type', 'internal'), ('external_ids', {'iface-status': 'active', 'iface-id': '10df58c6-8ad8-4f89-b3d1-36cf26ee5792', 'attached-mac': 'ca:fe:de:ad:be:ef'}))) do_commit neutron/agent/ovsdb/impl_idl.py:83
2016-07-20 12:18:18.570 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Running txn command(idx=0): DbGetCommand(table=Interface, column=ofport, record=qr-10df58c6-8a) do_commit neutron/agent/ovsdb/impl_idl.py:83
2016-07-20 12:18:18.570 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Transaction caused no change do_commit neutron/agent/ovsdb/impl_idl.py:111
2016-07-20 12:18:18.591 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Running txn command(idx=0): DbGetCommand(table=Interface, column=ofport, record=qr-10df58c6-8a) do_commit neutron/agent/ovsdb/impl_idl.py:83
2016-07-20 12:18:18.592 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Transaction caused no change do_commit neutron/agent/ovsdb/impl_idl.py:111
2016-07-20 12:18:18.634 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Running txn command(idx=0): DbGetCommand(table=Interface, column=ofport, record=qr-10df58c6-8a) do_commit neutron/agent/ovsdb/impl_idl.py:83
2016-07-20 12:18:18.634 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Transaction caused no change do_commit neutron/agent/ovsdb/impl_idl.py:111
2016-07-20 12:18:18.715 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Running txn command(idx=0): DbGetCommand(table=Interface, column=ofport, record=qr-10df58c6-8a) do_commit neutron/agent/ovsdb/impl_idl.py:83
2016-07-20 12:18:18.716 28212 DEBUG neutron.agent.ovsdb.impl_idl [-] Transaction caused no change do_commit neutron/agent/ovsdb/impl_idl.py:111
2016-07-20 12:18:18.716 28212 DEBUG neutron.agent.linux.utils [req-34784ee2-5510-47ce-af43-fe7691c9dcda - - - - -] Running command (rootwrap daemon): ['ip', 'link', 'set', 'qr-10df58c6-8a', 'address', 'ca:fe:de:ad:be:ef'] execute_rootwrap_daemon neutron/agent/linux/utils.py:99
2016-07-20 12:18:18.724 28212 ERROR neutron.agent.linux.utils [req-34784ee2-5510-47ce-af43-fe7691c9dcda - - - - -] Exit code: 1; Stdin: ; Stdout: ; Stderr: Cannot find device "qr-10df58c6-8a"

On examining the syslog, the interface shows up about 500ms later:

Jul 20 12:18:19 ubuntu-trusty-rax-ord-2672516 kernel: [ 978.400048] device qr-10df58c6-8a entered promiscuous mode

A similar effect is visible in the dhcp stale cleanup test where DelPortCommand is issued but then the port remains visible afterwards to a find via /sys/ : http://logs.openstack.org/31/344731/2/check/gate-neutron-dsvm-functional/98c6b55/logs/dsvm-functional-logs/neutron.tests.functional.agent.linux.test_dhcp.TestDhcp.test_cleanup_stale_devices.txt.gz

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/344859
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=11dc21d3a6d765f7bcc95548b55ff13c4397c2e7
Submitter: Jenkins
Branch: master

commit 11dc21d3a6d765f7bcc95548b55ff13c4397c2e7
Author: Terry Wilson <email address hidden>
Date: Fri Apr 22 08:55:11 2016 -0500

    Wait for vswitchd to add interfaces in native ovsdb

    ovs-vsctl, unless --no-wait is passed, will wait until ovs-vswitchd
    has reacted to a successful transaction. This patch implements
    the same logic, waiting for next_cfg to be incremented and checking
    that any added interfaces have actually been assigned ofports.

    Closes-Bug: #1604816
    Closes-Bug: #1604370
    Related-Bug: #1604115
    Change-Id: I638b82c13394f150c0bd23301285bd3375e66139

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/mitaka
Review: https://review.openstack.org/349416

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/349416
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=a98b6ebe48f4ecda689646d05050e156bc28be4d
Submitter: Jenkins
Branch: stable/mitaka

commit a98b6ebe48f4ecda689646d05050e156bc28be4d
Author: Terry Wilson <email address hidden>
Date: Fri Apr 22 08:55:11 2016 -0500

    Wait for vswitchd to add interfaces in native ovsdb

    ovs-vsctl, unless --no-wait is passed, will wait until ovs-vswitchd
    has reacted to a successful transaction. This patch implements
    the same logic, waiting for next_cfg to be incremented and checking
    that any added interfaces have actually been assigned ofports.

    Closes-Bug: #1604816
    Closes-Bug: #1604370
    Related-Bug: #1604115
    Change-Id: I638b82c13394f150c0bd23301285bd3375e66139
    (cherry picked from commit 11dc21d3a6d765f7bcc95548b55ff13c4397c2e7)

[OpenStack Infra (hudson-openstack)]

Change abandoned by Kevin Benton (<email address hidden>) on branch: master
Review: https://review.openstack.org/344850
Reason: Terry's patch should address the issue.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 9.0.0.0b3 development milestone.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 8.3.0 release.