[390136] Shipyard header logging

Moves shipyard header logging to debug and
prunes entries that need/should not be printed in logs

Change-Id: Ie2c6e0706726194ab2f2383211e7c95e0726d59a

shipyard_airflow/control/middleware/logging_mw.py

@@ -14,6 +14,7 @@
 """ Module for logging related middleware
 """
 import logging
+import re
 
 from shipyard_airflow.control import ucp_logging
 
@@ -24,6 +25,7 @@ class LoggingMiddleware(object):
     """ Sets values to the request scope, and logs request and
     response information
     """
+    hdr_exclude = re.compile('x-.*', re.IGNORECASE)
 
     def process_request(self, req, resp):
         """ Set up values to be logged across the request
@@ -32,8 +34,7 @@ class LoggingMiddleware(object):
         ucp_logging.set_logvar('external_ctx', req.context.external_marker)
         ucp_logging.set_logvar('user', req.context.user)
         LOG.info("Request %s %s", req.method, req.url)
-        for header, header_value in req.headers.items():
-            LOG.info("Request header %s: %s", header, header_value)
+        self._log_headers(req.headers)
 
     def process_response(self, req, resp, resource, req_succeeded):
         """ Log the response information
@@ -42,3 +43,10 @@ class LoggingMiddleware(object):
         resp.append_header('X-Shipyard-Req', ctx.request_id)
         LOG.info('%s %s - %s', req.method, req.uri, resp.status)
         LOG.debug('Response body:%s', resp.body)
+
+    def _log_headers(self, headers):
+        """ Log request headers, while scrubbing sensitive values
+        """
+        for header, header_value in headers.items():
+            if not LoggingMiddleware.hdr_exclude.match(header):
+                LOG.debug("Header %s: %s", header, header_value)

tests/unit/control/middleware/test_logging_mw.py

@@ -0,0 +1,38 @@
+# 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.
+from testfixtures import LogCapture
+
+from shipyard_airflow.control.middleware.logging_mw import LoggingMiddleware
+
+
+class TestLoggingMw(object):
+
+    def test_log_headers(self):
+        lm = LoggingMiddleware()
+        logger = 'shipyard_airflow.control.middleware.logging_mw'
+        with LogCapture() as lc:
+            lm._log_headers({"header": "val1",
+                             "X-HEADER": "val2",
+                             "x-hdr": "val3",
+                             "hdrX-hdr": "val4",
+                             "hdr-Xhdr": "val5"})
+        # because the order is hash, can't simply log_capturer.check
+        logs = ''
+        for rec in lc.records:
+            logs = logs + rec.msg % rec.args
+        assert 'Header header: val1' in logs
+        assert 'Header hdrX-hdr: val4' in logs
+        assert 'Header hdr-Xhdr: val5' in logs
+        assert 'val2' not in logs
+        assert 'val3' not in logs