From 0e9ecaa1547306f7af6527126fb88f8151908498 Mon Sep 17 00:00:00 2001 From: Jamie Lennox Date: Wed, 18 Jun 2014 10:22:10 +1000 Subject: [PATCH] Don't log sensitive auth data Add the ability to turn off logging from the session object and then handle logging of auth requests within their own sections. This is a very simplistic ability to completely disable logging. Logging more filtered debugging can be added later. This new ability is utilized in this patch to prevent logging of requests that include passwords. This covers authenticate, password change, and user update requests that include passwords. SecurityImpact Change-Id: I3dabb94ab047e86b8730e73416c1a1c333688489 Closes-Bug: #1004114 Closes-Bug: #1327019 --- keystoneclient/auth/identity/v2.py | 6 +- keystoneclient/auth/identity/v3.py | 3 +- keystoneclient/base.py | 5 + keystoneclient/contrib/auth/v3/saml2.py | 2 +- keystoneclient/session.py | 101 +++++++++++++----- keystoneclient/tests/auth/test_identity_v2.py | 12 +++ keystoneclient/tests/auth/test_identity_v3.py | 13 +++ keystoneclient/tests/v2_0/test_users.py | 21 ++-- keystoneclient/tests/v3/test_users.py | 41 +++++++ keystoneclient/v2_0/tokens.py | 2 +- keystoneclient/v2_0/users.py | 7 +- keystoneclient/v3/users.py | 47 ++++---- 12 files changed, 198 insertions(+), 62 deletions(-) diff --git a/keystoneclient/auth/identity/v2.py b/keystoneclient/auth/identity/v2.py index 434225142..ad93dbabc 100644 --- a/keystoneclient/auth/identity/v2.py +++ b/keystoneclient/auth/identity/v2.py @@ -11,6 +11,7 @@ # under the License. import abc +import logging from oslo.config import cfg import six @@ -20,6 +21,8 @@ from keystoneclient.auth.identity import base from keystoneclient import exceptions from keystoneclient import utils +_logger = logging.getLogger(__name__) + @six.add_metaclass(abc.ABCMeta) class Auth(base.BaseIdentityPlugin): @@ -66,8 +69,9 @@ class Auth(base.BaseIdentityPlugin): if self.trust_id: params['auth']['trust_id'] = self.trust_id + _logger.debug('Making authentication request to %s', url) resp = session.post(url, json=params, headers=headers, - authenticated=False) + authenticated=False, log=False) try: resp_data = resp.json()['access'] diff --git a/keystoneclient/auth/identity/v3.py b/keystoneclient/auth/identity/v3.py index 63a0230b7..010c80d0f 100644 --- a/keystoneclient/auth/identity/v3.py +++ b/keystoneclient/auth/identity/v3.py @@ -105,8 +105,9 @@ class Auth(base.BaseIdentityPlugin): elif self.trust_id: body['auth']['scope'] = {'OS-TRUST:trust': {'id': self.trust_id}} + _logger.debug('Making authentication request to %s', self.token_url) resp = session.post(self.token_url, json=body, headers=headers, - authenticated=False) + authenticated=False, log=False) try: resp_data = resp.json()['token'] diff --git a/keystoneclient/base.py b/keystoneclient/base.py index a8c6d7b74..f94c16b4f 100644 --- a/keystoneclient/base.py +++ b/keystoneclient/base.py @@ -46,6 +46,11 @@ def getid(obj): return obj +def filter_none(**kwargs): + """Remove any entries from a dictionary where the value is None.""" + return dict((k, v) for k, v in six.iteritems(kwargs) if v is not None) + + def filter_kwargs(f): @functools.wraps(f) def func(*args, **kwargs): diff --git a/keystoneclient/contrib/auth/v3/saml2.py b/keystoneclient/contrib/auth/v3/saml2.py index 03323a5c9..f2b458e76 100644 --- a/keystoneclient/contrib/auth/v3/saml2.py +++ b/keystoneclient/contrib/auth/v3/saml2.py @@ -246,7 +246,7 @@ class Saml2UnscopedToken(v3.AuthConstructor): headers={'Content-type': 'text/xml'}, data=etree.tostring(idp_saml2_authn_request), requests_auth=(self.username, self.password), - authenticated=False) + authenticated=False, log=False) try: self.saml2_idp_authn_response = etree.XML(idp_response.content) diff --git a/keystoneclient/session.py b/keystoneclient/session.py index 5426d991a..c74f752a6 100644 --- a/keystoneclient/session.py +++ b/keystoneclient/session.py @@ -130,11 +130,69 @@ class Session(object): if user_agent is not None: self.user_agent = user_agent + @utils.positional() + def _http_log_request(self, url, method=None, data=None, + json=None, headers=None): + if not _logger.isEnabledFor(logging.DEBUG): + # NOTE(morganfainberg): This whole debug section is expensive, + # there is no need to do the work if we're not going to emit a + # debug log. + return + + string_parts = ['REQ: curl -i'] + + # NOTE(jamielennox): None means let requests do its default validation + # so we need to actually check that this is False. + if self.verify is False: + string_parts.append('--insecure') + + if method: + string_parts.extend(['-X', method]) + + string_parts.append(url) + + if headers: + for header in six.iteritems(headers): + string_parts.append('-H "%s: %s"' % header) + if json: + data = jsonutils.dumps(json) + if data: + string_parts.append("-d '%s'" % data) + + _logger.debug(' '.join(string_parts)) + + @utils.positional() + def _http_log_response(self, response=None, json=None, + status_code=None, headers=None, text=None): + if not _logger.isEnabledFor(logging.DEBUG): + return + + if response: + if not status_code: + status_code = response.status_code + if not headers: + headers = response.headers + if not text: + text = response.text + if json: + text = jsonutils.dumps(json) + + string_parts = ['RESP:'] + + if status_code: + string_parts.append('[%s]' % status_code) + if headers: + string_parts.append('%s' % headers) + if text: + string_parts.append('\nRESP BODY: %s\n' % text) + + _logger.debug(' '.join(string_parts)) + @utils.positional(enforcement=utils.positional.WARN) def request(self, url, method, json=None, original_ip=None, user_agent=None, redirect=None, authenticated=None, endpoint_filter=None, auth=None, requests_auth=None, - raise_exc=True, allow_reauth=True, **kwargs): + raise_exc=True, allow_reauth=True, log=True, **kwargs): """Send an HTTP request with the specified characteristics. Wrapper around `requests.Session.request` to handle tasks such as @@ -183,6 +241,8 @@ class Session(object): :param bool allow_reauth: Allow fetching a new token and retrying the request on receiving a 401 Unauthorized response. (optional, default True) + :param bool log: If True then log the request and response data to the + debug log. (optional, default True) :param kwargs: any other parameter that can be passed to requests.Session.request (such as `headers`). Except: 'data' will be overwritten by the data in 'json' param. @@ -250,28 +310,10 @@ class Session(object): if requests_auth: kwargs['auth'] = requests_auth - string_parts = ['curl -i'] - - # NOTE(jamielennox): None means let requests do its default validation - # so we need to actually check that this is False. - if self.verify is False: - string_parts.append('--insecure') - - if method: - string_parts.extend(['-X', method]) - - string_parts.append(url) - - if headers: - for header in six.iteritems(headers): - string_parts.append('-H "%s: %s"' % header) - - try: - string_parts.append("-d '%s'" % kwargs['data']) - except KeyError: - pass - - _logger.debug('REQ: %s', ' '.join(string_parts)) + if log: + self._http_log_request(url, method=method, + data=kwargs.get('data'), + headers=headers) # Force disable requests redirect handling. We will manage this below. kwargs['allow_redirects'] = False @@ -279,7 +321,7 @@ class Session(object): if redirect is None: redirect = self.redirect - resp = self._send_request(url, method, redirect, **kwargs) + resp = self._send_request(url, method, redirect, log, **kwargs) # handle getting a 401 Unauthorized response by invalidating the plugin # and then retrying the request. This is only tried once. @@ -288,7 +330,8 @@ class Session(object): token = self.get_token(auth) if token: headers['X-Auth-Token'] = token - resp = self._send_request(url, method, redirect, **kwargs) + resp = self._send_request(url, method, redirect, log, + **kwargs) if raise_exc and resp.status_code >= 400: _logger.debug('Request returned failure status: %s', @@ -297,7 +340,7 @@ class Session(object): return resp - def _send_request(self, url, method, redirect, **kwargs): + def _send_request(self, url, method, redirect, log, **kwargs): # NOTE(jamielennox): We handle redirection manually because the # requests lib follows some browser patterns where it will redirect # POSTs as GETs for certain statuses which is not want we want for an @@ -315,8 +358,8 @@ class Session(object): msg = 'Unable to establish connection to %s' % url raise exceptions.ConnectionRefused(msg) - _logger.debug('RESP: [%s] %s\nRESP BODY: %s\n', - resp.status_code, resp.headers, resp.text) + if log: + self._http_log_response(response=resp) if resp.status_code in self.REDIRECT_STATUSES: # be careful here in python True == 1 and False == 0 @@ -335,7 +378,7 @@ class Session(object): _logger.warn("Failed to redirect request to %s as new " "location was not provided.", resp.url) else: - new_resp = self._send_request(location, method, redirect, + new_resp = self._send_request(location, method, redirect, log, **kwargs) if not isinstance(new_resp.history, list): diff --git a/keystoneclient/tests/auth/test_identity_v2.py b/keystoneclient/tests/auth/test_identity_v2.py index a264edd1f..0beea8344 100644 --- a/keystoneclient/tests/auth/test_identity_v2.py +++ b/keystoneclient/tests/auth/test_identity_v2.py @@ -11,6 +11,7 @@ # under the License. import copy +import uuid import httpretty from six.moves import urllib @@ -255,3 +256,14 @@ class V2IdentityPlugin(utils.TestCase): self.assertEqual('token1', s.get_token()) a.invalidate() self.assertEqual('token2', s.get_token()) + + @httpretty.activate + def test_doesnt_log_password(self): + self.stub_auth(json=self.TEST_RESPONSE_DICT) + password = uuid.uuid4().hex + + a = v2.Password(self.TEST_URL, username=self.TEST_USER, + password=password) + s = session.Session(auth=a) + self.assertEqual(self.TEST_TOKEN, s.get_token()) + self.assertNotIn(password, self.logger.output) diff --git a/keystoneclient/tests/auth/test_identity_v3.py b/keystoneclient/tests/auth/test_identity_v3.py index d44c8e7dc..a147a317b 100644 --- a/keystoneclient/tests/auth/test_identity_v3.py +++ b/keystoneclient/tests/auth/test_identity_v3.py @@ -11,6 +11,7 @@ # under the License. import copy +import uuid import httpretty from six.moves import urllib @@ -408,3 +409,15 @@ class V3IdentityPlugin(utils.TestCase): self.assertEqual('token1', s.get_token()) a.invalidate() self.assertEqual('token2', s.get_token()) + + @httpretty.activate + def test_doesnt_log_password(self): + self.stub_auth(json=self.TEST_RESPONSE_DICT) + + password = uuid.uuid4().hex + a = v3.Password(self.TEST_URL, username=self.TEST_USER, + password=password) + s = session.Session(a) + self.assertEqual(self.TEST_TOKEN, s.get_token()) + + self.assertNotIn(password, self.logger.output) diff --git a/keystoneclient/tests/v2_0/test_users.py b/keystoneclient/tests/v2_0/test_users.py index 4246a51b5..89901e4d8 100644 --- a/keystoneclient/tests/v2_0/test_users.py +++ b/keystoneclient/tests/v2_0/test_users.py @@ -47,10 +47,11 @@ class UserTests(utils.TestCase): def test_create(self): tenant_id = uuid.uuid4().hex user_id = uuid.uuid4().hex + password = uuid.uuid4().hex req_body = { "user": { "name": "gabriel", - "password": "test", + "password": password, "tenantId": tenant_id, "email": "test@example.com", "enabled": True, @@ -63,7 +64,7 @@ class UserTests(utils.TestCase): "enabled": True, "tenantId": tenant_id, "id": user_id, - "password": "test", + "password": password, "email": "test@example.com", } } @@ -80,6 +81,7 @@ class UserTests(utils.TestCase): self.assertEqual(user.name, "gabriel") self.assertEqual(user.email, "test@example.com") self.assertRequestBodyIs(json=req_body) + self.assertNotIn(password, self.logger.output) @httpretty.activate def test_create_user_without_email(self): @@ -210,10 +212,11 @@ class UserTests(utils.TestCase): "name": "gabriel", } } + password = uuid.uuid4().hex req_2 = { "user": { "id": self.DEMO_USER_ID, - "password": "swordfish", + "password": password, } } tenant_id = uuid.uuid4().hex @@ -245,18 +248,22 @@ class UserTests(utils.TestCase): name='gabriel', email='gabriel@example.com') self.assertRequestBodyIs(json=req_1) - self.client.users.update_password(self.DEMO_USER_ID, 'swordfish') + self.client.users.update_password(self.DEMO_USER_ID, password) self.assertRequestBodyIs(json=req_2) self.client.users.update_tenant(self.DEMO_USER_ID, tenant_id) self.assertRequestBodyIs(json=req_3) self.client.users.update_enabled(self.DEMO_USER_ID, False) self.assertRequestBodyIs(json=req_4) + self.assertNotIn(password, self.logger.output) @httpretty.activate def test_update_own_password(self): + old_password = uuid.uuid4().hex + new_password = uuid.uuid4().hex req_body = { 'user': { - 'password': 'ABCD', 'original_password': 'DCBA' + 'password': new_password, + 'original_password': old_password } } resp_body = { @@ -267,8 +274,10 @@ class UserTests(utils.TestCase): json=resp_body) self.client.user_id = user_id - self.client.users.update_own_password('DCBA', 'ABCD') + self.client.users.update_own_password(old_password, new_password) self.assertRequestBodyIs(json=req_body) + self.assertNotIn(old_password, self.logger.output) + self.assertNotIn(new_password, self.logger.output) @httpretty.activate def test_user_role_listing(self): diff --git a/keystoneclient/tests/v3/test_users.py b/keystoneclient/tests/v3/test_users.py index 153e27a6f..0841e9df1 100644 --- a/keystoneclient/tests/v3/test_users.py +++ b/keystoneclient/tests/v3/test_users.py @@ -96,6 +96,25 @@ class UserTests(utils.TestCase, utils.CrudTests): user=ref['id'], group=None) + @httpretty.activate + def test_create_doesnt_log_password(self): + password = uuid.uuid4().hex + ref = self.new_ref() + + self.stub_entity(httpretty.POST, [self.collection_key], + status=201, entity=ref) + + req_ref = ref.copy() + req_ref.pop('id') + param_ref = req_ref.copy() + + param_ref['password'] = password + params = utils.parameterize(param_ref) + + self.manager.create(**params) + + self.assertNotIn(password, self.logger.output) + @httpretty.activate def test_create_with_project(self): # Can create a user with the deprecated project option rather than @@ -148,6 +167,26 @@ class UserTests(utils.TestCase, utils.CrudTests): 'Expected different %s' % attr) self.assertEntityRequestBodyIs(req_ref) + @httpretty.activate + def test_update_doesnt_log_password(self): + password = uuid.uuid4().hex + ref = self.new_ref() + + req_ref = ref.copy() + req_ref.pop('id') + param_ref = req_ref.copy() + + self.stub_entity(httpretty.PATCH, + [self.collection_key, ref['id']], + status=200, entity=ref) + + param_ref['password'] = password + params = utils.parameterize(param_ref) + + self.manager.update(ref['id'], **params) + + self.assertNotIn(password, self.logger.output) + @httpretty.activate def test_update_with_project(self): # Can update a user with the deprecated project option rather than @@ -217,6 +256,8 @@ class UserTests(utils.TestCase, utils.CrudTests): self.assertEqual('/v3/users/test/password', httpretty.last_request().path) self.assertRequestBodyIs(json=exp_req_body) + self.assertNotIn(old_password, self.logger.output) + self.assertNotIn(new_password, self.logger.output) def test_update_password_with_bad_inputs(self): old_password = uuid.uuid4().hex diff --git a/keystoneclient/v2_0/tokens.py b/keystoneclient/v2_0/tokens.py index 53ea1da97..dc1b0a281 100644 --- a/keystoneclient/v2_0/tokens.py +++ b/keystoneclient/v2_0/tokens.py @@ -53,7 +53,7 @@ class TokenManager(base.Manager): reset = 1 self.api.management_url = self.api.auth_url token_ref = self._create('/tokens', params, "access", - return_raw=return_raw) + return_raw=return_raw, log=False) if reset: self.api.management_url = None return token_ref diff --git a/keystoneclient/v2_0/users.py b/keystoneclient/v2_0/users.py index 75a1f9b0b..df488f541 100644 --- a/keystoneclient/v2_0/users.py +++ b/keystoneclient/v2_0/users.py @@ -68,7 +68,7 @@ class UserManager(base.ManagerWithFind): "password": password}} return self._update("/users/%s/OS-KSADM/password" % base.getid(user), - params, "user") + params, "user", log=False) def update_own_password(self, origpasswd, passwd): """Update password.""" @@ -78,7 +78,8 @@ class UserManager(base.ManagerWithFind): return self._update("/OS-KSCRUD/users/%s" % self.api.user_id, params, response_key="access", method="PATCH", - management=False) + management=False, + log=False) def update_tenant(self, user, tenant): """Update default tenant.""" @@ -98,7 +99,7 @@ class UserManager(base.ManagerWithFind): "tenantId": tenant_id, "email": email, "enabled": enabled}} - return self._create('/users', params, "user") + return self._create('/users', params, "user", log=not bool(password)) def delete(self, user): """Delete a user.""" diff --git a/keystoneclient/v3/users.py b/keystoneclient/v3/users.py index 3deed1849..140c785cb 100644 --- a/keystoneclient/v3/users.py +++ b/keystoneclient/v3/users.py @@ -61,15 +61,17 @@ class UserManager(base.CrudManager): LOG.warning("The project argument is deprecated, " "use default_project instead.") default_project_id = base.getid(default_project) or base.getid(project) - return super(UserManager, self).create( - name=name, - domain_id=base.getid(domain), - default_project_id=default_project_id, - password=password, - email=email, - description=description, - enabled=enabled, - **kwargs) + user_data = base.filter_none(name=name, + domain_id=base.getid(domain), + default_project_id=default_project_id, + password=password, + email=email, + description=description, + enabled=enabled, + **kwargs) + + return self._create('/users', {'user': user_data}, 'user', + log=not bool(password)) @utils.positional(enforcement=utils.positional.WARN) def list(self, project=None, domain=None, group=None, default_project=None, @@ -125,16 +127,20 @@ class UserManager(base.CrudManager): LOG.warning("The project argument is deprecated, " "use default_project instead.") default_project_id = base.getid(default_project) or base.getid(project) - return super(UserManager, self).update( - user_id=base.getid(user), - name=name, - domain_id=base.getid(domain), - default_project_id=default_project_id, - password=password, - email=email, - description=description, - enabled=enabled, - **kwargs) + user_data = base.filter_none(name=name, + domain_id=base.getid(domain), + default_project_id=default_project_id, + password=password, + email=email, + description=description, + enabled=enabled, + **kwargs) + + return self._update('/users/%s' % base.getid(user), + {'user': user_data}, + 'user', + method='PATCH', + log=False) def update_password(self, old_password, new_password): """Update the password for the user the token belongs to.""" @@ -151,7 +157,8 @@ class UserManager(base.CrudManager): base_url = '/users/%s/password' % self.api.user_id - return self._update(base_url, params, method='POST', management=False) + return self._update(base_url, params, method='POST', management=False, + log=False) def add_to_group(self, user, group): self._require_user_and_group(user, group)