async def resurface_logger_middleware(request, handler):
start_time = time.time()
response = await handler(request)
interval = str((time.time() - start_time) * 1000)
data__: bytes = await request.read()
HttpMessage.send(
logger,
request=HttpRequestImpl(
url=str(request.url),
headers=request.headers,
params=request.query,
method=request.method,
body=data__.decode(),
),
response=HttpResponseImpl(
status=response.status,
headers=response.headers,
body=response.body.decode("utf8"),
),
interval=interval,
)
return response
def __call__(self, request):
start_time = time.time()
request_body = self.prepare_request_body(request)
response = self.get_response(request)
interval = str((time.time() - start_time) * 1000)
method = request.method
if request_body is None:
request_body = self.prepare_request_body(request, response)
try:
if response.content:
response_body = str(response.content.decode("utf8"))
else:
response_body = None
except AttributeError:
response_body = None
HttpMessage.send(
self.logger,
request=HttpRequestImpl(
method=method,
url=str(request.build_absolute_uri()),
headers=request.headers,
params=request.POST if method == "POST" else request.GET,
body=request_body,
),
response=HttpResponseImpl(
status=response.status_code,
body=response_body,
headers=response,
),
interval=interval,
)
return response
def __call__(self, request):
response = self.get_response(request)
status = response.status_code
if (status < 300
or status == 302) and HttpLogger.is_string_content_type(
response['Content-Type']):
HttpMessage.send(self.logger, request=request,
response=response) # todo add timing details
return response
def after_build_response(self, req, resp, response):
interval = str((time.time() - self.start_time) * 1000)
HttpMessage.send(
self.logger,
request=req,
response=response,
interval=interval,
)
return response
def test_formats_response_with_empty_body():
queue = []
logger = HttpLogger(queue=queue, rules="include debug")
HttpMessage.send(logger, request=mock_request(), response=mock_response_with_html(), response_body='')
assert len(queue) == 1
msg = queue[0]
assert parseable(msg) is True
assert f"[\"response_code\",\"200\"]" in msg
assert f"[\"response_header:content-type\",\"text/html; charset=utf-8\"]" in msg
assert f"response_body" not in msg
def test_formats_response():
queue = []
logger = HttpLogger(queue=queue, rules="include debug")
HttpMessage.send(logger, request=mock_request(), response=mock_response())
assert len(queue) == 1
msg = queue[0]
assert parseable(msg) is True
assert '["response_code","200"]' in msg
assert "response_body" not in msg
assert "response_header" not in msg
def test_formats_response_with_missing_details():
queue = []
logger = HttpLogger(queue=queue, rules="include debug")
HttpMessage.send(logger, request=mock_request(), response=HttpResponseImpl(), response_body=None, request_body=None,
now=None, interval=None)
assert len(queue) == 1
msg = queue[0]
assert parseable(msg) is True
assert f"response_body" not in msg
assert f"response_code" not in msg
assert f"response_header" not in msg
assert f"interval" not in msg
def __call__(self, request):
start_time = time.time()
response = self.get_response(request)
interval = str((time.time() - start_time) * 1000)
HttpMessage.send(
self.logger,
request=request,
response=response,
interval=interval,
)
return response
def test_formats_request_with_body():
queue = []
logger = HttpLogger(queue=queue, rules="include debug")
HttpMessage.send(logger, request=mock_request_with_json(), response=mock_response(), request_body=MOCK_HTML)
assert len(queue) == 1
msg = queue[0]
assert parseable(msg) is True
assert f"[\"request_body\",\"{MOCK_HTML}\"]" in msg
assert f"[\"request_header:content-type\",\"Application/JSON\"]" in msg
assert f"[\"request_method\",\"POST\"]" in msg
assert f"[\"request_param:message\",\"{MOCK_JSON_ESCAPED}\"]" in msg
assert f"[\"request_url\",\"{MOCK_URL}?{MOCK_QUERY_STRING}\"]" in msg
assert "request_param:foo" not in msg
def test_uses_stop_unless_rules():
queue = []
logger = HttpLogger(
queue=queue, rules="!response_header:blahblahblah! stop_unless !.*!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 0
queue = []
logger = HttpLogger(queue=queue, rules="!response_body! stop_unless !.*!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
queue = []
logger = HttpLogger(queue=queue,
rules="!response_body! stop_unless !.*World.*!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
queue = []
logger = HttpLogger(queue=queue,
rules="!response_body! stop_unless !.*blahblahblah.*!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 0
def test_uses_sample_rules():
queue = []
try:
HttpLogger(queue=queue, rules="sample 10\nsample 99")
assert False is True
except Exception as e:
assert str(e) == 'Multiple sample rules'
logger = HttpLogger(queue=queue, rules="sample 10")
for i in range(1, 101):
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert 2 <= len(queue) <= 20
def test_formats_response_with_body():
queue = []
logger = HttpLogger(queue=queue, rules="include debug")
HttpMessage.send(
logger,
request=mock_request(),
response=mock_response_with_html(),
response_body=MOCK_HTML2,
)
assert len(queue) == 1
msg = queue[0]
assert parseable(msg) is True
assert f'["response_body","{MOCK_HTML2}"]' in msg
assert '["response_code","200"]' in msg
assert '["response_header:content-type","text/html; charset=utf-8"]' in msg
def test_uses_replace_rules_with_complex_expressions():
queue = []
logger = HttpLogger(
queue=queue,
rules=
"/response_body/ replace /[a-zA-Z0-9.!#$%&’*+\\/=?^_`{|}~-]+@[a-zA-Z0-9-]+(?:\\.[a-zA-Z0-9-]+)/, /[email protected]/"
)
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html(),
response_body=MOCK_HTML.replace('World',
'*****@*****.**'))
assert len(queue) == 1
assert "[\"response_body\",\"<html>Hello [email protected]!</html>\"]," in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules="/response_body/ replace /[0-9\\.\\-\\/]{9,}/, /xyxy/")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html(),
response_body=MOCK_HTML.replace('World', '123-45-1343'))
assert len(queue) == 1
assert "[\"response_body\",\"<html>Hello xyxy!</html>\"]," in queue[0]
# todo this specific case not working (Clubhouse #150)
# queue = []
# logger = HttpLogger(queue=queue, rules="!response_body! replace !World!, !<b>\\0</b>!")
# HttpMessage.send(logger, request=mock_request_with_json2(), response=mock_response_with_html())
# assert len(queue) == 1
# assert "[\"response_body\",\"<html>Hello <b>World</b>!</html>\"]," in queue[0]
queue = []
logger = HttpLogger(
queue=queue, rules="!response_body! replace !(World)!, !<b>\\1</b>!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"response_body\",\"<html>Hello <b>World</b>!</html>\"]," in queue[
0]
queue = []
logger = HttpLogger(
queue=queue,
rules=
"!response_body! replace !<input([^>]*)>([^<]*)</input>!, !<input\\1></input>!"
)
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html(),
response_body=MOCK_HTML5)
assert len(queue) == 1
assert "[\"response_body\",\"<html>\\n<input type=\\\"hidden\\\"></input>\\n<input class='foo' type=\\\"hidden\\\"></input>\\n</html>\"]," in queue[
0]
def test_formats_request():
queue = []
logger = HttpLogger(queue=queue, rules="include debug")
HttpMessage.send(logger, request=mock_request(), response=mock_response(), now=MOCK_NOW)
assert len(queue) == 1
msg = queue[0]
assert parseable(msg) is True
assert f"[\"agent\",\"{HttpLogger.AGENT}\"]" in msg
assert f"[\"host\",\"{HttpLogger.host_lookup()}\"]" in msg
assert f"[\"version\",\"{HttpLogger.version_lookup()}\"]" in msg
assert f"[\"now\",\"{MOCK_NOW}\"]" in msg
assert f"[\"request_method\",\"GET\"]" in msg
assert f"[\"request_url\",\"{MOCK_URL}\"]" in msg
assert f"request_body" not in msg
assert f"request_header" not in msg
assert f"request_param" not in msg
assert f"interval" not in msg
def test_formats_request():
queue = []
logger = HttpLogger(queue=queue, rules="include debug")
HttpMessage.send(logger,
request=mock_request(),
response=mock_response(),
now=MOCK_NOW)
assert len(queue) == 1
msg = queue[0]
assert parseable(msg) is True
assert f'["host","{HttpLogger.host_lookup()}"]' in msg
assert f'["now","{MOCK_NOW}"]' in msg
assert '["request_method","GET"]' in msg
assert f'["request_url","{MOCK_URL}"]' in msg
assert "request_body" not in msg
assert "request_header" not in msg
assert "request_param" not in msg
assert "interval" not in msg
def test_formats_request_with_empty_body():
queue = []
logger = HttpLogger(queue=queue, rules="include debug")
HttpMessage.send(
logger,
request=mock_request_with_json2(),
response=mock_response(),
request_body="",
)
assert len(queue) == 1
msg = queue[0]
assert parseable(msg) is True
assert '["request_header:a","1, 2"]' in msg
assert '["request_header:abc","123"]' in msg
assert '["request_header:content-type","Application/JSON"]' in msg
assert '["request_method","POST"]' in msg
assert '["request_param:abc","123, 234"]' in msg
assert f'["request_param:message","{MOCK_JSON_ESCAPED}"]' in msg
assert f'["request_url","{MOCK_URL}?{MOCK_QUERY_STRING}"]' in msg
assert "request_body" not in msg
assert "request_param:foo" not in msg
def test_uses_stop_if_found_rules():
queue = []
logger = HttpLogger(
queue=queue, rules='!response_header:blahblahblah! stop_if_found !.*!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
queue = []
logger = HttpLogger(queue=queue,
rules='!response_body! stop_if_found !.*!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 0
queue = []
logger = HttpLogger(queue=queue,
rules='!response_body! stop_if_found !World!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 0
queue = []
logger = HttpLogger(queue=queue,
rules='!response_body! stop_if_found !.*World.*!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 0
queue = []
logger = HttpLogger(queue=queue,
rules='!response_body! stop_if_found !blahblahblah!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
def __call__(self, environ, start_response) -> ClosingIterator:
body__ = self.request_body(environ)
def _start_response(status, response_headers, *args):
self.start_response(status, response_headers)
return start_response(status, response_headers, *args)
response_chunks = self.finish_response(
self.app(environ, _start_response))
request = Request(environ)
parased_raw_params: Dict[str, List[str]] = parse.parse_qs(
parse.urlparse(request.url).query)
params: Dict[str, str] = {}
# Type correction
for k, v in parased_raw_params.items():
params[k] = v[0]
HttpMessage.send(
self.logger,
request=HttpRequestImpl(
method=request.method,
url=str(request.url),
headers=dict(request.headers),
params=params,
body=body__,
),
response=HttpResponseImpl(
status=self.status,
body=str(self.response[0].decode()) if self.response else None,
headers=dict(self.response_headers),
),
interval=str(self.interval),
)
return ClosingIterator(response_chunks)
def test_uses_remove_rules():
queue = []
logger = HttpLogger(queue=queue, rules="!.*! remove")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 0
queue = []
logger = HttpLogger(queue=queue, rules="!request_body! remove")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' not in queue[0]
assert '["response_body",' in queue[0]
queue = []
logger = HttpLogger(queue=queue, rules="!response_body! remove")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' in queue[0]
assert '["response_body",' not in queue[0]
queue = []
logger = HttpLogger(queue=queue,
rules="!request_body|response_body! remove")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' not in queue[0]
assert '["response_body",' not in queue[0]
queue = []
logger = HttpLogger(queue=queue, rules="!request_header:.*! remove")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' in queue[0]
assert '["request_header:' not in queue[0]
assert '["response_body",' in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules="!request_header:abc! remove\n!response_body! remove")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' in queue[0]
assert '["request_header:' in queue[0]
assert '["request_header:abc' not in queue[0]
assert '["response_body",' not in queue[0]
def test_uses_replace_rules():
queue = []
logger = HttpLogger(
queue=queue, rules="!response_body! replace !blahblahblah!, !ZZZZZ!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "World" in queue[0]
assert "ZZZZZ" not in queue[0]
queue = []
logger = HttpLogger(queue=queue,
rules="!response_body! replace !World!, !Mundo!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["response_body","<html>Hello Mundo!</html>"],' in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules="!request_body|response_body! replace !^.*!, !ZZZZZ!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body","ZZZZZ"' in queue[0]
assert '["response_body","ZZZZZ"' in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules=
"!request_body! replace !^.*!, !QQ!\n!response_body! replace !^.*!, !SS!",
)
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body","QQ"' in queue[0]
assert '["response_body","SS"' in queue[0]
queue = []
logger = HttpLogger(queue=queue,
rules="!response_body! replace !World!, !!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["response_body","<html>Hello !</html>"],' in queue[0]
queue = []
logger = HttpLogger(queue=queue, rules="!response_body! replace !.*!, !!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["response_body",' not in queue[0]
queue = []
logger = HttpLogger(queue=queue,
rules="!response_body! replace !World!, !Z!")
HttpMessage.send(
logger,
request=mock_request_with_json2(),
response=mock_response_with_html(),
response_body=MOCK_HTML3,
)
assert len(queue) == 1
assert '["response_body","<html>1 Z 2 Z Red Z Blue Z!</html>"],' in queue[
0]
queue = []
logger = HttpLogger(queue=queue,
rules="!response_body! replace !World!, !Z!")
HttpMessage.send(
logger,
request=mock_request_with_json2(),
response=mock_response_with_html(),
response_body=MOCK_HTML4,
)
assert len(queue) == 1
assert ('["response_body","<html>1 Z\\n2 Z\\nRed Z \\nBlue Z!\\n</html>"],'
in queue[0])
def test_uses_remove_unless_found_rules():
queue = []
logger = HttpLogger(
queue=queue,
rules="!response_header:blahblahblah! remove_unless_found !.*!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
queue = []
logger = HttpLogger(queue=queue,
rules="!.*! remove_unless_found !blahblahblah!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 0
queue = []
logger = HttpLogger(
queue=queue, rules="!request_body! remove_unless_found !blahblahblah!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' not in queue[0]
assert '["response_body",' in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules="!response_body! remove_unless_found !blahblahblah!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' in queue[0]
assert '["response_body",' not in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules="!response_body|request_body! remove_unless_found !World!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' not in queue[0]
assert '["response_body",' in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules="!response_body|request_body! remove_unless_found !.*World.*!",
)
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' not in queue[0]
assert '["response_body",' in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules="!response_body|request_body! remove_unless_found !.*!")
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert '["request_body",' in queue[0]
assert '["response_body",' in queue[0]
def test_uses_replace_rules():
queue = []
logger = HttpLogger(
queue=queue, rules='!response_body! replace !blahblahblah!, !ZZZZZ!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert 'World' in queue[0]
assert 'ZZZZZ' not in queue[0]
queue = []
logger = HttpLogger(queue=queue,
rules='!response_body! replace !World!, !Mundo!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"response_body\",\"<html>Hello Mundo!</html>\"]," in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules='!request_body|response_body! replace !^.*!, !ZZZZZ!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"request_body\",\"ZZZZZ\"" in queue[0]
assert "[\"response_body\",\"ZZZZZ\"" in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules=
"!request_body! replace !^.*!, !QQ!\n!response_body! replace !^.*!, !SS!"
)
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"request_body\",\"QQ\"" in queue[0]
assert "[\"response_body\",\"SS\"" in queue[0]
queue = []
logger = HttpLogger(queue=queue,
rules='!response_body! replace !World!, !!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"response_body\",\"<html>Hello !</html>\"]," in queue[0]
queue = []
logger = HttpLogger(queue=queue, rules='!response_body! replace !.*!, !!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"response_body\"," not in queue[0]
queue = []
logger = HttpLogger(queue=queue,
rules='!response_body! replace !World!, !Z!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html(),
response_body=MOCK_HTML3)
assert len(queue) == 1
assert "[\"response_body\",\"<html>1 Z 2 Z Red Z Blue Z!</html>\"]," in queue[
0]
queue = []
logger = HttpLogger(queue=queue,
rules='!response_body! replace !World!, !Z!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html(),
response_body=MOCK_HTML4)
assert len(queue) == 1
assert "[\"response_body\",\"<html>1 Z\\n2 Z\\nRed Z \\nBlue Z!\\n</html>\"]," in queue[
0]
def test_uses_remove_unless_rules():
queue = []
logger = HttpLogger(
queue=queue, rules='!response_header:blahblahblah! remove_unless !.*!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
queue = []
logger = HttpLogger(queue=queue,
rules='!.*! remove_unless !.*blahblahblah.*!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 0
queue = []
logger = HttpLogger(
queue=queue, rules='!request_body! remove_unless !.*blahblahblah.*!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"request_body\"," not in queue[0]
assert "[\"response_body\"," in queue[0]
queue = []
logger = HttpLogger(
queue=queue, rules='!response_body! remove_unless !.*blahblahblah.*!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"request_body\"," in queue[0]
assert "[\"response_body\"," not in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules='!response_body|request_body! remove_unless !.*World.*!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"request_body\"," not in queue[0]
assert "[\"response_body\"," in queue[0]
queue = []
logger = HttpLogger(
queue=queue, rules='!response_body|request_body! remove_unless !.*!')
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"request_body\"," in queue[0]
assert "[\"response_body\"," in queue[0]
queue = []
logger = HttpLogger(
queue=queue,
rules=
"!response_body! remove_unless !.*!\n!request_body! remove_unless !.*!"
)
HttpMessage.send(logger,
request=mock_request_with_json2(),
response=mock_response_with_html())
assert len(queue) == 1
assert "[\"request_body\"," in queue[0]
assert "[\"response_body\"," in queue[0]