Bug 1321150

Summary: nova evacuate fails for instance booted with volume
Product: Red Hat OpenStack Reporter: nalmond
Component: openstack-novaAssignee: Prateek Arora <parora>
Status: CLOSED DUPLICATE QA Contact: nlevinki <nlevinki>
Severity: medium Docs Contact:
Priority: medium    
Version: 7.0 (Kilo)CC: berrange, dasmith, eglynn, kchamart, ndipanov, parora, sbauza, sferdjao, sgordon, srevivo, vromanso
Target Milestone: ---Keywords: ZStream
Target Release: 7.0 (Kilo)   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-04-18 13:19:11 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description nalmond 2016-03-24 19:25:16 UTC
Description of problem:
Performing a nova evacuation on an instance with an attached volume fails with 'ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500)'

How reproducible:
Every time

Steps to Reproduce:
1. Launch an instance with an attached volume
2. Power off the compute node the instance was booted on
3. Attempt a nova evacuate: nova evacuate <instance_name> <destination_host> --password "${OS_PASSWORD}"

Actual results:
The evacuation fails with:

nova-compute.log:2016-03-10 11:20:23.867 3316 ERROR nova.compute.manager [req-324d2738-6808-4e7d-9b52-88f32bc609b8 bfeb81563d9440a78d313d923693fb5a 2d1a06b20fea47ddabe215347a61a861 - - -] [instance: <uuid>] Setting instance vm_state to ERROR
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>] Traceback (most recent call last):
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6476, in _error_out_instance_on_exception
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     yield
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 3113, in rebuild_instance
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     self._rebuild_default_impl(**kwargs)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2942, in _rebuild_default_impl
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     detach_block_devices(context, bdms)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 3091, in detach_block_devices 
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     destroy_bdm=False)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 4956, in _detach_volume
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     self.volume_api.terminate_connection(context, volume_id, connector)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/nova/volume/cinder.py", line 214, in wrapper
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     res = method(self, ctx, volume_id, *args, **kwargs)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/nova/volume/cinder.py", line 369, in terminate_connection
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     connector)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/cinderclient/v2/volumes.py", line 448, in terminate_connection
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     {'connector': connector})     
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/cinderclient/v2/volumes.py", line 375, in _action
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     return self.api.client.post(url, body=body)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/cinderclient/client.py", line 118, in post
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     return self._cs_request(url, 'POST', **kwargs)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/cinderclient/client.py", line 112, in _cs_request
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     return self.request(url, method, **kwargs)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]   File "/usr/lib/python2.7/site-packages/cinderclient/client.py", line 105, in request
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]     raise exceptions.from_response(resp, body)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>] ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-abaa35dc-c471-4613-b478-4579c2ce91d6)
nova-compute.log:2016-03-10 11:20:23.867 3316 TRACE nova.compute.manager [instance: <uuid>]

Expected results:
The evacuation is successful

Additional info:
The below error is seen in the cinder api log:

2016-03-10 11:20:23.863 5316 ERROR cinder.api.middleware.fault [req-abaa35dc-c471-4613-b478-4579c2ce91d6 bfeb81563d9440a78d313d923693fb5a 2d1a06b20fea47ddabe215347a61a861 - - -] Caught error: Remote error: Remote error: VolumeBackendAPIException Bad or unexpected response from the storage volume backend API: Unable to terminate volume connection: Failed to detach iSCSI target for volume <uuid>.
[u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply\n    executor_callback))\n', u'  File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch\n    executor_callback)\n', u'  File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch\n    result = func(ctxt, **new_args)\n', u'  File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 105, in wrapper\n    return f(*args, **kwargs)\n', u'  File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 1181, in terminate_connection\n    raise exception.VolumeBackendAPIException(data=err_msg)\n', u'VolumeBackendAPIException: Bad or unexpected response from the storage volume backend API: Unable to terminate volume connection: Failed to detach iSCSI target for volume <uuid>.\n']. None
None.
2016-03-10 11:20:23.864 5316 INFO cinder.api.middleware.fault [req-abaa35dc-c471-4613-b478-4579c2ce91d6 bfeb81563d9440a78d313d923693fb5a 2d1a06b20fea47ddabe215347a61a861 - - -] http://<ip>:8776/v2/<uuid>/volumes/<uuid>/action returned with HTTP 500

This looks like the issue reported in https://bugs.launchpad.net/nova/+bug/1522496 and there appears to be a patch already upstream for Liberty. Is it possible to backport this to OSP 7?

Comment 3 Prateek Arora 2016-04-14 05:50:30 UTC
@eglynn : Yes, I was on leave for the past few days. I have applied for the LDAP accesses and would start working once I get them.

Comment 4 Eoghan Glynn 2016-04-18 13:19:11 UTC

*** This bug has been marked as a duplicate of bug 1295681 ***