Skip to content

Commit

Permalink
Merge pull request #3361 from candlepin/mhorky/connection-debug
Browse files Browse the repository at this point in the history 
Improve debug logging
  • Loading branch information
@jirihnidek
jirihnidek authored Dec 14, 2023
2 parents 5ffa8be + 22e5630 commit 51f75db
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 51f75db

Please sign in to comment.