Merge "olso log sync"
diff --git a/etc/tempest.conf.sample b/etc/tempest.conf.sample
index 858fce9..8a7ad9c 100644
--- a/etc/tempest.conf.sample
+++ b/etc/tempest.conf.sample
@@ -23,47 +23,48 @@
 # of default WARNING level). (boolean value)
 #verbose=false
 
-# Log output to standard error (boolean value)
+# Log output to standard error. (boolean value)
 #use_stderr=true
 
-# format string to use for log messages with context (string
+# Format string to use for log messages with context. (string
 # value)
 #logging_context_format_string=%(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [%(request_id)s %(user_identity)s] %(instance)s%(message)s
 
-# format string to use for log messages without context
+# Format string to use for log messages without context.
 # (string value)
 #logging_default_format_string=%(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [-] %(instance)s%(message)s
 
-# data to append to log format when level is DEBUG (string
+# Data to append to log format when level is DEBUG. (string
 # value)
 #logging_debug_format_suffix=%(funcName)s %(pathname)s:%(lineno)d
 
-# prefix each line of exception output with this format
+# Prefix each line of exception output with this format.
 # (string value)
 #logging_exception_prefix=%(asctime)s.%(msecs)03d %(process)d TRACE %(name)s %(instance)s
 
-# list of logger=LEVEL pairs (list value)
-#default_log_levels=amqp=WARN,amqplib=WARN,boto=WARN,qpid=WARN,sqlalchemy=WARN,suds=INFO,iso8601=WARN
+# List of logger=LEVEL pairs. (list value)
+#default_log_levels=amqp=WARN,amqplib=WARN,boto=WARN,qpid=WARN,sqlalchemy=WARN,suds=INFO,oslo.messaging=INFO,iso8601=WARN,requests.packages.urllib3.connectionpool=WARN,urllib3.connectionpool=WARN
 
-# publish error events (boolean value)
+# Enables or disables publication of error events. (boolean
+# value)
 #publish_errors=false
 
-# make deprecations fatal (boolean value)
+# Enables or disables fatal status of deprecations. (boolean
+# value)
 #fatal_deprecations=false
 
-# If an instance is passed with the log message, format it
-# like this (string value)
+# The format for an instance that is passed with the log
+# message. (string value)
 #instance_format="[instance: %(uuid)s] "
 
-# If an instance UUID is passed with the log message, format
-# it like this (string value)
+# The format for an instance UUID that is passed with the log
+# message. (string value)
 #instance_uuid_format="[instance: %(uuid)s] "
 
-# The name of logging configuration file. It does not disable
-# existing loggers, but just appends specified logging
-# configuration to any other existing logging options. Please
-# see the Python logging module documentation for details on
-# logging configuration files. (string value)
+# The name of a logging configuration file. This file is
+# appended to any existing logging configuration files. For
+# details about logging configuration files, see the Python
+# logging module documentation. (string value)
 # Deprecated group/name - [DEFAULT]/log_config
 #log_config_append=<None>
 
@@ -75,7 +76,7 @@
 #log_format=<None>
 
 # Format string for %%(asctime)s in log records. Default:
-# %(default)s (string value)
+# %(default)s . (string value)
 #log_date_format=%Y-%m-%d %H:%M:%S
 
 # (Optional) Name of log file to output to. If no default is
@@ -84,14 +85,23 @@
 #log_file=<None>
 
 # (Optional) The base directory used for relative --log-file
-# paths (string value)
+# paths. (string value)
 # Deprecated group/name - [DEFAULT]/logdir
 #log_dir=<None>
 
-# Use syslog for logging. (boolean value)
+# Use syslog for logging. Existing syslog format is DEPRECATED
+# during I, and will change in J to honor RFC5424. (boolean
+# value)
 #use_syslog=false
 
-# syslog facility to receive log lines (string value)
+# (Optional) Enables or disables syslog rfc5424 format for
+# logging. If enabled, prefixes the MSG part of the syslog
+# message with APP-NAME (RFC5424). The format without the APP-
+# NAME is deprecated in I, and will be removed in J. (boolean
+# value)
+#use_syslog_rfc_format=false
+
+# Syslog facility to receive log lines. (string value)
 #syslog_log_facility=LOG_USER
 
 
diff --git a/tempest/openstack/common/gettextutils.py b/tempest/openstack/common/gettextutils.py
index 6102e67..872d58e 100644
--- a/tempest/openstack/common/gettextutils.py
+++ b/tempest/openstack/common/gettextutils.py
@@ -23,7 +23,6 @@
 """
 
 import copy
-import functools
 import gettext
 import locale
 from logging import handlers
@@ -42,7 +41,7 @@
     """Create translator functions
     """
 
-    def __init__(self, domain, lazy=False, localedir=None):
+    def __init__(self, domain, localedir=None):
         """Establish a set of translation functions for the domain.
 
         :param domain: Name of translation domain,
@@ -55,7 +54,6 @@
         :type localedir: str
         """
         self.domain = domain
-        self.lazy = lazy
         if localedir is None:
             localedir = os.environ.get(domain.upper() + '_LOCALEDIR')
         self.localedir = localedir
@@ -75,16 +73,19 @@
         """
         if domain is None:
             domain = self.domain
