From 20d96a0773ff3ca6207dbbf63e7556cdc571ff96 Mon Sep 17 00:00:00 2001 From: JP-Ellis Date: Thu, 21 Mar 2024 15:07:07 +1100 Subject: [PATCH] chore(tests): improve logging from provider As the provider is launched in its own Python process, logging is not configured. So instead of using various `logging` methods, directly write to `stderr`. Signed-off-by: JP-Ellis --- .../compatibility_suite/test_v1_provider.py | 4 +-- tests/v3/compatibility_suite/util/__init__.py | 16 ++++++++-- tests/v3/compatibility_suite/util/provider.py | 30 +++++++++---------- 3 files changed, 29 insertions(+), 21 deletions(-) diff --git a/tests/v3/compatibility_suite/test_v1_provider.py b/tests/v3/compatibility_suite/test_v1_provider.py index 359d135f9a..9b216962d4 100644 --- a/tests/v3/compatibility_suite/test_v1_provider.py +++ b/tests/v3/compatibility_suite/test_v1_provider.py @@ -420,10 +420,10 @@ def redirect() -> NoReturn: while True: if process.stdout: while line := process.stdout.readline(): - logger.debug("Provider stdout: %s", line) + logger.debug("Provider stdout: %s", line.strip()) if process.stderr: while line := process.stderr.readline(): - logger.debug("Provider stderr: %s", line) + logger.debug("Provider stderr: %s", line.strip()) thread = Thread(target=redirect, daemon=True) thread.start() diff --git a/tests/v3/compatibility_suite/util/__init__.py b/tests/v3/compatibility_suite/util/__init__.py index 50e149c73f..1f47080b24 100644 --- a/tests/v3/compatibility_suite/util/__init__.py +++ b/tests/v3/compatibility_suite/util/__init__.py @@ -25,6 +25,7 @@ def _(): import contextlib import hashlib import logging +import sys import typing from collections.abc import Collection, Mapping from datetime import date, datetime, time @@ -555,9 +556,18 @@ def add_to_flask(self, app: flask.Flask) -> None: app: The Flask app to add the interaction to. """ - - async def route_fn() -> flask.Response: - logger.info("Received request: %s %s", self.method, self.path) + sys.stderr.write( + f"Adding interaction to Flask app: {self.method} {self.path}\n" + ) + sys.stderr.write(f" Query: {self.query}\n") + sys.stderr.write(f" Headers: {self.headers}\n") + sys.stderr.write(f" Body: {self.body}\n") + sys.stderr.write(f" Response: {self.response}\n") + sys.stderr.write(f" Response headers: {self.response_headers}\n") + sys.stderr.write(f" Response body: {self.response_body}\n") + + def route_fn() -> flask.Response: + sys.stderr.write(f"Received request: {self.method} {self.path}\n") if self.query: query = URL.build(query_string=self.query).query # Perform a two-way check to ensure that the query parameters diff --git a/tests/v3/compatibility_suite/util/provider.py b/tests/v3/compatibility_suite/util/provider.py index 1f7b86c09f..f90c359028 100644 --- a/tests/v3/compatibility_suite/util/provider.py +++ b/tests/v3/compatibility_suite/util/provider.py @@ -180,14 +180,12 @@ def _add_after_request(self, app: flask.Flask) -> None: @app.after_request def log_request(response: flask.Response) -> flask.Response: - logger.debug("Request: %s %s", request.method, request.path) - logger.debug( - "Request query string: %s", request.query_string.decode("utf-8") - ) - logger.debug("Request query params: %s", serialize(request.args)) - logger.debug("Request headers: %s", serialize(request.headers)) - logger.debug("Request body: %s", request.data.decode("utf-8")) - logger.debug("Request form: %s", serialize(request.form)) + sys.stderr.write(f"START REQUEST: {request.method} {request.path}\n") + sys.stderr.write(f"Query string: {request.query_string.decode('utf-8')}\n") + sys.stderr.write(f"Header: {serialize(request.headers)}\n") + sys.stderr.write(f"Body: {request.data.decode('utf-8')}\n") + sys.stderr.write(f"Form: {serialize(request.form)}\n") + sys.stderr.write("END REQUEST\n") with ( self.provider_dir @@ -210,13 +208,13 @@ def log_request(response: flask.Response) -> flask.Response: @app.after_request def log_response(response: flask.Response) -> flask.Response: - try: - body = response.get_data(as_text=True) - except UnicodeDecodeError: - body = "" - logger.debug("Response: %s", response.status_code) - logger.debug("Response headers: %s", serialize(response.headers)) - logger.debug("Response body: %s", body) + sys.stderr.write(f"START RESPONSE: {response.status_code}\n") + sys.stderr.write(f"Headers: {serialize(response.headers)}\n") + sys.stderr.write( + f"Body: {response.get_data().decode('utf-8', errors='replace')}\n" + ) + sys.stderr.write("END RESPONSE\n") + with ( self.provider_dir / f"response.{datetime.now(tz=UTC).strftime('%H:%M:%S.%f')}.json" @@ -226,7 +224,7 @@ def log_response(response: flask.Response) -> flask.Response: "status_code": response.status_code, "headers_list": serialize(response.headers), "headers_dict": serialize(dict(response.headers)), - "body": body, + "body": response.get_data().decode("utf-8", errors="replace"), }, f, )