diff --git a/src/cthulhu/cthulhu.py b/src/cthulhu/cthulhu.py index 6e85089..fcf628b 100644 --- a/src/cthulhu/cthulhu.py +++ b/src/cthulhu/cthulhu.py @@ -1018,6 +1018,8 @@ class Cthulhu(GObject.Object): self.APIHelper = APIHelper(self) self.createCompatAPI() self.pluginSystemManager = plugin_system_manager.PluginSystemManager(self) + # Scan for available plugins at startup + self.pluginSystemManager.rescanPlugins() def getAPIHelper(self): return self.APIHelper def getPluginSystemManager(self): diff --git a/src/cthulhu/plugin.py b/src/cthulhu/plugin.py index 100e8f0..88a3080 100644 --- a/src/cthulhu/plugin.py +++ b/src/cthulhu/plugin.py @@ -16,6 +16,7 @@ try: import pluggy cthulhu_hookimpl = pluggy.HookimplMarker("cthulhu") PLUGGY_AVAILABLE = True + logging.getLogger(__name__).info("Successfully imported pluggy") except ImportError: # Fallback if pluggy is not available def cthulhu_hookimpl(func=None, **kwargs): @@ -29,7 +30,9 @@ except ImportError: return lambda f: f return func PLUGGY_AVAILABLE = False - logging.getLogger(__name__).info("Pluggy not available, plugins will be disabled") + logging.getLogger(__name__).warning("Pluggy not available, plugins will be disabled") + import traceback + logging.getLogger(__name__).debug(traceback.format_exc()) logger = logging.getLogger(__name__) diff --git a/src/cthulhu/plugin_system_manager.py b/src/cthulhu/plugin_system_manager.py index 8a7f13b..edb35ac 100644 --- a/src/cthulhu/plugin_system_manager.py +++ b/src/cthulhu/plugin_system_manager.py @@ -22,7 +22,12 @@ except ImportError: PLUGGY_AVAILABLE = False logging.getLogger(__name__).info("Pluggy not available, plugins will be disabled") +# Set to True for more detailed plugin loading debug info +PLUGIN_DEBUG = True + logger = logging.getLogger(__name__) +if PLUGIN_DEBUG: + logger.setLevel(logging.DEBUG) class PluginType(IntEnum): """Types of plugins we support.""" @@ -74,9 +79,11 @@ class PluginSystemManager: def __init__(self, app): self.app = app + logger.info("Initializing PluginSystemManager") # Initialize plugin manager if PLUGGY_AVAILABLE: + logger.info("Pluggy is available, setting up plugin manager") self.plugin_manager = pluggy.PluginManager("cthulhu") # Define hook specifications @@ -93,8 +100,10 @@ class PluginSystemManager: """Called when the plugin is deactivated.""" pass + logger.info("Adding hook specifications to plugin manager") self.plugin_manager.add_hookspecs(CthulhuHookSpecs) else: + logger.warning("Pluggy is not available, plugins will be disabled") self.plugin_manager = None # Plugin storage @@ -103,6 +112,10 @@ class PluginSystemManager: # Create plugin directories self._setup_plugin_dirs() + + # Log available plugins directory paths + logger.info(f"System plugins directory: {PluginType.SYSTEM.get_root_dir()}") + logger.info(f"User plugins directory: {PluginType.USER.get_root_dir()}") def _setup_plugin_dirs(self): """Ensure plugin directories exist.""" @@ -190,7 +203,25 @@ class PluginSystemManager: def setActivePlugins(self, activePlugins): """Set active plugins and sync their state.""" + logger.info(f"Setting active plugins: {activePlugins}") + + # Make sure we have scanned for plugins first + if not self._plugins: + logger.info("No plugins found, rescanning...") + self.rescanPlugins() + self._active_plugins = activePlugins + + # Log active vs available plugins + available_plugins = [p.get_module_name() for p in self.plugins] + logger.info(f"Available plugins: {available_plugins}") + logger.info(f"Active plugins: {self._active_plugins}") + + # Find missing plugins + missing_plugins = [p for p in self._active_plugins if p not in available_plugins] + if missing_plugins: + logger.warning(f"Active plugins not found: {missing_plugins}") + self.syncAllPluginsActive() def setPluginActive(self, pluginInfo, active): @@ -211,25 +242,52 @@ class PluginSystemManager: def isPluginActive(self, pluginInfo): """Check if a plugin is active.""" + module_name = pluginInfo.get_module_name() + + # Builtin plugins are always active if pluginInfo.builtin: + logger.debug(f"Plugin {module_name} is builtin, active by default") return True + # If a plugin is already loaded, it's active if pluginInfo.loaded: + logger.debug(f"Plugin {module_name} is already loaded, considered active") return True - return pluginInfo.get_module_name() in self.getActivePlugins() + # Check if plugin is in the active plugins list + is_active = module_name in self.getActivePlugins() + logger.debug(f"Plugin {module_name} active status: {is_active}") + return is_active def syncAllPluginsActive(self): """Sync the active state of all plugins.""" + logger.info("Syncing active state of all plugins") + + # Log plugin status before syncing + if PLUGIN_DEBUG: + for pluginInfo in self.plugins: + is_active = self.isPluginActive(pluginInfo) + is_loaded = pluginInfo.loaded + logger.debug(f"Plugin {pluginInfo.get_module_name()}: active={is_active}, loaded={is_loaded}") + # First unload inactive plugins for pluginInfo in self.plugins: if not self.isPluginActive(pluginInfo) and pluginInfo.loaded: + logger.info(f"Unloading inactive plugin: {pluginInfo.get_module_name()}") self.unloadPlugin(pluginInfo) # Then load active plugins for pluginInfo in self.plugins: if self.isPluginActive(pluginInfo) and not pluginInfo.loaded: - self.loadPlugin(pluginInfo) + logger.info(f"Loading active plugin: {pluginInfo.get_module_name()}") + result = self.loadPlugin(pluginInfo) + logger.info(f"Plugin {pluginInfo.get_module_name()} load result: {result}") + + # Log final plugin status + active_plugins = [p.get_module_name() for p in self.plugins if p.loaded] + logger.info(f"Active plugins after sync: {active_plugins}") + inactive_plugins = [p.get_module_name() for p in self.plugins if not p.loaded] + logger.info(f"Inactive plugins after sync: {inactive_plugins}") def loadPlugin(self, pluginInfo): """Load a plugin.""" @@ -239,15 +297,26 @@ class PluginSystemManager: return False module_name = pluginInfo.get_module_name() + logger.info(f"Attempting to load plugin: {module_name}") try: # Already loaded? if pluginInfo.loaded: + logger.info(f"Plugin {module_name} already loaded, skipping") return True # Import plugin module plugin_file = os.path.join(pluginInfo.get_module_dir(), "plugin.py") + if not os.path.exists(plugin_file): + logger.error(f"Plugin file not found: {plugin_file}") + return False + + logger.info(f"Loading plugin from: {plugin_file}") spec = importlib.util.spec_from_file_location(module_name, plugin_file) + if spec is None: + logger.error(f"Failed to create spec for plugin: {module_name}") + return False + module = importlib.util.module_from_spec(spec) spec.loader.exec_module(module) pluginInfo.module = module @@ -260,6 +329,7 @@ class PluginSystemManager: attr.__module__ == module.__name__ and hasattr(attr, 'activate')): plugin_class = attr + logger.info(f"Found plugin class: {attr.__name__} in {module_name}") break if not plugin_class: @@ -267,32 +337,47 @@ class PluginSystemManager: return False # Create and initialize plugin instance + logger.info(f"Creating instance of plugin class: {plugin_class.__name__}") plugin_instance = plugin_class() pluginInfo.instance = plugin_instance # Ensure plugins have a reference to the app plugin_instance.app = self.getApp() + logger.info(f"Set app reference for plugin: {module_name}") if hasattr(plugin_instance, 'set_app'): plugin_instance.set_app(self.getApp()) + logger.info(f"Called set_app() for plugin: {module_name}") if hasattr(plugin_instance, 'set_plugin_info'): plugin_instance.set_plugin_info(pluginInfo) + logger.info(f"Called set_plugin_info() for plugin: {module_name}") # Register with pluggy and activate + if self.plugin_manager is None: + logger.error(f"Plugin manager is None when loading {module_name}") + return False + + logger.info(f"Registering plugin with pluggy: {module_name}") self.plugin_manager.register(plugin_instance) + try: + logger.info(f"Activating plugin: {module_name}") self.plugin_manager.hook.activate(plugin=plugin_instance) except Exception as e: logger.error(f"Error activating plugin {module_name}: {e}") + import traceback + logger.error(traceback.format_exc()) return False pluginInfo.loaded = True - logger.info(f"Loaded plugin: {module_name}") + logger.info(f"Successfully loaded plugin: {module_name}") return True except Exception as e: logger.error(f"Failed to load plugin {module_name}: {e}") + import traceback + logger.error(traceback.format_exc()) return False def unloadPlugin(self, pluginInfo):