[refactor] logging refactor + redaction filter

Refactors the uwsgi-based logging filter to encapsulate
better and adds a redaction filter for api logging.

This change now also includes bringing a stray test back into
the correct location.

Change-Id: I53de7da6bd4182e824366fdbb5221c7c9ae5be09

.dockerignore

@@ -44,6 +44,7 @@ cov/*
 **/.tox/
 **/.coverage
 **/.coverage.*
+**/.pytest_cache/
 **/.cache
 nosetests.xml
 coverage.xml

.gitignore

@@ -42,6 +42,7 @@ cov/*
 .coverage
 .coverage.*
 .cache
+.pytest_cache/
 nosetests.xml
 coverage.xml
 *.cover

src/bin/shipyard_airflow/shipyard_airflow/control/logging/logging_config.py

@@ -0,0 +1,84 @@
+# Copyright 2017 AT&T Intellectual Property.  All other 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.
+"""Container for logging configuration"""
+import logging
+
+from shipyard_airflow.control.logging import request_logging
+from shipyard_airflow.control.logging.redaction_formatter import (
+    RedactionFormatter
+)
+LOG = logging.getLogger(__name__)
+
+
+class LoggingConfig():
+    """Encapsulates the properties of a Logging Config
+
+    :param level: The level value to set as the threshold for logging. Ideally
+        a client would use logging.INFO or the desired logging constant to set
+        this level value
+    :param named_levels: A dictionary of 'name': logging.level values that
+        configures the minimum logging level for the named logger.
+    :param format_string: Optional value allowing for override of the logging
+        format string. If new values beyond the default value are introduced,
+        the additional_fields must contain those fields to ensure they are set
+        upon using the logging filter.
+    :param additional_fields: Optionally allows for specifying more fields that
+        will be set on each logging record. If specified, the format_string
+        parameter should be set with matching fields, otherwise they will not
+        be displayed.
+    """
+
+    _default_log_format = (
+        "%(asctime)s %(levelname)-8s %(req_id)s %(external_ctx)s %(user)s "
+        "%(module)s(%(lineno)d) %(funcName)s - %(message)s")
+
+    def __init__(self,
+                 level,
+                 named_levels=None,
+                 format_string=None,
+                 additional_fields=None):
+        self.level = level
+        # Any false values passed for named_levels should instead be treated as
+        # an empty dictionary i.e. no special log levels
+        self.named_levels = named_levels or {}
+        # Any false values for format string should use the default instead
+        self.format_string = format_string or LoggingConfig._default_log_format
+        self.additional_fields = additional_fields
+
+    def setup_logging(self):
+        """ Establishes the base logging using the appropriate filter
+        attached to the console/stream handler.
+        """
+        console_handler = logging.StreamHandler()
+        request_logging.assign_request_filter(console_handler,
+                                              self.additional_fields)
+        logging.basicConfig(level=self.level,
+                            format=self.format_string,
+                            handlers=[console_handler])
+        for handler in logging.root.handlers:
+            handler.setFormatter(RedactionFormatter(handler.formatter))
+        logger = logging.getLogger(__name__)
+        logger.info('Established logging defaults')
+        self._setup_log_levels()
+
+    def _setup_log_levels(self):
+        """Sets up the logger levels for named loggers
+
+        :param named_levels: dict to set each of the specified
+            logging levels.
+        """
+        for logger_name, level in self.named_levels.items():
+            logger = logging.getLogger(logger_name)
+            logger.setLevel(level)
+            LOG.info("Set %s to use logging level %s", logger_name, level)

src/bin/shipyard_airflow/shipyard_airflow/control/logging/redaction_formatter.py

@@ -0,0 +1,59 @@
+# Copyright 2018 AT&T Intellectual Property.  All other 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.
+"""A logging formatter that attempts to scrub logged data.
+
+Addresses the OWASP considerations of things that should be excluded:
+https://www.owasp.org/index.php/Logging_Cheat_Sheet#Data_to_exclude
+
+These that should not usually be logged:
+
+Avoided by circumstance - no action taken by this formatter:
+- Application source code
+    - Avoided on a case by case basis
+- Session identification values (consider replacing with a hashed value if
+  needed to track session specific events)
+    - Stateless application logs a transaction correlation ID, but not a
+      replayable session id.
+- Access tokens
+    - Headers with access tokens are excluded in the request/response logging
+
+Formatter provides scrubbing facilities:
+- Authentication passwords
+- Database connection strings
+- Encryption keys and other master secrets
+"""
+import logging
+
+from shipyard_airflow.control.util.redactor import Redactor
+
+
+LOG = logging.getLogger(__name__)
+# Concepts from https://www.relaxdiego.com/2014/07/logging-in-python.html
+
+
+class RedactionFormatter(object):
+    """ A formatter to remove sensitive information from logs
+    """
+    def __init__(self, original_formatter):
+        self.original_formatter = original_formatter
+        self.redactor = Redactor()
+        LOG.info("RedactionFormatter wrapping %s",
+                 original_formatter.__class__.__name__)
+
+    def format(self, record):
+        msg = self.original_formatter.format(record)
+        return self.redactor.redact(msg)
+
+    def __getattr__(self, attr):
+        return getattr(self.original_formatter, attr)

src/bin/shipyard_airflow/shipyard_airflow/control/logging/request_logging.py

@@ -0,0 +1,76 @@
+# Copyright 2017 AT&T Intellectual Property.  All other 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.
+""" A logging filter to prepend request scoped formatting to all logging
+records that use this filter. Request-based values will cause the log
+records to have correlation values that can be used to better trace
+logs.  If no handler that supports a request scope is present, does not attempt
+to change the logs in any way
+
+Threads initiated using threading. Thread can be correlated to the request
+they came from by setting a kwarg of log_extra, containing a dictionary
+of values matching the VALID_ADDL_FIELDS below and any fields that are set
+as additional_fields by the setup_logging function. This mechanism assumes
+that the thread will maintain the correlation values for the life
+of the thread.
+"""
+import logging
+
+# Import uwsgi to determine if it has been provided to the application.
+# Only import the UwsgiLogFilter if uwsgi is present
+try:
+    import uwsgi
+    from shipyard_airflow.control.logging.uwsgi_filter import UwsgiLogFilter
+except ImportError:
+    uwsgi = None
+
+
+# BASE_ADDL_FIELDS are fields that will be included in the request based
+# logging - these fields need not be set up independently as opposed to the
+# additional_fields parameter used below, which allows for more fields beyond
+# this default set.
+BASE_ADDL_FIELDS = ['req_id', 'external_ctx', 'user']
+LOG = logging.getLogger(__name__)
+
+
+def set_logvar(key, value):
+    """ Attempts to set the logvar in the request scope, or ignores it
+    if not running in an environment that supports it.
+    """
+    if value:
+        if uwsgi:
+            uwsgi.set_logvar(key, value)
+        # If there were a different handler than uwsgi, here is where we'd
+        # need to set the logvar value for its use.
+
+
+def assign_request_filter(handler, additional_fields=None):
+    """Adds the request-scoped filter log filter to the passed handler
+
+    :param handler: a logging handler, e.g. a ConsoleHandler
+    :param additional_fields: fields that will be included in the logging
+        records (if a matching logging format is used)
+    """
+    handler_cls = handler.__class__.__name__
+    if uwsgi:
+        if additional_fields is None:
+            additional_fields = []
+        addl_fields = [*BASE_ADDL_FIELDS, *additional_fields]
+        handler.addFilter(UwsgiLogFilter(uwsgi, addl_fields))
+        LOG.info("UWSGI present, added UWSGI log filter to handler %s",
+                 handler_cls)
+    # if there are other handlers that would allow for request scoped logging
+    # to be set up, we could include those options here.
+    else:
+        LOG.info("No request based logging filter in the current environment. "
+                 "No log filter added to handler %s", handler_cls)

src/bin/shipyard_airflow/shipyard_airflow/control/logging/uwsgi_filter.py

@@ -0,0 +1,76 @@
+# Copyright 2017 AT&T Intellectual Property.  All other 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.
+"""A UWSGI-dependent implementation of a logging filter allowing for
+   request-based logging.
+"""
+import logging
+import threading
+
+
+class UwsgiLogFilter(logging.Filter):
+    """ A filter that preepends log records with additional request
+    based information, or information provided by log_extra in the
+    kwargs provided to a thread
+    """
+    def __init__(self, uwsgi, additional_fields=None):
+        super().__init__()
+        if additional_fields is None:
+            additional_fields = []
+        self.uwsgi = uwsgi
+        self.log_fields = additional_fields
+
+    def filter(self, record):
+        """ Checks for thread provided values, or attempts to get values
+        from uwsgi
+        """
+        if self._thread_has_log_extra():
+            value_setter = self._set_values_from_log_extra
+        else:
+            value_setter = self._set_value
+
+        for field_nm in self.log_fields:
+            value_setter(record, field_nm)
+        return True
+
+    def _set_value(self, record, logvar):
+        # handles setting the logvars from uwsgi or '' in case of none/empty
+        try:
+            logvar_value = self.uwsgi.get_logvar(logvar)
+            if logvar_value:
+                setattr(record, logvar, logvar_value.decode('UTF-8'))
+            else:
+                setattr(record, logvar, '')
+        except SystemError:
+            # This happens if log_extra is not on a thread that is spawned
+            # by a process running under uwsgi
+            setattr(record, logvar, '')
+
+    def _set_values_from_log_extra(self, record, logvar):
+        # sets the values from the log_extra on the thread
+        setattr(record, logvar, self._get_value_from_thread(logvar) or '')
+
+    def _thread_has_log_extra(self):
+        # Checks to see if log_extra is present on the current thread
+        if self._get_log_extra_from_thread():
+            return True
+        return False
+
+    def _get_value_from_thread(self, logvar):
+        # retrieve the logvar from the log_extra from kwargs for the thread
+        return self._get_log_extra_from_thread().get(logvar, '')
+
+    def _get_log_extra_from_thread(self):
+        # retrieves the log_extra value from kwargs or {} if it doesn't
+        # exist
+        return threading.current_thread()._kwargs.get('log_extra', {})

src/bin/shipyard_airflow/shipyard_airflow/control/middleware/logging_mw.py

@@ -16,7 +16,7 @@
 import logging
 import re
 
-from shipyard_airflow.control import ucp_logging
+from shipyard_airflow.control.logging import request_logging
 
 LOG = logging.getLogger(__name__)
 HEALTH_URL = '/health'
@@ -31,9 +31,9 @@ class LoggingMiddleware(object):
     def process_request(self, req, resp):
         """ Set up values to be logged across the request
         """
-        ucp_logging.set_logvar('req_id', req.context.request_id)
+        request_logging.set_logvar('req_id', req.context.request_id)
-        ucp_logging.set_logvar('external_ctx', req.context.external_marker)
+        request_logging.set_logvar('external_ctx', req.context.external_marker)
-        ucp_logging.set_logvar('user', req.context.user)
+        request_logging.set_logvar('user', req.context.user)
         if not req.url.endswith(HEALTH_URL):
             # Log requests other than the health check.
             LOG.info("Request %s %s", req.method, req.url)

src/bin/shipyard_airflow/shipyard_airflow/control/start_shipyard.py

@@ -16,13 +16,11 @@
 Sets up the global configurations for the Shipyard service. Hands off
 to the api startup to handle the Falcon specific setup.
 """
-import logging
-
 from oslo_config import cfg
 
 from shipyard_airflow.conf import config
 import shipyard_airflow.control.api as api
-from shipyard_airflow.control import ucp_logging
+from shipyard_airflow.control.logging.logging_config import LoggingConfig
 from shipyard_airflow import policy
 
 CONF = cfg.CONF
@@ -32,8 +30,10 @@ def start_shipyard(default_config_files=None):
     # Trigger configuration resolution.
     config.parse_args(args=[], default_config_files=default_config_files)
 
-    ucp_logging.setup_logging(CONF.logging.log_level)
+    LoggingConfig(
-    setup_log_levels()
+        level=CONF.logging.log_level,
+        named_levels=CONF.logging.named_log_levels
+    ).setup_logging()
 
     # Setup the RBAC policy enforcer
     policy.policy_engine = policy.ShipyardPolicy()
@@ -41,17 +41,3 @@ def start_shipyard(default_config_files=None):
 
     # Start the API
     return api.start_api()
-
-
-def setup_log_levels():
-    """Sets up the logger levels for named loggers
-
-    Uses the named_logger_levels dict to set each of the specified
-    logging levels.
-    """
-    level_dict = CONF.logging.named_log_levels or {}
-    for logger_name, level in level_dict.items():
-        logger = logging.getLogger(logger_name)
-        logger.setLevel(level)
-        tp_logger = logging.getLogger(__name__)
-        tp_logger.info("Set %s to use logging level %s", logger_name, level)

src/bin/shipyard_airflow/shipyard_airflow/control/ucp_logging.py

@@ -1,147 +0,0 @@
-# Copyright 2017 AT&T Intellectual Property.  All other 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.
-""" A logging filter to prepend UWSGI-handled formatting to all logging
-records that use this filter. Request-based values will cause the log
-records to have correlation values that can be used to better trace
-logs.  If uwsgi is not present, does not attempt to change the logs in
-any way
-
-Threads initiated using threading.Thread can be correlated to the request
-they came from by setting a kwarg of log_extra, containing a dictionary
-of valeus matching the VALID_ADDL_FIELDS below and any fields that are set
-as additional_fields by the setup_logging function. This mechanism assumes
-that the thread will maintain the correlation values for the life
-of the thread.
-"""
-import logging
-import threading
-
-# Import uwsgi to determine if it has been provided to the application.
-try:
-    import uwsgi
-except ImportError:
-    uwsgi = None
-
-VALID_ADDL_FIELDS = ['req_id', 'external_ctx', 'user']
-_DEFAULT_LOG_FORMAT = (
-    '%(asctime)s %(levelname)-8s %(req_id)s %(external_ctx)s %(user)s '
-    '%(module)s(%(lineno)d) %(funcName)s - %(message)s'
-)
-
-_LOG_FORMAT_IN_USE = None
-
-
-def setup_logging(level, format_string=None, additional_fields=None):
-    """ Establishes the base logging using the appropriate filter
-    attached to the console/stream handler.
-    :param level: The level value to set as the threshold for
-                  logging. Ideally a client would use logging.INFO or
-                  the desired logging constant to set this level value
-    :param format_string: Optional value allowing for override of the
-                          logging format string. If new values beyond
-                          the default value are introduced, the
-                          additional_fields must contain those fields
-                          to ensure they are set upon using the logging
-                          filter.
-    :param additional_fields: Optionally allows for specifying more
-                              fields that will be set on each logging
-                              record. If specified, the format_string
-                              parameter should be set with matching
-                              fields, otherwise they will not be
-                              displayed.
-    """
-    global _LOG_FORMAT_IN_USE
-    _LOG_FORMAT_IN_USE = format_string or _DEFAULT_LOG_FORMAT
-
-    console_handler = logging.StreamHandler()
-    if uwsgi:
-        console_handler.addFilter(UwsgiLogFilter(additional_fields))
-    logging.basicConfig(level=level,
-                        format=_LOG_FORMAT_IN_USE,
-                        handlers=[console_handler])
-    logger = logging.getLogger(__name__)
-    logger.info('Established logging defaults')
-
-
-def get_log_format():
-    """ Returns the common log format being used by this application
-    """
-    return _LOG_FORMAT_IN_USE
-
-
-def set_logvar(key, value):
-    """ Attempts to set the logvar in the request scope , or ignores it
-    if not running in uwsgi
-    """
-    if uwsgi and value:
-        uwsgi.set_logvar(key, value)
-
-
-class UwsgiLogFilter(logging.Filter):
-    """ A filter that preepends log records with additional request
-    based information, or information provided by log_extra in the
-    kwargs provided to a thread
-    """
-    def __init__(self, additional_fields=None):
-        super().__init__()
-        if additional_fields is None:
-            additional_fields = []
-        self.log_fields = [*VALID_ADDL_FIELDS, *additional_fields]
-
-    def filter(self, record):
-        """ Checks for thread provided values, or attempts to get values
-        from uwsgi
-        """
-        if self._thread_has_log_extra():
-            value_setter = self._set_values_from_log_extra
-        else:
-            value_setter = self._set_value
-
-        for field_nm in self.log_fields:
-            value_setter(record, field_nm)
-        return True
-
-    def _set_value(self, record, logvar):
-        # handles setting the logvars from uwsgi or '' in case of none/empty
-        try:
-            logvar_value = None
-            if uwsgi:
-                logvar_value = uwsgi.get_logvar(logvar)
-            if logvar_value:
-                setattr(record, logvar, logvar_value.decode('UTF-8'))
-            else:
-                setattr(record, logvar, '')
-        except SystemError:
-            # This happens if log_extra is not on a thread that is spawned
-            # by a process running under uwsgi
-            setattr(record, logvar, '')
-
-    def _set_values_from_log_extra(self, record, logvar):
-        # sets the values from the log_extra on the thread
-        setattr(record, logvar, self._get_value_from_thread(logvar) or '')
-
-    def _thread_has_log_extra(self):
-        # Checks to see if log_extra is present on the current thread
-        if self._get_log_extra_from_thread():
-            return True
-        return False
-
-    def _get_value_from_thread(self, logvar):
-        # retrieve the logvar from the log_extra from kwargs for the thread
-        return self._get_log_extra_from_thread().get(logvar, '')
-
-    def _get_log_extra_from_thread(self):
-        # retrieves the log_extra value from kwargs or {} if it doesn't
-        # exist
-        return threading.current_thread()._kwargs.get('log_extra', {})

src/bin/shipyard_airflow/shipyard_airflow/control/util/redactor.py

@@ -0,0 +1,119 @@
+# Copyright 2018 AT&T Intellectual Property.  All other 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.
+"""String redaction based upon regex patterns
+
+Uses the keys and patterns from oslo_utils as a starting point, and layers in
+new keys and patterns defined locally.
+"""
+import re
+
+# oslo_utils makes the choice to keep the list of supported redactions
+# non-extensible (purposefully). Here we can define new values, and follow the
+# same basic logic as used in strutils.
+# The following are copied from oslo_utils, strutils. Extend using the other
+# facilties to make these easier to keep in sync:
+_FORMAT_PATTERNS_1 = [r'(%(key)s\s*[=]\s*)[^\s^\'^\"]+']
+_FORMAT_PATTERNS_2 = [r'(%(key)s\s*[=]\s*[\"\'])[^\"\']*([\"\'])',
+                      r'(%(key)s\s+[\"\'])[^\"\']*([\"\'])',
+                      r'([-]{2}%(key)s\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*)']
+_SANITIZE_KEYS = ['adminPass', 'admin_pass', 'password', 'admin_password',
+                  'auth_token', 'new_pass', 'auth_password', 'secret_uuid',
+                  'secret', 'sys_pswd', 'token', 'configdrive',
+                  'CHAPPASSWORD', 'encrypted_key']
+
+
+class Redactor():
+    """String redactor that can be used to replace sensitive values
+
+    :param redaction: the string value to put in place in case of a redaction
+    :param keys: list of additional keys that are searched for and have related
+        values redacted
+    :param single_patterns: list of additional single capture group regex
+        patterns
+    :param double_patterns: list of additional double capture group regex
+        patterns
+    """
+    # Start with the values defined in strutils
+    _KEYS = list(_SANITIZE_KEYS)
+
+    _SINGLE_CG_PATTERNS = list(_FORMAT_PATTERNS_1)
+    _DOUBLE_CG_PATTERNS = list(_FORMAT_PATTERNS_2)
+
+    # More keys to extend the set of keys used in identifying redactions
+    _KEYS.extend([])
+    # More single capture group patterns
+    _SINGLE_CG_PATTERNS.extend([r'(%(key)s\s*[:]\s*)[^\s^\'^\"]+'])
+    # More two capture group patterns
+    _DOUBLE_CG_PATTERNS.extend([])
+
+    def __init__(self,
+                 redaction='***',
+                 keys=None,
+                 single_patterns=None,
+                 double_patterns=None):
+        if keys is None:
+            keys = []
+        if single_patterns is None:
+            single_patterns = []
+        if double_patterns is None:
+            double_patterns = []
+
+        self.redaction = redaction
+
+        self.keys = list(Redactor._KEYS)
+        self.keys.extend(keys)
+
+        singles = list(Redactor._SINGLE_CG_PATTERNS)
+        singles.extend(single_patterns)
+
+        doubles = list(Redactor._DOUBLE_CG_PATTERNS)
+        doubles.extend(double_patterns)
+
+        self._single_cg_patterns = self._gen_patterns(patterns=singles)
+        self._double_cg_patterns = self._gen_patterns(patterns=doubles)
+        # the two capture group patterns
+
+    def _gen_patterns(self, patterns):
+        """Initialize the redaction patterns"""
+        regex_patterns = {}
+        for key in self.keys:
+            regex_patterns[key] = []
+            for pattern in patterns:
+                reg_ex = re.compile(pattern % {'key': key}, re.DOTALL)
+                regex_patterns[key].append(reg_ex)
+        return regex_patterns
+
+    def redact(self, message):
+        """Apply regex based replacements to mask values
+
+        Modeled from:
+        https://github.com/openstack/oslo.utils/blob/9b23c17a6be6d07d171b64ada3629c3680598f7b/oslo_utils/strutils.py#L272
+        """
+        substitute1 = r'\g<1>' + self.redaction
+        substitute2 = r'\g<1>' + self.redaction + r'\g<2>'
+
+        for key in self.keys:
+            if key in message:
+                for pattern in self._double_cg_patterns[key]:
+                    message = re.sub(pattern, substitute2, message)
+                for pattern in self._single_cg_patterns[key]:
+                    message = re.sub(pattern, substitute1, message)
+        return message

src/bin/shipyard_airflow/shipyard_airflow/plugins/ucp_preflight_check_operator.py

@@ -111,7 +111,7 @@ class UcpHealthCheckOperator(BaseOperator):
         # and create xcom key 'drydock_continue_on_fail'
         if (component == 'physicalprovisioner' and
                 self.action_info['parameters'].get(
-                    'continue-on-fail').lower() == 'true' and
+                    'continue-on-fail', 'false').lower() == 'true' and
                 self.action_info['dag_id'] in ['update_site', 'deploy_site']):
             LOG.warning('Drydock did not pass health check. Continuing '
                         'as "continue-on-fail" option is enabled.')

src/bin/shipyard_airflow/test-requirements.txt

@@ -1,5 +1,5 @@
 # Testing
-pytest==3.2.1
+pytest==3.4
 pytest-cov==2.5.1
 mock==2.0.0
 responses==0.8.1

src/bin/shipyard_airflow/tests/unit/control/test_redaction.py

@@ -0,0 +1,106 @@
+# Copyright 2018 AT&T Intellectual Property.  All other 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.
+"""Tests for redaction functionality
+
+- redaction_formatter
+- redactor
+"""
+import logging
+import sys
+
+from shipyard_airflow.control.logging.redaction_formatter import (
+    RedactionFormatter
+)
+from shipyard_airflow.control.util.redactor import Redactor
+
+
+class TestRedaction():
+
+    def test_redactor(self):
+        redactor = Redactor()
+
+        to_redact = "My password = swordfish"
+        expected = "My password = ***"
+        assert redactor.redact(to_redact) == expected
+
+        # not a detected pattern - should be same
+        to_redact = "My pass = swordfish"
+        expected = "My pass = swordfish"
+        assert redactor.redact(to_redact) == expected
+
+        # yaml format
+        to_redact = "My password: swordfish"
+        expected = "My password: ***"
+        assert redactor.redact(to_redact) == expected
+
+        # yaml format
+        to_redact = "My password: swordfish is not for sale"
+        expected = "My password: *** is not for sale"
+        assert redactor.redact(to_redact) == expected
+
+        to_redact = """
+password:
+  swordfish
+"""
+        expected = """
+password:
+  ***
+"""
+        assert redactor.redact(to_redact) == expected
+
+        to_redact = """
+password:
+  swordfish
+  trains:
+    cheese
+"""
+        expected = """
+password:
+  ***
+  trains:
+    cheese
+"""
+        assert redactor.redact(to_redact) == expected
+
+    def test_extended_keys_redactor(self):
+        redactor = Redactor(redaction="++++", keys=['trains'])
+        to_redact = """
+password:
+  swordfish
+  trains:
+    cheese
+"""
+        expected = """
+password:
+  ++++
+  trains:
+    ++++
+"""
+        assert redactor.redact(to_redact) == expected
+
+    def test_redaction_formatter(self, caplog):
+        # since root logging is setup by prior tests need to remove all
+        # handlers to simulate a clean environment of setting up this
+        # RedactionFormatter
+        for handler in list(logging.root.handlers):
+            if not "LogCaptureHandler" == handler.__class__.__name__:
+                logging.root.removeHandler(handler)
+
+        logging.basicConfig(level=logging.DEBUG,
+                            handlers=[logging.StreamHandler(sys.stdout)])
+        for handler in logging.root.handlers:
+            handler.setFormatter(RedactionFormatter(handler.formatter))
+        logging.info('Established password: albatross for this test')
+        assert 'albatross' not in caplog.text
+        assert 'Established password: *** for this test' in caplog.text

src/bin/shipyard_airflow/tests/unit/plugins/test_ucp_preflight_check_operator.py

@@ -27,7 +27,7 @@ ucp_components = [
     'shipyard']
 
 
-def test_drydock_health_skip_update_site():
+def test_drydock_health_skip_update_site(caplog):
     """
     Ensure that an error is not thrown due to Drydock health failing during
     update_site or deploy site
@@ -46,19 +46,17 @@ def test_drydock_health_skip_update_site():
 
     op = UcpHealthCheckOperator(task_id='test')
     op.action_info = action_info
+    op.xcom_pusher = mock.MagicMock()
 
-    with mock.patch('logging.info', autospec=True) as mock_logger:
+    op.log_health_exception('physicalprovisioner', req)
-        op.log_health('physicalprovisioner', req)
+    assert expected_log in caplog.text
-    mock_logger.assert_called_with(expected_log)
 
     action_info = {
         "dag_id": "deploy_site",
         "parameters": {"continue-on-fail": "true"}
     }
-
+    op.log_health_exception('physicalprovisioner', req)
-    with mock.patch('logging.info', autospec=True) as mock_logger:
+    assert expected_log in caplog.text
-        op.log_health('physicalprovisioner', req)
-    mock_logger.assert_called_with(expected_log)
 
 
 def test_failure_log_health():
@@ -74,28 +72,13 @@ def test_failure_log_health():
 
     op = UcpHealthCheckOperator(task_id='test')
     op.action_info = action_info
+    op.xcom_pusher = mock.MagicMock()
 
     for i in ucp_components:
         with pytest.raises(AirflowException) as expected_exc:
-            op.log_health(i, req)
+            op.log_health_exception(i, req)
         assert "Health check failed" in str(expected_exc)
 
 
-def test_success_log_health():
+# TODO test that execute works correctly by using Responses framework and
-    """ Ensure 204 gives correct response for all components
+#     caplog
-    """
-    action_info = {
-        "dag_id": "deploy_site",
-        "parameters": {"something-else": "true"}
-    }
-
-    req = Response()
-    req.status_code = 204
-
-    op = UcpHealthCheckOperator(task_id='test')
-    op.action_info = action_info
-
-    for i in ucp_components:
-        with mock.patch('logging.info', autospec=True) as mock_logger:
-            op.log_health(i, req)
-        mock_logger.assert_called_with('%s is alive and healthy', i)

src/bin/shipyard_client/test-requirements.txt

@@ -1,5 +1,5 @@
 # Testing
-pytest==3.2.1
+pytest==3.4
 pytest-cov==2.5.1
 mock==2.0.0
 responses==0.8.1