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 <josh@jpellis.me>

Author: JP-Ellis

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()

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

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 = "<binary>"
-            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,
                 )