ml2 context for update/delete network sometimes lacks segmentation id when a network with subnet is deleted

[Jerry Zhao]

When a network is deleted, the current ml2 context randomly misses provider:segmentation_id when delete network precommit is called. update_network_precommit when segments are deleted doesn't have segmentation_id value either. The underlying ml2 mechanism driver may need this information when deleting the network.
In the context in question:
'provider:segmentation_id': None

Noticed this behavior after recent changes regarding callback registration. i wonder if a race may have caused this.

"event-dispatch" released by "neutron.plugins.ml2.ovo_rpc.dispatch_events" :: held 0.076s inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282
2017-03-21 19:30:49.860 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Notify callbacks ['neutron.services.segments.db._delete_segments_for_network-8743773399662', 'neutron.plugins.ml2.plugin.Ml2Plugin._network_delete_precommit_handler-579307'] for network, precommit_delete _notify_loop /opt/stack/new/neutron/neutron/callbacks/manager.py:142
2017-03-21 19:30:49.861 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Subscribe: <bound method Plugin._prevent_segment_delete_with_subnet_associated of <neutron.services.segments.plugin.Plugin object at 0x7f3d16401410>> segment before_delete subscribe /opt/stack/new/neutron/neutron/callbacks/manager.py:42
2017-03-21 19:30:49.861 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Subscribe: <bound method NovaSegmentNotifier._notify_host_addition_to_aggregate of <neutron.services.segments.plugin.NovaSegmentNotifier object at 0x7f3d16413bd0>> segment_host_mapping after_create subscribe /opt/stack/new/neutron/neutron/callbacks/manager.py:42
2017-03-21 19:30:49.862 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Subscribe: <bound method NovaSegmentNotifier._notify_port_created_or_deleted of <neutron.services.segments.plugin.NovaSegmentNotifier object at 0x7f3d16413bd0>> port after_create subscribe /opt/stack/new/neutron/neutron/callbacks/manager.py:42
2017-03-21 19:30:49.862 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Subscribe: <bound method NovaSegmentNotifier._notify_port_created_or_deleted of <neutron.services.segments.plugin.NovaSegmentNotifier object at 0x7f3d16413bd0>> port after_delete subscribe /opt/stack/new/neutron/neutron/callbacks/manager.py:42
2017-03-21 19:30:49.863 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Subscribe: <bound method NovaSegmentNotifier._notify_port_updated of <neutron.services.segments.plugin.NovaSegmentNotifier object at 0x7f3d16413bd0>> port after_update subscribe /opt/stack/new/neutron/neutron/callbacks/manager.py:42
2017-03-21 19:30:49.863 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Subscribe: <bound method NovaSegmentNotifier._notify_subnet_created of <neutron.services.segments.plugin.NovaSegmentNotifier object at 0x7f3d16413bd0>> subnet after_create subscribe /opt/stack/new/neutron/neutron/callbacks/manager.py:42
2017-03-21 19:30:49.864 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Subscribe: <bound method NovaSegmentNotifier._notify_subnet_deleted of <neutron.services.segments.plugin.NovaSegmentNotifier object at 0x7f3d16413bd0>> subnet after_delete subscribe /opt/stack/new/neutron/neutron/callbacks/manager.py:42
2017-03-21 19:30:49.864 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Subscribe: <bound method NovaSegmentNotifier._notify_subnet_updated of <neutron.services.segments.plugin.NovaSegmentNotifier object at 0x7f3d16413bd0>> subnet after_update subscribe /opt/stack/new/neutron/neutron/callbacks/manager.py:42
2017-03-21 19:30:49.942 21568 DEBUG neutron.services.segments.db [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] neutron.services.segments.plugin.Plugin method get_segments called with arguments (<neutron_lib.context.Context object at 0x7f3d16582550>,) {'filters': {'network_id': [u'9683a13e-832f-4385-b119-1dc28a0bf723']}} wrapper /usr/local/lib/python2.7/dist-packages/oslo_log/helpers.py:47
2017-03-21 19:30:49.959 21568 DEBUG neutron.services.segments.db [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] neutron.services.segments.plugin.Plugin method delete_segment called with arguments (<neutron_lib.context.Context object at 0x7f3d16582550>, u'69019811-bdd8-4dab-ae47-04616bd09d3d') {'for_net_delete': True} wrapper /usr/local/lib/python2.7/dist-packages/oslo_log/helpers.py:47
2017-03-21 19:30:49.960 21568 DEBUG neutron.services.segments.db [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] neutron.services.segments.plugin.Plugin method get_segment called with arguments (<neutron_lib.context.Context object at 0x7f3d16582550>, u'69019811-bdd8-4dab-ae47-04616bd09d3d') {} wrapper /usr/local/lib/python2.7/dist-packages/oslo_log/helpers.py:47
2017-03-21 19:30:49.975 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Notify callbacks ['neutron.services.segments.plugin.Plugin._prevent_segment_delete_with_subnet_associated--9223372036839706585', 'neutron.plugins.ml2.db._prevent_segment_delete_with_port_bound--9223363293081322876'] for segment, before_delete _notify_loop /opt/stack/new/neutron/neutron/callbacks/manager.py:142
2017-03-21 19:30:49.977 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Notify callbacks ['neutron.plugins.ml2.plugin.Ml2Plugin._handle_segment_change--9223372036854196202'] for segment, precommit_delete _notify_loop /opt/stack/new/neutron/neutron/callbacks/manager.py:142
2017-03-21 19:30:49.981 21568 DEBUG neutron.plugins.ml2.drivers.type_vlan [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Releasing vlan 1026 on physical network physnet1 to pool release_segment /opt/stack/new/neutron/neutron/plugins/ml2/drivers/type_vlan.py:224
2017-03-21 19:30:50.092 21568 DEBUG neutron.plugins.ml2.managers [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Network 9683a13e-832f-4385-b119-1dc28a0bf723 has no segments _extend_network_dict_provider /opt/stack/new/neutron/neutron/plugins/ml2/managers.py:165
2017-03-21 19:30:50.103 21568 DEBUG networking_fortinet.ml2.mech_fortinet [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] update_network_precommit called: org_network: {'provider:physical_network': None, 'ipv6_address_scope': None, 'revision_number': 6, 'port_security_enabled': True, 'provider:network_type': None, 'id': u'9683a13e-832f-4385-b119-1dc28a0bf723', 'router:external': False, 'availability_zone_hints': [], 'availability_zones': [], 'ipv4_address_scope': None, 'shared': False, 'project_id': u'ca3c74f06ffc49dfb3a5c8ccc07a3245', 'status': u'ACTIVE', 'subnets': [], 'description': u'', 'tags': [], 'updated_at': '2017-03-21T19:30:48Z', 'provider:segmentation_id': None, 'name': u'tempest-NetworksTest-test-network-1655620956', 'admin_state_up': True, 'tenant_id': u'ca3c74f06ffc49dfb3a5c8ccc07a3245', 'created_at': '2017-03-21T19:30:42Z', 'mtu': 0, 'vlan_transparent': None},
the cur_network {'provider:physical_network': None, 'ipv6_address_scope': None, 'revision_number': 6, 'port_security_enabled': True, 'provider:network_type': None, 'id': u'9683a13e-832f-4385-b119-1dc28a0bf723', 'router:external': False, 'availability_zone_hints': [], 'availability_zones': [], 'ipv4_address_scope': None, 'shared': False, 'project_id': u'ca3c74f06ffc49dfb3a5c8ccc07a3245', 'status': u'ACTIVE', 'subnets': [], 'description': u'', 'tags': [], 'updated_at': '2017-03-21T19:30:48Z', 'provider:segmentation_id': None, 'name': u'tempest-NetworksTest-test-network-1655620956', 'admin_state_up': True, 'tenant_id': u'ca3c74f06ffc49dfb3a5c8ccc07a3245', 'created_at': '2017-03-21T19:30:42Z', 'mtu': 0, 'vlan_transparent': None} update_network_precommit /opt/stack/new/networking-fortinet/networking_fortinet/ml2/mech_fortinet.py:246
2017-03-21 19:30:50.104 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Notify callbacks ['neutron.plugins.ml2.plugin.Ml2Plugin._handle_segment_change--9223372036854196202'] for segment, after_delete _notify_loop /opt/stack/new/neutron/neutron/callbacks/manager.py:142
2017-03-21 19:30:50.221 21568 DEBUG neutron.plugins.ml2.managers [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Network 9683a13e-832f-4385-b119-1dc28a0bf723 has no segments _extend_network_dict_provider /opt/stack/new/neutron/neutron/plugins/ml2/managers.py:165
2017-03-21 19:30:50.556 21568 DEBUG neutron.plugins.ml2.managers [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Network 9683a13e-832f-4385-b119-1dc28a0bf723 has no segments _extend_network_dict_provider /opt/stack/new/neutron/neutron/plugins/ml2/managers.py:165
2017-03-21 19:30:50.569 21568 DEBUG networking_fortinet.ml2.mech_fortinet [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] delete_network_precommit: called with {'provider:physical_network': None, 'ipv6_address_scope': None, 'revision_number': 6, 'port_security_enabled': True, 'provider:network_type': None, 'id': u'9683a13e-832f-4385-b119-1dc28a0bf723', 'router:external': False, 'availability_zone_hints': [], 'availability_zones': [], 'ipv4_address_scope': None, 'shared': False, 'project_id': u'ca3c74f06ffc49dfb3a5c8ccc07a3245', 'status': u'ACTIVE', 'subnets': [], 'description': u'', 'tags': [], 'updated_at': '2017-03-21T19:30:48Z', 'provider:segmentation_id': None, 'name': u'tempest-NetworksTest-test-network-1655620956', 'admin_state_up': True, 'tenant_id': u'ca3c74f06ffc49dfb3a5c8ccc07a3245', 'created_at': '2017-03-21T19:30:42Z', 'mtu': 0, 'vlan_transparent': None} delete_network_precommit /opt/stack/new/networking-fortinet/networking_fortinet/ml2/mech_fortinet.py:193
/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py:929: SAWarning: DELETE statement on table 'segmenthostmappings' expected to delete 1 row(s); 0 were matched. Please set confirm_deleted_rows=False within the mapper configuration to prevent this warning.
  (table.description, expected, rows_matched)
/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py:929: SAWarning: DELETE statement on table 'networksegments' expected to delete 1 row(s); 0 were matched. Please set confirm_deleted_rows=False within the mapper configuration to prevent this warning.
  (table.description, expected, rows_matched)
2017-03-21 19:30:50.586 21568 DEBUG neutron.callbacks.manager [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Notify callbacks ['neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api.DhcpAgentNotifyAPI._native_event_send_dhcp_notification--9223372036838049952', 'neutron.plugins.ml2.plugin.Ml2Plugin._network_delete_after_delete_handler--9223372036854196512', 'neutron.plugins.ml2.ovo_rpc._ObjectChangeHandler.handle_event-16219852'] for network, after_delete _notify_loop /opt/stack/new/neutron/neutron/callbacks/manager.py:142
2017-03-21 19:30:50.587 21568 DEBUG oslo_messaging._drivers.amqpdriver [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] CAST unique_id: f286c18591b543ef90fb6b19dbfa97a0 FANOUT topic 'dhcp_agent' _send /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:478
2017-03-21 19:30:50.592 21568 DEBUG networking_fortinet.ml2.mech_fortinet [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] delete_network_postcommit: called delete_network_postcommit /opt/stack/new/networking-fortinet/networking_fortinet/ml2/mech_fortinet.py:225
2017-03-21 19:30:50.854 21568 DEBUG networking_fortinet.common.utils [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] Keeping vdom, because existing db_routers: [],db_networks: [<neutron.db.models_v2.Network[object at 7f3d16a8a190] {project_id=u'ca3c74f06ffc49dfb3a5c8ccc07a3245', id=u'4eb639f4-78bf-45ac-9d3a-48ecf4956a4b', name=u'tempest-NetworksTest-test-network-1631120073', status=u'ACTIVE', admin_state_up=True, vlan_transparent=None, availability_zone_hints=u'[]', standard_attr_id=36}>], db_fips: [] delete_vdom /opt/stack/new/networking-fortinet/networking_fortinet/common/utils.py:348
2017-03-21 19:30:50.855 21568 INFO networking_fortinet.ml2.mech_fortinet [req-a7ff6e05-4dad-4d6b-bd5f-24667f0cf0c8 tempest-NetworksTest-421231814 tempest-NetworksTest-421231814] delete network postcommit: tenant= ca3c74f06ffc49dfb3a5c8ccc07a3245 network= {'provider:physical_network': None, 'ipv6_address_scope': None, 'revision_number': 6, 'port_security_enabled': True, 'provider:network_type': None, 'id': u'9683a13e-832f-4385-b119-1dc28a0bf723', 'router:external': False, 'availability_zone_hints': [], 'availability_zones': [], 'ipv4_address_scope': None, 'shared': False, 'project_id': u'ca3c74f06ffc49dfb3a5c8ccc07a3245', 'status': u'ACTIVE', 'subnets': [], 'description': u'', 'tags': [], 'updated_at': '2017-03-21T19:30:48Z', 'provider:segmentation_id': None, 'name': u'tempest-NetworksTest-test-network-1655620956', 'admin_state_up': True, 'tenant_id': u'ca3c74f06ffc49dfb3a5c8ccc07a3245', 'created_at': '2017-03-21T19:30:42Z', 'mtu': 0, 'vlan_transparent': None}

[Sam Su (sam-su)]

I think it is because the current network deletion code doesn't follow the sequence as the network creation, the deletion should follow the reverse sequence(like the operations push and pop in a stack) to release related resources.

For example:
In the network creation function _create_network_db: it create network segment first, then mechanism_manager.create_network_precommit.

In the network deletion function delete_network: it send related deletion events of resources.NETWORK in the following order:
   events.BEFORE_DELETE-> events.PRECOMMIT_DELETE -> events.AFTER_DELETE

when notified the event events.PRECOMMIT_DELETE, mechanism_manager.delete_network_precommit was triggered, however delete_segment was triggered either on the same event events.PRECOMMIT_DELETE(current implementation) or on the prior event events.BEFORE_DELETE (in the fix https://review.openstack.org/#/c/429441/8/neutron/services/segments/db.py ).

It is better to follow the push and pop operations to do the creation and deletion to avoid any potential resources dependence.

[OpenStack Infra (hudson-openstack)]

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

[Kevin Benton (kevinbenton)]

Segments can be deleted independently of networks. If you always need segmentation IDs of them, I think you will need to subscribe to segment AFTER/BEFORE delete events.

[OpenStack Infra (hudson-openstack)]

Change abandoned by Armando Migliaccio (<email address hidden>) on branch: master
Review: https://review.openstack.org/448822
Reason: This review is > 3 months without comment and currently blocked by a core reviewer with a -1. We are abandoning this for now. Feel free to reactivate the review by pressing the restore button and contacting the reviewer with the -1 on this review to ensure you address their concerns.

[sunzuohua (zuohuasun)]

Hi,Sam su：
    This bug also affects me.
    Will you continue to fix it?
    If not,I will try to fix it.

[Sam Su (sam-su)]

Yes, feel free to fix it. Just FYI, before submitting your code, you'd better to discuss your solution with Kevin Benton first.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Change abandoned by sunzuohua (<email address hidden>) on branch: master
Review: https://review.openstack.org/518461