Improve debug logging

src/cloud_what/_base_provider.py

@@ -17,6 +17,7 @@
 should not be imported outside this package.
 """
 
+import enum
 import requests
 import logging
 import json
@@ -28,6 +29,19 @@
 log = logging.getLogger(__name__)
 
 
+class COLOR(enum.Enum):
+    RED = "\033[91m"
+    YELLOW = "\033[93m"
+    GREEN = "\033[92m"
+    MAGENTA = "\033[95m"
+    BLUE = "\033[94m"
+    RESET = "\033[0m"
+
+
+def colorize(text: str, color: COLOR) -> str:
+    return color.value + text + COLOR.RESET.value
+
+
 class BaseCloudProvider:
     """
     Base class of cloud provider. This class is used for cloud detecting
@@ -345,19 +359,17 @@ def _debug_print_http_request(request: requests.PreparedRequest) -> None:
         :param request: prepared HTTP request
         :return: None
         """
-        yellow_col = "\033[93m"
-        blue_col = "\033[94m"
-        red_col = "\033[91m"
-        end_col = "\033[0m"
-        msg = blue_col + "Making request: " + end_col
-        msg += red_col + request.method + " " + request.url + end_col
+        print(colorize("Request:", COLOR.GREEN))
+        print(colorize(f"{request.method} {request.url}", COLOR.RED))
+
         if os.environ.get("SUBMAN_DEBUG_PRINT_REQUEST_HEADER", ""):
-            headers = ", ".join("{}: {}".format(k, v) for k, v in request.headers.items())
-            msg += blue_col + " {{{headers}}}".format(headers=headers) + end_col
+            print(colorize("Request headers:", COLOR.GREEN))
+            print(colorize(f"{request.headers}", COLOR.BLUE))
+
         if os.environ.get("SUBMAN_DEBUG_PRINT_REQUEST_BODY", "") and request.body is not None:
-            msg += yellow_col + f" {request.body}" + end_col
-        print()
-        print(msg)
+            print(colorize("Request body:", COLOR.GREEN))
+            print(colorize(f"{request.body}", COLOR.YELLOW))
+
         print()
 
     @staticmethod
@@ -369,15 +381,15 @@ def _cb_debug_print_http_response(response: requests.Response, *args, **kwargs)
         :param **kwargs: Not used
         :return: Instance of response
         """
-        print(
-            "\n{code} {{{headers}}}\n{body}\n".format(
-                code=response.status_code,
-                headers=", ".join(
-                    "{key}: {value}".format(key=k, value=v) for k, v in response.headers.items()
-                ),
-                body=response.text,
-            )
-        )
+        print(colorize("Response:", COLOR.GREEN))
+        print(colorize(f"{response.status_code}", COLOR.RED))
+
+        print(colorize("Response headers:", COLOR.GREEN))
+        print(colorize(f"{response.headers}", COLOR.BLUE))
+
+        print(colorize("Response content:", COLOR.GREEN))
+        print(colorize(f"{response.text}", COLOR.YELLOW))
+
         return response
 
     def _get_data_from_server(self, data_type: str, url: str, headers: dict = None) -> Union[str, None]:

src/rhsm/connection.py

