diff --git a/.dockerignore b/.dockerignore index 1a6c0731..107dba14 100644 --- a/.dockerignore +++ b/.dockerignore @@ -44,6 +44,7 @@ cov/* **/.tox/ **/.coverage **/.coverage.* +**/.pytest_cache/ **/.cache nosetests.xml coverage.xml diff --git a/.gitignore b/.gitignore index a78643fa..8d02ee84 100644 --- a/.gitignore +++ b/.gitignore @@ -42,6 +42,7 @@ cov/* .coverage .coverage.* .cache +.pytest_cache/ nosetests.xml coverage.xml *.cover diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/logging/__init__.py b/src/bin/shipyard_airflow/shipyard_airflow/control/logging/__init__.py new file mode 100644 index 00000000..e69de29b diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/logging/logging_config.py b/src/bin/shipyard_airflow/shipyard_airflow/control/logging/logging_config.py new file mode 100644 index 00000000..ab10d8aa --- /dev/null +++ b/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) diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/logging/redaction_formatter.py b/src/bin/shipyard_airflow/shipyard_airflow/control/logging/redaction_formatter.py new file mode 100644 index 00000000..cffec370 --- /dev/null +++ b/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) diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/logging/request_logging.py b/src/bin/shipyard_airflow/shipyard_airflow/control/logging/request_logging.py new file mode 100644 index 00000000..c1d66e4a --- /dev/null +++ b/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) diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/logging/uwsgi_filter.py b/src/bin/shipyard_airflow/shipyard_airflow/control/logging/uwsgi_filter.py new file mode 100644 index 00000000..1a6d7844 --- /dev/null +++ b/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', {}) diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/middleware/logging_mw.py b/src/bin/shipyard_airflow/shipyard_airflow/control/middleware/logging_mw.py index ef541327..c7b4e95b 100644 --- a/src/bin/shipyard_airflow/shipyard_airflow/control/middleware/logging_mw.py +++ b/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) - ucp_logging.set_logvar('external_ctx', req.context.external_marker) - ucp_logging.set_logvar('user', req.context.user) + request_logging.set_logvar('req_id', req.context.request_id) + request_logging.set_logvar('external_ctx', req.context.external_marker) + 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) diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/start_shipyard.py b/src/bin/shipyard_airflow/shipyard_airflow/control/start_shipyard.py index 8580e533..0cd9cb32 100644 --- a/src/bin/shipyard_airflow/shipyard_airflow/control/start_shipyard.py +++ b/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) - setup_log_levels() + LoggingConfig( + 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) diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/ucp_logging.py b/src/bin/shipyard_airflow/shipyard_airflow/control/ucp_logging.py deleted file mode 100644 index 9df95f9a..00000000 --- a/src/bin/shipyard_airflow/shipyard_airflow/control/ucp_logging.py +++ /dev/null @@ -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', {}) diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/util/__init__.py b/src/bin/shipyard_airflow/shipyard_airflow/control/util/__init__.py new file mode 100644 index 00000000..e69de29b diff --git a/src/bin/shipyard_airflow/shipyard_airflow/control/util/redactor.py b/src/bin/shipyard_airflow/shipyard_airflow/control/util/redactor.py new file mode 100644 index 00000000..cf9c4054 --- /dev/null +++ b/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>)[^<]*()', + 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 diff --git a/src/bin/shipyard_airflow/shipyard_airflow/plugins/ucp_preflight_check_operator.py b/src/bin/shipyard_airflow/shipyard_airflow/plugins/ucp_preflight_check_operator.py index c6bb820b..96db1fde 100644 --- a/src/bin/shipyard_airflow/shipyard_airflow/plugins/ucp_preflight_check_operator.py +++ b/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.') diff --git a/src/bin/shipyard_airflow/test-requirements.txt b/src/bin/shipyard_airflow/test-requirements.txt index fd5c41a5..4c77065d 100644 --- a/src/bin/shipyard_airflow/test-requirements.txt +++ b/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 diff --git a/src/bin/shipyard_airflow/tests/unit/control/test_redaction.py b/src/bin/shipyard_airflow/tests/unit/control/test_redaction.py new file mode 100644 index 00000000..c3a4679d --- /dev/null +++ b/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 diff --git a/tests/unit/plugins/test_ucp_preflight_check_operator.py b/src/bin/shipyard_airflow/tests/unit/plugins/test_ucp_preflight_check_operator.py similarity index 68% rename from tests/unit/plugins/test_ucp_preflight_check_operator.py rename to src/bin/shipyard_airflow/tests/unit/plugins/test_ucp_preflight_check_operator.py index 8a2fdcb4..39daaccc 100644 --- a/tests/unit/plugins/test_ucp_preflight_check_operator.py +++ b/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('physicalprovisioner', req) - mock_logger.assert_called_with(expected_log) + op.log_health_exception('physicalprovisioner', req) + assert expected_log in caplog.text action_info = { "dag_id": "deploy_site", "parameters": {"continue-on-fail": "true"} } - - with mock.patch('logging.info', autospec=True) as mock_logger: - op.log_health('physicalprovisioner', req) - mock_logger.assert_called_with(expected_log) + op.log_health_exception('physicalprovisioner', req) + assert expected_log in caplog.text 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(): - """ Ensure 204 gives correct response for all components - """ - 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) +# TODO test that execute works correctly by using Responses framework and +# caplog diff --git a/src/bin/shipyard_client/test-requirements.txt b/src/bin/shipyard_client/test-requirements.txt index 6d2b3412..96d33dff 100644 --- a/src/bin/shipyard_client/test-requirements.txt +++ b/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