Mask database user's password in trove logs

Currently passwords are logged in plaintext in trove-api and
trove-taskmanager logs. This fix will mask the passwords in the logs.
Syncing modules log, common.py from rpc  and versionutils from oslo.
common.py requires versionutils.py.

Change-Id:I50deb003d866e85e7c7ec8ab3ce7248d1c005e57
Closes-Bug: #1254914

openstack-common.conf

@@ -29,6 +29,7 @@ module=threadgroup
 module=timeutils
 module=utils
 module=wsgi
+module=versionutils
 
 # The base module to hold the copy of openstack.common
 base=trove

trove/common/auth.py

@@ -61,9 +61,10 @@ class TenantBasedAuth(object):
         match_for_tenant = self.tenant_scoped_url.match(request.path_info)
         if (match_for_tenant and
                 tenant_id == match_for_tenant.group('tenant_id')):
-            LOG.debug(_("Authorized tenant '%(tenant_id)s' request: "
+            LOG.debug(logging.mask_password(
+                      _("Authorized tenant '%(tenant_id)s' request: "
                         "%(request)s") %
-                      {'tenant_id': tenant_id, 'request': request})
+                      {'tenant_id': tenant_id, 'request': request}))
             return True
         msg = _("User with tenant id %s cannot access this resource")
         LOG.debug(msg % tenant_id)

trove/extensions/mysql/service.py

@@ -84,8 +84,8 @@ class UserController(wsgi.Controller):
     def create(self, req, body, tenant_id, instance_id):
         """Creates a set of users"""
         LOG.info(_("Creating users for instance '%s'") % instance_id)
-        LOG.info(_("req : '%s'\n\n") % req)
+        LOG.info(logging.mask_password(_("req : '%s'\n\n") % req))
-        LOG.info(_("body : '%s'\n\n") % body)
+        LOG.info(logging.mask_password(_("body : '%s'\n\n") % body))
         context = req.environ[wsgi.CONTEXT_KEY]
         users = body['users']
         try:
@@ -137,7 +137,7 @@ class UserController(wsgi.Controller):
     def update(self, req, body, tenant_id, instance_id, id):
         """Change attributes for one user."""
         LOG.info(_("Updating user attributes for instance '%s'") % instance_id)
-        LOG.info(_("req : '%s'\n\n") % req)
+        LOG.info(logging.mask_password(_("req : '%s'\n\n") % req))
         context = req.environ[wsgi.CONTEXT_KEY]
         id = correct_id_with_req(id, req)
         username, hostname = unquote_user_host(id)
@@ -159,7 +159,7 @@ class UserController(wsgi.Controller):
     def update_all(self, req, body, tenant_id, instance_id):
         """Change the password of one or more users."""
         LOG.info(_("Updating user passwords for instance '%s'") % instance_id)
-        LOG.info(_("req : '%s'\n\n") % req)
+        LOG.info(logging.mask_password(_("req : '%s'\n\n") % req))
         context = req.environ[wsgi.CONTEXT_KEY]
         users = body['users']
         model_users = []

trove/instance/service.py

@@ -179,8 +179,8 @@ class InstanceController(wsgi.Controller):
     def create(self, req, body, tenant_id):
         # TODO(hub-cap): turn this into middleware
         LOG.info(_("Creating a database instance for tenant '%s'") % tenant_id)
-        LOG.info(_("req : '%s'\n\n") % req)
+        LOG.info(logging.mask_password(_("req : '%s'\n\n") % req))
-        LOG.info(_("body : '%s'\n\n") % body)
+        LOG.info(logging.mask_password(_("body : '%s'\n\n") % body))
         context = req.environ[wsgi.CONTEXT_KEY]
         datastore_args = body['instance'].get('datastore', {})
         datastore, datastore_version = (

trove/openstack/common/log.py

@@ -1,5 +1,3 @@
-# vim: tabstop=4 shiftwidth=4 softtabstop=4
-
 # Copyright 2011 OpenStack Foundation.
 # Copyright 2010 United States Government as represented by the
 # Administrator of the National Aeronautics and Space Administration.
@@ -35,13 +33,15 @@ import logging
 import logging.config
 import logging.handlers
 import os
+import re
 import sys
 import traceback
 
 from oslo.config import cfg
+import six
 from six import moves
 
-from trove.openstack.common.gettextutils import _  # noqa
+from trove.openstack.common.gettextutils import _
 from trove.openstack.common import importutils
 from trove.openstack.common import jsonutils
 from trove.openstack.common import local
@@ -49,6 +49,24 @@ from trove.openstack.common import local
 
 _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',
                 short='d',
@@ -63,11 +81,13 @@ common_cli_opts = [
 ]
 
 logging_cli_opts = [
-    cfg.StrOpt('log-config',
+    cfg.StrOpt('log-config-append',
                metavar='PATH',
-               help='If this option is specified, the logging configuration '
+               deprecated_name='log-config',
-                    'file specified is used and overrides any other logging '
+               help='The name of logging configuration file. It does not '
-                    'options specified. Please see the Python logging module '
+                    '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.'),
     cfg.StrOpt('log-format',
@@ -110,7 +130,7 @@ generic_log_opts = [
 log_opts = [
     cfg.StrOpt('logging_context_format_string',
                default='%(asctime)s.%(msecs)03d %(process)d %(levelname)s '
-                       '%(name)s [%(request_id)s %(user)s %(tenant)s] '
+                       '%(name)s [%(request_id)s %(user_identity)s] '
                        '%(instance)s%(message)s',
                help='format string to use for log messages with context'),
     cfg.StrOpt('logging_default_format_string',
@@ -126,12 +146,13 @@ log_opts = [
                help='prefix each line of exception output with this format'),
     cfg.ListOpt('default_log_levels',
                 default=[
+                    'amqp=WARN',
                     'amqplib=WARN',
-                    'sqlalchemy=WARN',
                     'boto=WARN',
+                    'qpid=WARN',
+                    'sqlalchemy=WARN',
                     'suds=INFO',
-                    'keystone=INFO',
+                    'iso8601=WARN',
-                    'eventlet.wsgi.server=WARN'
                 ],
                 help='list of logger=LEVEL pairs'),
     cfg.BoolOpt('publish_errors',
@@ -207,6 +228,42 @@ def _get_log_file_path(binary=None):
         binary = binary or _get_binary_name()
         return '%s.log' % (os.path.join(logdir, binary),)
 
+    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):
 
@@ -249,6 +306,13 @@ class ContextAdapter(BaseLoggerAdapter):
             self.warn(stdmsg, *args, **kwargs)
 
     def process(self, msg, kwargs):
+        # NOTE(mrodden): catch any Message/other object and
+        #                coerce to unicode before they can get
+        #                to the python logging and possibly
+        #                cause string encoding trouble
+        if not isinstance(msg, six.string_types):
+            msg = six.text_type(msg)
+
         if 'extra' not in kwargs:
             kwargs['extra'] = {}
         extra = kwargs['extra']
@@ -260,18 +324,20 @@ class ContextAdapter(BaseLoggerAdapter):
             extra.update(_dictify_context(context))
 
         instance = kwargs.pop('instance', None)
+        instance_uuid = (extra.get('instance_uuid', None) or
+                         kwargs.pop('instance_uuid', None))
         instance_extra = ''
         if instance:
             instance_extra = CONF.instance_format % instance
-        else:
+        elif instance_uuid:
-            instance_uuid = kwargs.pop('instance_uuid', None)
+            instance_extra = (CONF.instance_uuid_format
-            if instance_uuid:
+                              % {'uuid': instance_uuid})
-                instance_extra = (CONF.instance_uuid_format
+        extra['instance'] = instance_extra
-                                  % {'uuid': instance_uuid})
-        extra.update({'instance': instance_extra})
 
-        extra.update({"project": self.project})
+        extra.setdefault('user_identity', kwargs.pop('user_identity', None))
-        extra.update({"version": self.version})
+
+        extra['project'] = self.project
+        extra['version'] = self.version
         extra['extra'] = extra.copy()
         return msg, kwargs
 
@@ -285,7 +351,7 @@ class JSONFormatter(logging.Formatter):
     def formatException(self, ei, strip_newlines=True):
         lines = traceback.format_exception(*ei)
         if strip_newlines:
-            lines = [itertools.ifilter(
+            lines = [moves.filter(
                 lambda x: x,
                 line.rstrip().splitlines()) for line in lines]
             lines = list(itertools.chain(*lines))
@@ -323,10 +389,10 @@ class JSONFormatter(logging.Formatter):
 
 
 def _create_logging_excepthook(product_name):
-    def logging_excepthook(type, value, tb):
+    def logging_excepthook(exc_type, value, tb):
         extra = {}
         if CONF.verbose:
-            extra['exc_info'] = (type, value, tb)
+            extra['exc_info'] = (exc_type, value, tb)
         getLogger(product_name).critical(str(value), **extra)
     return logging_excepthook
 
@@ -344,17 +410,18 @@ class LogConfigError(Exception):
                                    err_msg=self.err_msg)
 
 
-def _load_log_config(log_config):
+def _load_log_config(log_config_append):
     try:
-        logging.config.fileConfig(log_config)
+        logging.config.fileConfig(log_config_append,
+                                  disable_existing_loggers=False)
     except moves.configparser.Error as exc:
-        raise LogConfigError(log_config, str(exc))
+        raise LogConfigError(log_config_append, str(exc))
 
 
 def setup(product_name):
     """Setup logging."""
-    if CONF.log_config:
+    if CONF.log_config_append:
-        _load_log_config(CONF.log_config)
+        _load_log_config(CONF.log_config_append)
     else:
         _setup_logging_from_conf()
     sys.excepthook = _create_logging_excepthook(product_name)
@@ -410,7 +477,7 @@ def _setup_logging_from_conf():
         streamlog = ColorHandler()
         log_root.addHandler(streamlog)
 
-    elif not CONF.log_file:
+    elif not logpath:
         # pass sys.stdout as a positional argument
         # python2.6 calls the argument strm, in 2.7 it's stream
         streamlog = logging.StreamHandler(sys.stdout)

trove/openstack/common/rpc/common.py

@@ -1,5 +1,3 @@
-# vim: tabstop=4 shiftwidth=4 softtabstop=4
-
 # Copyright 2010 United States Government as represented by the
 # Administrator of the National Aeronautics and Space Administration.
 # All Rights Reserved.
@@ -24,17 +22,19 @@ import traceback
 from oslo.config import cfg
 import six
 
-from trove.openstack.common.gettextutils import _  # noqa
+from trove.openstack.common.gettextutils import _
 from trove.openstack.common import importutils
 from trove.openstack.common import jsonutils
 from trove.openstack.common import local
 from trove.openstack.common import log as logging
+from trove.openstack.common import versionutils
 
 
 CONF = cfg.CONF
 LOG = logging.getLogger(__name__)
 
 
+_RPC_ENVELOPE_VERSION = '2.0'
 '''RPC Envelope Version.
 
 This version number applies to the top level structure of messages sent out.
@@ -47,7 +47,7 @@ This version number applies to the message envelope that is used in the
 serialization done inside the rpc layer.  See serialize_msg() and
 deserialize_msg().
 
-The current message format (version 2.0) is very simple.  It is:
+The current message format (version 2.0) is very simple.  It is::
 
     {
         'oslo.version': <RPC Envelope Version as a String>,
@@ -65,7 +65,6 @@ We will JSON encode the application message payload.  The message envelope,
 which includes the JSON encoded application message body, will be passed down
 to the messaging libraries as a dict.
 '''
-_RPC_ENVELOPE_VERSION = '2.0'
 
 _VERSION_KEY = 'oslo.version'
 _MESSAGE_KEY = 'oslo.message'
@@ -87,7 +86,7 @@ class RPCException(Exception):
                 # kwargs doesn't match a variable in the message
                 # log the issue and the kwargs
                 LOG.exception(_('Exception in string format operation'))
-                for name, value in kwargs.iteritems():
+                for name, value in six.iteritems(kwargs):
                     LOG.error("%s: %s" % (name, value))
                 # at least get the core message out if something happened
                 message = self.msg_fmt
@@ -265,11 +264,15 @@ def _safe_log(log_func, msg, msg_data):
 
     def _fix_passwords(d):
         """Sanitizes the password fields in the dictionary."""
-        for k in d.iterkeys():
+        for k in six.iterkeys(d):
             if k.lower().find('password') != -1:
                 d[k] = '<SANITIZED>'
             elif k.lower() in SANITIZE:
                 d[k] = '<SANITIZED>'
+            elif isinstance(d[k], list):
+                for e in d[k]:
+                    if isinstance(e, dict):
+                        _fix_passwords(e)
             elif isinstance(d[k], dict):
                 _fix_passwords(d[k])
         return d
@@ -441,19 +444,15 @@ def client_exceptions(*exceptions):
     return outer
 
 
+# TODO(sirp): we should deprecate this in favor of
+# using `versionutils.is_compatible` directly
 def version_is_compatible(imp_version, version):
     """Determine whether versions are compatible.
 
     :param imp_version: The version implemented
     :param version: The version requested by an incoming message.
     """
-    version_parts = version.split('.')
+    return versionutils.is_compatible(version, imp_version)
-    imp_version_parts = imp_version.split('.')
-    if int(version_parts[0]) != int(imp_version_parts[0]):  # Major
-        return False
-    if int(version_parts[1]) > int(imp_version_parts[1]):  # Minor
-        return False
-    return True
 
 
 def serialize_msg(raw_msg):

trove/openstack/common/versionutils.py

@@ -0,0 +1,148 @@
+# Copyright (c) 2013 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.
+
+"""
+Helpers for comparing version strings.
+"""
+
+import functools
+import pkg_resources
+
+from trove.openstack.common.gettextutils import _
+from trove.openstack.common import log as logging
+
+
+LOG = logging.getLogger(__name__)
+
+
+class deprecated(object):
+    """A decorator to mark callables as deprecated.
+
+    This decorator logs a deprecation message when the callable it decorates is
+    used. The message will include the release where the callable was
+    deprecated, the release where it may be removed and possibly an optional
+    replacement.
+
+    Examples:
+
+    1. Specifying the required deprecated release
+
+    >>> @deprecated(as_of=deprecated.ICEHOUSE)
+    ... def a(): pass
+
+    2. Specifying a replacement:
+
+    >>> @deprecated(as_of=deprecated.ICEHOUSE, in_favor_of='f()')
+    ... def b(): pass
+
+    3. Specifying the release where the functionality may be removed:
+
+    >>> @deprecated(as_of=deprecated.ICEHOUSE, remove_in=+1)
+    ... def c(): pass
+
+    """
+
+    FOLSOM = 'F'
+    GRIZZLY = 'G'
+    HAVANA = 'H'
+    ICEHOUSE = 'I'
+
+    _RELEASES = {
+        'F': 'Folsom',
+        'G': 'Grizzly',
+        'H': 'Havana',
+        'I': 'Icehouse',
+    }
+
+    _deprecated_msg_with_alternative = _(
+        '%(what)s is deprecated as of %(as_of)s in favor of '
+        '%(in_favor_of)s and may be removed in %(remove_in)s.')
+
+    _deprecated_msg_no_alternative = _(
+        '%(what)s is deprecated as of %(as_of)s and may be '
+        'removed in %(remove_in)s. It will not be superseded.')
+
+    def __init__(self, as_of, in_favor_of=None, remove_in=2, what=None):
+        """Initialize decorator
+
+        :param as_of: the release deprecating the callable. Constants
+            are define in this class for convenience.
+        :param in_favor_of: the replacement for the callable (optional)
+        :param remove_in: an integer specifying how many releases to wait
+            before removing (default: 2)
+        :param what: name of the thing being deprecated (default: the
+            callable's name)
+
+        """
+        self.as_of = as_of
+        self.in_favor_of = in_favor_of
+        self.remove_in = remove_in
+        self.what = what
+
+    def __call__(self, func):
+        if not self.what:
+            self.what = func.__name__ + '()'
+
+        @functools.wraps(func)
+        def wrapped(*args, **kwargs):
+            msg, details = self._build_message()
+            LOG.deprecated(msg, details)
+            return func(*args, **kwargs)
+        return wrapped
+
+    def _get_safe_to_remove_release(self, release):
+        # TODO(dstanek): this method will have to be reimplemented once
+        #    when we get to the X release because once we get to the Y
+        #    release, what is Y+2?
+        new_release = chr(ord(release) + self.remove_in)
+        if new_release in self._RELEASES:
+            return self._RELEASES[new_release]
+        else:
+            return new_release
+
+    def _build_message(self):
+        details = dict(what=self.what,
+                       as_of=self._RELEASES[self.as_of],
+                       remove_in=self._get_safe_to_remove_release(self.as_of))
+
+        if self.in_favor_of:
+            details['in_favor_of'] = self.in_favor_of
+            msg = self._deprecated_msg_with_alternative
+        else:
+            msg = self._deprecated_msg_no_alternative
+        return msg, details
+
+
+def is_compatible(requested_version, current_version, same_major=True):
+    """Determine whether `requested_version` is satisfied by
+    `current_version`; in other words, `current_version` is >=
+    `requested_version`.
+
+    :param requested_version: version to check for compatibility
+    :param current_version: version to check against
+    :param same_major: if True, the major version must be identical between
+        `requested_version` and `current_version`. This is used when a
+        major-version difference indicates incompatibility between the two
+        versions. Since this is the common-case in practice, the default is
+        True.
+    :returns: True if compatible, False if not
+    """
+    requested_parts = pkg_resources.parse_version(requested_version)
+    current_parts = pkg_resources.parse_version(current_version)
+
+    if same_major and (requested_parts[0] != current_parts[0]):
+        return False
+
+    return current_parts >= requested_parts