Skip to content

Commit

Permalink
🎨 Reduce log verbosity
Browse files Browse the repository at this point in the history 
Signed-off-by: ff137 <[email protected]>
  • Loading branch information
@ff137
ff137 committed Nov 28, 2024
1 parent e7ba26f commit 7ee124b
Show file tree
Hide file tree
Showing 2 changed files with 6 additions and 57 deletions.
46 changes: 5 additions & 41 deletions acapy_agent/core/plugin_registry.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -133,7 +133,7 @@ def register_plugin(self, module_name: str) -> Optional[ModuleType]:
LOGGER.debug("Registered plugin: %s", module_name)
return mod

LOGGER.debug("Failed to register plugin: %s", module_name)
LOGGER.warning("Failed to register plugin: %s", module_name)
return None

def _is_already_registered(self, module_name: str) -> bool:
Expand Down Expand Up @@ -163,7 +163,6 @@ def _is_valid_plugin(self, mod: ModuleType, module_name: str) -> bool:
"""Validate the plugin based on various criteria."""
# Check if the plugin has a 'setup' method
if hasattr(mod, "setup"):
LOGGER.debug("Plugin %s has a 'setup' method.", module_name)
return True

# Check for 'routes' or 'message_types' modules
Expand All @@ -172,7 +171,6 @@ def _is_valid_plugin(self, mod: ModuleType, module_name: str) -> bool:
routes = ClassLoader.load_module("routes", module_name)
message_types = ClassLoader.load_module("message_types", module_name)
if routes or message_types:
LOGGER.debug("Plugin %s has 'routes' or 'message_types'.", module_name)
return True

