Do not reveal auth token in swiftclient log messages by defaultliberty-eolstable/liberty

Currently the swiftclient logs sensitive info in headers when logging
HTTP requests. This patch hides sensitive info in headers such as
'X-Auth-Token' in a similar way to swift itself (we add a
'reveal_sensitive_prefix' configuration to the client).

With this patch, tokens are truncated by removing the specified number
of characters, after which '...' is appended to the logged token to
indicate that it has been redacted.

Also include client.parse_header_string() for safe unicode handling
of header data.

Backport based on commits:

  c3f06417049e17a8d45ee5926c5043cb6c8aa9ef
  4d44dcf36086add13d3353915c014f095ab99c6d
  ce569f46517e10f2ce0d27e9ee0a922ad1d84e2f
  46d817828082105a69d4da53fef2f2fbefc54809
  aa0edd00966237163451fc44cda2c593a5215cbe

Co-Authored-By: Tim Burke <tim.burke@gmail.com>
Co-Authored-By: Alistair Coles <alistair.coles@hpe.com>
Co-Authored-By: Li Cheng <shcli@cn.ibm.com>
Co-Authored-By: Zack M. Davis <zdavis@swiftstack.com>

Change-Id: I71fc5aad23bc076b06f75888c3ea507feffc7b48
Closes-bug: #1516692

4 files changed, 221 insertions, 12 deletions

diff --git a/swiftclient/client.py b/swiftclient/client.py
index 9d6517e..91036a9 100644
--- a/swiftclient/client.py
+++ b/swiftclient/client.py
@@ -24,7 +24,7 @@ import warnings
 from distutils.version import StrictVersion
 from requests.exceptions import RequestException, SSLError
 from six.moves import http_client
-from six.moves.urllib.parse import quote as _quote
+from six.moves.urllib.parse import quote as _quote, unquote
 from six.moves.urllib.parse import urlparse, urlunparse
 from time import sleep, time
 import six
@@ -71,6 +71,69 @@ if StrictVersion(requests.__version__) < StrictVersion('2.0.0'):
 logger = logging.getLogger("swiftclient")
 logger.addHandler(NullHandler())
 
+#: Default behaviour is to redact header values known to contain secrets,
+#: such as ``X-Auth-Key`` and ``X-Auth-Token``. Up to the first 16 chars
+#: may be revealed.
+#:
+#: To disable, set the value of ``redact_sensitive_headers`` to ``False``.
+#:
+#: When header redaction is enabled, ``reveal_sensitive_prefix`` configures the
+#: maximum length of any sensitive header data sent to the logs. If the header
+#: is less than twice this length, only ``int(len(value)/2)`` chars will be
+#: logged; if it is less than 15 chars long, even less will be logged.
+logger_settings = {
+    'redact_sensitive_headers': True,
+    'reveal_sensitive_prefix': 16
+}
+#: A list of sensitive headers to redact in logs. Note that when extending this
+#: list, the header names must be added in all lower case.
+LOGGER_SENSITIVE_HEADERS = [
+    'x-auth-token', 'x-auth-key', 'x-service-token', 'x-storage-token',
+    'x-account-meta-temp-url-key', 'x-account-meta-temp-url-key-2',
+    'x-container-meta-temp-url-key', 'x-container-meta-temp-url-key-2',
+    'set-cookie'
+]
+
+
+def safe_value(name, value):
+    """
+    Only show up to logger_settings['reveal_sensitive_prefix'] characters
+    from a sensitive header.
+
+    :param name: Header name
+    :param value: Header value
+    :return: Safe header value
+    """
+    if name.lower() in LOGGER_SENSITIVE_HEADERS:
+        prefix_length = logger_settings.get('reveal_sensitive_prefix', 16)
+        prefix_length = int(
+            min(prefix_length, (len(value) ** 2) / 32, len(value) / 2)
+        )
+        redacted_value = value[0:prefix_length]
+        return redacted_value + '...'
+    return value
+
+
+def scrub_headers(headers):
+    """
+    Redact header values that can contain sensitive information that
+    should not be logged.
+
+    :param headers: Either a dict or an iterable of two-element tuples
+    :return: Safe dictionary of headers with sensitive information removed
+    """
+    if isinstance(headers, dict):
+        headers = headers.items()
+    headers = [
+        (parse_header_string(key), parse_header_string(val))
+        for (key, val) in headers
+    ]
+    if not logger_settings.get('redact_sensitive_headers', True):
+        return dict(headers)
+    if logger_settings.get('reveal_sensitive_prefix', 16) < 0:
+        logger_settings['reveal_sensitive_prefix'] = 16
+    return dict((key, safe_value(key, val)) for (key, val) in headers)
+
 
 def http_log(args, kwargs, resp, body):
     if not logger.isEnabledFor(logging.INFO):
