From a5f75722dc7a7af587b3b89c803466828606bd95 Mon Sep 17 00:00:00 2001 From: Felipe Monteiro Date: Mon, 12 Mar 2018 21:33:28 +0000 Subject: [PATCH] Log all document data following any layering action failure This is to log out all document data following any layering action failure. This consists of two stages: 1) Scrubbing all primitives contained in the data sections of both the child and parent being layered together. 2) Logging scrubbed-out data sections for both documents, in addition to their names, schemas, and the layering action itself. This will hopefully provide DEs with enough information about why a layering action may have failed to apply while at the same time preventing any secret data from being logged out. Change-Id: I3fedd259bba7b930c7969e9c30d1fffef5bf77bd --- deckhand/common/utils.py | 13 ++--- deckhand/engine/layering.py | 49 +++++++++++++++++-- deckhand/engine/utils.py | 25 ++++++++++ deckhand/errors.py | 10 +++- ...ment_layering_and_substitution_negative.py | 30 ++++++++++-- .../engine/test_document_layering_negative.py | 17 +++++-- 6 files changed, 123 insertions(+), 21 deletions(-) diff --git a/deckhand/common/utils.py b/deckhand/common/utils.py index 5c0a6d60..2a3d1b29 100644 --- a/deckhand/common/utils.py +++ b/deckhand/common/utils.py @@ -19,6 +19,7 @@ import string import jsonpath_ng from oslo_log import log as logging +from oslo_utils import excutils import six from deckhand import errors @@ -175,9 +176,10 @@ def jsonpath_replace(data, value, jsonpath, pattern=None): try: new_value = re.sub(pattern, str(value), to_replace) except TypeError as e: - LOG.error('Failed to substitute the value %s into %s ' - 'using pattern %s. Details: %s', str(value), - to_replace, pattern, six.text_type(e)) + with excutils.save_and_reraise_exception(): + LOG.error('Failed to substitute the value %s into %s ' + 'using pattern %s. Details: %s', str(value), + to_replace, pattern, six.text_type(e)) return p.update(data, new_value) result = _do_replace() @@ -188,10 +190,9 @@ def jsonpath_replace(data, value, jsonpath, pattern=None): # and then figure out what re.match(data[jsonpath], pattern) is (in # pseudocode). But raise an exception in case the path isn't present in the # data and a pattern has been provided since it is impossible to do the - # look up. + # look-up. if pattern: - raise errors.MissingDocumentPattern( - data=data, path=jsonpath, pattern=pattern) + raise errors.MissingDocumentPattern(path=jsonpath, pattern=pattern) # However, Deckhand should be smart enough to create the nested keys in the # data if they don't exist and a pattern isn't required. diff --git a/deckhand/engine/layering.py b/deckhand/engine/layering.py index 6d3da5cf..fbba9548 100644 --- a/deckhand/engine/layering.py +++ b/deckhand/engine/layering.py @@ -20,6 +20,7 @@ from networkx.algorithms.cycles import find_cycle from networkx.algorithms.dag import topological_sort from oslo_log import log as logging from oslo_log import versionutils +from oslo_utils import excutils from deckhand.common import document as document_wrapper from deckhand.common import utils @@ -445,6 +446,29 @@ class DocumentLayering(object): del self._documents_by_layer del self._documents_by_labels + def _log_data_for_layering_failure(self, child, parent, action): + child_data = copy.deepcopy(child.data) + parent_data = copy.deepcopy(parent.data) + + engine_utils.deep_scrub(child_data, None) + engine_utils.deep_scrub(parent_data, None) + + LOG.debug('An exception occurred while attempting to layer child ' + 'document [%s] %s with parent document [%s] %s using ' + 'layering action: %s.\nScrubbed child document data: %s.\n' + 'Scrubbed parent document data: %s.', child.schema, + child.name, parent.schema, parent.name, action, child_data, + parent_data) + + def _log_data_for_substitution_failure(self, document): + document_data = copy.deepcopy(document.data) + engine_utils.deep_scrub(document_data, None) + + LOG.debug('An exception occurred while attempting to add substitutions' + ' %s into document [%s] %s\nScrubbed document data: %s.', + document.substitutions, document.schema, document.name, + document_data) + def _apply_action(self, action, child_data, overall_data): """Apply actions to each layer that is rendered. @@ -565,10 +589,18 @@ class DocumentLayering(object): # Apply each action to the current document. for action in doc.actions: LOG.debug('Applying action %s to document with ' - 'schema=%s, name=%s, layer=%s.', action, + 'schema=%s, layer=%s, name=%s.', action, *doc.meta) - rendered_data = self._apply_action( - action, doc, rendered_data) + try: + rendered_data = self._apply_action( + action, doc, rendered_data) + except Exception: + with excutils.save_and_reraise_exception(): + try: + self._log_data_for_layering_failure( + doc, parent, action) + except Exception: # nosec + pass if not doc.is_abstract: doc.data = rendered_data.data self.secrets_substitution.update_substitution_sources( @@ -584,8 +616,15 @@ class DocumentLayering(object): # Perform substitutions on abstract data for child documents that # inherit from it, but only update the document's data if concrete. if doc.substitutions: - substituted_data = list( - self.secrets_substitution.substitute_all(doc)) + try: + substituted_data = list( + self.secrets_substitution.substitute_all(doc)) + except Exception: + with excutils.save_and_reraise_exception(): + try: + self._log_data_for_substitution_failure(doc) + except Exception: # nosec + pass if substituted_data: rendered_data = substituted_data[0] # Update the actual document data if concrete. diff --git a/deckhand/engine/utils.py b/deckhand/engine/utils.py index 0d05ee63..b6d11044 100644 --- a/deckhand/engine/utils.py +++ b/deckhand/engine/utils.py @@ -69,3 +69,28 @@ def deep_delete(target, value, parent): if found: return True return False + + +def deep_scrub(value, parent): + """Scrubs all primitives in document data recursively. Useful for scrubbing + any and all secret data that may have been substituted into the document + data section before logging it out safely following an error. + """ + primitive = (int, float, complex, str, bytes, bool) + + def is_primitive(value): + return isinstance(value, primitive) + + if is_primitive(value): + if isinstance(parent, list): + parent[parent.index(value)] = 'Scrubbed' + elif isinstance(parent, dict): + for k, v in parent.items(): + if v == value: + parent[k] = 'Scrubbed' + elif isinstance(value, list): + for v in value: + deep_scrub(v, value) + elif isinstance(value, dict): + for v in value.values(): + deep_scrub(v, value) diff --git a/deckhand/errors.py b/deckhand/errors.py index b3f68dc5..bf502f9a 100644 --- a/deckhand/errors.py +++ b/deckhand/errors.py @@ -255,9 +255,15 @@ class MissingDocumentPattern(DeckhandException): """'Pattern' is not None and data[jsonpath] doesn't exist. **Troubleshoot:** + + * Check that the destination document's data section contains the + pattern specified under `substitutions.dest.pattern` in its data + section at `substitutions.dest.path`. """ - msg_fmt = ("Missing document pattern %(pattern)s in %(data)s at path " - "%(path)s.") + msg_fmt = ("The destination document's `data` section is missing the " + "pattern %(pattern)s specified under " + "`substitutions.dest.pattern` at path %(jsonpath)s, specified " + "under `substitutions.dest.path`.") code = 400 diff --git a/deckhand/tests/unit/engine/test_document_layering_and_substitution_negative.py b/deckhand/tests/unit/engine/test_document_layering_and_substitution_negative.py index 344da0a8..cf336c77 100644 --- a/deckhand/tests/unit/engine/test_document_layering_and_substitution_negative.py +++ b/deckhand/tests/unit/engine/test_document_layering_and_substitution_negative.py @@ -12,6 +12,8 @@ # See the License for the specific language governing permissions and # limitations under the License. +import mock + from deckhand.engine import layering from deckhand import errors from deckhand import factories @@ -113,10 +115,12 @@ class TestDocumentLayeringWithSubstitutionNegative( self.assertRaises( errors.SubstitutionDependencyCycle, self._test_layering, documents) - def test_layering_with_missing_substitution_source_raises_exc(self): + @mock.patch.object(layering, 'LOG', autospec=True) + def test_layering_with_missing_substitution_source_raises_exc( + self, mock_log): """Validate that a missing substitution source document fails.""" mapping = { - "_SITE_SUBSTITUTIONS_1_": [{ + "_GLOBAL_SUBSTITUTIONS_1_": [{ "dest": { "path": ".c" }, @@ -125,10 +129,26 @@ class TestDocumentLayeringWithSubstitutionNegative( "name": "nowhere-to-be-found", "path": "." } - }] + }], + "_GLOBAL_DATA_1_": { + "data": { + "a": {"b": [1, 2, 3]}, "c": "d" + } + } } - doc_factory = factories.DocumentFactory(2, [1, 1]) - documents = doc_factory.gen_test(mapping, site_abstract=False) + doc_factory = factories.DocumentFactory(1, [1]) + documents = doc_factory.gen_test(mapping, global_abstract=False) + + scrubbed_data = { + 'a': {'b': ['Scrubbed', 'Scrubbed', 'Scrubbed']}, 'c': 'Scrubbed'} self.assertRaises( errors.SubstitutionSourceNotFound, self._test_layering, documents) + + # Verifies that document data is recursively scrubbed prior to logging + # it. + mock_log.debug.assert_called_with( + 'An exception occurred while attempting to add substitutions %s ' + 'into document [%s] %s\nScrubbed document data: %s.', + documents[1]['metadata']['substitutions'], documents[1]['schema'], + documents[1]['metadata']['name'], scrubbed_data) diff --git a/deckhand/tests/unit/engine/test_document_layering_negative.py b/deckhand/tests/unit/engine/test_document_layering_negative.py index 587ca1b0..bb64650e 100644 --- a/deckhand/tests/unit/engine/test_document_layering_negative.py +++ b/deckhand/tests/unit/engine/test_document_layering_negative.py @@ -39,20 +39,31 @@ class TestDocumentLayeringNegative( self.assertRaises(errors.MissingDocumentKey, self._test_layering, documents) - def test_layering_method_delete_key_not_in_child(self): + @mock.patch.object(layering, 'LOG', autospec=True) + def test_layering_method_delete_key_not_in_child(self, mock_log): # The key will not be in the site after the global data is copied into # the site data implicitly. + action = {'method': 'delete', 'path': '.b'} mapping = { "_GLOBAL_DATA_1_": {"data": {"a": {"x": 1, "y": 2}, "c": 9}}, "_SITE_DATA_1_": {"data": {"a": {"x": 7, "z": 3}, "b": 4}}, - "_SITE_ACTIONS_1_": { - "actions": [{"method": "delete", "path": ".b"}]} + "_SITE_ACTIONS_1_": {"actions": [action]} } doc_factory = factories.DocumentFactory(2, [1, 1]) documents = doc_factory.gen_test(mapping, site_abstract=False) self.assertRaises(errors.MissingDocumentKey, self._test_layering, documents) + # Verifies that document data is recursively scrubbed prior to logging + # it. + mock_log.debug.assert_called_with( + 'An exception occurred while attempting to layer child document ' + '[%s] %s with parent document [%s] %s using layering action: %s.\n' + 'Scrubbed child document data: %s.\nScrubbed parent document data:' + ' %s.', documents[2]['schema'], documents[2]['metadata']['name'], + documents[1]['schema'], documents[1]['metadata']['name'], + action, {'b': 'Scrubbed', 'a': {'z': 'Scrubbed', 'x': 'Scrubbed'}}, + {'c': 'Scrubbed', 'a': {'x': 'Scrubbed', 'y': 'Scrubbed'}}) def test_layering_method_replace_key_not_in_child(self): mapping = {