# Check for 'definition' module with 'versions' attribute
Expand All @@ -194,7 +192,6 @@ def _is_valid_plugin(self, mod: ModuleType, module_name: str) -> bool:
# Validate the 'versions' attribute
try:
self.validate_version(definition.versions, module_name)
LOGGER.debug("Plugin %s has valid versions.", module_name)
return True
except ProtocolDefinitionValidationError as e:
LOGGER.error(
Expand All @@ -217,14 +214,15 @@ def register_package(self, package_name: str) -> Sequence[ModuleType]:
for module_name in module_names:
# Skip any module whose last segment is 'tests'
if module_name.split(".")[-1] == "tests":
LOGGER.debug("Skipping test module: %s", module_name)
continue

plugin = self.register_plugin(module_name)
if plugin:
registered_plugins.append(plugin)
else:
LOGGER.debug("Failed to register %s under %s", module_name, package_name)
LOGGER.warning(
"Failed to register %s under %s", module_name, package_name
)

return registered_plugins

Expand All @@ -233,14 +231,9 @@ async def init_context(self, context: InjectionContext) -> None:
LOGGER.debug("Initializing plugin context for %d plugins", len(self._plugins))

for plugin in self._plugins.values():
plugin_name = plugin.__name__
if hasattr(plugin, "setup"):
LOGGER.debug("Running setup for plugin: %s", plugin_name)
await plugin.setup(context)
else:
LOGGER.debug(
"Loading protocols for plugin without setup: %s", plugin_name
)
await self.load_protocols(context, plugin)

# register event handlers for each protocol, if provided
Expand All @@ -256,56 +249,45 @@ async def load_protocol_version(
protocol_registry = context.inject(ProtocolRegistry)
goal_code_registry = context.inject(GoalCodeRegistry)

module_name = mod.__name__
LOGGER.debug("Loading protocol version for module: %s", module_name)

if hasattr(mod, "MESSAGE_TYPES"):
LOGGER.debug("Registering message types for: %s", module_name)
protocol_registry.register_message_types(
mod.MESSAGE_TYPES, version_definition=version_definition
)

if hasattr(mod, "CONTROLLERS"):
LOGGER.debug("Registering controllers for: %s", module_name)
protocol_registry.register_controllers(mod.CONTROLLERS)
goal_code_registry.register_controllers(mod.CONTROLLERS)

async def load_protocols(self, context: InjectionContext, plugin: ModuleType) -> None:
"""For modules that don't implement setup, register protocols manually."""
plugin_name = plugin.__name__
LOGGER.debug("Loading protocols for plugin: %s", plugin_name)

# If this module contains message_types, then assume that
# this is a valid module of the old style (not versioned)
try:
message_types_path = f"{plugin_name}.message_types"
LOGGER.debug("Attempting to load message types from: %s", message_types_path)
mod = ClassLoader.load_module(message_types_path)
except ModuleLoadError as e:
LOGGER.error("Error loading plugin module message types: %s", e)
return

if mod:
LOGGER.debug("Found non-versioned message types for: %s", plugin_name)
await self.load_protocol_version(context, mod)
else:
# Otherwise, try check for definition.py for versioned protocol packages
try:
definition_path = f"{plugin_name}.definition"
LOGGER.debug("Attempting to load definition from: %s", definition_path)
definition = ClassLoader.load_module(definition_path)
except ModuleLoadError as e:
LOGGER.error("Error loading plugin definition module: %s", e)
return

if definition:
LOGGER.debug("Loading versioned protocols for: %s", plugin_name)
for protocol_version in definition.versions:
version_path = (
f"{plugin_name}.{protocol_version['path']}.message_types"
)
try:
LOGGER.debug("Loading message types from: %s", version_path)
mod = ClassLoader.load_module(version_path)
except ModuleLoadError as e:
LOGGER.error(
Expand All @@ -318,24 +300,21 @@ async def load_protocols(self, context: InjectionContext, plugin: ModuleType) ->
if mod:
await self.load_protocol_version(context, mod, protocol_version)
else:
LOGGER.debug("Failed to load %s", version_path)
LOGGER.warning("Failed to load %s", version_path)

async def register_admin_routes(self, app) -> None:
"""Call route registration methods on the current context."""
LOGGER.debug("Registering admin routes for %d plugins", len(self._plugins))

for plugin in self._plugins.values():
plugin_name = plugin.__name__
LOGGER.debug("Processing routes for plugin: %s", plugin_name)
mod = None
definition = ClassLoader.load_module("definition", plugin_name)
if definition:
# Load plugin routes that are in a versioned package.
LOGGER.debug("Loading versioned routes for: %s", plugin_name)
for plugin_version in definition.versions:
version_path = f"{plugin_name}.{plugin_version['path']}.routes"
try:
LOGGER.debug("Loading routes from: %s", version_path)
mod = ClassLoader.load_module(version_path)
except ModuleLoadError as e:
LOGGER.error(
Expand All @@ -344,20 +323,17 @@ async def register_admin_routes(self, app) -> None:
continue

if mod and hasattr(mod, "register"):
LOGGER.debug("Registering routes for: %s", plugin_name)
await mod.register(app)
else:
# Load plugin routes that aren't in a versioned package.
routes_path = f"{plugin_name}.routes"
try:
LOGGER.debug("Loading non-versioned routes from: %s", routes_path)
mod = ClassLoader.load_module(routes_path)
except ModuleLoadError as e:
LOGGER.error("Error loading admin routes from %s: %s", routes_path, e)
continue

if mod and hasattr(mod, "register"):
LOGGER.debug("Registering routes for: %s", plugin_name)
await mod.register(app)

def register_protocol_events(self, context: InjectionContext) -> None:
Expand All @@ -371,36 +347,30 @@ def register_protocol_events(self, context: InjectionContext) -> None:

for plugin in self._plugins.values():
plugin_name = plugin.__name__
LOGGER.debug("Processing events for plugin: %s", plugin_name)
mod = None
definition = ClassLoader.load_module("definition", plugin_name)
if definition:
# Load plugin routes that are in a versioned package.
LOGGER.debug("Loading versioned events for: %s", plugin_name)
for plugin_version in definition.versions:
version_path = f"{plugin_name}.{plugin_version['path']}.routes"
try:
LOGGER.debug("Loading events from: %s", version_path)
mod = ClassLoader.load_module(version_path)
except ModuleLoadError as e:
LOGGER.error("Error loading events from %s: %s", version_path, e)
continue

if mod and hasattr(mod, "register_events"):
LOGGER.debug("Registering events from: %s", version_path)
mod.register_events(event_bus)
else:
# Load plugin routes that aren't in a versioned package.
routes_path = f"{plugin_name}.routes"
try:
LOGGER.debug("Loading non-versioned events from: %s", routes_path)
mod = ClassLoader.load_module(routes_path)
except ModuleLoadError as e:
LOGGER.error("Error loading events from %s: %s", routes_path, e)
continue

if mod and hasattr(mod, "register_events"):
LOGGER.debug("Registering events from: %s", version_path)
mod.register_events(event_bus)

def post_process_routes(self, app) -> None:
Expand All @@ -409,36 +379,30 @@ def post_process_routes(self, app) -> None:

for plugin in self._plugins.values():
plugin_name = plugin.__name__
LOGGER.debug("Post-processing routes for plugin: %s", plugin_name)
mod = None
definition = ClassLoader.load_module("definition", plugin_name)
if definition:
# Set binary file responses for routes that are in a versioned package.
LOGGER.debug("Processing versioned routes for: %s", plugin_name)
for plugin_version in definition.versions:
version_path = f"{plugin_name}.{plugin_version['path']}.routes"
try:
LOGGER.debug("Loading routes from: %s", version_path)
mod = ClassLoader.load_module(version_path)
except ModuleLoadError as e:
LOGGER.error("Error loading routes from %s: %s", version_path, e)
continue

if mod and hasattr(mod, "post_process_routes"):
LOGGER.debug("Post-processing routes for %s", plugin_name)
mod.post_process_routes(app)
else:
# Set binary file responses for routes not in a versioned package.
routes_path = f"{plugin_name}.routes"
try:
LOGGER.debug("Loading non-versioned routes from: %s", routes_path)
mod = ClassLoader.load_module(routes_path)
except ModuleLoadError as e:
LOGGER.error("Error loading routes from %s: %s", routes_path, e)
continue

if mod and hasattr(mod, "post_process_routes"):
LOGGER.debug("Post-processing routes for %s", plugin_name)
mod.post_process_routes(app)

def __repr__(self) -> str:
Expand Down
17 changes: 1 addition & 16 deletions acapy_agent/utils/classloader.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -48,15 +48,8 @@ def load_module(
# Check the cache
cache_key = (mod_path, package)
if cache_key in cls._module_cache:
LOGGER.debug("Module found in cache: %s", cache_key)
return cls._module_cache[cache_key]

LOGGER.debug(
"Loading module: %s%s",
mod_path,
f" with package: {package}" if package else "",
)

if package:
# preload parent package
if not cls.load_module(package):
Expand Down Expand Up @@ -87,7 +80,6 @@ def load_module(
return None

try:
LOGGER.debug("Importing package: %s, module: %s", package, mod_path)
module = import_module(mod_path, package)
cls._module_cache[cache_key] = module # Cache the loaded module
return module
Expand Down Expand Up @@ -124,13 +116,6 @@ def load_class(
LOGGER.debug("Class found in cache: %s", class_name)
return cls._class_cache[cache_key]

LOGGER.debug(
"Loading class: %s%s%s",
class_name,
f", with default_module: {default_module}" if default_module else "",
f", with package: {package}" if package else "",
)

if "." in class_name:
# import module and find class
mod_path, class_name = class_name.rsplit(".", 1)
Expand Down Expand Up @@ -244,7 +229,7 @@ def scan_subpackages(cls, package: str) -> Sequence[str]:
if (item / "__init__.py").exists():
subpackage = f"{package}.{joiner}{item.name}"
found.append(subpackage)
LOGGER.debug("Total sub-packages found under %s: %s", package, found)
LOGGER.debug("%d sub-packages found under %s: %s", len(found), package, found)
return found


Expand Down

0 comments on commit 7ee124b

Please sign in to comment.