[FT] Failure of "test_floatingip_mac_bindings"

New occurrence:

Log: https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_f76/825521/3/gate/neutron-functional-with-uwsgi/f76cef6/testr_results.html

Snippet: https://paste.opendev.org/show/812328/

I today compared logs from the failed (https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_f76/825521/3/gate/neutron-functional-with-uwsgi/f76cef6/controller/logs/dsvm-functional-logs/neutron.tests.functional.plugins.ml2.drivers.ovn.mech_driver.ovsdb.test_ovsdb_monitor.TestNBDbMonitorOverTcp.test_floatingip_mac_bindings/) and good (https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_f76/825521/3/gate/neutron-functional-with-uwsgi/f76cef6/controller/logs/dsvm-functional-logs/neutron.tests.functional.plugins.ml2.drivers.ovn.mech_driver.ovsdb.test_ovsdb_monitor.TestNBDbMonitor.test_floatingip_mac_bindings/) runs. Here's what I found:

- In the SB logs, there is difference like:

* in good run we have:
2022-01-23T19:28:26.309Z|00140|jsonrpc|DBG|unix#3: send notification, method="update2", params=["a220fbde-7c82-11ec-9a03-4fce359daaf8",{"Datapath_Binding":{"2c98db7e-84ad-4782-9d87-24eafae1700e":{"insert":{"tunnel_key":1,"external_ids":["map",[["logical-switch","5b801987-900b-4b79-aa3b-05c5fdc422eb"],["name","neutron-2d726047-4990-446b-9f1b-9dc6403adb3e"],["name2","network1"]]]}}}}]
2022-01-23T19:28:26.330Z|00141|poll_loop|DBG|wakeup due to [POLLIN] on fd 17 (/tmp/tmp8aro35_w/ovnsb_db.sock<->) at lib/stream-fd.c:157
2022-01-23T19:28:26.330Z|00142|jsonrpc|DBG|unix#3: received request, method="transact", params=["OVN_Southbound",{"uuid-name":"rowdebd1810_12e4_4ae8_9bcd_a18781f1b986","table":"MAC_Binding","op":"insert","row":{"ip":"100.0.0.21","datapath":["uuid","2c98db7e-84ad-4782-9d87-24eafae1700e"]}}], id=1260
2022-01-23T19:28:26.330Z|00143|jsonrpc|DBG|unix#3: send reply, result=[{"uuid":["uuid","e514d19c-7371-4d1b-9958-25ffd612b68b"]}], id=1260
2022-01-23T19:28:26.330Z|00144|jsonrpc|DBG|unix#4: send notification, method="update3", params=[["monid","OVN_Southbound"],"00000000-0000-0000-0000-000000000000",{"MAC_Binding":{"e514d19c-7371-4d1b-9958-25ffd612b68b":{"insert":{"ip":"100.0.0.21","datapath":["uuid","2c98db7e-84ad-4782-9d87-24eafae1700e"]}}}}]
2022-01-23T19:28:26.460Z|00145|poll_loop|DBG|wakeup due to [POLLIN] on fd 18 (/tmp/tmp8aro35_w/ovnsb_db.sock<->) at lib/stream-fd.c:157

but in failed run there is only:

2022-01-23T19:28:46.868Z|00156|jsonrpc|DBG|tcp:127.0.0.1:33296: send notification, method="update2", params=["ae7bd9c6-7c82-11ec-9a03-4fce359daaf8",{"Connection":{"83c29962-a6e2-4f3c-9fc7-888cf46540ed":{"modify":{"is_connected":true,"status":["map",[["bound_port","42597"],["n_connections","2"],["sec_since_connect","0"],["sec_since_disconnect","0"]]]}}},"Datapath_Binding":{"15003f80-2b91-44d6-8b9d-f8d217285fb3":{"insert":{"tunnel_key":1,"external_ids":["map",[["logical-switch","70caa880-3fed-4f9b-9558-f624c0d2c469"],["name","neutron-51ac15e4-24cc-4348-85c3-fe3a51cfcaec"],["name2","network1"]]]}}}}]
2022-01-23T19:28:49.369Z|00157|poll_loop|DBG|wakeup due to 2500-ms timeout at ovsdb/ovsdb-server.c:296 (0% CPU usage)
2022-01-23T19:28:51.872Z|00158|poll_loop|DBG|wakeup due to 2503-ms timeout at ovsdb/ovsdb-server.c:296 (0% CPU usage)
2022-01-23T19:28:54.373Z|00159|poll_loop|DBG|wakeup due to 2501-ms timeout at ovsdb/ovsdb-server.c:296 (0% CPU usage)

and nothi...

The ovsdb error is stopping the test:
2022-01-23 19:28:46.875 54853 ERROR ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:42597: error parsing update: ovsdb error: Modify non-existing row: ovs.db.error.Error: ovsdb error: Modify non-existing row

After this line, the test is just stopping the controllers and the DB servers.

I think we should implement [1] but for all FT tests, that means in "TestOVNFunctionalBase" and not only for the NB but for the SB too. In the DB log I see the connection is updated AFTER the network creation command "network1" has been committed:
2022-01-23T19:28:46.868Z|00156|jsonrpc|DBG|tcp:127.0.0.1:33296: send notification, method="update2", params=["ae7bd9c6-7c82-11ec-9a03-4fce359daaf8",{"Connection":{"83c29962-a6e2-4f3c-9fc7-888cf46540ed":{"modify":{"is_connected":true,"status":["map",[["bound_port","42597"],["n_connections","2"],["sec_since_connect","0"],["sec_since_disconnect","0"]]]}}},"Datapath_Binding":{"15003f80-2b91-44d6-8b9d-f8d217285fb3":{"insert":{"tunnel_key":1,"external_ids":["map",[["logical-switch","70caa880-3fed-4f9b-9558-f624c0d2c469"],["name","neutron-51ac15e4-24cc-4348-85c3-fe3a51cfcaec"],["name2","network1"]]]}}}}]

In any case, what I think is failing is the connection to the OVS DB, not the NB or SB DBs.

[0]https://review.opendev.org/q/Id84bf17953527c415d611bfc198038fb6f811de3
[1]https://review.opendev.org/c/openstack/neutron/+/825530/8/neutron/tests/functional/plugins/ml2/drivers/ovn/mech_driver/ovsdb/test_ovn_db_resources.py#32

Closing this bug because this error is not being reproduce in the CI.

New occurence: https://storage.bhs.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_66f/866225/4/check/neutron-functional-with-uwsgi/66fa82b/testr_results.html

This time the error is different: https://paste.opendev.org/show/bFLxtBIVP9akE2h61pw7/