[FEATURE] Initial implementation of module logging for debugging (- WIP #233 -)

Changes in file .coveragerc:
 * updated related config

Changes in file multicast/__init__.py:
 * added debug signposts via logging module

Changes in file multicast/env.py:
 * added debug signposts via logging module

Changes in file multicast/exceptions.py:
 * added debug signposts via logging module

Changes in file multicast/hear.py:
 * added debug signposts via logging module
 * related work

Changes in file multicast/recv.py:
 * added debug signposts via logging module

Changes in file multicast/send.py:
 * added debug signposts via logging module
 * related work

Changes in file multicast/skt.py:
 * added debug signpost via logging module

Changes in file requirements.txt:
 * mention of loggin builtin

Changes in file tests/__init__.py:
  * added debug signposts via logging module

Changes in file tests/context.py:
 * related work

Changes in file tests/run_selective.py:
 * related work def main() -> None:

Author: reactive-firewall

.coveragerc

@@ -34,6 +34,7 @@ exclude_lines =
     if __name__ in u"__main__":
     if __name__ .. .__main__.:
     if __sys_path__ not in sys.path:
+    if __debug__
     os.abort()
     exit
 
@@ -52,6 +53,7 @@ partial_branches =
     if __name__ in u'__main__':
     if __name__ in u"__main__":
     if __name__ in '__main__':
+    if __debug__
     if __sys_path__ not in sys.path:
     # don't complain about sys.modules
     sys.modules

multicast/__init__.py

@@ -22,6 +22,7 @@
 import socket
 import struct
 import abc
+import logging
 
 # skipcq
 __all__ = [
@@ -404,6 +405,10 @@
 
 """
 
+if logging.__name__ is not None:  # pragma: no branch
+	logging.getLogger(__module__).addHandler(logging.NullHandler())
+	logging.getLogger(__module__).debug(f"Loading {__module__}")
+
 if sys.__name__ is None:
 	raise ModuleNotFoundError(
 		"FAIL: we could not import sys. We're like in the matrix! ABORT."
@@ -418,6 +423,7 @@
 if socket.__name__ is None:
 	raise ModuleNotFoundError("FAIL: we could not import socket. ABORT.") from None
 else:  # pragma: no branch
+	logging.getLogger(__module__).debug(f"Setting default packet timeout to {_MCAST_DEFAULT_TTL}")
 	socket.setdefaulttimeout(int(_MCAST_DEFAULT_TTL))
 
 if struct.__name__ is None:
@@ -460,6 +466,7 @@
 if _config is None:
 	raise ImportError("FAIL: we could not import environment. ABORT.") from None
 else:
+	logging.getLogger(__module__).debug("Configuring overrides and defaults.")
 	_MCAST_DEFAULT_PORT = _config["port"]
 	_MCAST_DEFAULT_GROUP = _config["group"]
 	_MCAST_DEFAULT_TTL = _config["ttl"]
@@ -468,6 +475,11 @@
 	_MCAST_DEFAULT_BIND_IP = _config["bind_addr"]
 	global _MCAST_DEFAULT_GROUPS  # skipcq: PYL-W0604
 	_MCAST_DEFAULT_GROUPS = _config["groups"]
+	if __debug__:  # pragma: no branch
+		logging.getLogger(__module__).info("Overrides and defaults are configured.")
+		logging.getLogger(__module__).debug("Defaults:")
+		for key, value in _config.items():
+			logging.getLogger(__module__).debug(f"\t{key}={str(value)}")
 
 del _config  # skipcq - cleanup any bootstrap/setup leaks early
 
@@ -543,6 +555,7 @@ def buildArgs(cls, calling_parser_group):
 
 		"""
 		if calling_parser_group is None:  # pragma: no branch
+			logging.getLogger(__module__).debug(f"Building {__name__} arguments.")
 			calling_parser_group = argparse.ArgumentParser(
 				prog=str(cls.__name__ if cls.__proc__ is None else cls.__proc__),
 				description=cls.__prologue__,

multicast/env.py

@@ -88,6 +88,7 @@
 try:
 	import os
 	import warnings
+	from . import logging  # skipcq: PLY-C0414
 	from . import socket  # skipcq: PYL-C0414
 	import ipaddress
 except Exception as err:
@@ -98,6 +99,11 @@
 	raise baton from err
 
 
+module_logger = logging.getLogger(__module__)
+module_logger.debug(f"loading {__module__}")
+module_logger.debug(f"Initializing {__package__} environment.")
+
+
 def validate_buffer_size(size: int) -> bool:
 	"""
 	Validate if the buffer size is a positive integer.
@@ -334,26 +340,31 @@ def load_buffer_size() -> int:
 	"""
 	# Import globals that we'll potentially update
 	from multicast import _MCAST_DEFAULT_BUFFER_SIZE
+	module_logger.debug("Looking for MULTICAST_BUFFER_SIZE in environment.")
 	try:
 		buffer_size = int(os.getenv(
 			"MULTICAST_BUFFER_SIZE",
 			_MCAST_DEFAULT_BUFFER_SIZE  # skipcq: PYL-W1508
 		))
+		module_logger.debug("Done.")
 	except ValueError:
 		warnings.warn(
 			f"Invalid MULTICAST_BUFFER_SIZE value, using default {_MCAST_DEFAULT_BUFFER_SIZE}",
 			stacklevel=2
 		)
 		buffer_size = _MCAST_DEFAULT_BUFFER_SIZE  # skipcq: PYL-W1508
-	# Validate and potentially update port
+	# Validate and potentially update buffer-size
+	module_logger.debug("Validating MULTICAST_BUFFER_SIZE.")
 	if validate_buffer_size(buffer_size):
 		globals()["_MCAST_DEFAULT_BUFFER_SIZE"] = buffer_size
+		module_logger.debug("Valid.")
 	else:
 		warnings.warn(
 			f"Invalid MULTICAST_BUFFER_SIZE {buffer_size}, using default {_MCAST_DEFAULT_BUFFER_SIZE}",
 			stacklevel=2
 		)
 		buffer_size = _MCAST_DEFAULT_BUFFER_SIZE
+	module_logger.debug(f"Loaded {buffer_size} as internal multicast buffer size.")
 	return buffer_size
 
 
@@ -435,22 +446,27 @@ def load_port() -> int:
 	"""
 	# Import globals that we'll potentially update
 	from multicast import _MCAST_DEFAULT_PORT
+	module_logger.debug("Looking for MULTICAST_PORT in environment.")
 	try:
 		port = int(os.getenv("MULTICAST_PORT", _MCAST_DEFAULT_PORT))
+		module_logger.debug("Done.")
 	except ValueError:
 		warnings.warn(
 			f"Invalid MULTICAST_PORT value, using default {_MCAST_DEFAULT_PORT}", stacklevel=2
 		)
 		port = _MCAST_DEFAULT_PORT
 	# Validate and potentially update port
+	module_logger.debug("Validating MULTICAST_PORT.")
 	if validate_port(port):
 		globals()["_MCAST_DEFAULT_PORT"] = port
+		module_logger.debug("Valid.")
 	else:
 		warnings.warn(
 			f"Port {port} is outside valid range (49152-65535), using default {_MCAST_DEFAULT_PORT}",
 			stacklevel=2
 		)
 		port = _MCAST_DEFAULT_PORT
+	module_logger.debug(f"Loaded {port} as default multicast port.")
 	return port
 
 
@@ -555,15 +571,19 @@ def load_group() -> ipaddress.IPv4Address:
 	"""
 	# Import globals that we'll potentially update
 	from multicast import _MCAST_DEFAULT_GROUP
+	module_logger.debug("Looking for any MULTICAST_GROUP in environment.")
 	group = os.getenv("MULTICAST_GROUP", _MCAST_DEFAULT_GROUP)
 	# Validate and potentially update group
+	module_logger.debug("Validating either MULTICAST_GROUP or default.")
 	if validate_multicast_address(group):
 		globals()["_MCAST_DEFAULT_GROUP"] = group
+		module_logger.debug("Valid.")
 	else:
 		warnings.warn(
 			f"Invalid multicast group {group}, using default {_MCAST_DEFAULT_GROUP}", stacklevel=2
 		)
 		group = _MCAST_DEFAULT_GROUP
+	module_logger.debug(f"Loaded {group} as default multicast group.")
 	return ipaddress.IPv4Address(group)
 
 
@@ -638,24 +658,31 @@ def load_TTL() -> int:
 	"""
 	# Import globals that we'll potentially update
 	from multicast import _MCAST_DEFAULT_TTL
+	module_logger.debug("Looking for MULTICAST_TTL in environment.")
 	try:
 		ttl = int(os.getenv("MULTICAST_TTL", _MCAST_DEFAULT_TTL))
+		module_logger.debug("Done.")
 	except ValueError:
 		warnings.warn(
 			f"Invalid MULTICAST_TTL value, using default {_MCAST_DEFAULT_TTL}", stacklevel=2
 		)
 		ttl = _MCAST_DEFAULT_TTL
 	# Validate and potentially update TTL
+	module_logger.debug("Validating MULTICAST_TTL.")
 	if validate_ttl(ttl):
 		globals()["_MCAST_DEFAULT_TTL"] = ttl
+		module_logger.debug("Valid.")
 	else:
 		warnings.warn(
 			f"TTL {ttl} is outside valid range (1-126), using default {_MCAST_DEFAULT_TTL}",
 			stacklevel=2
 		)
 		ttl = _MCAST_DEFAULT_TTL
+	module_logger.debug(f"Loaded {ttl} as default multicast time-to-live.")
 	# Update socket default timeout
+	module_logger.debug("Update socket default timeout.")
 	socket.setdefaulttimeout(int(ttl))
+	module_logger.debug("Updated.")
 	return ttl
 
 
@@ -857,13 +884,19 @@ def load_config() -> dict:
 
 	"""
 	# Load values from environment with defaults
+	module_logger.info("Loading multicast overrides from environment.")
 	port = load_port()
 	group = load_group()
 	ttl = load_TTL()
 	buffer_size = load_buffer_size()
+	module_logger.debug("Looking for MULTICAST_GROUPS in environment.")
 	groups_str = os.getenv("MULTICAST_GROUPS", "")
+	module_logger.debug("Done.")
+	module_logger.debug("Looking for MULTICAST_BIND_ADDR in environment.")
 	bind_addr = os.getenv("MULTICAST_BIND_ADDR", str(group))  # skipcq: PYL-W1508
+	module_logger.debug("Done.")
 	# Process and validate groups
+	module_logger.debug("Processing and validating groups.")
 	groups = set()
 	if groups_str:
 		for addr in groups_str.split():
@@ -875,9 +908,14 @@ def load_config() -> dict:
 				)
 	# Always include the primary group
 	groups.add(str(group))
+	module_logger.debug("Processed groups.")
 	# Include bind_addr if it's a valid multicast address
+	module_logger.debug("Processing and validating bind-address.")
 	if validate_multicast_address(bind_addr):
+		module_logger.debug("Adding multicast bind-address to groups.")
 		groups.add(str(bind_addr))
+	module_logger.debug("Processed bind-address.")
+	module_logger.debug("Overrides and defaults are ready to configure.")
 	return {
 		"port": port,
 		"group": str(group),

multicast/exceptions.py

@@ -193,8 +193,8 @@
 """
 
 try:
-	from . import sys  # skipcq: PYL-C0414
 	from . import argparse  # skipcq: PYL-C0414
+	from . import logging  # skipcq: PYL-C0414
 	import functools
 except Exception as err:
 	baton = ImportError(err, str("[CWE-758] Module failed completely."))
@@ -204,6 +204,11 @@
 	raise baton from err
 
 
+module_logger = logging.getLogger(__module__)
+module_logger.debug(f"loading {__module__}")
+module_logger.debug(f"Initializing {__package__} exceptions.")
+
+
 class CommandExecutionError(RuntimeError):
 	"""
 	Exception raised when a command execution fails.
@@ -433,8 +438,11 @@ def __init__(self, *args, **kwargs) -> None:
 		self.exit_code = 143  # Use SIGTERM exit code for graceful shutdown
 
 
+module_logger.debug("Initialized exceptions.")
+module_logger.debug("Initializing error message strings.")
 # Error message constants
 EXIT_CODE_RANGE_ERROR = "Exit code must be an integer between 0 and 255"
+module_logger.debug("Initialized message strings.")
 
 
 def validate_exit_code(code) -> None:
@@ -509,8 +517,13 @@ def validate_exit_code(code) -> None:
 			>>> success
 			True
 	"""
+	module_logger.info("Validating possible exit code.")
 	if not isinstance(code, int) or code < 0 or code > 255:
 		raise ValueError(EXIT_CODE_RANGE_ERROR)
+	module_logger.info("Validated possible exit code.")
+
+
+module_logger.debug("Initializing CEP-8 EXIT_CODES")
 
 
 EXIT_CODES = {
@@ -555,6 +568,7 @@ def validate_exit_code(code) -> None:
 
 Usage Example:
 	```python
+		import sys
 		from multicast.exceptions import EXIT_CODES
 		from multicast.exceptions import get_exit_code_from_exception
 
@@ -621,6 +635,9 @@ def validate_exit_code(code) -> None:
 """
 
 
+module_logger.debug("Initialized EXIT_CODES.")
+
+
 def get_exit_code_from_exception(exc: BaseException) -> int:
 	"""
 	Retrieve the exit code associated with a specific exception.
@@ -733,25 +750,28 @@ def exit_on_exception(func: callable):
 
 	@functools.wraps(func)
 	def wrapper(*args, **kwargs):
+		_func_logger = module_logger
 		try:
+			_func_logger = logging.getLogger(func.__name__)
 			return func(*args, **kwargs)
 		except SystemExit as exc:
 			# Handle SystemExit exceptions, possibly from argparse
 			exit_code = exc.code if isinstance(exc.code, int) else 2
-			if (sys.stderr.isatty()):
-				print(f"{EXIT_CODES[exit_code][1]}: {exc}", file=sys.stderr)
+			_func_logger.warning(f"{EXIT_CODES[exit_code][1]}: {exc}")
 			raise SystemExit(exit_code) from exc
 			# otherwise sys.exit(exit_code)
 		except BaseException as err:
 			exit_code = get_exit_code_from_exception(err)
-			if (sys.stderr.isatty()):
-				print(f"{EXIT_CODES[exit_code][1]}: {err}", file=sys.stderr)
+			_func_logger.warning(f"{EXIT_CODES[exit_code][1]}: {err}")
 			raise SystemExit(exit_code) from err
 			# otherwise sys.exit(exit_code)
 
 	return wrapper
 
 
+module_logger.debug(f"loaded {__module__}")
+
+
 # skipcq
 __all__ = [
 	"""__package__""",