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.
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-ed87f5102f f1 None None] Provisioning complete for port b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f 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-ed87f5102f f1 None None] Port b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f 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-72faf18b88 34 None None] Device b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f 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-72faf18b88 34 None None] Provisioning for port b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f 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-72faf18b88 34 None None] Current status of the port b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f 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-1db0d331d6 b5'] response: {'server_uuid': '3a81145d- d263-4e1d- 8ec3-faf38fed34 f2', 'name': 'network- vif-plugged' , 'status': 'completed', 'tag': 'b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f', '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-72faf18b88 34 None None] Device b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f 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-72faf18b88 34 None None] Provisioning complete for port b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f 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-72faf18b88 34 None None] Publish callbacks ['neutron. plugins. ml2.plugin. Ml2Plugin. _port_provision ed-1963382' ] for port (b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f), 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-72faf18b88 34 None None] Current status of the port b6dc2b79- ed38-4907- 86e2-bdff1c5a9b 9f 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.