nova removes ports not owned by "compute" in deallocate_for_instance

Bug #1673429 reported by Vladyslav Drok
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
In Progress
Undecided
Vladyslav Drok

Bug Description

Hit this on ocata when aborting a deployment through nova (nova boot, then nova delete while instance is still in BUILD), using ironic virt driver. Relevant bits of n-cpu log:

2017-03-16 10:06:16.780 ERROR nova.compute.manager [req-37b74c46-5553-484b-b397-6efbede9d962 admin admin] [instance: 888b7c5a-6f7d-400d-a61f
-f367441e7a91] Build of instance 888b7c5a-6f7d-400d-a61f-f367441e7a91 aborted: Instance 888b7c5a-6f7d-400d-a61f-f367441e7a91 provisioning wa
s aborted
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] Traceback (most recent call last):
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] File "/opt/stack/nova/nova/compute/man
ager.py", line 1780, in _do_build_and_run_instance
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] filter_properties)
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] File "/opt/stack/nova/nova/compute/man
ager.py", line 1961, in _build_and_run_instance
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] phase=fields.NotificationPhase.ERROR
, exception=e)
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] File "/usr/local/lib/python2.7/dist-pa
ckages/oslo_utils/excutils.py", line 220, in __exit__
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] self.force_reraise()
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] File "/usr/local/lib/python2.7/dist-pa
ckages/oslo_utils/excutils.py", line 196, in force_reraise
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] six.reraise(self.type_, self.value,
self.tb)
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] File "/opt/stack/nova/nova/compute/man
ager.py", line 1933, in _build_and_run_instance
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] instance=instance)
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] File "/usr/lib/python2.7/contextlib.py
", line 35, in __exit__
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] self.gen.throw(type, value, tracebac
k)
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] File "/opt/stack/nova/nova/compute/manager.py", line 2152, in _build_resources
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] reason=six.text_type(exc))
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] BuildAbortException: Build of instance 888b7c5a-6f7d-400d-a61f-f367441e7a91 aborted: Instance 888b7c5a-6f7d-400d-a61f-f367441e7a91 provisioning was aborted
2017-03-16 10:06:16.780 TRACE nova.compute.manager [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91]
2017-03-16 10:06:16.781 DEBUG nova.compute.manager [req-37b74c46-5553-484b-b397-6efbede9d962 admin admin] [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] Deallocating network for instance from (pid=25464) _deallocate_network /opt/stack/nova/nova/compute/manager.py:1661
2017-03-16 10:06:16.781 DEBUG nova.network.neutronv2.api [req-37b74c46-5553-484b-b397-6efbede9d962 admin admin] [instance: 888b7c5a-6f7d-400d-a61f-f367441e7a91] deallocate_for_instance() from (pid=25464) deallocate_for_instance /opt/stack/nova/nova/network/neutronv2/api.py:1156
2017-03-16 10:06:16.901 DEBUG neutronclient.v2_0.client [req-37b74c46-5553-484b-b397-6efbede9d962 admin admin] GET call to neutron for http://192.168.122.22:9696/v2.0/ports.json?device_id=888b7c5a-6f7d-400d-a61f-f367441e7a91 used request id req-be903c33-c4da-433a-8e52-9bd5d14ed018 from (pid=25464) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2017-03-16 10:06:17.587 DEBUG neutronclient.v2_0.client [req-37b74c46-5553-484b-b397-6efbede9d962 admin admin] DELETE call to neutron for http://192.168.122.22:9696/v2.0/ports/1dee64d3-4e81-4ce5-b428-ab90700051dd.json used request id req-a5d90558-2b04-46fa-833e-d65446146a16 from (pid=25464) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2017-03-16 10:06:19.055 DEBUG oslo_service.periodic_task [req-f990991a-f1ee-4e3e-a1e6-82a33df8f6d3 None None] Running periodic task ComputeManager._heal_instance_info_cache from (pid=25464) run_periodic_tasks /usr/local/lib/python2.7/dist-packages/oslo_service/periodic_task.py:215
2017-03-16 10:06:19.055 DEBUG nova.compute.manager [req-f990991a-f1ee-4e3e-a1e6-82a33df8f6d3 None None] Starting heal instance info cache from (pid=25464) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:5851
2017-03-16 10:06:19.056 DEBUG nova.compute.manager [req-f990991a-f1ee-4e3e-a1e6-82a33df8f6d3 None None] Rebuilding the list of instances to heal from (pid=25464) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:5855
2017-03-16 10:06:19.057 DEBUG oslo_messaging._drivers.amqpdriver [req-f990991a-f1ee-4e3e-a1e6-82a33df8f6d3 None None] CALL msg_id: 99a597d83cf54335a9d71edbdc6da979 exchange 'nova' topic 'conductor' from (pid=25464) _send /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:442
2017-03-16 10:06:19.070 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 99a597d83cf54335a9d71edbdc6da979 from (pid=25464) __call__ /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:299
2017-03-16 10:06:19.071 DEBUG nova.compute.manager [req-f990991a-f1ee-4e3e-a1e6-82a33df8f6d3 None None] Didn't find any instances for network info cache update. from (pid=25464) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:5927
2017-03-16 10:06:19.534 DEBUG oslo_messaging._drivers.amqpdriver [-] CALL msg_id: a99d550a6c02409ea18eeab85d8f0e57 exchange 'nova' topic 'conductor' from (pid=25464) _send /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:442
2017-03-16 10:06:19.554 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: a99d550a6c02409ea18eeab85d8f0e57 from (pid=25464) __call__ /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:299
2017-03-16 10:06:22.746 DEBUG neutronclient.v2_0.client [req-37b74c46-5553-484b-b397-6efbede9d962 admin admin] DELETE call to neutron for http://192.168.122.22:9696/v2.0/ports/c643c888-52e2-4df9-b222-eb7e4c90f8df.json used request id req-cfe45eb1-ddec-421a-b675-4031bb941746 from (pid=25464) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128