@@ -847,94 +847,105 @@ def _print_debug_info_about_request(
         :return: None
         """
 
-        if os.environ.get("SUBMAN_DEBUG_PRINT_REQUEST", ""):
-            magenta_col = "\033[95m"
-            blue_col = "\033[94m"
-            yellow_col = "\033[93m"
-            green_col = "\033[92m"
-            red_col = "\033[91m"
-            end_col = "\033[0m"
-
-            msg = ""
-
-            if self.auth_type == ConnectionType.KEYCLOAK_AUTH:
-                auth = "keycloak auth"
-            elif self.auth_type == ConnectionType.BASIC_AUTH:
-                auth = "basic auth"
-            elif self.auth_type == ConnectionType.CONSUMER_CERT_AUTH:
-                auth = "consumer auth"
-            elif self.auth_type == ConnectionType.NO_AUTH:
-                auth = "no auth"
-            else:
-                auth = "undefined auth"
+        if os.environ.get("SUBMAN_DEBUG_PRINT_REQUEST", "") == "":
+            return
 
-            # Print information about TCP/IP layer
-            if (
-                os.environ.get("SUBMAN_DEBUG_TCP_IP", "")
-                and self.__conn is not None
-                and self.__conn.sock is not None
-            ):
-                msg += blue_col + f"{self.__conn.sock}\n" + end_col
-
-            # When proxy server is used, then print some additional information about proxy connection
-            if self.proxy_hostname and self.proxy_port:
-                # Note: using only https:// is not a mistake. We use only https for proxy connection.
-                msg += blue_col + "Using proxy: " + magenta_col + "https://"
-                # Print username and eventually password
-                if self.proxy_user:
-                    if self.proxy_user and self.proxy_password:
-                        msg += f"{self.proxy_user}:{self.proxy_password}@"
-                    elif self.proxy_user and not self.proxy_password:
-                        msg += f"{self.proxy_user}@"
-                # Print hostname and port
-                msg += f"{normalized_host(self.proxy_hostname)}:{safe_int(self.proxy_port)}"
-                msg += end_col
-                # Print HTTP headers used for proxy connection
-                tunel_headers = None
-                if self.__conn is not None and hasattr(self.__conn, "_tunnel_headers"):
-                    tunel_headers = getattr(self.__conn, "_tunnel_headers")
-                if tunel_headers is not None:
-                    msg += blue_col + f" {tunel_headers}" + end_col
-                msg += "\n"
-
-            if self.insecure is True:
-                msg += blue_col + f"Making insecure ({auth}) request:" + end_col
-            else:
-                msg += blue_col + f"Making ({auth}) request:" + end_col
-            msg += (
-                red_col
-                + " https://"
-                + f"{normalized_host(self.host)}:{safe_int(self.ssl_port)}{handler} {request_type}"
-                + end_col
+        print()
+
+        # Print information about TCP/IP layer
+        if (
+            os.environ.get("SUBMAN_DEBUG_TCP_IP", "")
+            and self.__conn is not None
+            and self.__conn.sock is not None
+        ):
+            print(utils.colorize("TCP socket:", utils.COLOR.GREEN))
+            print(utils.colorize(f"{self.__conn.sock}", utils.COLOR.BLUE))
+
+        # When proxy server is used, then print some additional information about proxy connection
+        if self.proxy_hostname and self.proxy_port:
+            print(utils.colorize("Proxy:", utils.COLOR.GREEN))
+            # Note: using only https:// is not a mistake. We use only https for proxy connection.
+            proxy_msg: str = "https://"
+            # Print username and eventually password
+            if self.proxy_user:
+                if self.proxy_user and self.proxy_password:
+                    proxy_msg += f"{self.proxy_user}:{self.proxy_password}@"
+                elif self.proxy_user and not self.proxy_password:
+                    proxy_msg += f"{self.proxy_user}@"
+            # Print hostname and port
+            proxy_msg += f"{normalized_host(self.proxy_hostname)}:{safe_int(self.proxy_port)}"
+            print(utils.colorize(proxy_msg, utils.COLOR.MAGENTA))
+
+            # Print HTTP headers used for proxy connection
+            tunnel_msg = ""
+            tunnel_headers = None
+            if self.__conn is not None and hasattr(self.__conn, "_tunnel_headers"):
+                tunnel_headers = getattr(self.__conn, "_tunnel_headers")
+            if tunnel_headers is not None:
+                tunnel_msg = f"{tunnel_headers}"
+            if tunnel_msg:
+                print(utils.colorize(tunnel_msg, utils.COLOR.BLUE))
+
+        auth = ""
+        if self.insecure:
+            auth = "insecure "
+        if self.auth_type == ConnectionType.KEYCLOAK_AUTH:
+            auth += "keycloak auth"
+        elif self.auth_type == ConnectionType.BASIC_AUTH:
+            auth += "basic auth"
+        elif self.auth_type == ConnectionType.CONSUMER_CERT_AUTH:
+            auth += "consumer auth"
+        elif self.auth_type == ConnectionType.NO_AUTH:
+            auth += "no auth"
+        else:
+            auth += "undefined auth"
+
+        print(utils.colorize("Request:", utils.COLOR.GREEN))
+        print(
+            utils.colorize(
+                f"{request_type} "
+                + "https://"
+                + f"{normalized_host(self.host)}:{safe_int(self.ssl_port)}{handler}",
+                utils.COLOR.RED,
             )
+            + " using "
+            + utils.colorize(f"{auth}", utils.COLOR.BLUE)
+        )
 
-            if os.environ.get("SUBMAN_DEBUG_PRINT_REQUEST_HEADER", ""):
-                msg += blue_col + " %s" % final_headers + end_col
-            if os.environ.get("SUBMAN_DEBUG_PRINT_REQUEST_BODY", "") and body is not None:
-                msg += yellow_col + " %s" % body + end_col
-            print()
-            print(msg)
-            print()
-            if os.environ.get("SUBMAN_DEBUG_SAVE_TRACEBACKS", ""):
-                debug_dir = Path("/tmp/rhsm/")
-                debug_dir.mkdir(exist_ok=True)
+        if os.environ.get("SUBMAN_DEBUG_PRINT_REQUEST_HEADER", ""):
+            print(utils.colorize("Request headers:", utils.COLOR.GREEN))
+            print(utils.colorize(f"{final_headers}", utils.COLOR.BLUE))
+
+        if os.environ.get("SUBMAN_DEBUG_PRINT_REQUEST_BODY", "") and body is not None:
+            print(utils.colorize("Request body:", utils.COLOR.GREEN))
+            print(utils.colorize(f"{body}", utils.COLOR.YELLOW))
+
+        if os.environ.get("SUBMAN_DEBUG_PRINT_TRACEBACKS", ""):
+            print(utils.colorize("Current call stack:", utils.COLOR.GREEN))
+            traceback.print_stack(file=sys.stdout)
 
-                timestamp: str = datetime.datetime.now().strftime("%Y-%m-%d_%H-%M-%S")
+        if os.environ.get("SUBMAN_DEBUG_SAVE_TRACEBACKS", ""):
+            debug_dir = Path("/tmp/rhsm/")
+            debug_dir.mkdir(exist_ok=True)
 
-                # make sure we don't overwrite previous logs
-                i = 0
-                while True:
-                    filename = Path(f"{timestamp}_{i}.log")
-                    debug_log = debug_dir / filename
-                    if not debug_log.exists():
-                        break
-                    i += 1
+            timestamp: str = datetime.datetime.now().strftime("%Y-%m-%d_%H-%M-%S")
 
-                with debug_log.open("w", encoding="utf-8") as handle:
-                    traceback.print_stack(file=handle)
+            # make sure we don't overwrite previous logs
+            i = 0
+            while True:
+                filename = Path(f"{timestamp}_{i}.log")
+                debug_log = debug_dir / filename
+                if not debug_log.exists():
+                    break
+                i += 1
 
-                print(green_col + f"Traceback saved to {str(debug_log)}." + end_col)
-                print()
+            with debug_log.open("w", encoding="utf-8") as handle:
+                traceback.print_stack(file=handle)
+
+            print(utils.colorize("Call stack file:", utils.COLOR.GREEN))
+            print(f"{str(debug_log)}")
+
+        print()
 
     @staticmethod
     def _print_debug_info_about_response(result: dict) -> None:
@@ -946,10 +957,16 @@ def _print_debug_info_about_response(result: dict) -> None:
         """
 
         if os.environ.get("SUBMAN_DEBUG_PRINT_RESPONSE", ""):
-            gray_col = "\033[90m"
-            end_col = "\033[0m"
-            print(gray_col + "%s %s" % (result["status"], result["headers"]))
-            print(result["content"] + end_col)
+            print(utils.colorize("Response:", utils.COLOR.GREEN))
+            print(utils.colorize(f"{result['status']}", utils.COLOR.RED))
+
+            print(utils.colorize("Response headers:", utils.COLOR.GREEN))
+            print(utils.colorize(f"{result['headers']}", utils.COLOR.BLUE))
+
+            if result["content"]:
+                print(utils.colorize("Response body:", utils.COLOR.GREEN))
+                print(utils.colorize(f"{result['content']}", utils.COLOR.YELLOW))
+
             print()
 
     def _set_accept_language_in_header(self) -> None:

src/rhsm/utils.py

@@ -11,7 +11,7 @@
 # granted to use or replicate Red Hat trademarks that are incorporated
 # in this software or its documentation.
 #
-
+import enum
 import functools
 import os
 import re
@@ -35,6 +35,19 @@
 """
 
 
+class COLOR(enum.Enum):
+    RED = "\033[91m"
+    YELLOW = "\033[93m"
+    GREEN = "\033[92m"
+    MAGENTA = "\033[95m"
+    BLUE = "\033[94m"
+    RESET = "\033[0m"
+
+
+def colorize(text: str, color: COLOR) -> str:
+    return color.value + text + COLOR.RESET.value
+
+
 def remove_scheme(uri: str) -> str:
     """Remove the scheme component from a URI."""
     return re.sub("^[A-Za-z][A-Za-z0-9+-.]*://", "", uri)