Browse Source

Only log application/json content type

This is a combination of 2 commits. The first commit's
message is:

Prevent MemoryError when logging response bodies

Response bodies are loaded into memory prior to
being logged.

Loading huge response bodies may result in a
MemoryError.

This patch proposes that only JSON and TEXT
responses be logged, i.e when the Content-Type
header is application/json or application/text.

Responses that do not include or have a different
Content-Type header will have their body omitted.

Closes-bug: 1616105

Change-Id: I93b6fff73368c4f58bdebf8566c4948b50980cee
(cherry picked from commit f345559a06)

This is the 2nd commit message:

Only log application/json in session to start

When whitelisting content types to debug print from session we chose
application/json and application/text. application/text is not a real
mime type, text is typically text/plain.

Rather than guess at mime types only print application/json to start
with, but make it easy for additional types to be added later.

Change-Id: Ica5fee076cdab8b1d5167161d28af7313fad9477
Related-Bug: 1616105
(cherry-picked from: d73fd3ee84)
Samuel de Medeiros Queiroz 2 years ago
parent
commit
13054e8b6d

+ 18
- 1
keystoneauth1/session.py View File

@@ -43,6 +43,11 @@ DEFAULT_USER_AGENT = 'keystoneauth1/%s %s %s/%s' % (
43 43
     keystoneauth1.__version__, requests.utils.default_user_agent(),
44 44
     platform.python_implementation(), platform.python_version())
45 45
 
46
+# NOTE(jamielennox): Clients will likely want to print more than json. Please
47
+# propose a patch if you have a content type you think is reasonable to print
48
+# here and we'll add it to the list as required.
49
+_LOG_CONTENT_TYPES = set(['application/json'])
50
+
46 51
 _logger = utils.get_logger(__name__)
47 52
 
48 53
 
@@ -260,7 +265,19 @@ class Session(object):
260 265
             if not headers:
261 266
                 headers = response.headers
262 267
             if not text:
263
-                text = self._remove_service_catalog(response.text)
268
+                # NOTE(samueldmq): If the response does not provide enough info
269
+                # about the content type to decide whether it is useful and
270
+                # safe to log it or not, just do not log the body. Trying to
271
+                # read the response body anyways may result on reading a long
272
+                # stream of bytes and getting an unexpected MemoryError. See
273
+                # bug 1616105 for further details.
274
+                content_type = response.headers.get('content-type', None)
275
+                if content_type in _LOG_CONTENT_TYPES:
276
+                    text = self._remove_service_catalog(response.text)
277
+                else:
278
+                    text = ('Omitted, Content-Type is set to %s. Only '
279
+                            '%s responses have their bodies logged.')
280
+                    text = text % (content_type, ', '.join(_LOG_CONTENT_TYPES))
264 281
         if json:
265 282
             text = self._json.encode(json)
266 283
 

+ 57
- 17
keystoneauth1/tests/unit/test_session.py View File

@@ -145,13 +145,14 @@ class SessionTests(utils.TestCase):
145 145
         in order to redact secure headers while debug is true.