The only filter nova applies is device_id filter, and it ignores the device_owner value. This causes the deletion of both 1dee64d3-4e81-4ce5-b428-ab90700051dd, which is a tenant port, and c643c888-52e2-4df9-b222-eb7e4c90f8df, which is provisioning port. A pieces of q-svc.log:

2017-03-16 10:06:17.653 DEBUG neutron.plugins.ml2.plugin [req-cfe45eb1-ddec-421a-b675-4031bb941746 admin admin] Deleting port c643c888-52e2-
4df9-b222-eb7e4c90f8df from (pid=27713) _pre_delete_port /opt/stack/neutron/neutron/plugins/ml2/plugin.py:1576
2017-03-16 10:06:17.654 DEBUG neutron.callbacks.manager [req-cfe45eb1-ddec-421a-b675-4031bb941746 admin admin] Notify callbacks [('neutron.d
b.l3_db._prevent_l3_port_delete_callback-8784608762101', <function _prevent_l3_port_delete_callback at 0x7fd537c18f50>)] for port, before_de
lete from (pid=27713) _notify_loop /opt/stack/neutron/neutron/callbacks/manager.py:142
2017-03-16 10:06:17.771 DEBUG neutron.plugins.ml2.db [req-cfe45eb1-ddec-421a-b675-4031bb941746 admin admin] For port c643c888-52e2-4df9-b222
-eb7e4c90f8df, host 88f150ce-20c1-4ba9-992d-73a6c4118a52, got binding levels [<neutron.plugins.ml2.models.PortBindingLevel[object at 7fd5366
41c90] {port_id=u'c643c888-52e2-4df9-b222-eb7e4c90f8df', host=u'88f150ce-20c1-4ba9-992d-73a6c4118a52', level=0, driver=u'genericswitch', seg
ment_id=u'ef37742a-ad89-4431-960b-9d2d1d7ab3a9'}>] from (pid=27713) get_binding_levels /opt/stack/neutron/neutron/plugins/ml2/db.py:97
2017-03-16 10:06:17.785 DEBUG neutron.plugins.ml2.plugin [req-cfe45eb1-ddec-421a-b675-4031bb941746 admin admin] Calling delete_port for c643
c888-52e2-4df9-b222-eb7e4c90f8df owned by baremetal:none from (pid=27713) delete_port /opt/stack/neutron/neutron/plugins/ml2/plugin.py:1634

Vladyslav Drok (vdrok)
tags: added: ironic
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

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

Changed in nova:
assignee: nobody → Vladyslav Drok (vdrok)
status: New → In Progress
Revision history for this message
Sean Dague (sdague) wrote :

Automatically discovered version ocata in description. If this is incorrect, please update the description to include 'nova version: ...'

tags: added: openstack-version.ocata
Revision history for this message
Mark Goddard (mgoddard) wrote :

This fix should not be merged until ironic bug https://bugs.launchpad.net/ironic/+bug/1732412 has been resolved. Turns out ironic is not very diligent in cleaning up provisioning ports, and until now this has been masked by nova cleaning up after it.

Revision history for this message
Mark Goddard (mgoddard) wrote :

The above fix in ironic was released in ironic 10.0.0. The fix for this issue in nova can now be unblocked.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.