Tempest test neutron_tempest_plugin.scenario.test_trunk.TrunkTest.test_trunk_subport_lifecycle randomly fails on master and stable branches. 2019-09-26 08:22:58.803569 | primary | {2} neutron_tempest_plugin.scenario.test_trunk.TrunkTest.test_trunk_subport_lifecycle [145.434088s] ... FAILED 2019-09-26 08:22:58.804121 | primary | 2019-09-26 08:22:58.804180 | primary | Captured traceback: 2019-09-26 08:22:58.804250 | primary | ~~~~~~~~~~~~~~~~~~~ 2019-09-26 08:22:58.804331 | primary | b'Traceback (most recent call last):' 2019-09-26 08:22:58.804475 | primary | b' File "/opt/stack/new/neutron-tempest-plugin/neutron_tempest_plugin/common/utils.py", line 78, in wait_until_true' 2019-09-26 08:22:58.804615 | primary | b' eventlet.sleep(sleep)' 2019-09-26 08:22:58.804760 | primary | b' File "/usr/local/lib/python3.5/dist-packages/eventlet/greenthread.py", line 34, in sleep' 2019-09-26 08:22:58.804834 | primary | b' hub.switch()' 2019-09-26 08:22:58.804967 | primary | b' File "/usr/local/lib/python3.5/dist-packages/eventlet/hubs/hub.py", line 294, in switch' 2019-09-26 08:22:58.805029 | primary | b' return self.greenlet.switch()' 2019-09-26 08:22:58.805085 | primary | b'eventlet.timeout.Timeout: 60 seconds' 2019-09-26 08:22:58.805108 | primary | b'' 2019-09-26 08:22:58.805194 | primary | b'During handling of the above exception, another exception occurred:' 2019-09-26 08:22:58.805217 | primary | b'' 2019-09-26 08:22:58.805271 | primary | b'Traceback (most recent call last):' 2019-09-26 08:22:58.805420 | primary | b' File "/opt/stack/new/neutron-tempest-plugin/neutron_tempest_plugin/scenario/test_trunk.py", line 236, in test_trunk_subport_lifecycle' 2019-09-26 08:22:58.805504 | primary | b' self._wait_for_trunk(vm.trunk)' 2019-09-26 08:22:58.805662 | primary | b' File "/opt/stack/new/neutron-tempest-plugin/neutron_tempest_plugin/scenario/test_trunk.py", line 148, in _wait_for_trunk' 2019-09-26 08:22:58.805762 | primary | b' "status {!r}.".format(trunk[\'id\'], status)))' 2019-09-26 08:22:58.805899 | primary | b' File "/opt/stack/new/neutron-tempest-plugin/neutron_tempest_plugin/common/utils.py", line 82, in wait_until_true' 2019-09-26 08:22:58.805940 | primary | b' raise exception' 2019-09-26 08:22:58.806074 | primary | b"RuntimeError: Timed out waiting for trunk 'a2867f25-6ce0-4596-8517-793f0e804c5c' to transition to get status 'ACTIVE'." 2019-09-26 08:22:58.806134 | primary | b'' 2019-09-26 08:22:58.806161 | primary | While checking gates logs I found this error in neutron logs: Sep 26 08:21:51.753519 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: DEBUG neutron.db.provisioning_blocks [None req-029df57c-a96e-4274-9a3f-54bb050d655d None None] Transition to ACTIVE for port object 5bf4e97f-71cb-43e4-9957-ce38a52c97c7 will not be triggered until provisioned by entity L2. {{(pid=31758) add_provisioning_component /opt/stack/new/neutron/neutron/db/provisioning_blocks.py:73}} Sep 26 08:21:52.172865 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: DEBUG neutron_lib.callbacks.manager [None req-267c86f8-eb08-4076-833f-53a16eab185c tempest-TrunkTest-1452780584 tempest-TrunkTest-1452780584] Notify callbacks [] for subports, precommit_create {{(pid=31756) _notify_loop /usr/local/lib/python3.5/dist-packages/neutron_lib/callbacks/manager.py:193}} Sep 26 08:21:52.176038 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: DEBUG neutron_lib.callbacks.manager [None req-267c86f8-eb08-4076-833f-53a16eab185c tempest-TrunkTest-1452780584 tempest-TrunkTest-1452780584] Notify callbacks ['networking_ovn.ml2.trunk_driver.OVNTrunkHandler.subport_event--9223372036854446820'] for subports, after_create {{(pid=31756) _notify_loop /usr/local/lib/python3.5/dist-packages/neutron_lib/callbacks/manager.py:193}} Sep 26 08:21:52.338192 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager [None req-267c86f8-eb08-4076-833f-53a16eab185c tempest-TrunkTest-1452780584 tempest-TrunkTest-1452780584] Error during notification for networking_ovn.ml2.trunk_driver.OVNTrunkHandler.subport_event--9223372036854446820 subports, after_create: sqlalchemy.orm.exc.StaleDataError: UPDATE statement on table 'standardattributes' expected to update 1 row(s); 0 were matched. Sep 26 08:21:52.338524 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager Traceback (most recent call last): Sep 26 08:21:52.338768 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/neutron_lib/callbacks/manager.py", line 197, in _notify_loop Sep 26 08:21:52.339033 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager callback(resource, event, trigger, **kwargs) Sep 26 08:21:52.339249 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/opt/stack/new/networking-ovn/networking_ovn/ml2/trunk_driver.py", line 145, in subport_event Sep 26 08:21:52.339552 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager payload.subports) Sep 26 08:21:52.339771 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/opt/stack/new/networking-ovn/networking_ovn/ml2/trunk_driver.py", line 128, in subports_added Sep 26 08:21:52.340031 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager self._set_sub_ports(trunk.port_id, subports) Sep 26 08:21:52.340241 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/opt/stack/new/networking-ovn/networking_ovn/ml2/trunk_driver.py", line 50, in _set_sub_ports Sep 26 08:21:52.340449 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager self._set_binding_profile(port, parent_port, ovn_txn) Sep 26 08:21:52.340712 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/opt/stack/new/networking-ovn/networking_ovn/ml2/trunk_driver.py", line 75, in _set_binding_profile Sep 26 08:21:52.340934 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager host=binding.host) Sep 26 08:21:52.341142 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/opt/stack/new/neutron/neutron/objects/base.py", line 675, in update_object Sep 26 08:21:52.341394 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager **cls.modify_fields_to_db(kwargs)) Sep 26 08:21:52.341652 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/opt/stack/new/neutron/neutron/objects/db/api.py", line 82, in update_object Sep 26 08:21:52.341915 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager db_obj.save(session=context.session) Sep 26 08:21:52.342149 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/oslo_db/sqlalchemy/models.py", line 50, in save Sep 26 08:21:52.342380 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager session.flush() Sep 26 08:21:52.342657 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/orm/session.py", line 2254, in flush Sep 26 08:21:52.342870 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager self._flush(objects) Sep 26 08:21:52.343092 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/orm/session.py", line 2380, in _flush Sep 26 08:21:52.343345 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager transaction.rollback(_capture_exception=True) Sep 26 08:21:52.343542 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__ Sep 26 08:21:52.343761 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager compat.reraise(exc_type, exc_value, exc_tb) Sep 26 08:21:52.344039 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/util/compat.py", line 249, in reraise Sep 26 08:21:52.344263 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager raise value Sep 26 08:21:52.344488 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/orm/session.py", line 2344, in _flush Sep 26 08:21:52.344800 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager flush_context.execute() Sep 26 08:21:52.345069 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute Sep 26 08:21:52.345384 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager rec.execute(self) Sep 26 08:21:52.345724 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute Sep 26 08:21:52.347471 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager uow Sep 26 08:21:52.348294 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj Sep 26 08:21:52.348651 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager mapper, table, update) Sep 26 08:21:52.348943 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager File "/usr/local/lib/python3.5/dist-packages/sqlalchemy/orm/persistence.py", line 791, in _emit_update_statements Sep 26 08:21:52.349248 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager (table.description, len(records), rows)) Sep 26 08:21:52.349537 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager sqlalchemy.orm.exc.StaleDataError: UPDATE statement on table 'standardattributes' expected to update 1 row(s); 0 were matched. Sep 26 08:21:52.349836 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: ERROR neutron_lib.callbacks.manager Sep 26 08:21:52.350105 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: INFO neutron.wsgi [None req-267c86f8-eb08-4076-833f-53a16eab185c tempest-TrunkTest-1452780584 tempest-TrunkTest-1452780584] 158.69.66.180 "PUT /v2.0/trunks/a2867f25-6ce0-4596-8517-793f0e804c5c/add_subports HTTP/1.1" status: 200 len: 1004 time: 0.9139748 Sep 26 08:21:52.350384 ubuntu-xenial-ovh-bhs1-0011869985 neutron-server[31580]: DEBUG neutron.wsgi [-] (31756) accepted ('158.69.66.180', 41394) {{(pid=31756) server /usr/local/lib/python3.5/dist-packages/eventlet/wsgi.py:883}}