-        if self.lazy:
-            return functools.partial(Message, domain=domain)
-        t = gettext.translation(
-            domain,
-            localedir=self.localedir,
-            fallback=True,
-        )
-        if six.PY3:
-            return t.gettext
-        return t.ugettext
+        t = gettext.translation(domain,
+                                localedir=self.localedir,
+                                fallback=True)
+        # Use the appropriate method of the translation object based
+        # on the python version.
+        m = t.gettext if six.PY3 else t.ugettext
+
+        def f(msg):
+            """oslo.i18n.gettextutils translation function."""
+            if USE_LAZY:
+                return Message(msg, domain=domain)
+            return m(msg)
+        return f
 
     @property
     def primary(self):
@@ -147,19 +148,11 @@
     your project is importing _ directly instead of using the
     gettextutils.install() way of importing the _ function.
     """
-    # FIXME(dhellmann): This function will be removed in oslo.i18n,
-    # because the TranslatorFactory makes it superfluous.
-    global _, _LI, _LW, _LE, _LC, USE_LAZY
-    tf = TranslatorFactory('tempest', lazy=True)
-    _ = tf.primary
-    _LI = tf.log_info
-    _LW = tf.log_warning
-    _LE = tf.log_error
-    _LC = tf.log_critical
+    global USE_LAZY
     USE_LAZY = True
 
 
-def install(domain, lazy=False):
+def install(domain):
     """Install a _() function using the given translation domain.
 
     Given a translation domain, install a _() function using gettext's
@@ -170,26 +163,14 @@
     a translation-domain-specific environment variable (e.g.
     NOVA_LOCALEDIR).
 
+    Note that to enable lazy translation, enable_lazy must be
+    called.
+
     :param domain: the translation domain
