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)

        # Also look everything at DEBUG if you want to filter this
        # out, don't run at debug.
        if self.LOG.isEnabledFor(real_logging.DEBUG):
            self._log_request_full(method, req_url, resp, secs, req_headers,
                                   req_body, resp_body, caller_name, extra)

    def wait_for_resource_status(self, fetch, status):
        """Waits for a network resource to reach a status

        @param fetch: the callable to be used to query the resource status
        @type fetch: callable that takes no parameters and returns the resource
        @param status: the status that the resource has to reach
        @type status: String
        """
        interval = self.build_interval
        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 += ' (current: %s)' % resource['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 wrapper(self, *args, **kwargs):
     try:
         return function(self, *args, **kwargs)
     except tempest.lib.exceptions.SSHTimeout:
         try:
             original_exception = sys.exc_info()
             caller = misc_utils.find_test_caller() or "not found"
             if self.server:
                 msg = 'Caller: %s. Timeout trying to ssh to server %s'
                 LOG.debug(msg, caller, self.server)
                 if self.log_console and self.servers_client:
                     try:
                         msg = 'Console log for server %s: %s'
                         console_log = (
                             self.servers_client.get_console_output(
                                 self.server['id'])['output'])
                         LOG.debug(msg, self.server['id'], console_log)
                     except Exception:
                         msg = 'Could not get console_log for server %s'
                         LOG.debug(msg, self.server['id'])
             # re-raise the original ssh timeout exception
             six.reraise(*original_exception)
         finally:
             # Delete the traceback to avoid circular references
             _, _, trace = original_exception
             del trace

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 get_tenant_network(creds_provider, compute_networks_client,
                       shared_network_name):
    """Get a network usable by the primary tenant

    :param creds_provider: instance of credential provider
    :param compute_networks_client: compute network client. We want to have the
           compute network client so we can have use a common approach for both
           neutron and nova-network cases. If this is not an admin network
           client, set_network_kwargs might fail in case fixed_network_name
           is the network to be used, and it's not visible to the tenant
    :param shared_network_name: name of the shared network to be used if no
           tenant network is available in the creds provider
    :returns: a dict with 'id' and 'name' of the network
    """
    caller = misc_utils.find_test_caller()
    net_creds = creds_provider.get_primary_creds()
    network = getattr(net_creds, 'network', None)
    if not network or not network.get('name'):
        if shared_network_name:
            msg = ('No valid network provided or created, defaulting to '
                   'fixed_network_name')
            if caller:
                msg = '(%s) %s' % (caller, msg)
            LOG.debug(msg)
            try:
                network = get_network_from_name(shared_network_name,
                                                compute_networks_client)
            except exceptions.InvalidTestResource:
                network = {}
    msg = ('Found network %s available for tenant' % network)
    if caller:
        msg = '(%s) %s' % (caller, msg)
    LOG.info(msg)
    return network

    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_zone_import_status(client, zone_import_id, status):
    """Waits for an imported zone to reach the given status."""
    LOG.info('Waiting for zone import %s to reach %s', zone_import_id, status)

    _, zone_import = client.show_zone_import(zone_import_id)
    start = int(time.time())

    while zone_import['status'] != status:
        time.sleep(client.build_interval)
        _, zone_import = client.show_zone_import(zone_import_id)
        status_curr = zone_import['status']
        if status_curr == status:
            LOG.info('Zone import %s reached %s', zone_import_id, status)
            return

        if int(time.time()) - start >= client.build_timeout:
            message = ('Zone import %(zone_import_id)s failed to reach '
                       'status=%(status)s within the required time '
                       '(%(timeout)s s). Current '
                       'status: %(status_curr)s' %
                       {'zone_import_id': zone_import_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 lib_exc.TimeoutException(message)

def wait_for_zone_404(client, zone_id):
    """Waits for a zone to 404."""
    LOG.info('Waiting for zone %s to 404', zone_id)
    start = int(time.time())

    while True:
        time.sleep(client.build_interval)

        try:
            _, zone = client.show_zone(zone_id)
        except lib_exc.NotFound:
            LOG.info('Zone %s is 404ing', zone_id)
            return

        if int(time.time()) - start >= client.build_timeout:
            message = ('Zone %(zone_id)s failed to 404 within the required '
                       'time (%(timeout)s s). Current status: '
                       '%(status_curr)s' %
                       {'zone_id': zone_id,
                        'status_curr': zone['status'],
                        'timeout': client.build_timeout})

            caller = misc_utils.find_test_caller()

            if caller:
                message = '(%s) %s' % (caller, message)

            raise lib_exc.TimeoutException(message)

    def wait_for_resource_deletion(self, id):
        """Waits for a resource to be deleted

        This method will loop over is_resource_deleted until either
        is_resource_deleted returns True or the build timeout is reached. This
        depends on is_resource_deleted being implemented

        :param str id: The id of the resource to check
        :raises TimeoutException: If the build_timeout has elapsed and the
                                  resource still hasn't been 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 _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()
     if self.trace_requests and re.search(self.trace_requests, caller_name):
         self.LOG.debug('Starting Request (%s): %s %s' %
                        (caller_name, method, req_url))

 def log_request(self, request_kwargs, response, user_name):
     test_name = misc_utils.find_test_caller()
     str_request = self.stringify_request(request_kwargs, response)
     if user_name is None:
         user_info = ''
     else:
         user_info = "(user={0})".format(user_name)
     LOG.info('Request %s (%s)\n %s',
              user_info,
              test_name,
              str_request)

def wait_for_bm_node_status(client, node_id, attr, status, timeout=None,
                            interval=None):
    """Waits for a baremetal node attribute to reach given status.

    :param client: an instance of tempest plugin BaremetalClient.
    :param node_id: identifier of the node.
    :param attr: node's API-visible attribute to check status of.
    :param status: desired status.
    :param timeout: the timeout after which the check is considered as failed.
        Defaults to client.build_timeout.
    :param interval: an interval between show_node calls for status check.
        Defaults to client.build_interval.

    The client should have a show_node(node_id) method to get the node.
    """
    if timeout is None:
        timeout = client.build_timeout
    if interval is None:
        interval = client.build_interval
    if timeout < 0 or interval < 0:
        raise lib_exc.InvalidConfiguration(
            'timeout and interval should be >= 0 or None, current values are: '
            '%(timeout)s, %(interval)s respectively.' % dict(timeout=timeout,
                                                             interval=interval)
        )

    start = int(time.time())
    _, node = client.show_node(node_id)

    while node[attr] != status:
        status_curr = node[attr]
        if status_curr == status:
            return

        if int(time.time()) - start >= 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 lib_exc.TimeoutException(message)

        time.sleep(interval)
        _, node = client.show_node(node_id)

def get_network_from_name(name, compute_networks_client):
    """Get a full network dict from just a network name

    :param str name: the name of the network to use
    :param NetworksClient compute_networks_client: The network client
        object to use for making the network lists api request
    :return: The full dictionary for the network in question
    :rtype: dict
    :raises InvalidTestResource: If the name provided is invalid, the networks
        list returns a 404, there are no found networks, or the found network
        is invalid
    """
    caller = misc_utils.find_test_caller()

    if not name:
        raise exceptions.InvalidTestResource(type='network', name=name)

    networks = compute_networks_client.list_networks()['networks']
    networks = [n for n in networks if n['label'] == name]

    # Check that a network exists, else raise an InvalidConfigurationException
    if len(networks) == 1:
        network = sorted(networks)[0]
    elif len(networks) > 1:
        msg = ("Network with name: %s had multiple matching networks in the "
               "list response: %s\n Unable to specify a single network" % (
                   name, networks))
        if caller:
            msg = '(%s) %s' % (caller, msg)
        LOG.warning(msg)
        raise exceptions.InvalidTestResource(type='network', name=name)
    else:
        msg = "Network with name: %s not found" % name
        if caller:
            msg = '(%s) %s' % (caller, msg)
        LOG.warning(msg)
        raise exceptions.InvalidTestResource(type='network', name=name)
    # To be consistent between neutron and nova network always use name even
    # if label is used in the api response. If neither is present than then
    # the returned network is invalid.
    name = network.get('name') or network.get('label')
    if not name:
        msg = "Network found from list doesn't contain a valid name or label"
        if caller:
            msg = '(%s) %s' % (caller, msg)
        LOG.warning(msg)
        raise exceptions.InvalidTestResource(type='network', name=name)
    network['name'] = name
    return network

def wait_for_image_status(client, image_id, status):
    """Waits for an image to reach a given status.

    The client should have a show_image(image_id) method to get the image.
    The client should also have build_interval and build_timeout attributes.
    """
    if isinstance(client, images_v1_client.ImagesClient):
        # The 'check_image' method is used here because the show_image method
        # returns image details plus the image itself which is very expensive.
        # The 'check_image' method returns just image details.
        def _show_image_v1(image_id):
            resp = client.check_image(image_id)
            return common_image.get_image_meta_from_headers(resp)

        show_image = _show_image_v1
    else:
        show_image = client.show_image

    current_status = 'An unknown status'
    start = int(time.time())
    while int(time.time()) - start < client.build_timeout:
        image = show_image(image_id)
        # Compute image client returns response wrapped in 'image' element
        # which is not case with Glance image client.
        if 'image' in image:
            image = image['image']

        current_status = image['status']
        if current_status == status:
            return
        if current_status.lower() == 'killed':
            raise exceptions.ImageKilledException(image_id=image_id,
                                                  status=status)
        if current_status.lower() == 'error':
            raise exceptions.AddImageException(image_id=image_id)

        time.sleep(client.build_interval)

    message = ('Image %(image_id)s failed to reach %(status)s state '
               '(current state %(current_status)s) within the required '
               'time (%(timeout)s s).' % {'image_id': image_id,
                                          'status': status,
                                          'current_status': current_status,
                                          'timeout': client.build_timeout})
    caller = misc_utils.find_test_caller()
    if caller:
        message = '(%s) %s' % (caller, message)
    raise exceptions.TimeoutException(message)

def wait_for_query(client, name, rdatatype, found=True):
    """Query nameservers until the record of the given name and type is found.

    :param client: A QueryClient
    :param name: The record name for which to query
    :param rdatatype: The record type for which to query
    :param found: If True, wait until the record is found. Else, wait until the
        record disappears.
    """
    state = "found" if found else "removed"
    LOG.info("Waiting for record %s of type %s to be %s on nameservers %s",
             name, rdatatype, state, client.nameservers)
    start = int(time.time())

    while True:
        time.sleep(client.build_interval)

        responses = client.query(name, rdatatype)
        if found:
            all_answers_good = all(r.answer for r in responses)
        else:
            all_answers_good = all(not r.answer for r in responses)

        if not client.nameservers or all_answers_good:
            LOG.info("Record %s of type %s was successfully %s on nameservers "
                     "%s", name, rdatatype, state, client.nameservers)
            return

        if int(time.time()) - start >= client.build_timeout:
            message = ('Record %(name)s of type %(rdatatype)s not %(state)s '
                       'on nameservers %(nameservers)s within the required '
                       'time (%(timeout)s s)' %
                       {'name': name,
                        'rdatatype': rdatatype,
                        'state': state,
                        'nameservers': client.nameservers,
                        'timeout': client.build_timeout})

            caller = misc_utils.find_test_caller()
            if caller:
                message = "(%s) %s" % (caller, message)

            raise lib_exc.TimeoutException(message)

def wait_for_image_status(client, image_id, status):
    """Waits for an image to reach a given status.

    The client should have a show_image(image_id) method to get the image.
    The client should also have build_interval and build_timeout attributes.
    """
    image = client.show_image(image_id)
    # Compute image client return response wrapped in 'image' element
    # which is not case with glance image client.
    if 'image' in image:
        image = image['image']
    start = int(time.time())

    while image['status'] != status:
        time.sleep(client.build_interval)
        image = client.show_image(image_id)
        # Compute image client return response wrapped in 'image' element
        # which is not case with glance image client.
        if 'image' in image:
            image = image['image']
        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 wait_for_resource_status(self, fetch, status, interval=None,
                                 timeout=None):
        """This has different calling signature then rest_client.

        @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 += ' (current: %s)' % resource['status']
        message += ' within the required time %s' % timeout
        caller = misc_utils.find_test_caller()
        if caller:
            message = '(%s) %s' % (caller, message)
        raise exceptions.TimeoutException(message)

    def get_remote_client(self, ip, username=None):
        """Get a SSH client to a remote server

        :param server_or_ip: a server object as returned by Tempest compute
            client or an IP address to connect to
        :param username: name of the Linux account on the remote server
        :return: a RemoteClient object
        """
        if username is None:
            username = CONF.validation.image_ssh_user
        password = CONF.validation.image_ssh_password
        linux_client = ssh.Client(ip, username, password)

        try:
            linux_client.test_connection_auth()
        except Exception as e:
            message = ('Initializing SSH connection to %(ip)s failed. '
                       'Error: %(error)s' % {'ip': ip, 'error': e})
            caller = misc_utils.find_test_caller()
            if caller:
                message = '(%s) %s' % (caller, message)
            LOG.exception(message)
            raise
        return linux_client

 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(self, server_id, status, ready_wait=True,
                               extra_timeout=0, raise_on_error=True):
        """Waits for a server to reach a given status."""
        build_interval = CONF.compute.build_interval
        build_timeout = CONF.compute.build_timeout

        def _get_task_state(body):
            return body.get('OS-EXT-STS:task_state', None)
        rs_client = self._connect_server()
        resp, body = rs_client.get("servers/%s" % str(server_id))
        body = jsonutils.loads(body)
        old_status = server_status = body['server']['status']
        old_task_state = task_state = _get_task_state(body)
        start_time = int(time.time())
        timeout = build_timeout + extra_timeout
        while True:
            if status == 'BUILD' and server_status != 'UNKNOWN':
                return
            if server_status == status:
                if ready_wait:
                    if status == 'BUILD':
                        return
                    if str(task_state) == "None":
                        time.sleep(CONF.compute.ready_wait)
                        return
                else:
                    return

            time.sleep(build_interval)
            resp, body = rs_client.get("servers/%s" % str(server_id))
            body = jsonutils.loads(body)
            server_status = body['server']['status']
            task_state = _get_task_state(body)
            if (server_status != old_status) or (task_state != old_task_state):
                oldstatus = '/'.join((old_status, str(old_task_state)))
                serverstatus = '/'.join((server_status, str(task_state)))
                waitsec = (time.time() - start_time)
                LOG.info(
                    _LI('State transition %(oldstatus)s => %(serverstatus)s '
                        'after %(waitsec)d second wait'),
                    {'oldstatus': oldstatus, 'serverstatus': serverstatus,
                     'waitsec': waitsec}
                )
            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 lib_exc.TimeoutException(message)
            old_status = server_status
            old_task_state = task_state