Skip to content

Commit 2e6022b

Browse files
authored
acknowledge the existence of a body (#12830)
* acknowledge the existence of a body * Clarify the no-body logs
1 parent cc50321 commit 2e6022b

File tree

4 files changed

+606
-176
lines changed

4 files changed

+606
-176
lines changed

sdk/core/azure-core/azure/core/pipeline/policies/_universal.py

Lines changed: 24 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -288,8 +288,17 @@ def on_request(self, request):
288288
# We don't want to log the binary data of a file upload.
289289
if isinstance(http_request.body, types.GeneratorType):
290290
_LOGGER.debug("File upload")
291-
else:
291+
return
292+
try:
293+
if isinstance(http_request.body, types.AsyncGeneratorType):
294+
_LOGGER.debug("File upload")
295+
return
296+
except AttributeError:
297+
pass
298+
if http_request.body:
292299
_LOGGER.debug(str(http_request.body))
300+
return
301+
_LOGGER.debug("This request has no body")
293302
except Exception as err: # pylint: disable=broad-except
294303
_LOGGER.debug("Failed to log request: %r", err)
295304

@@ -415,6 +424,20 @@ def on_request(self, request):
415424
for header, value in http_request.headers.items():
416425
value = self._redact_header(header, value)
417426
logger.info(" %r: %r", header, value)
427+
if isinstance(http_request.body, types.GeneratorType):
428+
logger.info("File upload")
429+
return
430+
try:
431+
if isinstance(http_request.body, types.AsyncGeneratorType):
432+
logger.info("File upload")
433+
return
434+
except AttributeError:
435+
pass
436+
if http_request.body:
437+
logger.info("A body is sent with the request")
438+
return
439+
logger.info("No body was attached to the request")
440+
return
418441
except Exception as err: # pylint: disable=broad-except
419442
logger.warning("Failed to log request: %s", repr(err))
420443

Lines changed: 291 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,291 @@
1+
# ------------------------------------
2+
# Copyright (c) Microsoft Corporation.
3+
# Licensed under the MIT License.
4+
# ------------------------------------
5+
"""Tests for the HttpLoggingPolicy."""
6+
7+
import logging
8+
import types
9+
import pytest
10+
import sys
11+
from unittest.mock import Mock
12+
from azure.core.pipeline import (
13+
PipelineResponse,
14+
PipelineRequest,
15+
PipelineContext
16+
)
17+
from azure.core.pipeline.transport import (
18+
HttpRequest,
19+
HttpResponse,
20+
)
21+
from azure.core.pipeline.policies import (
22+
HttpLoggingPolicy,
23+
)
24+
25+
26+
def test_http_logger():
27+
28+
class MockHandler(logging.Handler):
29+
def __init__(self):
30+
super(MockHandler, self).__init__()
31+
self.messages = []
32+
def reset(self):
33+
self.messages = []
34+
def emit(self, record):
35+
self.messages.append(record)
36+
mock_handler = MockHandler()
37+
38+
logger = logging.getLogger("testlogger")
39+
logger.addHandler(mock_handler)
40+
logger.setLevel(logging.DEBUG)
41+
42+
policy = HttpLoggingPolicy(logger=logger)
43+
44+
universal_request = HttpRequest('GET', 'http://127.0.0.1/')
45+
http_response = HttpResponse(universal_request, None)
46+
http_response.status_code = 202
47+
request = PipelineRequest(universal_request, PipelineContext(None))
48+
49+
# Basics
50+
51+
policy.on_request(request)
52+
response = PipelineResponse(request, http_response, request.context)
53+
policy.on_response(request, response)
54+
55+
assert all(m.levelname == 'INFO' for m in mock_handler.messages)
56+
assert len(mock_handler.messages) == 6
57+
assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
58+
assert mock_handler.messages[1].message == "Request method: 'GET'"
59+
assert mock_handler.messages[2].message == 'Request headers:'
60+
assert mock_handler.messages[3].message == 'No body was attached to the request'
61+
assert mock_handler.messages[4].message == 'Response status: 202'
62+
assert mock_handler.messages[5].message == 'Response headers:'
63+
64+
mock_handler.reset()
65+
66+
# Let's make this request a failure, retried twice
67+
68+
policy.on_request(request)
69+
response = PipelineResponse(request, http_response, request.context)
70+
policy.on_response(request, response)
71+
72+
policy.on_request(request)
73+
response = PipelineResponse(request, http_response, request.context)
74+
policy.on_response(request, response)
75+
76+
assert all(m.levelname == 'INFO' for m in mock_handler.messages)
77+
assert len(mock_handler.messages) == 12
78+
assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
79+
assert mock_handler.messages[1].message == "Request method: 'GET'"
80+
assert mock_handler.messages[2].message == 'Request headers:'
81+
assert mock_handler.messages[3].message == 'No body was attached to the request'
82+
assert mock_handler.messages[4].message == 'Response status: 202'
83+
assert mock_handler.messages[5].message == 'Response headers:'
84+
assert mock_handler.messages[6].message == "Request URL: 'http://127.0.0.1/'"
85+
assert mock_handler.messages[7].message == "Request method: 'GET'"
86+
assert mock_handler.messages[8].message == 'Request headers:'
87+
assert mock_handler.messages[9].message == 'No body was attached to the request'
88+
assert mock_handler.messages[10].message == 'Response status: 202'
89+
assert mock_handler.messages[11].message == 'Response headers:'
90+
91+
mock_handler.reset()
92+
93+
# Headers and query parameters
94+
95+
policy.allowed_query_params = ['country']
96+
97+
universal_request.headers = {
98+
"Accept": "Caramel",
99+
"Hate": "Chocolat",
100+
}
101+
http_response.headers = {
102+
"Content-Type": "Caramel",
103+
"HateToo": "Chocolat",
104+
}
105+
universal_request.url = "http://127.0.0.1/?country=france&city=aix"
106+
107+
policy.on_request(request)
108+
response = PipelineResponse(request, http_response, request.context)
109+
policy.on_response(request, response)
110+
111+
assert all(m.levelname == 'INFO' for m in mock_handler.messages)
112+
assert len(mock_handler.messages) == 10
113+
assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/?country=france&city=REDACTED'"
114+
assert mock_handler.messages[1].message == "Request method: 'GET'"
115+
assert mock_handler.messages[2].message == "Request headers:"
116+
# Dict not ordered in Python, exact logging order doesn't matter
117+
assert set([
118+
mock_handler.messages[3].message,
119+
mock_handler.messages[4].message
120+
]) == set([
121+
" 'Accept': 'Caramel'",
122+
" 'Hate': 'REDACTED'"
123+
])
124+
assert mock_handler.messages[5].message == 'No body was attached to the request'
125+
assert mock_handler.messages[6].message == "Response status: 202"
126+
assert mock_handler.messages[7].message == "Response headers:"
127+
# Dict not ordered in Python, exact logging order doesn't matter
128+
assert set([
129+
mock_handler.messages[8].message,
130+
mock_handler.messages[9].message
131+
]) == set([
132+
" 'Content-Type': 'Caramel'",
133+
" 'HateToo': 'REDACTED'"
134+
])
135+
136+
mock_handler.reset()
137+
138+
139+
140+
def test_http_logger_operation_level():
141+
142+
class MockHandler(logging.Handler):
143+
def __init__(self):
144+
super(MockHandler, self).__init__()
145+
self.messages = []
146+
def reset(self):
147+
self.messages = []
148+
def emit(self, record):
149+
self.messages.append(record)
150+
mock_handler = MockHandler()
151+
152+
logger = logging.getLogger("testlogger")
153+
logger.addHandler(mock_handler)
154+
logger.setLevel(logging.DEBUG)
155+
156+
policy = HttpLoggingPolicy()
157+
kwargs={'logger': logger}
158+
159+
universal_request = HttpRequest('GET', 'http://127.0.0.1/')
160+
http_response = HttpResponse(universal_request, None)
161+
http_response.status_code = 202
162+
request = PipelineRequest(universal_request, PipelineContext(None, **kwargs))
163+
164+
# Basics
165+
166+
policy.on_request(request)
167+
response = PipelineResponse(request, http_response, request.context)
168+
policy.on_response(request, response)
169+
170+
assert all(m.levelname == 'INFO' for m in mock_handler.messages)
171+
assert len(mock_handler.messages) == 6
172+
assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
173+
assert mock_handler.messages[1].message == "Request method: 'GET'"
174+
assert mock_handler.messages[2].message == 'Request headers:'
175+
assert mock_handler.messages[3].message == 'No body was attached to the request'
176+
assert mock_handler.messages[4].message == 'Response status: 202'
177+
assert mock_handler.messages[5].message == 'Response headers:'
178+
179+
mock_handler.reset()
180+
181+
# Let's make this request a failure, retried twice
182+
183+
request = PipelineRequest(universal_request, PipelineContext(None, **kwargs))
184+
185+
policy.on_request(request)
186+
response = PipelineResponse(request, http_response, request.context)
187+
policy.on_response(request, response)
188+
189+
policy.on_request(request)
190+
response = PipelineResponse(request, http_response, request.context)
191+
policy.on_response(request, response)
192+
193+
assert all(m.levelname == 'INFO' for m in mock_handler.messages)
194+
assert len(mock_handler.messages) == 12
195+
assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
196+
assert mock_handler.messages[1].message == "Request method: 'GET'"
197+
assert mock_handler.messages[2].message == 'Request headers:'
198+
assert mock_handler.messages[3].message == 'No body was attached to the request'
199+
assert mock_handler.messages[4].message == 'Response status: 202'
200+
assert mock_handler.messages[5].message == 'Response headers:'
201+
assert mock_handler.messages[6].message == "Request URL: 'http://127.0.0.1/'"
202+
assert mock_handler.messages[7].message == "Request method: 'GET'"
203+
assert mock_handler.messages[8].message == 'Request headers:'
204+
assert mock_handler.messages[9].message == 'No body was attached to the request'
205+
assert mock_handler.messages[10].message == 'Response status: 202'
206+
assert mock_handler.messages[11].message == 'Response headers:'
207+
208+
mock_handler.reset()
209+
210+
211+
def test_http_logger_with_body():
212+
213+
class MockHandler(logging.Handler):
214+
def __init__(self):
215+
super(MockHandler, self).__init__()
216+
self.messages = []
217+
def reset(self):
218+
self.messages = []
219+
def emit(self, record):
220+
self.messages.append(record)
221+
mock_handler = MockHandler()
222+
223+
logger = logging.getLogger("testlogger")
224+
logger.addHandler(mock_handler)
225+
logger.setLevel(logging.DEBUG)
226+
227+
policy = HttpLoggingPolicy(logger=logger)
228+
229+
universal_request = HttpRequest('GET', 'http://127.0.0.1/')
230+
universal_request.body = "testbody"
231+
http_response = HttpResponse(universal_request, None)
232+
http_response.status_code = 202
233+
request = PipelineRequest(universal_request, PipelineContext(None))
234+
235+
policy.on_request(request)
236+
response = PipelineResponse(request, http_response, request.context)
237+
policy.on_response(request, response)
238+
239+
assert all(m.levelname == 'INFO' for m in mock_handler.messages)
240+
assert len(mock_handler.messages) == 6
241+
assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
242+
assert mock_handler.messages[1].message == "Request method: 'GET'"
243+
assert mock_handler.messages[2].message == 'Request headers:'
244+
assert mock_handler.messages[3].message == 'A body is sent with the request'
245+
assert mock_handler.messages[4].message == 'Response status: 202'
246+
assert mock_handler.messages[5].message == 'Response headers:'
247+
248+
mock_handler.reset()
249+
250+
251+
@pytest.mark.skipif(sys.version_info < (3, 6), reason="types.AsyncGeneratorType does not exist in 3.5")
252+
def test_http_logger_with_generator_body():
253+
254+
class MockHandler(logging.Handler):
255+
def __init__(self):
256+
super(MockHandler, self).__init__()
257+
self.messages = []
258+
def reset(self):
259+
self.messages = []
260+
def emit(self, record):
261+
self.messages.append(record)
262+
mock_handler = MockHandler()
263+
264+
logger = logging.getLogger("testlogger")
265+
logger.addHandler(mock_handler)
266+
logger.setLevel(logging.DEBUG)
267+
268+
policy = HttpLoggingPolicy(logger=logger)
269+
270+
universal_request = HttpRequest('GET', 'http://127.0.0.1/')
271+
mock = Mock()
272+
mock.__class__ = types.AsyncGeneratorType
273+
universal_request.body = mock
274+
http_response = HttpResponse(universal_request, None)
275+
http_response.status_code = 202
276+
request = PipelineRequest(universal_request, PipelineContext(None))
277+
278+
policy.on_request(request)
279+
response = PipelineResponse(request, http_response, request.context)
280+
policy.on_response(request, response)
281+
282+
assert all(m.levelname == 'INFO' for m in mock_handler.messages)
283+
assert len(mock_handler.messages) == 6
284+
assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
285+
assert mock_handler.messages[1].message == "Request method: 'GET'"
286+
assert mock_handler.messages[2].message == 'Request headers:'
287+
assert mock_handler.messages[3].message == 'File upload'
288+
assert mock_handler.messages[4].message == 'Response status: 202'
289+
assert mock_handler.messages[5].message == 'Response headers:'
290+
291+
mock_handler.reset()

0 commit comments

Comments
 (0)