def wait_for_image_status(client, image_id, status):
"""Waits for an image to reach a given status.
The client should have a get_image(image_id) method to get the image.
The client should also have build_interval and build_timeout attributes.
"""
image = client.get_image(image_id)
start = int(time.time())
while image['status'] != status:
time.sleep(client.build_interval)
image = client.get_image(image_id)
status_curr = image['status']
if status_curr == 'ERROR':
raise exceptions.AddImageException(image_id=image_id)
# check the status again to avoid a false negative where we hit
# the timeout at the same time that the image reached the expected
# status
if status_curr == status:
return
if int(time.time()) - start >= client.build_timeout:
message = ('Image %(image_id)s failed to reach %(status)s state'
'(current state %(status_curr)s) '
'within the required time (%(timeout)s s).' %
{'image_id': image_id,
'status': status,
'status_curr': status_curr,
'timeout': client.build_timeout})
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
def _log_request_start(self, method, req_url, req_headers={},
req_body=None):
caller_name = misc_utils.find_test_caller()
trace_regex = CONF.debug.trace_requests
if trace_regex and re.search(trace_regex, caller_name):
self.LOG.debug('Starting Request (%s): %s %s' %
(caller_name, method, req_url))
def wait_for_image_status(client, image_id, status):
"""Waits for an image to reach a given status.
The client should have a get_image(image_id) method to get the image.
The client should also have build_interval and build_timeout attributes.
"""
image = client.get_image(image_id)
start = int(time.time())
while image['status'] != status:
time.sleep(client.build_interval)
image = client.get_image(image_id)
status_curr = image['status']
if status_curr == 'ERROR':
raise exceptions.AddImageException(image_id=image_id)
# check the status again to avoid a false negative where we hit
# the timeout at the same time that the image reached the expected
# status
if status_curr == status:
return
if int(time.time()) - start >= client.build_timeout:
message = ('Image %(image_id)s failed to reach %(status)s state'
'(current state %(status_curr)s) '
'within the required time (%(timeout)s s).' % {
'image_id': image_id,
'status': status,
'status_curr': status_curr,
'timeout': client.build_timeout
})
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
def _log_request(self,
method,
req_url,
resp,
secs="",
req_headers=None,
req_body=None,
resp_body=None):
if req_headers is None:
req_headers = {}
# if we have the request id, put it in the right part of the log
extra = dict(request_id=self._get_request_id(resp))
# NOTE(sdague): while we still have 6 callers to this function
# we're going to just provide work around on who is actually
# providing timings by gracefully adding no content if they don't.
# Once we're down to 1 caller, clean this up.
caller_name = misc_utils.find_test_caller()
if secs:
secs = " %.3fs" % secs
if not self.LOG.isEnabledFor(real_logging.DEBUG):
self.LOG.info('Request (%s): %s %s %s%s' %
(caller_name, resp['status'], method, req_url, secs),
extra=extra)
# Also look everything at DEBUG if you want to filter this
# out, don't run at debug.
self._log_request_full(method, req_url, resp, secs, req_headers,
req_body, resp_body, caller_name, extra)
def _log_request(self, method, req_url, resp,
secs="", req_headers=None,
req_body=None, resp_body=None):
if req_headers is None:
req_headers = {}
# if we have the request id, put it in the right part of the log
extra = dict(request_id=self._get_request_id(resp))
# NOTE(sdague): while we still have 6 callers to this function
# we're going to just provide work around on who is actually
# providing timings by gracefully adding no content if they don't.
# Once we're down to 1 caller, clean this up.
caller_name = misc_utils.find_test_caller()
if secs:
secs = " %.3fs" % secs
if not self.LOG.isEnabledFor(real_logging.DEBUG):
self.LOG.info(
'Request (%s): %s %s %s%s' % (
caller_name,
resp['status'],
method,
req_url,
secs),
extra=extra)
# Also look everything at DEBUG if you want to filter this
# out, don't run at debug.
self._log_request_full(method, req_url, resp, secs, req_headers,
req_body, resp_body, caller_name, extra)
def wait_for_bm_node_status(client, node_id, attr, status):
"""Waits for a baremetal node attribute to reach given status.
The client should have a show_node(node_uuid) method to get the node.
"""
_, node = client.show_node(node_id)
start = int(time.time())
while node[attr] != status:
time.sleep(client.build_interval)
_, node = client.show_node(node_id)
status_curr = node[attr]
if status_curr == status:
return
if int(time.time()) - start >= client.build_timeout:
message = ('Node %(node_id)s failed to reach %(attr)s=%(status)s '
'within the required time (%(timeout)s s).' % {
'node_id': node_id,
'attr': attr,
'status': status,
'timeout': client.build_timeout
})
message += ' Current state of %s: %s.' % (attr, status_curr)
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
def wait_for_image_status(self, image_id, status):
"""Waits for a Image to reach a given status."""
start_time = time.time()
old_value = value = self._get_image_status(image_id)
while True:
dtime = time.time() - start_time
time.sleep(self.build_interval)
if value != old_value:
LOG.info(
'Value transition from "%s" to "%s"'
'in %d second(s).', old_value, value, dtime)
if value == status:
return value
if value == 'killed':
raise exceptions.ImageKilledException(image_id=image_id,
status=status)
if dtime > self.build_timeout:
message = ('Time Limit Exceeded! (%ds)'
'while waiting for %s, '
'but we got %s.' %
(self.build_timeout, status, value))
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
time.sleep(self.build_interval)
old_value = value
value = self._get_image_status(image_id)
def wait_for_resource_status(self, fetch, status, interval=None,
timeout=None):
"""
@summary: Waits for a network resource to reach a status
@param fetch: the callable to be used to query the resource status
@type fecth: callable that takes no parameters and returns the resource
@param status: the status that the resource has to reach
@type status: String
@param interval: the number of seconds to wait between each status
query
@type interval: Integer
@param timeout: the maximum number of seconds to wait for the resource
to reach the desired status
@type timeout: Integer
"""
if not interval:
interval = self.build_interval
if not timeout:
timeout = self.build_timeout
start_time = time.time()
while time.time() - start_time <= timeout:
resource = fetch()
if resource['status'] == status:
return
time.sleep(interval)
# At this point, the wait has timed out
message = 'Resource %s' % (str(resource))
message += ' failed to reach status %s' % status
message += ' within the required time %s' % timeout
caller = misc.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
def wait_for_bm_node_status(client, node_id, attr, status):
"""Waits for a baremetal node attribute to reach given status.
The client should have a show_node(node_uuid) method to get the node.
"""
_, node = client.show_node(node_id)
start = int(time.time())
while node[attr] != status:
time.sleep(client.build_interval)
_, node = client.show_node(node_id)
status_curr = node[attr]
if status_curr == status:
return
if int(time.time()) - start >= client.build_timeout:
message = ('Node %(node_id)s failed to reach %(attr)s=%(status)s '
'within the required time (%(timeout)s s).' %
{'node_id': node_id,
'attr': attr,
'status': status,
'timeout': client.build_timeout})
message += ' Current state of %s: %s.' % (attr, status_curr)
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
def wait_for_image_status(self, image_id, status):
"""Waits for a Image to reach a given status."""
start_time = time.time()
old_value = value = self._get_image_status(image_id)
while True:
dtime = time.time() - start_time
time.sleep(self.build_interval)
if value != old_value:
LOG.info('Value transition from "%s" to "%s"'
'in %d second(s).', old_value,
value, dtime)
if value == status:
return value
if value == 'killed':
raise exceptions.ImageKilledException(image_id=image_id,
status=status)
if dtime > self.build_timeout:
message = ('Time Limit Exceeded! (%ds)'
'while waiting for %s, '
'but we got %s.' %
(self.build_timeout, status, value))
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
time.sleep(self.build_interval)
old_value = value
value = self._get_image_status(image_id)
def _log_request_start(self, method, req_url, req_headers=None,
req_body=None):
if req_headers is None:
req_headers = {}
caller_name = misc_utils.find_test_caller()
trace_regex = CONF.debug.trace_requests
if trace_regex and re.search(trace_regex, caller_name):
self.LOG.debug('Starting Request (%s): %s %s' %
(caller_name, method, req_url))
def _log_request(self, method, req_url, resp,
secs="", req_headers=None,
req_body=None, resp_body=None):
if req_headers is None:
req_headers = {}
# if we have the request id, put it in the right part of the log
extra = dict(request_id=self._get_request_id(resp))
# NOTE(sdague): while we still have 6 callers to this function
# we're going to just provide work around on who is actually
# providing timings by gracefully adding no content if they don't.
# Once we're down to 1 caller, clean this up.
caller_name = misc_utils.find_test_caller()
if secs:
secs = " %.3fs" % secs
self.LOG.info(
'Request (%s): %s %s %s%s' % (
caller_name,
resp['status'],
method,
req_url,
secs),
extra=extra)
# We intentionally duplicate the info content because in a parallel
# world this is important to match
trace_regex = CONF.debug.trace_requests
if trace_regex and re.search(trace_regex, caller_name):
if 'X-Auth-Token' in req_headers:
req_headers['X-Auth-Token'] = '<omitted>'
log_fmt = """Request (%s): %s %s %s%s
Request - Headers: %s
Body: %s
Response - Headers: %s
Body: %s"""
self.LOG.debug(
log_fmt % (
caller_name,
resp['status'],
method,
req_url,
secs,
str(req_headers),
filter(lambda x: x in string.printable,
str(req_body)[:2048]),
str(resp),
filter(lambda x: x in string.printable,
str(resp_body)[:2048])),
extra=extra)
def wait_for_resource_deletion(self, id):
"""Waits for a resource to be deleted."""
start_time = int(time.time())
while True:
if self.is_resource_deleted(id):
return
if int(time.time()) - start_time >= self.build_timeout:
message = ('Failed to delete resource %(id)s within the '
'required time (%(timeout)s s).' %
{'id': id, 'timeout': self.build_timeout})
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
time.sleep(self.build_interval)
def wait_for_resource_deletion(self, id):
"""Waits for a resource to be deleted."""
start_time = int(time.time())
while True:
if self.is_resource_deleted(id):
return
if int(time.time()) - start_time >= self.build_timeout:
message = ('Failed to delete %(resource_type)s %(id)s within '
'the required time (%(timeout)s s).' %
{'resource_type': self.resource_type, 'id': id,
'timeout': self.build_timeout})
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
time.sleep(self.build_interval)
def test_find_test_caller_test_case(self):
# Calling it from here should give us the method we're in.
self.assertEqual('TestMisc:test_find_test_caller_test_case',
misc.find_test_caller())
def log_request(self, request_kwargs, response):
test_name = misc_utils.find_test_caller()
str_request = self.stringify_request(request_kwargs, response)
LOG.info('Request (%s)\n %s', test_name, str_request)
def tearDownClass(cls):
return misc.find_test_caller()
def tearDown():
return misc.find_test_caller()
def setUpClass(cls): # noqa
return misc.find_test_caller()
def setUp():
return misc.find_test_caller()
def test_find_test_caller_test_case(self):
# Calling it from here should give us the method we're in.
self.assertEqual('TestMisc:test_find_test_caller_test_case',
misc.find_test_caller())
def wait_for_server_status(client,
server_id,
status,
ready_wait=True,
extra_timeout=0,
raise_on_error=True):
"""Waits for a server to reach a given status."""
def _get_task_state(body):
return body.get('OS-EXT-STS:task_state', None)
# NOTE(afazekas): UNKNOWN status possible on ERROR
# or in a very early stage.
body = client.get_server(server_id)
old_status = server_status = body['status']
old_task_state = task_state = _get_task_state(body)
start_time = int(time.time())
timeout = client.build_timeout + extra_timeout
while True:
# NOTE(afazekas): Now the BUILD status only reached
# between the UNKNOWN->ACTIVE transition.
# TODO(afazekas): enumerate and validate the stable status set
if status == 'BUILD' and server_status != 'UNKNOWN':
return
if server_status == status:
if ready_wait:
if status == 'BUILD':
return
# NOTE(afazekas): The instance is in "ready for action state"
# when no task in progress
# NOTE(afazekas): Converted to string bacuse of the XML
# responses
if str(task_state) == "None":
# without state api extension 3 sec usually enough
time.sleep(CONF.compute.ready_wait)
return
else:
return
time.sleep(client.build_interval)
body = client.get_server(server_id)
server_status = body['status']
task_state = _get_task_state(body)
if (server_status != old_status) or (task_state != old_task_state):
LOG.info('State transition "%s" ==> "%s" after %d second wait',
'/'.join((old_status, str(old_task_state))), '/'.join(
(server_status, str(task_state))),
time.time() - start_time)
if (server_status == 'ERROR') and raise_on_error:
if 'fault' in body:
raise exceptions.BuildErrorException(body['fault'],
server_id=server_id)
else:
raise exceptions.BuildErrorException(server_id=server_id)
timed_out = int(time.time()) - start_time >= timeout
if timed_out:
expected_task_state = 'None' if ready_wait else 'n/a'
message = ('Server %(server_id)s failed to reach %(status)s '
'status and task state "%(expected_task_state)s" '
'within the required time (%(timeout)s s).' % {
'server_id': server_id,
'status': status,
'expected_task_state': expected_task_state,
'timeout': timeout
})
message += ' Current status: %s.' % server_status
message += ' Current task state: %s.' % task_state
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
old_status = server_status
old_task_state = task_state
def setUp():
return misc.find_test_caller()
def setUpClass(cls): # noqa
return misc.find_test_caller()
def tearDown():
return misc.find_test_caller()
def tearDownClass(cls):
return misc.find_test_caller()
def wait_for_server_status(client, server_id, status, ready_wait=True,
extra_timeout=0, raise_on_error=True):
"""Waits for a server to reach a given status."""
def _get_task_state(body):
return body.get('OS-EXT-STS:task_state', None)
# NOTE(afazekas): UNKNOWN status possible on ERROR
# or in a very early stage.
resp, body = client.get_server(server_id)
old_status = server_status = body['status']
old_task_state = task_state = _get_task_state(body)
start_time = int(time.time())
timeout = client.build_timeout + extra_timeout
while True:
# NOTE(afazekas): Now the BUILD status only reached
# between the UNKNOWN->ACTIVE transition.
# TODO(afazekas): enumerate and validate the stable status set
if status == 'BUILD' and server_status != 'UNKNOWN':
return
if server_status == status:
if ready_wait:
if status == 'BUILD':
return
# NOTE(afazekas): The instance is in "ready for action state"
# when no task in progress
# NOTE(afazekas): Converted to string bacuse of the XML
# responses
if str(task_state) == "None":
# without state api extension 3 sec usually enough
time.sleep(CONF.compute.ready_wait)
return
else:
return
time.sleep(client.build_interval)
resp, body = client.get_server(server_id)
server_status = body['status']
task_state = _get_task_state(body)
if (server_status != old_status) or (task_state != old_task_state):
LOG.info('State transition "%s" ==> "%s" after %d second wait',
'/'.join((old_status, str(old_task_state))),
'/'.join((server_status, str(task_state))),
time.time() - start_time)
if (server_status == 'ERROR') and raise_on_error:
if 'fault' in body:
raise exceptions.BuildErrorException(body['fault'],
server_id=server_id)
else:
raise exceptions.BuildErrorException(server_id=server_id)
timed_out = int(time.time()) - start_time >= timeout
if timed_out:
expected_task_state = 'None' if ready_wait else 'n/a'
message = ('Server %(server_id)s failed to reach %(status)s '
'status and task state "%(expected_task_state)s" '
'within the required time (%(timeout)s s).' %
{'server_id': server_id,
'status': status,
'expected_task_state': expected_task_state,
'timeout': timeout})
message += ' Current status: %s.' % server_status
message += ' Current task state: %s.' % task_state
caller = misc_utils.find_test_caller()
if caller:
message = '(%s) %s' % (caller, message)
raise exceptions.TimeoutException(message)
old_status = server_status
old_task_state = task_state