@@ -86,8 +149,9 @@ def http_log(args, kwargs, resp, body):
         else:
             string_parts.append(' %s' % element)
     if 'headers' in kwargs:
-        for element in kwargs['headers']:
-            header = ' -H "%s: %s"' % (element, kwargs['headers'][element])
+        headers = scrub_headers(kwargs['headers'])
+        for element in headers:
+            header = ' -H "%s: %s"' % (element, headers[element])
             string_parts.append(header)
 
     # log response as debug if good, or info if error
@@ -98,11 +162,43 @@ def http_log(args, kwargs, resp, body):
 
     log_method("REQ: %s", "".join(string_parts))
     log_method("RESP STATUS: %s %s", resp.status, resp.reason)
-    log_method("RESP HEADERS: %s", resp.getheaders())
+    log_method("RESP HEADERS: %s", scrub_headers(resp.getheaders()))
     if body:
         log_method("RESP BODY: %s", body)
 
 
+def parse_header_string(data):
+    if not isinstance(data, (six.text_type, six.binary_type)):
+        data = str(data)
+    if six.PY2:
+        if isinstance(data, six.text_type):
+            # Under Python2 requests only returns binary_type, but if we get
+            # some stray text_type input, this should prevent unquote from
+            # interpreting %-encoded data as raw code-points.
+            data = data.encode('utf8')
+        try:
+            unquoted = unquote(data).decode('utf8')
+        except UnicodeDecodeError:
+            try:
+                return data.decode('utf8')
+            except UnicodeDecodeError:
+                return quote(data).decode('utf8')
+    else:
+        if isinstance(data, six.binary_type):
+            # Under Python3 requests only returns text_type and tosses (!) the
+            # rest of the headers. If that ever changes, this should be a sane
+            # approach.
+            try:
+                data = data.decode('ascii')
+            except UnicodeDecodeError:
+                data = quote(data)
+        try:
+            unquoted = unquote(data, errors='strict')
+        except UnicodeDecodeError:
+            return data
+    return unquoted
+
+
 def quote(value, safe='/'):
     """
     Patched version of urllib.quote that encodes utf8 strings before quoting.
@@ -301,11 +397,11 @@ def get_auth_1_0(url, user, key, snet, **kwargs):
     parsed, conn = http_connection(url, cacert=cacert, insecure=insecure,
                                    timeout=timeout)
     method = 'GET'
-    conn.request(method, parsed.path, '',
-                 {'X-Auth-User': user, 'X-Auth-Key': key})
+    headers = {'X-Auth-User': user, 'X-Auth-Key': key}
+    conn.request(method, parsed.path, '', headers)
     resp = conn.getresponse()
     body = resp.read()
-    http_log((url, method,), {}, resp, body)
+    http_log((url, method,), headers, resp, body)
     url = resp.getheader('x-storage-url')
 
     # There is a side-effect on current Rackspace 1.0 server where a
diff --git a/swiftclient/shell.py b/swiftclient/shell.py
index 652980f..eda6475 100755
--- a/swiftclient/shell.py
+++ b/swiftclient/shell.py
@@ -32,6 +32,7 @@ from swiftclient.utils import config_true_value, generate_temp_url, prt_bytes
 from swiftclient.multithreading import OutputManager
 from swiftclient.exceptions import ClientException
 from swiftclient import __version__ as client_version
+from swiftclient.client import logger_settings as client_logger_settings
 from swiftclient.service import SwiftService, SwiftError, \
     SwiftUploadObject, get_conn
 from swiftclient.command_helpers import print_account_stats, \
@@ -1414,6 +1415,7 @@ Examples:
         logging.getLogger("swiftclient")
         if options.debug:
             logging.basicConfig(level=logging.DEBUG)
+            client_logger_settings['redact_sensitive_headers'] = False
         elif options.info:
             logging.basicConfig(level=logging.INFO)
 
diff --git a/tests/unit/test_swiftclient.py b/tests/unit/test_swiftclient.py
index 23b3138..3ca758e 100644
--- a/tests/unit/test_swiftclient.py
+++ b/tests/unit/test_swiftclient.py
@@ -130,6 +130,31 @@ class TestHttpHelpers(MockHttpTest):
         value = u'unicode:\xe9\u20ac'
         self.assertEqual('unicode%3A%C3%A9%E2%82%AC', c.quote(value))
 
+    def test_parse_header_string(self):
+        value = b'bytes'
+        self.assertEqual(u'bytes', c.parse_header_string(value))
+        value = u'unicode:\xe9\u20ac'
+        self.assertEqual(u'unicode:\xe9\u20ac', c.parse_header_string(value))
+        value = 'native%20string'
+        self.assertEqual(u'native string', c.parse_header_string(value))
+
+        value = b'encoded%20bytes%E2%82%AC'
+        self.assertEqual(u'encoded bytes\u20ac', c.parse_header_string(value))
+        value = 'encoded%20unicode%E2%82%AC'
+        self.assertEqual(u'encoded unicode\u20ac',
+                         c.parse_header_string(value))
+
+        value = b'bad%20bytes%ff%E2%82%AC'
+        self.assertEqual(u'bad%20bytes%ff%E2%82%AC',
+                         c.parse_header_string(value))
+        value = u'bad%20unicode%ff\u20ac'
+        self.assertEqual(u'bad%20unicode%ff\u20ac',
+                         c.parse_header_string(value))
+
+        value = b'really%20bad\xffbytes'
+        self.assertEqual(u'really%2520bad%FFbytes',
+                         c.parse_header_string(value))
+
     def test_http_connection(self):
         url = 'http://www.test.com'
         _junk, conn = c.http_connection(url)
@@ -748,7 +773,7 @@ class TestPutObject(MockHttpTest):
                 mock_file)
         text = u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
         headers = {'X-Header1': text,
-                   'X-2': 1, 'X-3': {'a': 'b'}, 'a-b': '.x:yz mn:fg:lp'}
+                   'X-2': '1', 'X-3': "{'a': 'b'}", 'a-b': '.x:yz mn:fg:lp'}
 
         resp = MockHttpResponse()
         conn[1].getresponse = resp.fake_response
@@ -926,8 +951,17 @@ class TestPostObject(MockHttpTest):
 
     def test_ok(self):
         c.http_connection = self.fake_http_connection(200)
-        args = ('http://www.test.com', 'asdf', 'asdf', 'asdf', {})
+        delete_at = 2.1  # not str! we don't know what other devs will use!
+        args = ('http://www.test.com', 'token', 'container', 'obj',
+                {'X-Object-Meta-Test': 'mymeta',
+                 'X-Delete-At': delete_at})
         c.post_object(*args)
+        self.assertRequests([
+            ('POST', '/container/obj', '', {
+                'x-auth-token': 'token',
+                'X-Object-Meta-Test': 'mymeta',
+                'X-Delete-At': delete_at}),
+        ])
 
     def test_unicode_ok(self):
         conn = c.http_connection(u'http://www.test.com/')
@@ -938,7 +972,7 @@ class TestPostObject(MockHttpTest):
         text = u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
         headers = {'X-Header1': text,
                    b'X-Header2': 'value',
-                   'X-2': '1', 'X-3': {'a': 'b'}, 'a-b': '.x:yz mn:kl:qr',
+                   'X-2': '1', 'X-3': "{'a': 'b'}", 'a-b': '.x:yz mn:kl:qr',
                    'X-Object-Meta-Header-not-encoded': text,
                    b'X-Object-Meta-Header-encoded': 'value'}
 
@@ -1812,6 +1846,83 @@ class TestLogging(MockHttpTest):
                               'http://www.test.com', 'asdf', 'asdf', 'asdf')
         self.assertEqual(e.http_status, 404)
 
+    def test_redact_token(self):
+        with mock.patch('swiftclient.client.logger.debug') as mock_log:
+            token_value = 'tkee96b40a8ca44fc5ad72ec5a7c90d9b'
+            token_encoded = token_value.encode('utf8')
+            unicode_token_value = (u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
+                                   u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
+                                   u'\u5929\u7a7a\u4e2d\u7684\u4e4c')
+            unicode_token_encoded = unicode_token_value.encode('utf8')
+            set_cookie_value = 'X-Auth-Token=%s' % token_value
+            set_cookie_encoded = set_cookie_value.encode('utf8')
+            c.http_log(
+                ['GET'],
+                {'headers': {
+                    'X-Auth-Token': token_encoded,
+                    'X-Storage-Token': unicode_token_encoded
+                }},
+                MockHttpResponse(
+                    status=200,
+                    headers={
+                        'X-Auth-Token': token_encoded,
+                        'X-Storage-Token': unicode_token_encoded,
+                        'Etag': b'mock_etag',
+                        'Set-Cookie': set_cookie_encoded
+                    }
+                ),
+                ''
+            )
+            out = []
+            for _, args, kwargs in mock_log.mock_calls:
+                for arg in args:
+                    out.append(u'%s' % arg)
+            output = u''.join(out)
+            self.assertIn('X-Auth-Token', output)
+            self.assertIn(token_value[:16] + '...', output)
+            self.assertIn('X-Storage-Token', output)
+            self.assertIn(unicode_token_value[:8] + '...', output)
+            self.assertIn('Set-Cookie', output)
+            self.assertIn(set_cookie_value[:16] + '...', output)
+            self.assertNotIn(token_value, output)
+            self.assertNotIn(unicode_token_value, output)
+            self.assertNotIn(set_cookie_value, output)
+
+    def test_show_token(self):
+        with mock.patch('swiftclient.client.logger.debug') as mock_log:
+            token_value = 'tkee96b40a8ca44fc5ad72ec5a7c90d9b'
+            token_encoded = token_value.encode('utf8')
+            unicode_token_value = (u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
+                                   u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
+                                   u'\u5929\u7a7a\u4e2d\u7684\u4e4c')
+            c.logger_settings['redact_sensitive_headers'] = False
+            unicode_token_encoded = unicode_token_value.encode('utf8')
+            c.http_log(
+                ['GET'],
+                {'headers': {
+                    'X-Auth-Token': token_encoded,
+                    'X-Storage-Token': unicode_token_encoded
+                }},
+                MockHttpResponse(
+                    status=200,
+                    headers=[
+                        ('X-Auth-Token', token_encoded),
+                        ('X-Storage-Token', unicode_token_encoded),
+                        ('Etag', b'mock_etag')
+                    ]
+                ),
+                ''
+            )
+            out = []
+            for _, args, kwargs in mock_log.mock_calls:
+                for arg in args:
+                    out.append(u'%s' % arg)
+            output = u''.join(out)
+            self.assertIn('X-Auth-Token', output)
+            self.assertIn(token_value, output)
+            self.assertIn('X-Storage-Token', output)
+            self.assertIn(unicode_token_value, output)
+
 
 class TestCloseConnection(MockHttpTest):
 
diff --git a/tests/unit/utils.py b/tests/unit/utils.py
index ac9aefd..a9759eb 100644
--- a/tests/unit/utils.py
+++ b/tests/unit/utils.py
@@ -124,7 +124,7 @@ def fake_http_connect(*code_iter, **kwargs):
         def getheaders(self):
             if self.headers:
                 return self.headers.items()
-            headers = {'content-length': len(self.body),
+            headers = {'content-length': str(len(self.body)),
                        'content-type': 'x-application/test',
                        'x-timestamp': self.timestamp,
                        'last-modified': self.timestamp,
@@ -132,7 +132,7 @@ def fake_http_connect(*code_iter, **kwargs):
                        'etag':
                        self.etag or '"%s"' % EMPTY_ETAG,
                        'x-works': 'yes',
-                       'x-account-container-count': 12345}
+                       'x-account-container-count': '12345'}
             if not self.timestamp:
                 del headers['x-timestamp']
             try: