Skip to content

Commit

Permalink
Improve debug logging to make it faster to understand
Browse files Browse the repository at this point in the history
This change clearly labels each section that's printed to make it easier
to identify the interesting parts.

This also adds SUBMAN_DEBUG_PRINT_TRACEBACKS flag to print the traceback
directly to stdout.

GREEN:  title
RED:    method + url (request), status code (response)
BLUE:   headers
YELLOW: body
WHITE:  call stack
  • Loading branch information
m-horky committed Dec 12, 2023
1 parent 5ffa8be commit 7f837cc
Show file tree
Hide file tree
Showing 3 changed files with 110 additions and 72 deletions.
52 changes: 32 additions & 20 deletions src/cloud_what/_base_provider.py
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
should not be imported outside this package.
"""

import enum
import requests
import logging
import json
Expand All @@ -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
Expand Down Expand Up @@ -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
Expand All @@ -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]:
Expand Down
115 changes: 64 additions & 51 deletions src/rhsm/connection.py
Original file line number Diff line number Diff line change
Expand Up @@ -848,73 +848,78 @@ def _print_debug_info_about_request(
"""

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"

# 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
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.
msg += blue_col + "Using proxy: " + magenta_col + "https://"
proxy_msg: str = "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}@"
proxy_msg += f"{self.proxy_user}:{self.proxy_password}@"
elif self.proxy_user and not self.proxy_password:
msg += f"{self.proxy_user}@"
proxy_msg += f"{self.proxy_user}@"
# Print hostname and port
msg += f"{normalized_host(self.proxy_hostname)}:{safe_int(self.proxy_port)}"
msg += end_col
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
tunel_headers = None
tunnel_msg = ""
tunnel_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
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:
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
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
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:
msg += yellow_col + " %s" % body + end_col
print()
print(msg)
print()
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)

if os.environ.get("SUBMAN_DEBUG_SAVE_TRACEBACKS", ""):
debug_dir = Path("/tmp/rhsm/")
debug_dir.mkdir(exist_ok=True)
Expand All @@ -933,8 +938,10 @@ def _print_debug_info_about_request(
with debug_log.open("w", encoding="utf-8") as handle:
traceback.print_stack(file=handle)

print(green_col + f"Traceback saved to {str(debug_log)}." + end_col)
print()
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:
Expand All @@ -946,10 +953,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:
Expand Down
15 changes: 14 additions & 1 deletion src/rhsm/utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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)
Expand Down

0 comments on commit 7f837cc

Please sign in to comment.