diff --git a/acapy_agent/config/default_context.py b/acapy_agent/config/default_context.py index 32750b31be..8f28b0eaee 100644 --- a/acapy_agent/config/default_context.py +++ b/acapy_agent/config/default_context.py @@ -5,7 +5,6 @@ from ..anoncreds.registry import AnonCredsRegistry from ..cache.base import BaseCache from ..cache.in_memory import InMemoryCache -from ..config.logging.utils import add_trace_level from ..core.event_bus import EventBus from ..core.goal_code_registry import GoalCodeRegistry from ..core.plugin_registry import PluginRegistry @@ -29,17 +28,22 @@ from .injection_context import InjectionContext from .provider import CachedProvider, ClassProvider +LOGGER = logging.getLogger(__name__) + class DefaultContextBuilder(ContextBuilder): """Default context builder.""" async def build_context(self) -> InjectionContext: """Build the base injection context; set DIDComm prefix to emit.""" + LOGGER.debug("Building new injection context") + context = InjectionContext(settings=self.settings) context.settings.set_default("default_label", "Aries Cloud Agent") if context.settings.get("timing.enabled"): timing_log = context.settings.get("timing.log_file") + LOGGER.debug("Enabling timing collector with log file: %s", timing_log) collector = Collector(log_path=timing_log) context.injector.bind_instance(Collector, collector) @@ -81,11 +85,13 @@ async def build_context(self) -> InjectionContext: async def bind_providers(self, context: InjectionContext): """Bind various class providers.""" + LOGGER.debug("Begin binding providers to context") context.injector.bind_provider(ProfileManager, ProfileManagerProvider()) wallet_type = self.settings.get("wallet.type") if wallet_type == "askar-anoncreds": + LOGGER.debug("Using AnonCreds tails server") context.injector.bind_provider( BaseTailsServer, ClassProvider( @@ -93,6 +99,7 @@ async def bind_providers(self, context: InjectionContext): ), ) else: + LOGGER.debug("Using Indy tails server") context.injector.bind_provider( BaseTailsServer, ClassProvider( @@ -115,6 +122,7 @@ async def bind_providers(self, context: InjectionContext): async def load_plugins(self, context: InjectionContext): """Set up plugin registry and load plugins.""" + LOGGER.debug("Initializing plugin registry") plugin_registry = PluginRegistry( blocklist=self.settings.get("blocked_plugins", []) ) @@ -152,8 +160,10 @@ async def load_plugins(self, context: InjectionContext): "acapy_agent.revocation", ] - def register_askar_plugins(): - for plugin in askar_plugins: + def register_plugins(plugins: list[str], plugin_type: str): + """Register a group of plugins with logging.""" + LOGGER.debug("Registering %s plugins", plugin_type) + for plugin in plugins: plugin_registry.register_plugin(plugin) def register_askar_plugins(): @@ -165,6 +175,7 @@ def register_anoncreds_plugins(): register_plugins(default_plugins, "default") if context.settings.get("multitenant.admin_enabled"): + LOGGER.debug("Multitenant admin enabled - registering additional plugins") plugin_registry.register_plugin("acapy_agent.multitenant.admin") register_askar_plugins() register_anoncreds_plugins() @@ -176,6 +187,7 @@ def register_anoncreds_plugins(): # Register external plugins for plugin_path in self.settings.get("external_plugins", []): + LOGGER.debug("Registering external plugin: %s", plugin_path) plugin_registry.register_plugin(plugin_path) # Register message protocols diff --git a/acapy_agent/config/logging/configurator.py b/acapy_agent/config/logging/configurator.py index 5f7c67eee5..128ccf5e49 100644 --- a/acapy_agent/config/logging/configurator.py +++ b/acapy_agent/config/logging/configurator.py @@ -31,13 +31,6 @@ from .timed_rotating_file_multi_process_handler import ( TimedRotatingFileMultiProcessHandler, ) -from .utils import add_trace_level - - -LOGGER = logging.getLogger(__name__) - -# Add TRACE level to logging before any configuration -add_trace_level() LOGGER = logging.getLogger(__name__) diff --git a/acapy_agent/config/logging/utils.py b/acapy_agent/config/logging/utils.py deleted file mode 100644 index 10092d261a..0000000000 --- a/acapy_agent/config/logging/utils.py +++ /dev/null @@ -1,102 +0,0 @@ -"""Logging utilities.""" - -import logging -from functools import partial, partialmethod -from typing import Optional - -LOGGER = logging.getLogger(__name__) -_TRACE_LEVEL_ADDED = False - - -def add_logging_level( - level_name: str, level_num: int, method_name: Optional[str] = None -) -> None: - """Add a custom logging level to the `logging` module. - - Comprehensively adds a new logging level to the `logging` module and the - currently configured logging class. - - `level_name` becomes an attribute of the `logging` module with the value - `level_num`. - `methodName` becomes a convenience method for both `logging` itself - and the class returned by `logging.getLoggerClass()` (usually just - `logging.Logger`). - If `methodName` is not specified, `levelName.lower()` is used. - - To avoid accidental clobberings of existing attributes, this method will - raise an `AttributeError` if the level name is already an attribute of the - `logging` module or if the method name is already present - - Example: - ------- - >>> add_logging_level('TRACE', logging.DEBUG - 5) - >>> logging.getLogger(__name__).setLevel('TRACE') - >>> logging.getLogger(__name__).trace('that worked') - >>> logging.trace('so did this') - >>> logging.TRACE - 5 - - References: - - https://stackoverflow.com/a/35804945 - """ - if not method_name: - method_name = level_name.lower() - - if hasattr(logging, level_name): - raise AttributeError(f"{level_name} already defined in logging module") - if hasattr(logging, method_name): - raise AttributeError(f"{method_name} already defined in logging module") - if hasattr(logging.getLoggerClass(), method_name): - raise AttributeError(f"{method_name} already defined in logger class") - - # Add the new logging level - logging.addLevelName(level_num, level_name) - setattr(logging, level_name, level_num) - setattr( - logging.getLoggerClass(), - method_name, - partialmethod(logging.getLoggerClass().log, level_num), - ) - setattr(logging, method_name, partial(logging.log, level_num)) - - -def add_trace_level() -> None: - """Add the TRACE level to the logging module safely. - - This function adds a TRACE level to the logging module if it hasn't been added yet. - It handles the case where TRACE is already defined, avoiding duplicate additions. - - Returns: - None - """ - global _TRACE_LEVEL_ADDED - - if _TRACE_LEVEL_ADDED: - return - - TRACE_LEVEL_NUM = logging.DEBUG - 5 - TRACE_LEVEL_NAME = "TRACE" - TRACE_METHOD_NAME = "trace" - - # Check if TRACE level is already defined - level_exists = ( - hasattr(logging, TRACE_LEVEL_NAME) - and getattr(logging, TRACE_LEVEL_NAME) == TRACE_LEVEL_NUM - ) - - method_exists = hasattr(logging, TRACE_METHOD_NAME) and callable( - getattr(logging, TRACE_METHOD_NAME) - ) - - if not level_exists or not method_exists: - try: - add_logging_level(TRACE_LEVEL_NAME, TRACE_LEVEL_NUM, TRACE_METHOD_NAME) - LOGGER.debug("%s level added to logging module.", TRACE_LEVEL_NAME) - except AttributeError as e: - LOGGER.warning("%s level already exists: %s", TRACE_LEVEL_NAME, e) - else: - LOGGER.debug( - "%s level is already present in the logging module.", TRACE_LEVEL_NAME - ) - - _TRACE_LEVEL_ADDED = True diff --git a/acapy_agent/core/conductor.py b/acapy_agent/core/conductor.py index 346dea1c9b..08d89c37e2 100644 --- a/acapy_agent/core/conductor.py +++ b/acapy_agent/core/conductor.py @@ -27,7 +27,6 @@ load_multiple_genesis_transactions_from_config, ) from ..config.logging import LoggingConfigurator -from ..config.logging.utils import add_trace_level from ..config.provider import ClassProvider from ..config.wallet import wallet_config from ..core.profile import Profile @@ -83,8 +82,6 @@ from .util import SHUTDOWN_EVENT_TOPIC, STARTUP_EVENT_TOPIC LOGGER = logging.getLogger(__name__) -add_trace_level() # Allow trace logs from this module - # Refer ACA-Py issue #2197 # When the from version is not found DEFAULT_ACAPY_VERSION = "v0.7.5" @@ -364,6 +361,7 @@ async def start(self) -> None: # Get agent label default_label = context.settings.get("default_label") + public_did = self.setup_public_did and self.setup_public_did.did LOGGER.debug("Agent label: %s", default_label) if context.settings.get("log.banner", True): @@ -531,7 +529,6 @@ async def start(self) -> None: qr.add_data(invite_url) qr.print_ascii(invert=True) del mgr - LOGGER.trace("Invitation created and QR code printed.") except Exception: LOGGER.exception("Error creating invitation.") @@ -558,9 +555,6 @@ async def start(self) -> None: qr.add_data(invite_url) qr.print_ascii(invert=True) del mgr - LOGGER.trace( - "Connections protocol invitation created and QR code printed." - ) except Exception: LOGGER.exception("Error creating connections protocol invitation.") diff --git a/acapy_agent/core/plugin_registry.py b/acapy_agent/core/plugin_registry.py index 59cebdd0bd..4b6b31d99e 100644 --- a/acapy_agent/core/plugin_registry.py +++ b/acapy_agent/core/plugin_registry.py @@ -6,7 +6,6 @@ from typing import Optional, Sequence, Set from ..config.injection_context import InjectionContext -from ..config.logging.utils import add_trace_level from ..core.event_bus import EventBus from ..utils.classloader import ClassLoader, ModuleLoadError from .error import ProtocolDefinitionValidationError @@ -14,7 +13,6 @@ from .protocol_registry import ProtocolRegistry LOGGER = logging.getLogger(__name__) -add_trace_level() # Allow trace logs from this module class PluginRegistry: diff --git a/acapy_agent/utils/classloader.py b/acapy_agent/utils/classloader.py index 31f0b1a39a..0ae5ae18e8 100644 --- a/acapy_agent/utils/classloader.py +++ b/acapy_agent/utils/classloader.py @@ -9,7 +9,6 @@ from types import ModuleType from typing import Optional, Sequence, Type -from ..config.logging.utils import add_trace_level from ..core.error import BaseError LOGGER = logging.getLogger(__name__)