Hi, On the different case # 01601450 from same Cu. It has been identified that host parameter was configured in cinder.conf file which was leading to the host mismatch issue when the cinder service was getting fail-over between controller nodes. After adding this parameter, previously created volumes are also updated in DB. ~~~ host=<something> in cinder.conf ~~~ But it seems like that still cinder vol detaching issue persist.
I was able to reproduce this bug using devstack, so I created an upstream bug here: https://bugs.launchpad.net/nova/+bug/1563547 I have also proposed a small patch upstream to Nova master (Newton/OSP10). https://review.openstack.org/#/c/298997/ If that merges, I will also propose an upstream backport patch for Nova Mitaka/OSP9 (and perhaps Liberty/OSP8 if it isn't too late). This fix will likely not be backported to OSP7 (and perhaps not OSP8) since the root cause is really the failing cinder connection which should be troubleshooted in a different ticket. In the mean time, you can reset the instance status back to ACTIVE from ERROR using 'nova reset-state'. For example: http://paste.openstack.org/show/492368/
A version of the original bug description follows to assist with collaborating on a resolution in the upstream community, potentially customer sensitive values have been replaced with <placeholder>. Description of problem: Nova deletes an instance, but doesn't update the database Version-Release number of selected component (if applicable): RHEL OSP 6 How reproducible: Most of the time for Cu. Steps to Reproduce: 1) Boot an instance and attach a volume to it. 2) Delete the instance using "nova delete" command. 3) Instance is deleted from host it's not showing in output "virsh list --all". 4) Vol. stuck in detaching state. 5) Instance is still present in DB and "nova list" output. 6) The instance cannot be deleted via a nova command, since it will attempt to detach the volume from the non-existent instance and fail. Actual results: Instance is not get deleted. Expected results: It should get deleted. Additional info: - cinder vol is coming EMC VNX storage. Multipath is used to talk to the VNX. - From compute node nova log file [sosreport-<placeholder>.localdomain-20160315195803] : ~~~ grep 'd0670b16-1bf9-49b9-ae26-194dfa425147' var/log/nova/nova-compute.log | grep -i error 2016-03-15 15:04:24.249 49083 ERROR nova.compute.manager [req-8aa90f3b-6695-4ab1-bcec-fa0ccc9482dc 6a0ec1d4df0c47169e231da823ed058b cab71e273d404e2d8409957545edd2ca - - -] [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] Setting instance vm_state to ERROR 2016-03-15 19:47:15.913 49083 ERROR nova.compute.manager [req-e70622b4-0a7b-4f06-98a5-641b0c4ee8c8 6a0ec1d4df0c47169e231da823ed058b cab71e273d404e2d8409957545edd2ca - - -] [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] Setting instance vm_state to ERROR 2016-03-15 20:01:07.937 49083 ERROR nova.compute.manager [req-8a1de3cd-360f-4cae-8d5b-35131e3fc761 6a0ec1d4df0c47169e231da823ed058b cab71e273d404e2d8409957545edd2ca - - -] [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] Setting instance vm_state to ERROR ~~~ - Call trace showing the error : ~~~ awk '/2016-03-15 15:04:18.963 49083/,/2016-03-15 15:04:24.447 49083/ {print $0}' var/log/nova/nova-compute.log 2016-03-15 15:04:18.963 49083 DEBUG nova.openstack.common.periodic_task [req-f60489b5-9a10-4acf-97da-ee1799bf3e46 - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/site-packages/nova/openstack/common/periodic_task.py:219 2016-03-15 15:04:18.963 49083 DEBUG nova.openstack.common.loopingcall [req-f60489b5-9a10-4acf-97da-ee1799bf3e46 - - - - -] Dynamic looping call <bound method Service.periodic_tasks of <nova.service.Service object at 0x4bf2b90>> sleeping for 6.22 seconds _inner /usr/lib/python2.7/site-packages/nova/openstack/common/loopingcall.py:132 2016-03-15 15:04:24.249 49083 ERROR nova.compute.manager [req-8aa90f3b-6695-4ab1-bcec-fa0ccc9482dc 6a0ec1d4df0c47169e231da823ed058b cab71e273d404e2d8409957545edd2ca - - -] [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] Setting instance vm_state to ERROR 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] Traceback (most recent call last): 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2772, in do_terminate_instance 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] self._delete_instance(context, instance, bdms, quotas) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/nova/hooks.py", line 149, in inner 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] rv = f(*args, **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2741, in _delete_instance 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] quotas.rollback() 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__ 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] six.reraise(self.type_, self.value, self.tb) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2711, in _delete_instance 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] self._shutdown_instance(context, instance, bdms) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2647, in _shutdown_instance 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] connector) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/nova/volume/cinder.py", line 214, in wrapper 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] res = method(self, ctx, volume_id, *args, **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/nova/volume/cinder.py", line 369, in terminate_connection 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] connector) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/cinderclient/v2/volumes.py", line 448, in terminate_connection 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] {'connector': connector}) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/cinderclient/v2/volumes.py", line 375, in _action 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] return self.api.client.post(url, body=body) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/cinderclient/client.py", line 118, in post 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] return self._cs_request(url, 'POST', **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/cinderclient/client.py", line 112, in _cs_request 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] return self.request(url, method, **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/cinderclient/client.py", line 103, in request 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/keystoneclient/adapter.py", line 206, in request 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] resp = super(LegacyJsonAdapter, self).request(*args, **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/keystoneclient/adapter.py", line 95, in request 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] return self.session.request(url, method, **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/keystoneclient/utils.py", line 318, in inner 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] return func(*args, **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 382, in request 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] resp = send(**kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 439, in _send_request 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 439, in _send_request 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 439, in _send_request 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] **kwargs) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 426, in _send_request 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] raise exceptions.ConnectionRefused(msg) 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] ConnectionRefused: Unable to establish connection to http://192.168.88.10:8776/v2/cab71e273d404e2d8409957545edd2ca/volumes/e2257e46-28df-4537-948c-98ae45a12940/action 2016-03-15 15:04:24.249 49083 TRACE nova.compute.manager [instance: d0670b16-1bf9-49b9-ae26-194dfa425147] 2016-03-15 15:04:24.447 49083 DEBUG oslo_concurrency.lockutils [req-8aa90f3b-6695-4ab1-bcec-fa0ccc9482dc 6a0ec1d4df0c47169e231da823ed058b cab71e273d404e2d8409957545edd2ca - - -] Lock "compute_resources" acquired by "update_usage" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:444 ~~~ - Above call trace is showing that IP http://192.168.88.10:8776/ is not accessible but Cu confirmed that curl was able to connect at the time of issue. [heat-admin@<placeholder> ~]$ curl http://192.168.88.10:8776 {"versions": [{"status": "SUPPORTED", "updated": "2014-06-28T12:20:21Z", "id": "v1.0", "links": [{"href": "http://192.168.88.10:8776/v1/", "rel": "self"}]}, {"status": "CURRENT", "updated": "2012-11-21T11:33:21Z", "id": "v2.0", "links": [{"href": "http://192.168.88.10:8776/v2/", "rel": "self"}]}]} - DB output while reproducing the issue with other instance. [stack@sl<placeholder>ospd ~]$ nova list --all | grep slsg2 | 36d323a1-4d57-4e7f-939c-b7edf3ab74ce | slsg2-s00c01h0 | 00c4d7d296c140069190c53df54aa413 | ACTIVE | deleting | Running | [stack@sl<placeholder>ospd ~]$ cinder list --all | grep c01h0 | 34e3cb7e-bda5-4d92-98ea-cb4ec0cf4ce4 | 00c4d7d296c140069190c53df54aa413 | detaching | slsg2-s00c01h0VOL | 68 | - | false | 36d323a1-4d57-4e7f-9| [heat-admin@sl<placeholder>ctl0 ~]$ echo "select * from volumes where id='34e3cb7e-bda5-4d92-98ea-cb4ec0cf4ce4'\G" | sudo mysql cinder *************************** 1. row *************************** created_at: 2016-03-02 04:31:29 updated_at: 2016-03-15 21:23:15 deleted_at: NULL deleted: 0 id: 34e3cb7e-bda5-4d92-98ea-cb4ec0cf4ce4 ec2_id: NULL user_id: 5785cff2b204457b87ff97ed5b65182b project_id: 00c4d7d296c140069190c53df54aa413 host: sl<placeholder>ctl0.localdomain@cinder_vnx#Pool1-iSCSI size: 68 availability_zone: nova status: detaching attach_status: attached scheduled_at: 2016-03-02 04:31:29 launched_at: 2016-03-02 04:31:46 terminated_at: NULL display_name: slsg2-s00c01h0VOL display_description: Used for VM /storage partition. provider_location: version^05.04.02|type^lun|system^APM00144418842|id^80 provider_auth: NULL snapshot_id: NULL volume_type_id: NULL source_volid: NULL bootable: 0 provider_geometry: NULL _name_id: NULL encryption_key_id: NULL migration_status: NULL replication_status: disabled replication_extended_status: NULL replication_driver_data: NULL consistencygroup_id: NULL provider_id: NULL multiattach: 0 [heat-admin@sl<placeholder>ctl0 ~]$ echo "select * from instances where uuid='36d323a1-4d57-4e7f-939c-b7edf3ab74ce'\G" | sudo mysql nova *************************** 1. row *************************** created_at: 2016-03-02 04:33:48 updated_at: 2016-03-16 13:41:55 deleted_at: NULL id: 1643 internal_id: NULL user_id: 5785cff2b204457b87ff97ed5b65182b project_id: 00c4d7d296c140069190c53df54aa413 image_ref: 20f689ec-471c-4d0e-8e25-3b13211f89b9 kernel_id: ramdisk_id: launch_index: 0 key_name: NULL key_data: NULL power_state: 0 vm_state: error memory_mb: 8192 vcpus: 2 hostname: slsg2-s00c01h0 host: <placeholder>.localdomain user_data: <placeholder> reservation_id: r-jaebuhz5 scheduled_at: NULL launched_at: 2016-03-02 04:34:38 terminated_at: NULL display_name: slsg2-s00c01h0 display_description: slsg2-s00c01h0 availability_zone: sl<placeholder>-mtc-zone1 locked: 0 os_type: NULL launched_on: <placeholder>.localdomain instance_type_id: 143 vm_mode: NULL uuid: 36d323a1-4d57-4e7f-939c-b7edf3ab74ce architecture: NULL root_device_name: /dev/vda access_ip_v4: NULL access_ip_v6: NULL config_drive: True task_state: NULL default_ephemeral_device: /dev/vdb default_swap_device: /dev/vdc progress: 0 auto_disk_config: 0 shutdown_terminate: 0 disable_terminate: 0 root_gb: 21 ephemeral_gb: 21 cell_name: NULL node: <placeholder>.localdomain deleted: 0 locked_by: NULL cleaned: 1 ephemeral_key_uuid: NULL [root@<placeholder> ~]# virsh list --all Id Name State ----------------------------------------------------
*** Bug 1293235 has been marked as a duplicate of this bug. ***
*** Bug 1260426 has been marked as a duplicate of this bug. ***
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2016:1198