-    :param lazy: indicates whether or not to install the lazy _() function.
-                 The lazy _() introduces a way to do deferred translation
-                 of messages by installing a _ that builds Message objects,
-                 instead of strings, which can then be lazily translated into
-                 any available locale.
     """
-    if lazy:
-        from six import moves
-        tf = TranslatorFactory(domain, lazy=True)
-        moves.builtins.__dict__['_'] = tf.primary
-    else:
-        localedir = '%s_LOCALEDIR' % domain.upper()
-        if six.PY3:
-            gettext.install(domain,
-                            localedir=os.environ.get(localedir))
-        else:
-            gettext.install(domain,
-                            localedir=os.environ.get(localedir),
-                            unicode=True)
+    from six import moves
+    tf = TranslatorFactory(domain)
+    moves.builtins.__dict__['_'] = tf.primary
 
 
 class Message(six.text_type):
@@ -373,8 +354,8 @@
                'zh_Hant_HK': 'zh_HK',
                'zh_Hant': 'zh_TW',
                'fil': 'tl_PH'}
-    for (locale, alias) in six.iteritems(aliases):
-        if locale in language_list and alias not in language_list:
+    for (locale_, alias) in six.iteritems(aliases):
+        if locale_ in language_list and alias not in language_list:
             language_list.append(alias)
 
     _AVAILABLE_LANGUAGES[domain] = language_list
diff --git a/tempest/openstack/common/jsonutils.py b/tempest/openstack/common/jsonutils.py
index 53c0ad4..cb83557 100644
--- a/tempest/openstack/common/jsonutils.py
+++ b/tempest/openstack/common/jsonutils.py
@@ -31,25 +31,29 @@
 '''
 
 
+import codecs
 import datetime
 import functools
 import inspect
 import itertools
-import json
-try:
-    import xmlrpclib
-except ImportError:
-    # NOTE(jaypipes): xmlrpclib was renamed to xmlrpc.client in Python3
-    #                 however the function and object call signatures
-    #                 remained the same. This whole try/except block should
-    #                 be removed and replaced with a call to six.moves once
-    #                 six 1.4.2 is released. See http://bit.ly/1bqrVzu
-    import xmlrpc.client as xmlrpclib
+import sys
+
+if sys.version_info < (2, 7):
+    # On Python <= 2.6, json module is not C boosted, so try to use
+    # simplejson module if available
+    try:
+        import simplejson as json
+    except ImportError:
+        import json
+else:
+    import json
 
 import six
+import six.moves.xmlrpc_client as xmlrpclib
 
 from tempest.openstack.common import gettextutils
 from tempest.openstack.common import importutils
+from tempest.openstack.common import strutils
 from tempest.openstack.common import timeutils
 
 netaddr = importutils.try_import("netaddr")
@@ -164,12 +168,16 @@
     return json.dumps(value, default=default, **kwargs)
 
 
-def loads(s):
-    return json.loads(s)
+def dump(obj, fp, *args, **kwargs):
+    return json.dump(obj, fp, *args, **kwargs)
 
 
-def load(s):
-    return json.load(s)
+def loads(s, encoding='utf-8', **kwargs):
+    return json.loads(strutils.safe_decode(s, encoding), **kwargs)
+
+
+def load(fp, encoding='utf-8', **kwargs):
+    return json.load(codecs.getreader(encoding)(fp), **kwargs)
 
 
 try:
diff --git a/tempest/openstack/common/log.py b/tempest/openstack/common/log.py
index 7bebfdb..44102c0 100644
--- a/tempest/openstack/common/log.py
+++ b/tempest/openstack/common/log.py
@@ -15,7 +15,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-"""Openstack logging handler.
+"""OpenStack logging handler.
 
 This module adds to logging functionality by adding the option to specify
 a context object when calling the various log methods.  If the context object
@@ -33,7 +33,6 @@
 import logging.config
 import logging.handlers
 import os
-import re
 import sys
 import traceback
 
@@ -45,27 +44,13 @@
 from tempest.openstack.common import importutils
 from tempest.openstack.common import jsonutils
 from tempest.openstack.common import local
+# NOTE(flaper87): Pls, remove when graduating this module
+# from the incubator.
+from tempest.openstack.common.strutils import mask_password  # noqa
 
 
 _DEFAULT_LOG_DATE_FORMAT = "%Y-%m-%d %H:%M:%S"
 
-_SANITIZE_KEYS = ['adminPass', 'admin_pass', 'password', 'admin_password']
-
-# NOTE(ldbragst): Let's build a list of regex objects using the list of
-# _SANITIZE_KEYS we already have. This way, we only have to add the new key
-# to the list of _SANITIZE_KEYS and we can generate regular expressions
-# for XML and JSON automatically.
-_SANITIZE_PATTERNS = []
-_FORMAT_PATTERNS = [r'(%(key)s\s*[=]\s*[\"\']).*?([\"\'])',
-                    r'(<%(key)s>).*?(</%(key)s>)',
-                    r'([\"\']%(key)s[\"\']\s*:\s*[\"\']).*?([\"\'])',
-                    r'([\'"].*?%(key)s[\'"]\s*:\s*u?[\'"]).*?([\'"])']
-
-for key in _SANITIZE_KEYS:
-    for pattern in _FORMAT_PATTERNS:
-        reg_ex = re.compile(pattern % {'key': key}, re.DOTALL)
-        _SANITIZE_PATTERNS.append(reg_ex)
-
 
 common_cli_opts = [
     cfg.BoolOpt('debug',
@@ -84,14 +69,11 @@
     cfg.StrOpt('log-config-append',
                metavar='PATH',
                deprecated_name='log-config',
-               help='The name of logging configuration file. It does not '
-                    'disable existing loggers, but just appends specified '
-                    'logging configuration to any other existing logging '
-                    'options. Please see the Python logging module '
-                    'documentation for details on logging configuration '
-                    'files.'),
+               help='The name of a logging configuration file. This file '
+                    'is appended to any existing logging configuration '
+                    'files. For details about logging configuration files, '
+                    'see the Python logging module documentation.'),
     cfg.StrOpt('log-format',
-               default=None,
                metavar='FORMAT',
                help='DEPRECATED. '
                     'A logging.Formatter log message format string which may '
@@ -103,7 +85,7 @@
                default=_DEFAULT_LOG_DATE_FORMAT,
                metavar='DATE_FORMAT',
                help='Format string for %%(asctime)s in log records. '
-                    'Default: %(default)s'),
+                    'Default: %(default)s .'),
     cfg.StrOpt('log-file',
                metavar='PATH',
                deprecated_name='logfile',
@@ -112,67 +94,76 @@
     cfg.StrOpt('log-dir',
                deprecated_name='logdir',
                help='(Optional) The base directory used for relative '
-                    '--log-file paths'),
+                    '--log-file paths.'),
     cfg.BoolOpt('use-syslog',
                 default=False,
-                help='Use syslog for logging.'),
+                help='Use syslog for logging. '
+                     'Existing syslog format is DEPRECATED during I, '
+                     'and will change in J to honor RFC5424.'),
+    cfg.BoolOpt('use-syslog-rfc-format',
+                # TODO(bogdando) remove or use True after existing
+                #    syslog format deprecation in J
+                default=False,
+                help='(Optional) Enables or disables syslog rfc5424 format '
+                     'for logging. If enabled, prefixes the MSG part of the '
+                     'syslog message with APP-NAME (RFC5424). The '
+                     'format without the APP-NAME is deprecated in I, '
+                     'and will be removed in J.'),
     cfg.StrOpt('syslog-log-facility',
                default='LOG_USER',
-               help='syslog facility to receive log lines')
+               help='Syslog facility to receive log lines.')
 ]
 
 generic_log_opts = [
     cfg.BoolOpt('use_stderr',
                 default=True,
-                help='Log output to standard error')
+                help='Log output to standard error.')
 ]
 
+DEFAULT_LOG_LEVELS = ['amqp=WARN', 'amqplib=WARN', 'boto=WARN',
+                      'qpid=WARN', 'sqlalchemy=WARN', 'suds=INFO',
+                      'oslo.messaging=INFO', 'iso8601=WARN',
+                      'requests.packages.urllib3.connectionpool=WARN',
+                      'urllib3.connectionpool=WARN']
+
 log_opts = [
     cfg.StrOpt('logging_context_format_string',
                default='%(asctime)s.%(msecs)03d %(process)d %(levelname)s '
                        '%(name)s [%(request_id)s %(user_identity)s] '
                        '%(instance)s%(message)s',
-               help='format string to use for log messages with context'),
+               help='Format string to use for log messages with context.'),
     cfg.StrOpt('logging_default_format_string',
                default='%(asctime)s.%(msecs)03d %(process)d %(levelname)s '
                        '%(name)s [-] %(instance)s%(message)s',
-               help='format string to use for log messages without context'),
+               help='Format string to use for log messages without context.'),
     cfg.StrOpt('logging_debug_format_suffix',
                default='%(funcName)s %(pathname)s:%(lineno)d',
-               help='data to append to log format when level is DEBUG'),
+               help='Data to append to log format when level is DEBUG.'),
     cfg.StrOpt('logging_exception_prefix',
                default='%(asctime)s.%(msecs)03d %(process)d TRACE %(name)s '
                '%(instance)s',
-               help='prefix each line of exception output with this format'),
+               help='Prefix each line of exception output with this format.'),
     cfg.ListOpt('default_log_levels',
-                default=[
-                    'amqp=WARN',
-                    'amqplib=WARN',
-                    'boto=WARN',
-                    'qpid=WARN',
-                    'sqlalchemy=WARN',
-                    'suds=INFO',
-                    'iso8601=WARN',
-                ],
-                help='list of logger=LEVEL pairs'),
+                default=DEFAULT_LOG_LEVELS,
+                help='List of logger=LEVEL pairs.'),
     cfg.BoolOpt('publish_errors',
                 default=False,
-                help='publish error events'),
+                help='Enables or disables publication of error events.'),
     cfg.BoolOpt('fatal_deprecations',
                 default=False,
-                help='make deprecations fatal'),
+                help='Enables or disables fatal status of deprecations.'),
 
     # NOTE(mikal): there are two options here because sometimes we are handed
     # a full instance (and could include more information), and other times we
     # are just handed a UUID for the instance.
     cfg.StrOpt('instance_format',
                default='[instance: %(uuid)s] ',
-               help='If an instance is passed with the log message, format '
-                    'it like this'),
+               help='The format for an instance that is passed with the log '
+                    'message.'),
     cfg.StrOpt('instance_uuid_format',
                default='[instance: %(uuid)s] ',
-               help='If an instance UUID is passed with the log message, '
-                    'format it like this'),
+               help='The format for an instance UUID that is passed with the '
+                    'log message.'),
 ]
 
 CONF = cfg.CONF
@@ -231,40 +222,6 @@
     return None
 
 
-def mask_password(message, secret="***"):
-    """Replace password with 'secret' in message.
-
-    :param message: The string which includes security information.
-    :param secret: value with which to replace passwords.
-    :returns: The unicode value of message with the password fields masked.
-
-    For example:
-
-    >>> mask_password("'adminPass' : 'aaaaa'")
-    "'adminPass' : '***'"
-    >>> mask_password("'admin_pass' : 'aaaaa'")
-    "'admin_pass' : '***'"
-    >>> mask_password('"password" : "aaaaa"')
-    '"password" : "***"'
-    >>> mask_password("'original_password' : 'aaaaa'")
-    "'original_password' : '***'"
-    >>> mask_password("u'original_password' :   u'aaaaa'")
-    "u'original_password' :   u'***'"
-    """
-    message = six.text_type(message)
-
-    # NOTE(ldbragst): Check to see if anything in message contains any key
-    # specified in _SANITIZE_KEYS, if not then just return the message since
-    # we don't have to mask any passwords.
-    if not any(key in message for key in _SANITIZE_KEYS):
-        return message
-
-    secret = r'\g<1>' + secret + r'\g<2>'
-    for pattern in _SANITIZE_PATTERNS:
-        message = re.sub(pattern, secret, message)
-    return message
-
-
 class BaseLoggerAdapter(logging.LoggerAdapter):
 
     def audit(self, msg, *args, **kwargs):
@@ -282,6 +239,11 @@
     def logger(self):
         if not self._logger:
             self._logger = getLogger(self.name, self.version)
+            if six.PY3:
+                # In Python 3, the code fails because the 'manager' attribute
+                # cannot be found when using a LoggerAdapter as the
+                # underlying logger. Work around this issue.
+                self._logger.manager = self._logger.logger.manager
         return self._logger
 
 
@@ -292,18 +254,39 @@
         self.logger = logger
         self.project = project_name
         self.version = version_string
+        self._deprecated_messages_sent = dict()
 
     @property
     def handlers(self):
         return self.logger.handlers
 
     def deprecated(self, msg, *args, **kwargs):
+        """Call this method when a deprecated feature is used.
+
+        If the system is configured for fatal deprecations then the message
+        is logged at the 'critical' level and :class:`DeprecatedConfig` will
+        be raised.
+
+        Otherwise, the message will be logged (once) at the 'warn' level.
+
+        :raises: :class:`DeprecatedConfig` if the system is configured for
+                 fatal deprecations.
+
+        """
         stdmsg = _("Deprecated: %s") % msg
         if CONF.fatal_deprecations:
             self.critical(stdmsg, *args, **kwargs)
             raise DeprecatedConfig(msg=stdmsg)
-        else:
-            self.warn(stdmsg, *args, **kwargs)
+
+        # Using a list because a tuple with dict can't be stored in a set.
+        sent_args = self._deprecated_messages_sent.setdefault(msg, list())
+
+        if args in sent_args:
+            # Already logged this message, so don't log it again.
+            return
+
+        sent_args.append(args)
+        self.warn(stdmsg, *args, **kwargs)
 
     def process(self, msg, kwargs):
         # NOTE(mrodden): catch any Message/other object and
@@ -324,7 +307,7 @@
             extra.update(_dictify_context(context))
 
         instance = kwargs.pop('instance', None)
-        instance_uuid = (extra.get('instance_uuid', None) or
+        instance_uuid = (extra.get('instance_uuid') or
                          kwargs.pop('instance_uuid', None))
         instance_extra = ''
         if instance:
@@ -390,10 +373,10 @@
 
 def _create_logging_excepthook(product_name):
     def logging_excepthook(exc_type, value, tb):
-        extra = {}
-        if CONF.verbose:
-            extra['exc_info'] = (exc_type, value, tb)
-        getLogger(product_name).critical(str(value), **extra)
+        extra = {'exc_info': (exc_type, value, tb)}
+        getLogger(product_name).critical(
+            "".join(traceback.format_exception_only(exc_type, value)),
+            **extra)
     return logging_excepthook
 
 
@@ -414,23 +397,31 @@
     try:
         logging.config.fileConfig(log_config_append,
                                   disable_existing_loggers=False)
-    except moves.configparser.Error as exc:
-        raise LogConfigError(log_config_append, str(exc))
+    except (moves.configparser.Error, KeyError) as exc:
+        raise LogConfigError(log_config_append, six.text_type(exc))
 
 
-def setup(product_name):
+def setup(product_name, version='unknown'):
     """Setup logging."""
     if CONF.log_config_append:
         _load_log_config(CONF.log_config_append)
     else:
-        _setup_logging_from_conf()
+        _setup_logging_from_conf(product_name, version)
     sys.excepthook = _create_logging_excepthook(product_name)
 
 
-def set_defaults(logging_context_format_string):
-    cfg.set_defaults(log_opts,
-                     logging_context_format_string=
-                     logging_context_format_string)
+def set_defaults(logging_context_format_string,
+                 default_log_levels=None):
+    # Just in case the caller is not setting the
+    # default_log_level. This is insurance because
+    # we introduced the default_log_level parameter
+    # later in a backwards in-compatible change
+    if default_log_levels is None:
+        default_log_levels = DEFAULT_LOG_LEVELS
+    cfg.set_defaults(
+            log_opts,
+            logging_context_format_string=logging_context_format_string,
+            default_log_levels=default_log_levels)
 
 
 def _find_facility_from_conf():
@@ -457,15 +448,38 @@
     return facility
 
 
-def _setup_logging_from_conf():
+class RFCSysLogHandler(logging.handlers.SysLogHandler):
+    def __init__(self, *args, **kwargs):
+        self.binary_name = _get_binary_name()
+        # Do not use super() unless type(logging.handlers.SysLogHandler)
+        #  is 'type' (Python 2.7).
+        # Use old style calls, if the type is 'classobj' (Python 2.6)
+        logging.handlers.SysLogHandler.__init__(self, *args, **kwargs)
+
+    def format(self, record):
+        # Do not use super() unless type(logging.handlers.SysLogHandler)
+        #  is 'type' (Python 2.7).
+        # Use old style calls, if the type is 'classobj' (Python 2.6)
+        msg = logging.handlers.SysLogHandler.format(self, record)
+        msg = self.binary_name + ' ' + msg
+        return msg
+
+
+def _setup_logging_from_conf(project, version):
     log_root = getLogger(None).logger
     for handler in log_root.handlers:
         log_root.removeHandler(handler)
 
     if CONF.use_syslog:
         facility = _find_facility_from_conf()
-        syslog = logging.handlers.SysLogHandler(address='/dev/log',
-                                                facility=facility)
+        # TODO(bogdando) use the format provided by RFCSysLogHandler
+        #   after existing syslog format deprecation in J
+        if CONF.use_syslog_rfc_format:
+            syslog = RFCSysLogHandler(address='/dev/log',
+                                      facility=facility)
+        else:
+            syslog = logging.handlers.SysLogHandler(address='/dev/log',
+                                                    facility=facility)
         log_root.addHandler(syslog)
 
     logpath = _get_log_file_path()
@@ -484,9 +498,14 @@
         log_root.addHandler(streamlog)
 
     if CONF.publish_errors:
-        handler = importutils.import_object(
-            "tempest.openstack.common.log_handler.PublishErrorsHandler",
-            logging.ERROR)
+        try:
+            handler = importutils.import_object(
+                "tempest.openstack.common.log_handler.PublishErrorsHandler",
+                logging.ERROR)
+        except ImportError:
+            handler = importutils.import_object(
+                "oslo.messaging.notify.log_handler.PublishErrorsHandler",
+                logging.ERROR)
         log_root.addHandler(handler)
 
     datefmt = CONF.log_date_format
@@ -499,7 +518,9 @@
             log_root.info('Deprecated: log_format is now deprecated and will '
                           'be removed in the next release')
         else:
-            handler.setFormatter(ContextFormatter(datefmt=datefmt))
+            handler.setFormatter(ContextFormatter(project=project,
+                                                  version=version,
+                                                  datefmt=datefmt))
 
     if CONF.debug:
         log_root.setLevel(logging.DEBUG)
@@ -510,9 +531,15 @@
 
     for pair in CONF.default_log_levels:
         mod, _sep, level_name = pair.partition('=')
-        level = logging.getLevelName(level_name)
         logger = logging.getLogger(mod)
-        logger.setLevel(level)
+        # NOTE(AAzza) in python2.6 Logger.setLevel doesn't convert string name
+        # to integer code.
+        if sys.version_info < (2, 7):
+            level = logging.getLevelName(level_name)
+            logger.setLevel(level)
+        else:
+            logger.setLevel(level_name)
+
 
 _loggers = {}
 
@@ -543,7 +570,7 @@
         self.level = level
 
     def write(self, msg):
-        self.logger.log(self.level, msg)
+        self.logger.log(self.level, msg.rstrip())
 
 
 class ContextFormatter(logging.Formatter):
@@ -557,27 +584,64 @@
     For information about what variables are available for the formatter see:
     http://docs.python.org/library/logging.html#formatter
 
+    If available, uses the context value stored in TLS - local.store.context
+
     """
 
