Do not reveal auth token in swiftclient log messages by default

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.

Co-Authored-By: Li Cheng <shcli@cn.ibm.com>
Co-Authored-By: Zack M. Davis <zdavis@swiftstack.com>
Change-Id: I43dd7254f7281d4db59b286aa2145643c64e1705
Closes-bug: #1516692
This commit is contained in:
Joel Wright 2016-02-19 13:18:15 +00:00
parent da0aa24f28
commit 4d44dcf360
3 changed files with 141 additions and 8 deletions

View File

@ -72,6 +72,64 @@ if StrictVersion(requests.__version__) < StrictVersion('2.0.0'):
logger = logging.getLogger("swiftclient")
logger.addHandler(NullHandler())
#: Default behaviour is to redact tokens, showing only the initial 16 chars.
#: To disable, set the value of 'redact_sensitive_tokens' to False.
#: When token redaction is enabled 'reveal_sensitive_prefix' configures the
#: maximum length of any sensitive token data sent to the logs (if the token
#: is less than 32 chars long then int(len(token)/2) chars will be logged,
logger_settings = {
'redact_sensitive_tokens': 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) pair
"""
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_tokens', True):
return dict(headers)
if logger_settings.get('reveal_sensitive_prefix', 16) < 0:
logger_settings['reveal_sensitive_prefix'] = 16
return {key: safe_value(key, val) for (key, val) in headers}
def http_log(args, kwargs, resp, body):
if not logger.isEnabledFor(logging.INFO):
@ -87,8 +145,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
@ -99,7 +158,7 @@ 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)
@ -386,11 +445,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

View File

@ -33,6 +33,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, \
@ -1107,6 +1108,7 @@ def parse_args(parser, args, enforce_requires=True):
if options.debug:
logging.basicConfig(level=logging.DEBUG)
logging.getLogger('iso8601').setLevel(logging.WARNING)
client_logger_settings['redact_sensitive_tokens'] = False
elif options.info:
logging.basicConfig(level=logging.INFO)

View File

@ -987,7 +987,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
@ -1221,7 +1221,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'}
@ -2188,6 +2188,78 @@ 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'
unicode_token_value = (u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
u'\u5929\u7a7a\u4e2d\u7684\u4e4c\u4e91'
u'\u5929\u7a7a\u4e2d\u7684\u4e4c')
set_cookie_value = 'X-Auth-Token=%s' % token_value
c.http_log(
['GET'],
{'headers': {
'X-Auth-Token': token_value,
'X-Storage-Token': unicode_token_value
}},
MockHttpResponse(
status=200,
headers={
'X-Auth-Token': token_value,
'X-Storage-Token': unicode_token_value,
'Etag': b'mock_etag',
'Set-Cookie': set_cookie_value
}
),
''
)
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'
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_tokens'] = False
c.http_log(
['GET'],
{'headers': {
'X-Auth-Token': token_value,
'X-Storage-Token': unicode_token_value
}},
MockHttpResponse(
status=200,
headers=[
('X-Auth-Token', token_value),
('X-Storage-Token', unicode_token_value),
('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):