146 146
         """
147 147
         session = client_session.Session(verify=False)
148
-        headers = {'HEADERA': 'HEADERVALB'}
148
+        headers = {'HEADERA': 'HEADERVALB',
149
+                   'Content-Type': 'application/json'}
149 150
         security_headers = {'Authorization': uuid.uuid4().hex,
150 151
                             'X-Auth-Token': uuid.uuid4().hex,
151 152
                             'X-Subject-Token': uuid.uuid4().hex,
152 153
                             'X-Service-Token': uuid.uuid4().hex}
153
-        body = 'BODYRESPONSE'
154
-        data = 'BODYDATA'
154
+        body = '{"a": "b"}'
155
+        data = '{"c": "d"}'
155 156
         all_headers = dict(
156 157
             itertools.chain(headers.items(), security_headers.items()))
157 158
         self.stub_url('POST', text=body, headers=all_headers)
@@ -179,13 +180,48 @@ class SessionTests(utils.TestCase):
179 180
         """Test that output is logged even for failed requests"""
180 181
 
181 182
         session = client_session.Session()
182
-        body = uuid.uuid4().hex
183
+        body = {uuid.uuid4().hex: uuid.uuid4().hex}
183 184
 
184
-        self.stub_url('GET', text=body, status_code=400)
185
+        self.stub_url('GET', json=body, status_code=400,
186
+                      headers={'Content-Type': 'application/json'})
185 187
         resp = session.get(self.TEST_URL, raise_exc=False)
186 188
 
187 189
         self.assertEqual(resp.status_code, 400)
190
+        self.assertIn(list(body.keys())[0], self.logger.output)
191
+        self.assertIn(list(body.values())[0], self.logger.output)
192
+
193
+    def test_logging_body_only_for_specified_content_types(self):
194
+        """Verify response body is only logged in specific content types.
195
+
196
+        Response bodies are logged only when the response's Content-Type header
197
+        is set to application/json. This prevents us to get an unexpected
198
+        MemoryError when reading arbitrary responses, such as streams.
199
+        """
200
+        OMITTED_BODY = ('Omitted, Content-Type is set to %s. Only '
201
+                        'application/json responses have their bodies logged.')
202
+        session = client_session.Session(verify=False)
203
+
204
+        # Content-Type is not set
205
+        body = json.dumps({'token': {'id': '...'}})
206
+        self.stub_url('POST', text=body)
207
+        session.post(self.TEST_URL)
208
+        self.assertNotIn(body, self.logger.output)
209
+        self.assertIn(OMITTED_BODY % None, self.logger.output)
210
+
211
+        # Content-Type is set to text/xml
212
+        body = '<token><id>...</id></token>'
213
+        self.stub_url('POST', text=body, headers={'Content-Type': 'text/xml'})
214
+        session.post(self.TEST_URL)
215
+        self.assertNotIn(body, self.logger.output)
216
+        self.assertIn(OMITTED_BODY % 'text/xml', self.logger.output)
217
+
218
+        # Content-Type is set to application/json
219
+        body = json.dumps({'token': {'id': '...'}})
220
+        self.stub_url('POST', text=body,
221
+                      headers={'Content-Type': 'application/json'})
222
+        session.post(self.TEST_URL)
188 223
         self.assertIn(body, self.logger.output)
224
+        self.assertNotIn(OMITTED_BODY % 'application/json', self.logger.output)
189 225
 
190 226
     def test_logging_cacerts(self):
191 227
         path_to_certs = '/path/to/certs'
@@ -693,22 +729,24 @@ class SessionAuthTests(utils.TestCase):
693 729
 
694 730
         auth = AuthPlugin()
695 731
         sess = client_session.Session(auth=auth)
696
-        response = uuid.uuid4().hex
732
+        response = {uuid.uuid4().hex: uuid.uuid4().hex}
697 733
 
698 734
         self.stub_url('GET',
699
-                      text=response,
700
-                      headers={'Content-Type': 'text/html'})
735
+                      json=response,
736
+                      headers={'Content-Type': 'application/json'})
701 737
 
702 738
         resp = sess.get(self.TEST_URL, logger=logger)
703 739
 
704
-        self.assertEqual(response, resp.text)
740
+        self.assertEqual(response, resp.json())
705 741
         output = io.getvalue()
706 742
 
707 743
         self.assertIn(self.TEST_URL, output)
708
-        self.assertIn(response, output)
744
+        self.assertIn(list(response.keys())[0], output)
745
+        self.assertIn(list(response.values())[0], output)
709 746
 
710 747
         self.assertNotIn(self.TEST_URL, self.logger.output)
711
-        self.assertNotIn(response, self.logger.output)
748
+        self.assertNotIn(list(response.keys())[0], self.logger.output)
749
+        self.assertNotIn(list(response.values())[0], self.logger.output)
712 750
 
713 751
 
714 752
 class AdapterTest(utils.TestCase):
@@ -883,21 +921,23 @@ class AdapterTest(utils.TestCase):
883 921
         sess = client_session.Session(auth=auth)
884 922
         adpt = adapter.Adapter(sess, auth=auth, logger=logger)
885 923
 
886
-        response = uuid.uuid4().hex
924
+        response = {uuid.uuid4().hex: uuid.uuid4().hex}
887 925
 
888
-        self.stub_url('GET', text=response,
889
-                      headers={'Content-Type': 'text/html'})
926
+        self.stub_url('GET', json=response,
927
+                      headers={'Content-Type': 'application/json'})
890 928
 
891 929
         resp = adpt.get(self.TEST_URL, logger=logger)
892 930
 
893
-        self.assertEqual(response, resp.text)
931
+        self.assertEqual(response, resp.json())
894 932
         output = io.getvalue()
895 933
 
896 934
         self.assertIn(self.TEST_URL, output)
897
-        self.assertIn(response, output)
935
+        self.assertIn(list(response.keys())[0], output)
936
+        self.assertIn(list(response.values())[0], output)
898 937
 
899 938
         self.assertNotIn(self.TEST_URL, self.logger.output)
900
-        self.assertNotIn(response, self.logger.output)
939
+        self.assertNotIn(list(response.keys())[0], self.logger.output)
940
+        self.assertNotIn(list(response.values())[0], self.logger.output)
901 941
 
902 942
     def test_unknown_connection_error(self):
903 943
         self.stub_url('GET', exc=requests.exceptions.RequestException)

+ 8
- 0
releasenotes/notes/bug-1616105-cc8b85eb056e99e2.yaml View File

@@ -0,0 +1,8 @@
1
+---
2
+fixes:
3
+  - >
4
+    [`bug 1616105 <https://bugs.launchpad.net/keystoneauth/+bug/1616105>`_]
5
+    Only log the response body when the ``Content-Type`` header is set to
6
+    ``application/json``. This avoids logging large binary objects (such as
7
+    images). Other ``Content-Type`` will not be logged. Additional
8
+    ``Content-Type`` strings can be added as required.

Loading…
Cancel
Save