+    def __init__(self, *args, **kwargs):
+        """Initialize ContextFormatter instance
+
+        Takes additional keyword arguments which can be used in the message
+        format string.
+
+        :keyword project: project name
+        :type project: string
+        :keyword version: project version
+        :type version: string
+
+        """
+
+        self.project = kwargs.pop('project', 'unknown')
+        self.version = kwargs.pop('version', 'unknown')
+
+        logging.Formatter.__init__(self, *args, **kwargs)
+
     def format(self, record):
         """Uses contextstring if request_id is set, otherwise default."""
-        # NOTE(sdague): default the fancier formating params
+
+        # store project info
+        record.project = self.project
+        record.version = self.version
+
+        # store request info
+        context = getattr(local.store, 'context', None)
+        if context:
+            d = _dictify_context(context)
+            for k, v in d.items():
+                setattr(record, k, v)
+
+        # NOTE(sdague): default the fancier formatting params
         # to an empty string so we don't throw an exception if
         # they get used
-        for key in ('instance', 'color'):
+        for key in ('instance', 'color', 'user_identity'):
             if key not in record.__dict__:
                 record.__dict__[key] = ''
 
-        if record.__dict__.get('request_id', None):
-            self._fmt = CONF.logging_context_format_string
+        if record.__dict__.get('request_id'):
+            fmt = CONF.logging_context_format_string
         else:
-            self._fmt = CONF.logging_default_format_string
+            fmt = CONF.logging_default_format_string
 
         if (record.levelno == logging.DEBUG and
                 CONF.logging_debug_format_suffix):
-            self._fmt += " " + CONF.logging_debug_format_suffix
+            fmt += " " + CONF.logging_debug_format_suffix
 
-        # Cache this on the record, Logger will respect our formated copy
+        if sys.version_info < (3, 2):
+            self._fmt = fmt
+        else:
+            self._style = logging.PercentStyle(fmt)
+            self._fmt = self._style._fmt
+        # Cache this on the record, Logger will respect our formatted copy
         if record.exc_info:
             record.exc_text = self.formatException(record.exc_info, record)
         return logging.Formatter.format(self, record)
diff --git a/tempest/openstack/common/strutils.py b/tempest/openstack/common/strutils.py
new file mode 100644
index 0000000..605cc02
--- /dev/null
+++ b/tempest/openstack/common/strutils.py
@@ -0,0 +1,295 @@
+# Copyright 2011 OpenStack Foundation.
+# All Rights Reserved.
+#
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+
+"""
+System-level utilities and helper functions.
+"""
+
+import math
+import re
+import sys
+import unicodedata
+
+import six
+
+from tempest.openstack.common.gettextutils import _
+
+
+UNIT_PREFIX_EXPONENT = {
+    'k': 1,
+    'K': 1,
+    'Ki': 1,
+    'M': 2,
+    'Mi': 2,
+    'G': 3,
+    'Gi': 3,
+    'T': 4,
+    'Ti': 4,
+}
+UNIT_SYSTEM_INFO = {
+    'IEC': (1024, re.compile(r'(^[-+]?\d*\.?\d+)([KMGT]i?)?(b|bit|B)$')),
+    'SI': (1000, re.compile(r'(^[-+]?\d*\.?\d+)([kMGT])?(b|bit|B)$')),
+}
+
+TRUE_STRINGS = ('1', 't', 'true', 'on', 'y', 'yes')
+FALSE_STRINGS = ('0', 'f', 'false', 'off', 'n', 'no')
+
+SLUGIFY_STRIP_RE = re.compile(r"[^\w\s-]")
+SLUGIFY_HYPHENATE_RE = re.compile(r"[-\s]+")
+
+
+# NOTE(flaper87): The following 3 globals are used by `mask_password`
+_SANITIZE_KEYS = ['adminPass', 'admin_pass', 'password', 'admin_password']
+
+# NOTE(ldbragst): Let's build a list of regex objects using the list of
+# _SANITIZE_KEYS we already have. This way, we only have to add the new key
+# to the list of _SANITIZE_KEYS and we can generate regular expressions
+# for XML and JSON automatically.
+_SANITIZE_PATTERNS = []
+_FORMAT_PATTERNS = [r'(%(key)s\s*[=]\s*[\"\']).*?([\"\'])',
+                    r'(<%(key)s>).*?(</%(key)s>)',
+                    r'([\"\']%(key)s[\"\']\s*:\s*[\"\']).*?([\"\'])',
+                    r'([\'"].*?%(key)s[\'"]\s*:\s*u?[\'"]).*?([\'"])',
+                    r'([\'"].*?%(key)s[\'"]\s*,\s*\'--?[A-z]+\'\s*,\s*u?[\'"])'
+                    '.*?([\'"])',
+                    r'(%(key)s\s*--?[A-z]+\s*)\S+(\s*)']
+
+for key in _SANITIZE_KEYS:
+    for pattern in _FORMAT_PATTERNS:
+        reg_ex = re.compile(pattern % {'key': key}, re.DOTALL)
+        _SANITIZE_PATTERNS.append(reg_ex)
+
+
+def int_from_bool_as_string(subject):
+    """Interpret a string as a boolean and return either 1 or 0.
+
+    Any string value in:
+
+        ('True', 'true', 'On', 'on', '1')
+
+    is interpreted as a boolean True.
+
+    Useful for JSON-decoded stuff and config file parsing
+    """
+    return bool_from_string(subject) and 1 or 0
+
+
+def bool_from_string(subject, strict=False, default=False):
+    """Interpret a string as a boolean.
+
+    A case-insensitive match is performed such that strings matching 't',
+    'true', 'on', 'y', 'yes', or '1' are considered True and, when
+    `strict=False`, anything else returns the value specified by 'default'.
+
+    Useful for JSON-decoded stuff and config file parsing.
+
+    If `strict=True`, unrecognized values, including None, will raise a
+    ValueError which is useful when parsing values passed in from an API call.
+    Strings yielding False are 'f', 'false', 'off', 'n', 'no', or '0'.
+    """
+    if not isinstance(subject, six.string_types):
+        subject = six.text_type(subject)
+
+    lowered = subject.strip().lower()
+
+    if lowered in TRUE_STRINGS:
+        return True
+    elif lowered in FALSE_STRINGS:
+        return False
+    elif strict:
+        acceptable = ', '.join(
+            "'%s'" % s for s in sorted(TRUE_STRINGS + FALSE_STRINGS))
+        msg = _("Unrecognized value '%(val)s', acceptable values are:"
+                " %(acceptable)s") % {'val': subject,
+                                      'acceptable': acceptable}
+        raise ValueError(msg)
+    else:
+        return default
+
+
+def safe_decode(text, incoming=None, errors='strict'):
+    """Decodes incoming text/bytes string using `incoming` if they're not
+       already unicode.
+
+    :param incoming: Text's current encoding
+    :param errors: Errors handling policy. See here for valid
+        values http://docs.python.org/2/library/codecs.html
+    :returns: text or a unicode `incoming` encoded
+                representation of it.
+    :raises TypeError: If text is not an instance of str
+    """
+    if not isinstance(text, (six.string_types, six.binary_type)):
+        raise TypeError("%s can't be decoded" % type(text))
+
+    if isinstance(text, six.text_type):
+        return text
+
+    if not incoming:
+        incoming = (sys.stdin.encoding or
+                    sys.getdefaultencoding())
+
+    try:
+        return text.decode(incoming, errors)
+    except UnicodeDecodeError:
+        # Note(flaper87) If we get here, it means that
+        # sys.stdin.encoding / sys.getdefaultencoding
+        # didn't return a suitable encoding to decode
+        # text. This happens mostly when global LANG
+        # var is not set correctly and there's no
+        # default encoding. In this case, most likely
+        # python will use ASCII or ANSI encoders as
+        # default encodings but they won't be capable
+        # of decoding non-ASCII characters.
+        #
+        # Also, UTF-8 is being used since it's an ASCII
+        # extension.
+        return text.decode('utf-8', errors)
+
+
+def safe_encode(text, incoming=None,
+                encoding='utf-8', errors='strict'):
+    """Encodes incoming text/bytes string using `encoding`.
+
+    If incoming is not specified, text is expected to be encoded with
+    current python's default encoding. (`sys.getdefaultencoding`)
+
+    :param incoming: Text's current encoding
+    :param encoding: Expected encoding for text (Default UTF-8)
+    :param errors: Errors handling policy. See here for valid
+        values http://docs.python.org/2/library/codecs.html
+    :returns: text or a bytestring `encoding` encoded
+                representation of it.
+    :raises TypeError: If text is not an instance of str
+    """
+    if not isinstance(text, (six.string_types, six.binary_type)):
+        raise TypeError("%s can't be encoded" % type(text))
+
+    if not incoming:
+        incoming = (sys.stdin.encoding or
+                    sys.getdefaultencoding())
+
+    if isinstance(text, six.text_type):
+        return text.encode(encoding, errors)
+    elif text and encoding != incoming:
+        # Decode text before encoding it with `encoding`
+        text = safe_decode(text, incoming, errors)
+        return text.encode(encoding, errors)
+    else:
+        return text
+
+
+def string_to_bytes(text, unit_system='IEC', return_int=False):
+    """Converts a string into an float representation of bytes.
+
+    The units supported for IEC ::
+
+        Kb(it), Kib(it), Mb(it), Mib(it), Gb(it), Gib(it), Tb(it), Tib(it)
+        KB, KiB, MB, MiB, GB, GiB, TB, TiB
+
+    The units supported for SI ::
+
+        kb(it), Mb(it), Gb(it), Tb(it)
+        kB, MB, GB, TB
+
+    Note that the SI unit system does not support capital letter 'K'
+
+    :param text: String input for bytes size conversion.
+    :param unit_system: Unit system for byte size conversion.
+    :param return_int: If True, returns integer representation of text
+                       in bytes. (default: decimal)
+    :returns: Numerical representation of text in bytes.
+    :raises ValueError: If text has an invalid value.
+
+    """
+    try:
+        base, reg_ex = UNIT_SYSTEM_INFO[unit_system]
+    except KeyError:
+        msg = _('Invalid unit system: "%s"') % unit_system
+        raise ValueError(msg)
+    match = reg_ex.match(text)
+    if match:
+        magnitude = float(match.group(1))
+        unit_prefix = match.group(2)
+        if match.group(3) in ['b', 'bit']:
+            magnitude /= 8
+    else:
+        msg = _('Invalid string format: %s') % text
+        raise ValueError(msg)
+    if not unit_prefix:
+        res = magnitude
+    else:
+        res = magnitude * pow(base, UNIT_PREFIX_EXPONENT[unit_prefix])
+    if return_int:
+        return int(math.ceil(res))
+    return res
+
+
+def to_slug(value, incoming=None, errors="strict"):
+    """Normalize string.
+
+    Convert to lowercase, remove non-word characters, and convert spaces
+    to hyphens.
+
+    Inspired by Django's `slugify` filter.
+
+    :param value: Text to slugify
+    :param incoming: Text's current encoding
+    :param errors: Errors handling policy. See here for valid
+        values http://docs.python.org/2/library/codecs.html
+    :returns: slugified unicode representation of `value`
+    :raises TypeError: If text is not an instance of str
+    """
+    value = safe_decode(value, incoming, errors)
+    # NOTE(aababilov): no need to use safe_(encode|decode) here:
+    # encodings are always "ascii", error handling is always "ignore"
+    # and types are always known (first: unicode; second: str)
+    value = unicodedata.normalize("NFKD", value).encode(
+        "ascii", "ignore").decode("ascii")
+    value = SLUGIFY_STRIP_RE.sub("", value).strip().lower()
+    return SLUGIFY_HYPHENATE_RE.sub("-", value)
+
+
+def mask_password(message, secret="***"):
+    """Replace password with 'secret' in message.
+
+    :param message: The string which includes security information.
+    :param secret: value with which to replace passwords.
+    :returns: The unicode value of message with the password fields masked.
+
+    For example:
+
+    >>> mask_password("'adminPass' : 'aaaaa'")
+    "'adminPass' : '***'"
+    >>> mask_password("'admin_pass' : 'aaaaa'")
+    "'admin_pass' : '***'"
+    >>> mask_password('"password" : "aaaaa"')
+    '"password" : "***"'
+    >>> mask_password("'original_password' : 'aaaaa'")
+    "'original_password' : '***'"
+    >>> mask_password("u'original_password' :   u'aaaaa'")
+    "u'original_password' :   u'***'"
+    """
+    message = six.text_type(message)
+
+    # NOTE(ldbragst): Check to see if anything in message contains any key
+    # specified in _SANITIZE_KEYS, if not then just return the message since
+    # we don't have to mask any passwords.
+    if not any(key in message for key in _SANITIZE_KEYS):
+        return message
+
+    secret = r'\g<1>' + secret + r'\g<2>'
+    for pattern in _SANITIZE_PATTERNS:
+        message = re.sub(pattern, secret, message)
+    return message
diff --git a/tempest/openstack/common/timeutils.py b/tempest/openstack/common/timeutils.py
index d5ed81d..c48da95 100644
--- a/tempest/openstack/common/timeutils.py
+++ b/tempest/openstack/common/timeutils.py
@@ -114,7 +114,7 @@
 
 
 def iso8601_from_timestamp(timestamp):
-    """Returns a iso8601 formated date from timestamp."""
+    """Returns an iso8601 formatted date from timestamp."""
     return isotime(datetime.datetime.utcfromtimestamp(timestamp))
 
 
@@ -134,7 +134,7 @@
 
 def advance_time_delta(timedelta):
     """Advance overridden time using a datetime.timedelta."""
-    assert(not utcnow.override_time is None)
+    assert utcnow.override_time is not None
     try:
         for dt in utcnow.override_time:
             dt += timedelta