storwize delete clone volume failing

[Gerald McBrearty]

Steps to reproduce:

Clone volume-1 to volume-2
Clone volume-2 to volume-3
Delete volume-2

Volume-2 then goes into the error state.

2017-02-06 12:23:42.342 53954 ERROR cinder.volume.drivers.ibm.storwize_svc.storwize_svc_common [-] Error has occurred: Unexpected error while running command.
Command: svctask rmfcmap -force 1
Exit code: 1
Stdout: u''
Stderr: u'CMMVC6318E The FlashCopy mapping could not be deleted because the source volume is required by other maps.\n'
2017-02-06 12:23:43.204 53954 ERROR cinder.volume.drivers.ibm.storwize_svc.storwize_svc_common [-] Error running SSH command: svctask rmfcmap -force 1
2017-02-06 12:23:43.205 53954 WARNING cinder.volume.drivers.ibm.storwize_svc.storwize_svc_common [-] Not able to use storwize_san_secondary_ip since it is not configured.
2017-02-06 12:23:43.206 53954 ERROR cinder.volume.drivers.ibm.storwize_svc.storwize_svc_common [-] Error running SSH command: svctask rmfcmap -force 1
2017-02-06 12:23:43.206 53954 ERROR cinder.volume.drivers.ibm.storwize_svc.storwize_svc_common [-] CLI Exception output:
 command: ['svctask', 'rmfcmap', '-force', u'1']
 stdout:
 stderr: CMMVC6318E The FlashCopy mapping could not be deleted because the source volume is required by other maps.
.
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall [-] Fixed interval looping call 'cinder.volume.drivers.ibm.storwize_svc.storwize_svc_common.StorwizeHelpers._check_vdisk_fc_mappings' failed
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall Traceback (most recent call last):
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall File "/usr/lib/python2.7/site-packages/oslo_service/loopingcall.py", line 136, in _run_loop
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall result = func(*self.args, **self.kw)
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ibm/storwize_svc/storwize_svc_common.py", line 1502, in _check_vdisk_fc_mappings
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall self.ssh.rmfcmap(map_id)
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ibm/storwize_svc/storwize_svc_common.py", line 493, in rmfcmap
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall self.run_ssh_assert_no_output(ssh_cmd)
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ibm/storwize_svc/storwize_svc_common.py", line 149, in run_ssh_assert_no_output
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall out, err = self._run_ssh(ssh_cmd)
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ibm/storwize_svc/storwize_svc_common.py", line 139, in _run_ssh
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall raise exception.VolumeBackendAPIException(data=msg)
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall VolumeBackendAPIException: Bad or unexpected response from the storage volume backend API: CLI Exception output:
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall command: ['svctask', 'rmfcmap', '-force', u'1']
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall stdout:
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall stderr: CMMVC6318E The FlashCopy mapping could not be deleted because the source volume is required by other maps.
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall .
2017-02-06 12:23:43.207 53954 ERROR oslo.service.loopingcall
2017-02-06 12:23:48.226 53954 INFO powervc_cinder.volume.manager [req-93e070a4-0571-4bb7-b8e1-00aaa5775098 0688b01e6439ca32d698d20789d52169126fb41fb1a4ddafcebb97d854e836c9 f5b0fe599e3a47309efb93cf03c97ec5 - default default] PB-F7BAE2D Exception Bad or unexpected response from the storage volume backend API: CLI Exception output:
 command: ['svctask', 'rmfcmap', '-force', u'1']
 stdout:
 stderr: CMMVC6318E The FlashCopy mapping could not be deleted because the source volume is required by other maps.
. occurred. Retry in progress...
2017-02-06 12:23:49.233 53954 ERROR cinder.volume.drivers.ibm.storwize_svc.storwize_svc_common [-] Error has occurred: Unexpected error while running command.
Command: svctask rmfcmap -force 1
Exit code: 1
Stdout: u''

[xiaoqin (xiaoqin-li)]

Hi Gerald, we plan to provide an option just like force_delete in volume_type, so the user can choose whether to force delete the volume. The way it behaves just like the storwize GUI. If there is host-mapping, flashcoppy and the force-delete is not set, the delete will be fail. If the force-delete is set the volume will be deleted by force. Hoe do you think about it?

[Gerald McBrearty (gfm-r)]

Hi Xio Quin, I think if you force delete that would kill the copies instead of waiting for them to complete? We really want the flash copies to complete.

I took another look at the driver this week. The following is how I would propose resolving this defect. If you agree I'll take that forward as a fix. If the Volume is involved in multiple flash copies ... just wait.

diff --git a/cinder/volume/drivers/ibm/storwize_svc/storwize_svc_common.py b/cinder/volume/drivers/ibm/storwize_svc/storwize_svc_common.py
index e3af7b5..bb7739c 100644
--- a/cinder/volume/drivers/ibm/storwize_svc/storwize_svc_common.py
+++ b/cinder/volume/drivers/ibm/storwize_svc/storwize_svc_common.py
@@ -1559,6 +1559,10 @@ class StorwizeHelpers(object):
             status = attrs['status']

             if allow_fctgt and target == name and status == 'copying':
+ # if there are other fc maps don't stop the this map
+ if len(mapping_ids) > 1:
+ wait_for_copy = True
+ continue
                 self.ssh.stopfcmap(map_id)
                 attrs = self._get_flashcopy_mapping_attributes(map_id)
                 if attrs:
@@ -1594,6 +1598,10 @@ class StorwizeHelpers(object):
                 if status == 'prepared':
                     self.ssh.stopfcmap(map_id)
                     self.ssh.rmfcmap(map_id)
+ # if there are other fc maps we are just going to wait.
+ # any stopped or idle fc maps could be dependent maps
+ elif len(mapping_ids) > 1:
+ wait_for_copy = True
                 elif status in ['idle_or_copied', 'stopped']:
                     # Prepare failed or stopped
                     self.ssh.rmfcmap(map_id)

[Gerald McBrearty (gfm-r)]

xiaoqin

[Veda (annayappaa)]

Is there any update on this bug?

[xiaoqin (xiaoqin-li)]

The volume can not be deleted is due to some other volume is dependent on the volume2.
The workaround for this issue is:
1. If the the users do not care about the flash copies, they can force delete this volumes in the backend storage.
2. If users really want the flash copies to complete, they can do the delete operation sometime later. Since the flash copy relationship will be deleted automatically after data copy finished.

Gerald, we can not set wait_for_copy to true directly if len(mapping_ids) > 1, since there is also snapshot cases. The copy_rate for snapshot is 0, we still need to change the copyrate and set autodelete. What we should check the vdisk dependency relationship.