Comment 2 for bug 1971563

looking at this brifely it appears that the neutron server has rescived the provisioning complete notification form the dhcp agent and l2 agent

May 03 16:47:04.296348 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: DEBUG neutron.db.provisioning_blocks [None req-89d4fdba-e0f4-4778-b944-ed87f5102ff1 None None] Provisioning complete for port b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f triggered by entity DHCP.

then since the port is not bound we see

May 03 16:47:04.325819 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: DEBUG neutron.plugins.ml2.plugin [None req-89d4fdba-e0f4-4778-b944-ed87f5102ff1 None None] Port b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f cannot update to ACTIVE because it is not bound. {{(pid=89517) _port_provisioned /opt/stack/neutron/neutron/plugins/ml2/plugin.py:352}}

later we see the l2 agent wire up the port

May 03 16:47:22.223506 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: DEBUG neutron.plugins.ml2.rpc [None req-d5636366-a9cc-4a96-a55f-72faf18b8834 None None] Device b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f up at agent ovs-agent-ubuntu-focal-ovh-bhs1-0029531417 {{(pid=89517) update_device_up /opt/stack/neutron/neutron/plugins/ml2/rpc.py:296}}

May 03 16:47:22.277185 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: DEBUG neutron.db.provisioning_blocks [None req-d5636366-a9cc-4a96-a55f-72faf18b8834 None None] Provisioning for port b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f completed by entity L2. {{(pid=89517) provisioning_complete /opt/stack/neutron/neutron/db/provisioning_blocks.py:137}}

and the neutron server moves the port to active

May 03 16:47:22.346079 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: DEBUG neutron.plugins.ml2.plugin [None req-d5636366-a9cc-4a96-a55f-72faf18b8834 None None] Current status of the port b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f is: DOWN; New status is: ACTIVE {{(pid=89517) _update_individual_port_db_status /opt/stack/neutron/neutron/plugins/ml2/plugin.py:2297}}

neutron sends the event at

May 03 16:47:22.410536 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: INFO neutron.notifiers.nova [-] Nova event matching ['req-17e4fee0-ad06-4350-af09-1db0d331d6b5'] response: {'server_uuid': '3a81145d-d263-4e1d-8ec3-faf38fed34f2', 'name': 'network-vif-plugged', 'status': 'completed', 'tag': 'b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f', 'code': 200}

we then have additional events where the l2 agent marks the port as provisioned

May 03 16:47:24.195188 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: DEBUG neutron.plugins.ml2.rpc [None req-d5636366-a9cc-4a96-a55f-72faf18b8834 None None] Device b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f up at agent ovs-agent-ubuntu-focal-ovh-bhs1-0029531417 {{(pid=89517) update_device_up /opt/stack/neutron/neutron/plugins/ml2/rpc.py:296}}

May 03 16:47:24.228930 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: DEBUG neutron.db.provisioning_blocks [None req-d5636366-a9cc-4a96-a55f-72faf18b8834 None None] Provisioning complete for port b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f triggered by entity L2. {{(pid=89517) provisioning_complete /opt/stack/neutron/neutron/db/provisioning_blocks.py:145}}

May 03 16:47:24.229155 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: DEBUG neutron_lib.callbacks.manager [None req-d5636366-a9cc-4a96-a55f-72faf18b8834 None None] Publish callbacks ['neutron.plugins.ml2.plugin.Ml2Plugin._port_provisioned-1963382'] for port (b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f), provisioning_complete {{(pid=89517) _notify_loop /usr/local/lib/python3.8/dist-packages/neutron_lib/callbacks/manager.py:176}}

May 03 16:47:24.282572 ubuntu-focal-ovh-bhs1-0029531414 neutron-server[89517]: DEBUG neutron.plugins.ml2.plugin [None req-d5636366-a9cc-4a96-a55f-72faf18b8834 None None] Current status of the port b6dc2b79-ed38-4907-86e2-bdff1c5a9b9f is: ACTIVE; New status is: ACTIVE {{(pid=89517) _update_individual_port_db_status /opt/stack/neutron/neutron/plugins/ml2/plugin.py:2297}}

but that does not trigger the network-vif-plugged event to be sent again.