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
m-horky committed Dec 13, 2023
1 parent 5ffa8be commit 22e5630
Show file tree
Hide file tree
Showing 3 changed files with 148 additions and 106 deletions.
52 changes: 32 additions & 20 deletions src/cloud_what/_base_provider.py
View file
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
187 changes: 102 additions & 85 deletions src/rhsm/connection.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand All @@ -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:
Expand Down
15 changes: 14 additions & 1 deletion src/rhsm/utils.py
View file
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 22e5630

Please sign in to comment.