def _wait_for_exec_hsnm(self, args, printflag, noretry, timeout, start):
lock = basic_lib.get_process_lock(self.hsnm_lock_file)
with self.hsnm_lock, lock:
ret, stdout, stderr = self.exec_command('env',
args=args,
printflag=printflag)
if not ret or noretry:
raise loopingcall.LoopingCallDone((ret, stdout, stderr))
if time.time() - start >= timeout:
LOG.error(_LE("snm2 command timeout."))
raise loopingcall.LoopingCallDone((ret, stdout, stderr))
if (re.search('DMEC002047', stderr) or re.search('DMEC002048', stderr)
or re.search('DMED09000A', stderr)
or re.search('DMED090026', stderr)
or re.search('DMED0E002B', stderr)
or re.search('DMER03006A', stderr)
or re.search('DMER030080', stderr)
or re.search('DMER0300B8', stderr)
or re.search('DMER0800CF', stderr)
or re.search('DMER0800D[0-6D]', stderr)
or re.search('DMES052602', stderr)):
LOG.error(_LE("Unexpected error occurs in snm2."))
raise loopingcall.LoopingCallDone((ret, stdout, stderr))
def _check_snapshot_delete_finished(self, snapshot_name):
try:
is_snapshot_exist = self._is_snapshot_exist(snapshot_name)
except Exception as ex:
msg = (_LE('Check snapshot delete finished failed: ' '%s.') % ex)
LOG.error(msg)
raise loopingcall.LoopingCallDone(retvalue=False)
if not is_snapshot_exist:
raise loopingcall.LoopingCallDone(retvalue=True)
def _check_vdisk_fc_mappings(self, name, allow_snaps=True):
"""FlashCopy mapping check helper."""
LOG.debug('Loopcall: _check_vdisk_fc_mappings(), vdisk %s' % name)
mapping_ids = self._get_vdisk_fc_mappings(name)
wait_for_copy = False
for map_id in mapping_ids:
attrs = self._get_flashcopy_mapping_attributes(map_id)
if not attrs:
continue
source = attrs['source_vdisk_name']
target = attrs['target_vdisk_name']
copy_rate = attrs['copy_rate']
status = attrs['status']
if copy_rate == '0':
if source == name:
# Vdisk with snapshots. Return False if snapshot
# not allowed.
if not allow_snaps:
raise loopingcall.LoopingCallDone(retvalue=False)
self.ssh.chfcmap(map_id, copyrate='50', autodel='on')
wait_for_copy = True
else:
# A snapshot
if target != name:
msg = (_('Vdisk %(name)s not involved in '
'mapping %(src)s -> %(tgt)s') % {
'name': name,
'src': source,
'tgt': target
})
LOG.error(msg)
raise exception.VolumeDriverException(message=msg)
if status in ['copying', 'prepared']:
self.ssh.stopfcmap(map_id)
# Need to wait for the fcmap to change to
# stopped state before remove fcmap
wait_for_copy = True
elif status in ['stopping', 'preparing']:
wait_for_copy = True
else:
self.ssh.rmfcmap(map_id)
# Case 4: Copy in progress - wait and will autodelete
else:
if status == 'prepared':
self.ssh.stopfcmap(map_id)
self.ssh.rmfcmap(map_id)
elif status == 'idle_or_copied':
# Prepare failed
self.ssh.rmfcmap(map_id)
else:
wait_for_copy = True
if not wait_for_copy or not len(mapping_ids):
raise loopingcall.LoopingCallDone(retvalue=True)
def _retry_check_for_volume_creation():
"""Called at an interval till the volume is created."""
retries = kwargs['retries']
max_retries = kwargs['max_retries']
jobid = kwargs['jobid']
cb_vol = kwargs['cb_vol']
# Query the CloudByte storage with this jobid
volume_response = self._queryAsyncJobResult_request(jobid)
result_res = None
if volume_response is not None:
result_res = volume_response.get('queryasyncjobresultresponse')
if volume_response is None or result_res is None:
msg = _("Null response received while querying "
"for create volume job [%s] "
"at CloudByte storage.") % jobid
raise exception.VolumeBackendAPIException(data=msg)
status = result_res.get('jobstatus')
if status == 1:
LOG.info(
_LI("Volume [%s] created successfully in "
"CloudByte storage."), cb_vol)
raise loopingcall.LoopingCallDone()
elif retries == max_retries:
# All attempts exhausted
LOG.error(
_LE("Error in creating volume [%(vol)s] in "
"CloudByte storage. "
"Exhausted all [%(max)s] attempts."), {
'vol': cb_vol,
'max': retries
})
raise loopingcall.LoopingCallDone(retvalue=False)
else:
retries += 1
kwargs['retries'] = retries
LOG.debug(
"Wait for volume [%(vol)s] creation, "
"retry [%(retry)s] of [%(max)s].", {
'vol': cb_vol,
'retry': retries,
'max': max_retries
})
def _wait_event(self, callFun, objuuid, eventid=None):
nRetry = 30
fExit = False
status = {}
status['state'] = 'error'
status['output'] = {}
while nRetry:
try:
if eventid:
ret, output = callFun(self._conver_uuid2hex(objuuid),
self._conver_uuid2hex(eventid))
else:
ret, output = callFun(self._conver_uuid2hex(objuuid))
if ret == 0:
if output['completionStatus'] == 'Complete':
fExit = True
status['state'] = 'available'
status['output'] = output
elif output['completionStatus'] == 'Error':
fExit = True
status['state'] = 'error'
raise loopingcall.LoopingCallDone(retvalue=False)
else:
nsleep = random.randint(0, 10)
value = round(float(nsleep) / 10, 2)
time.sleep(value)
elif ret == errno.ENODATA:
status['state'] = 'deleted'
fExit = True
else:
nRetry -= 1
time.sleep(3)
continue
except Exception as e:
msg = _('Flexvisor failed to get event %(volume)s'
'(%(status)s).') % {
'volume': eventid,
'status': six.text_type(e)
}
LOG.error(msg)
raise loopingcall.LoopingCallDone(retvalue=False)
status['state'] = 'error'
fExit = True
if fExit is True:
break
return status
def _poll_lease(self, lease):
try:
state = self.invoke_api(vim_util, 'get_object_property', self.vim,
lease, 'state')
if state == 'ready':
# done
LOG.debug(_("Lease is ready."))
elif state == 'initializing':
LOG.debug(_("Lease initializing..."))
return
elif state == 'error':
error_msg = self.invoke_api(vim_util, 'get_object_property',
self.vim, lease, 'error')
LOG.exception(error_msg)
excep = error_util.VimFaultException([], error_msg)
raise excep
else:
# unknown state - complain
error_msg = _("Error: unknown lease state %s.") % state
raise error_util.VimFaultException([], error_msg)
except Exception as excep:
LOG.exception(excep)
raise excep
# stop the loop since state is ready
raise loopingcall.LoopingCallDone()
def _wait_for_snap_delete(snapshot, start_time):
# defining CLI command
snapshotname = snapshot['name']
volumename = snapshot['volume_name']
snap_destroy = ('snap', '-destroy', '-id', snapshotname, '-o')
# executing CLI command
out, rc = self._cli_execute(*snap_destroy)
LOG.debug('Delete Snapshot: Volume: %(volumename)s Snapshot: '
'%(snapshotname)s Output: %(out)s'
% {'volumename': volumename,
'snapshotname': snapshotname,
'out': out})
if rc not in [0, 9, 5]:
if rc == 13:
if int(time.time()) - start_time < \
self.timeout * 60:
LOG.info(_('Snapshot %s is in use'), snapshotname)
else:
msg = (_('Failed to destroy %s '
' because snapshot is in use.'), snapshotname)
LOG.error(msg)
raise exception.SnapshotIsBusy(data=msg)
else:
msg = (_('Failed to destroy %s'), snapshotname)
LOG.error(msg)
raise exception.VolumeBackendAPIException(data=msg)
else:
raise loopingcall.LoopingCallDone()
def _poll_task(self, task):
"""Poll the given task.
If the task completes successfully then returns task info.
In case of error sends back appropriate error.
:param task: Managed object reference of the task
:param event: Event that captures task status
"""
try:
task_info = self.invoke_api(vim_util, 'get_object_property',
self.vim, task, 'info')
if task_info.state in ['queued', 'running']:
# If task already completed on server, it will not return
# the progress.
if hasattr(task_info, 'progress'):
LOG.debug("Task: %(task)s progress: %(prog)s." %
{'task': task, 'prog': task_info.progress})
return
elif task_info.state == 'success':
LOG.debug("Task %s status: success." % task)
else:
error_msg = str(task_info.error.localizedMessage)
LOG.exception(_LE("Task: %(task)s failed with "
"error: %(err)s.") %
{'task': task, 'err': error_msg})
raise error_util.VimFaultException([], error_msg)
except Exception as excep:
LOG.exception(_LE("Task: %(task)s failed with "
"error: %(err)s.") %
{'task': task, 'err': excep})
raise excep
# got the result. So stop the loop.
raise loopingcall.LoopingCallDone(task_info)
def _wait_for_state_change(self, volume_id, original_state, expected_state,
middle_state):
"""
Utility method to wait for a volume to change to the
expected state.
The process of some operation contains three states.
during the operation. If the operation has no middle state,
it can be set as original state.
"""
volume = None
try:
volume = PowerVCService._client.volumes.get(volume_id)
except exceptions.NotFound:
raise exception.VolumeNotFound('volume not found: %s' % volume_id)
if volume.status == expected_state:
LOG.debug("Operation %(vm_id)s successfully, " +
"status changed to %(state)s" % {
'vm_id': volume.id,
'state': expected_state
})
raise loopingcall.LoopingCallDone()
if (volume.status != original_state and volume.status != expected_state
and volume.status != middle_state):
raise exception.InvalidVolume()
def _loop_func():
LOG.debug("Entering _wait_run_delete_lun_snapshot loop: "
"vol=%(vol)s, snap_id=%(snap_id)s, oid=%(oid)s" % {
'vol': cinder_volume_id,
'oid': oid,
'snap_id': cinder_snapshot_id
})
ans = self.vmem_mg.snapshot.delete_lun_snapshot(
snapshot_object_id=oid)
if ans['success']:
LOG.debug("Delete snapshot %(snap_id)s for %(vol)s: "
"success" % {
'vol': cinder_volume_id,
'snap_id': cinder_snapshot_id
})
raise loopingcall.LoopingCallDone(retvalue=True)
else:
LOG.warn(
_("Delete snapshot %(snap)s of %(vol)s "
"encountered temporary error: %(msg)s") % {
'snap': cinder_snapshot_id,
'vol': cinder_volume_id,
'msg': ans['msg']
})
def _wait_for_task(task_id):
status = self.client.getTask(task_id)
LOG.debug("3PAR Task id %(id)s status = %(status)s" %
{'id': task_id,
'status': status['status']})
if status['status'] is not self.client.TASK_ACTIVE:
self._task_status = status
raise loopingcall.LoopingCallDone()
def _wait_routine():
# unfortunately, the array API at this time doesn't have any
# way to poll. In the future we will add that ability and
# this routine is where were will poll for ready.
if self._looping_count == 0:
self._looping_count += 1
else:
raise loopingcall.LoopingCallDone()
def _wait_for_pair_status(self, pvol, svol, is_vvol,
status, timeout, start):
if self._comm_pairevtwait(pvol, svol, is_vvol) in status:
raise loopingcall.LoopingCallDone()
if time.time() - start >= timeout:
msg = basic_lib.output_err(
637, method='_wait_for_pair_status', timeout=timeout)
raise exception.HBSDError(message=msg)
def _wait_for_lun_ready(volumename, start_time):
# executing cli command to check volume
command_to_verify = ('lun', '-list', '-name', volumename)
out, rc = self._cli_execute(*command_to_verify)
if rc == 0 and out.find("Ready") > -1:
raise loopingcall.LoopingCallDone()
if int(time.time()) - start_time > self.timeout * 60:
msg = (_('LUN %s failed to become Ready'), volumename)
LOG.error(msg)
raise exception.VolumeBackendAPIException(data=msg)
def _wait_for_sync():
"""Called at an interval until the synchronization is finished"""
if self._is_sync_complete(conn, syncName):
raise loopingcall.LoopingCallDone()
if self.retries > JOB_RETRIES:
LOG.error(_("_wait_for_sync failed after %(retries)d tries")
% {'retries': self.retries})
raise loopingcall.LoopingCallDone()
try:
self.retries += 1
if not self.wait_for_sync_called:
if self._is_sync_complete(conn, syncName):
self.wait_for_sync_called = True
except Exception as e:
LOG.error(_("Exception: %s") % six.text_type(e))
exceptionMessage = (_("Issue encountered waiting for "
"synchronization."))
LOG.error(exceptionMessage)
raise exception.VolumeBackendAPIException(exceptionMessage)
def _inner():
try:
res = func()
except Exception as ex:
raise exception.VolumeBackendAPIException(data=ex)
if res:
raise loopingcall.LoopingCallDone()
if int(time.time()) - start_time > timeout:
msg = (_('wait_for_condition: %s timed out.') % func.__name__)
LOG.error(msg)
raise exception.VolumeBackendAPIException(data=msg)
def _loop_func():
status = [False, False]
mg_conns = [self.common.mga, self.common.mgb]
LOG.debug("Entering _wait_for_targetstate loop: target=%s.",
target_name)
for node_id in xrange(2):
resp = mg_conns[node_id].basic.get_node_values(bn)
if len(resp.keys()):
status[node_id] = True
if status[0] and status[1]:
raise loopingcall.LoopingCallDone(retvalue=True)
def _wait_for_job_complete():
"""Called at an interval until the job is finished"""
retries = kwargs['retries']
wait_for_job_called = kwargs['wait_for_job_called']
if self._is_job_finished(conn, job):
raise loopingcall.LoopingCallDone()
if retries > JOB_RETRIES:
LOG.error(_LE("_wait_for_job_complete "
"failed after %(retries)d "
"tries."),
{'retries': retries})
raise loopingcall.LoopingCallDone()
try:
kwargs['retries'] = retries + 1
if not wait_for_job_called:
if self._is_job_finished(conn, job):
kwargs['wait_for_job_called'] = True
except Exception as e:
LOG.error(_LE("Exception: %s") % six.text_type(e))
exceptionMessage = (_("Issue encountered waiting for job."))
LOG.error(exceptionMessage)
raise exception.VolumeBackendAPIException(exceptionMessage)
def _loop_func():
LOG.debug(
"Entering _wait_for_lun_or_snap_copy loop: "
"vdev=%s, objid=%s", dest_vdev_id, dest_obj_id)
target_id, mb_copied, percent = wait_func(src_vol_id)
if target_id is None:
# pre-copy transient result
LOG.debug("lun or snap copy prepping.")
pass
elif target_id != wait_id:
# the copy is complete, another lun is being copied
LOG.debug("lun or snap copy complete.")
raise loopingcall.LoopingCallDone(retvalue=True)
elif mb_copied is not None:
# copy is in progress
LOG.debug("MB copied:%d, percent done: %d.", mb_copied,
percent)
pass
elif percent == 0:
# copy has just started
LOG.debug("lun or snap copy started.")
pass
elif percent == 100:
# copy is complete
LOG.debug("lun or snap copy complete.")
raise loopingcall.LoopingCallDone(retvalue=True)
else:
# unexpected case
LOG.debug(
"unexpected case (%{id}s, %{bytes}s, %{percent}s)", {
'id': str(target_id),
'bytes': str(mb_copied),
'percent': str(percent)
})
raise loopingcall.LoopingCallDone(retvalue=False)
def _loop_func(state):
status = [False, False]
mg_conns = [self.mga, self.mgb]
LOG.debug("Entering _wait_for_export_config loop: state=%s.",
state)
for node_id in xrange(2):
resp = mg_conns[node_id].basic.get_node_values(bn)
if state and len(resp.keys()):
status[node_id] = True
elif (not state) and (not len(resp.keys())):
status[node_id] = True
if status[0] and status[1]:
raise loopingcall.LoopingCallDone(retvalue=True)
def _wait_for_sync_status(volumename, start_time):
lun_list = ('lun', '-list', '-name', volumename,
'-attachedSnapshot')
out, rc = self._cli_execute(*lun_list)
if rc == 0:
vol_details = out.split('\n')
snapshotname = vol_details[2].split(':')[1].strip()
if (snapshotname == 'N/A'):
raise loopingcall.LoopingCallDone()
else:
LOG.info(_('Waiting for the update on Sync status of %s'),
volumename)
if int(time.time()) - start_time >= self.timeout * 60:
msg = (_('Failed to really migrate %s'), volumename)
LOG.error(msg)
raise exception.VolumeBackendAPIException(data=msg)
def _inner():
try:
testValue = testmethod()
except Exception as ex:
testValue = False
LOG.debug('Helper.'
'_wait_for_condition: %(method_name)s '
'execution failed for %(exception)s',
{'method_name': testmethod.__name__,
'exception': ex.message})
if testValue:
raise loopingcall.LoopingCallDone()
if int(time.time()) - start_time > timeout:
msg = (_('CommandLineHelper._wait_for_condition: %s timeout')
% testmethod.__name__)
LOG.error(msg)
raise exception.VolumeBackendAPIException(data=msg)
def _wait_for_volume_removal(volume_path):
LOG.debug("Waiting for SCSI mount point %s to be removed.",
volume_path)
if os.path.exists(volume_path):
if self.tries >= self.scan_attempts:
msg = _LE("Exceeded the number of attempts to detect "
"volume removal.")
LOG.error(msg)
raise exception.VolumePathNotRemoved(
volume_path=volume_path)
LOG.debug("%(path)s still exists, rescanning. Try number: "
"%(tries)s",
{'path': volume_path, 'tries': self.tries})
self.tries = self.tries + 1
else:
LOG.debug("SCSI mount point %s has been removed.", volume_path)
raise loopingcall.LoopingCallDone()
def _func(*args, **kwargs):
try:
result = f(*args, **kwargs)
except self._exceptions as excep:
LOG.exception(_LE("Failure while invoking function: "
"%(func)s. Error: %(excep)s.") %
{'func': f.__name__, 'excep': excep})
if (self._max_retry_count != -1 and
self._retry_count >= self._max_retry_count):
raise excep
else:
self._retry_count += 1
self._sleep_time += self._inc_sleep_time
return self._sleep_time
except Exception as excep:
raise excep
# got result. Stop the loop.
raise loopingcall.LoopingCallDone(result)
def _wait_for_device_discovery(host_devices):
tries = self.tries
for device in host_devices:
LOG.debug(_("Looking for Fibre Channel dev %(device)s"),
{'device': device})
if os.path.exists(device):
self.host_device = device
# get the /dev/sdX device. This is used
# to find the multipath device.
self.device_name = os.path.realpath(device)
raise loopingcall.LoopingCallDone()
if self.tries >= CONF.num_iscsi_scan_tries:
msg = _("Fibre Channel device not found.")
raise exception.CinderException(msg)
LOG.warn(_("Fibre volume not yet found. "
"Will rescan & retry. Try number: %(tries)s"),
{'tries': tries})
self._linuxfc.rescan_hosts(hbas)
self.tries = self.tries + 1
def _wait_for_add_chap_user(self, cmd, auth_username, auth_password,
start):
# Don't move 'import pexpect' to the beginning of the file so that
# a tempest can work.
import pexpect
lock = basic_lib.get_process_lock(self.hsnm_lock_file)
with self.hsnm_lock, lock:
try:
child = pexpect.spawn(cmd)
child.expect('Secret: ', timeout=CHAP_TIMEOUT)
child.sendline(auth_password)
child.expect('Re-enter Secret: ', timeout=CHAP_TIMEOUT)
child.sendline(auth_password)
child.expect(
'The CHAP user information has '
'been added successfully.',
timeout=CHAP_TIMEOUT)
except Exception:
if time.time() - start >= EXEC_TIMEOUT:
msg = basic_lib.output_err(642, user=auth_username)
raise exception.HBSDError(message=msg)
else:
raise loopingcall.LoopingCallDone(True)
