Try to get around plugins causing the screen reader to hang in infinite loop.

This commit is contained in:
Storm Dragon 2025-04-04 02:15:26 -04:00
parent bb1ff5c579
commit cd76760d9f
3 changed files with 354 additions and 79 deletions

View File

@ -610,8 +610,39 @@ def loadUserSettings(script=None, inputEvent=None, skipReloadMessage=False):
_storeXmodmap(_cthulhuModifiers) _storeXmodmap(_cthulhuModifiers)
_createCthulhuXmodmap() _createCthulhuXmodmap()
activePlugins = list(_settingsManager.getSetting('activePlugins')) # Make plugin loading more robust by handling potential exceptions
cthulhuApp.getPluginSystemManager().setActivePlugins(activePlugins) try:
activePlugins = list(_settingsManager.getSetting('activePlugins'))
logger.info(f"CTHULHU: Loading active plugins: {activePlugins}")
# Setup a timeout for plugin activation to prevent hanging
import threading
import time
activation_completed = [False]
def activate_plugins_with_timeout():
try:
cthulhuApp.getPluginSystemManager().setActivePlugins(activePlugins)
activation_completed[0] = True
except Exception as e:
logger.error(f"CTHULHU: Error activating plugins: {e}")
import traceback
logger.error(traceback.format_exc())
plugin_thread = threading.Thread(target=activate_plugins_with_timeout)
plugin_thread.daemon = True # Make thread daemonic so it doesn't block program exit
plugin_thread.start()
# Give plugins up to 30 seconds to load, then continue regardless
plugin_thread.join(30)
if not activation_completed[0]:
logger.error("CTHULHU: Plugin activation timed out - continuing without all plugins")
except Exception as e:
logger.error(f"CTHULHU: Error setting up plugin activation: {e}")
import traceback
logger.error(traceback.format_exc())
_scriptManager.activate() _scriptManager.activate()
_eventManager.activate() _eventManager.activate()

View File

@ -23,5 +23,5 @@
# Fork of Orca Screen Reader (GNOME) # Fork of Orca Screen Reader (GNOME)
# Original source: https://gitlab.gnome.org/GNOME/orca # Original source: https://gitlab.gnome.org/GNOME/orca
version = "2025.04.03" version = "2025.04.04"
codeName = "plugins" codeName = "plugins"

View File

@ -232,49 +232,122 @@ class PluginSystemManager:
return self._active_plugins return self._active_plugins
def setActivePlugins(self, activePlugins): def setActivePlugins(self, activePlugins):
"""Set active plugins and sync their state.""" """Set active plugins and sync their state with robust error handling."""
logger.info(f"Setting active plugins: {activePlugins}") logger.info(f"Setting active plugins: {activePlugins}")
# Make sure we have scanned for plugins first # Set a timeout for the entire operation
operation_timeout = 60 # seconds
start_time = time.time()
# Make sure we have scanned for plugins first, with timeout
if not self._plugins: if not self._plugins:
logger.info("No plugins found, rescanning...") logger.info("No plugins found, rescanning...")
self.rescanPlugins() try:
# Use a separate thread with timeout for rescanning
rescan_success = [False]
def rescan_with_timeout():
try:
self.rescanPlugins()
rescan_success[0] = True
except Exception as e:
logger.error(f"Error in plugin rescan thread: {e}")
import traceback
logger.error(traceback.format_exc())
rescan_thread = threading.Thread(target=rescan_with_timeout)
rescan_thread.daemon = True
rescan_thread.start()
rescan_thread.join(10) # 10 second timeout for rescanning
if not rescan_success[0]:
logger.error("Plugin rescan timed out or failed, continuing with whatever plugins were found")
except Exception as e:
logger.error(f"Error setting up plugin rescan: {e}")
import traceback
logger.error(traceback.format_exc())
# Check if the operation has already timed out
if time.time() - start_time > operation_timeout:
logger.error("Plugin activation operation timed out during rescan, continuing with empty plugin list")
self._active_plugins = []
return
# Create a clean list of valid active plugins # Create a clean list of valid active plugins
available_plugins = [p.get_module_name() for p in self.plugins]
valid_active_plugins = []
for plugin_name in activePlugins:
# Check for exact match first
if plugin_name in available_plugins:
valid_active_plugins.append(plugin_name)
continue
# Try case-insensitive match
plugin_name_lower = plugin_name.lower()
matched = False
for available in available_plugins:
if available.lower() == plugin_name_lower:
# Use the correctly cased name from available plugins
valid_active_plugins.append(available)
matched = True
logger.info(f"Case-insensitive match: requested '{plugin_name}', using '{available}'")
break
if not matched:
logger.warning(f"Plugin '{plugin_name}' not found, skipping")
# Only use valid plugins
self._active_plugins = valid_active_plugins
logger.info(f"Using verified active plugins: {self._active_plugins}")
try: try:
self.syncAllPluginsActive() available_plugins = [p.get_module_name() for p in self.plugins]
valid_active_plugins = []
for plugin_name in activePlugins:
# Check for exact match first
if plugin_name in available_plugins:
valid_active_plugins.append(plugin_name)
continue
# Try case-insensitive match
plugin_name_lower = plugin_name.lower()
matched = False
for available in available_plugins:
if available.lower() == plugin_name_lower:
# Use the correctly cased name from available plugins
valid_active_plugins.append(available)
matched = True
logger.info(f"Case-insensitive match: requested '{plugin_name}', using '{available}'")
break
if not matched:
logger.warning(f"Plugin '{plugin_name}' not found, skipping")
# Only use valid plugins
self._active_plugins = valid_active_plugins
logger.info(f"Using verified active plugins: {self._active_plugins}")
except Exception as e: except Exception as e:
logger.error(f"Error syncing plugins: {e}") logger.error(f"Error validating active plugins: {e}")
import traceback import traceback
logger.error(traceback.format_exc()) logger.error(traceback.format_exc())
# Continue with an empty plugin list in case of error
self._active_plugins = []
# Check if the operation has already timed out
if time.time() - start_time > operation_timeout:
logger.error("Plugin activation operation timed out during validation, skipping sync")
return
# Now sync the plugins with timeout protection
try:
# Use a separate thread with timeout for syncing
sync_success = [False]
def sync_with_timeout():
try:
self.syncAllPluginsActive()
sync_success[0] = True
except Exception as e:
logger.error(f"Error in plugin sync thread: {e}")
import traceback
logger.error(traceback.format_exc())
# Make sure we don't exceed our overall operation timeout
remaining_time = operation_timeout - (time.time() - start_time)
if remaining_time <= 0:
logger.error("No time remaining for plugin sync, skipping")
return
sync_thread = threading.Thread(target=sync_with_timeout)
sync_thread.daemon = True
sync_thread.start()
sync_thread.join(min(30, remaining_time)) # Use either 30 seconds or remaining time, whichever is less
if not sync_success[0]:
logger.error("Plugin sync timed out or failed, some plugins may not be properly loaded")
except Exception as e:
logger.error(f"Error setting up plugin sync: {e}")
import traceback
logger.error(traceback.format_exc())
logger.info("Plugin activation operation completed")
return
def setPluginActive(self, pluginInfo, active): def setPluginActive(self, pluginInfo, active):
"""Set the active state of a plugin.""" """Set the active state of a plugin."""
@ -339,6 +412,10 @@ class PluginSystemManager:
logger.warning("No plugins found, skipping plugin sync") logger.warning("No plugins found, skipping plugin sync")
return return
# Set an overall timeout for the sync operation to prevent the screen reader from hanging
sync_timeout = 30 # seconds
sync_start_time = time.time()
# Log plugin status before syncing # Log plugin status before syncing
if PLUGIN_DEBUG: if PLUGIN_DEBUG:
for pluginInfo in self.plugins: for pluginInfo in self.plugins:
@ -353,14 +430,55 @@ class PluginSystemManager:
# First unload inactive plugins # First unload inactive plugins
for pluginInfo in to_unload: for pluginInfo in to_unload:
# Check if we've exceeded our total sync timeout
if time.time() - sync_start_time > sync_timeout:
logger.error("Plugin sync operation timed out, continuing with partially synced plugins")
break
logger.info(f"Unloading inactive plugin: {pluginInfo.get_module_name()}") logger.info(f"Unloading inactive plugin: {pluginInfo.get_module_name()}")
self.unloadPlugin(pluginInfo) try:
unload_result = self.unloadPlugin(pluginInfo)
logger.info(f"Plugin {pluginInfo.get_module_name()} unload result: {unload_result}")
except Exception as e:
logger.error(f"Error unloading plugin {pluginInfo.get_module_name()}: {e}")
import traceback
logger.error(traceback.format_exc())
# Continue with other plugins even if this one fails
# Then load active plugins # Then load active plugins
for pluginInfo in to_load: for pluginInfo in to_load:
# Check if we've exceeded our total sync timeout
if time.time() - sync_start_time > sync_timeout:
logger.error("Plugin sync operation timed out, continuing with partially synced plugins")
break
logger.info(f"Loading active plugin: {pluginInfo.get_module_name()}") 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}") # Use a separate thread with timeout to load each plugin
# This prevents any single plugin from hanging the sync operation
load_success = [False]
load_result = [False]
def load_plugin_with_timeout():
try:
result = self.loadPlugin(pluginInfo)
load_result[0] = result
load_success[0] = True
except Exception as e:
logger.error(f"Error in plugin loading thread for {pluginInfo.get_module_name()}: {e}")
import traceback
logger.error(traceback.format_exc())
# Each plugin gets up to 5 seconds to load
load_thread = threading.Thread(target=load_plugin_with_timeout)
load_thread.daemon = True
load_thread.start()
load_thread.join(5) # 5 second timeout per plugin
if load_success[0]:
logger.info(f"Plugin {pluginInfo.get_module_name()} load result: {load_result[0]}")
else:
logger.error(f"Plugin {pluginInfo.get_module_name()} load timed out or failed")
# Log final plugin status # Log final plugin status
active_plugins = [p.get_module_name() for p in self.plugins if p.loaded] active_plugins = [p.get_module_name() for p in self.plugins if p.loaded]
@ -372,6 +490,9 @@ class PluginSystemManager:
import traceback import traceback
logger.error(traceback.format_exc()) logger.error(traceback.format_exc())
logger.info("Plugin sync operation completed")
return
def loadPlugin(self, pluginInfo): def loadPlugin(self, pluginInfo):
"""Load a plugin.""" """Load a plugin."""
# Skip if pluggy is not available # Skip if pluggy is not available
@ -382,14 +503,18 @@ class PluginSystemManager:
module_name = pluginInfo.get_module_name() module_name = pluginInfo.get_module_name()
logger.debug(f"===== PLUGIN LOADING START: {module_name} =====") logger.debug(f"===== PLUGIN LOADING START: {module_name} =====")
# Setup timeout for plugin loading # Setup timeout for plugin loading with a proper handler that interrupts the process
load_timeout = 5 # seconds load_timeout = 5 # seconds
load_completed = False load_completed = False
load_timed_out = False
def timeout_handler(): def timeout_handler():
nonlocal load_completed nonlocal load_completed, load_timed_out
if not load_completed: if not load_completed:
load_timed_out = True
logger.error(f"Plugin loading timed out for {module_name}") logger.error(f"Plugin loading timed out for {module_name}")
# When we time out, we want to mark this as a failed plugin
# but still allow the screen reader to continue
timer = threading.Timer(load_timeout, timeout_handler) timer = threading.Timer(load_timeout, timeout_handler)
timer.start() timer.start()
@ -401,6 +526,10 @@ class PluginSystemManager:
load_completed = True load_completed = True
return True return True
# Check for timeout on every critical step
if load_timed_out:
return False
# Try to find the plugin file # Try to find the plugin file
module_name = pluginInfo.get_module_name() module_name = pluginInfo.get_module_name()
plugin_dir = pluginInfo.get_module_dir() plugin_dir = pluginInfo.get_module_dir()
@ -420,54 +549,132 @@ class PluginSystemManager:
load_completed = True load_completed = True
return False return False
# Check for timeout again
if load_timed_out:
return False
logger.info(f"Loading plugin from: {plugin_file}") logger.info(f"Loading plugin from: {plugin_file}")
spec = importlib.util.spec_from_file_location(module_name, plugin_file) try:
if spec is None: spec = importlib.util.spec_from_file_location(module_name, plugin_file)
logger.error(f"Failed to create spec for plugin: {module_name}") if spec is None:
logger.error(f"Failed to create spec for plugin: {module_name}")
load_completed = True
return False
module = importlib.util.module_from_spec(spec)
# Use a separate thread with timeout to execute the module
# This prevents hanging on problematic module imports
exec_success = [False]
def exec_module_with_timeout():
try:
spec.loader.exec_module(module)
exec_success[0] = True
except Exception as e:
logger.error(f"Error executing module {module_name}: {e}")
import traceback
logger.error(traceback.format_exc())
exec_thread = threading.Thread(target=exec_module_with_timeout)
exec_thread.daemon = True # Make thread daemonic so it doesn't block program exit
exec_thread.start()
exec_thread.join(3) # 3 second timeout for module execution
if not exec_success[0]:
logger.error(f"Module execution timed out or failed for {module_name}")
load_completed = True
return False
pluginInfo.module = module
except Exception as e:
logger.error(f"Failed to load module {module_name}: {e}")
import traceback
logger.error(traceback.format_exc())
load_completed = True load_completed = True
return False return False
module = importlib.util.module_from_spec(spec) # Check for timeout
spec.loader.exec_module(module) if load_timed_out:
pluginInfo.module = module return False
# Find Plugin class # Find Plugin class - limit the time we spend searching
start_time = time.time()
plugin_class = None plugin_class = None
for attr_name in dir(module): try:
attr = getattr(module, attr_name) for attr_name in dir(module):
if (inspect.isclass(attr) and # Prevent infinite loops or excessive time in dir() operation
attr.__module__ == module.__name__ and if time.time() - start_time > 2: # 2 second timeout
hasattr(attr, 'activate')): logger.error(f"Finding plugin class timed out for {module_name}")
plugin_class = attr break
logger.info(f"Found plugin class: {attr.__name__} in {module_name}")
break try:
attr = getattr(module, attr_name)
if (inspect.isclass(attr) and
attr.__module__ == module.__name__ and
hasattr(attr, 'activate')):
plugin_class = attr
logger.info(f"Found plugin class: {attr.__name__} in {module_name}")
break
except Exception as e:
logger.error(f"Error checking attribute {attr_name} in {module_name}: {e}")
continue
except Exception as e:
logger.error(f"Error finding plugin class in {module_name}: {e}")
if not plugin_class: if not plugin_class:
logger.error(f"No plugin class found in {module_name}") logger.error(f"No plugin class found in {module_name}")
load_completed = True load_completed = True
return False return False
# Create and initialize plugin instance # Check for timeout
logger.info(f"Creating instance of plugin class: {plugin_class.__name__}") if load_timed_out:
plugin_instance = plugin_class() return False
pluginInfo.instance = plugin_instance
# Create and initialize plugin instance with error handling
try:
logger.info(f"Creating instance of plugin class: {plugin_class.__name__}")
plugin_instance = plugin_class()
pluginInfo.instance = plugin_instance
except Exception as e:
logger.error(f"Failed to create instance of plugin class {plugin_class.__name__}: {e}")
import traceback
logger.error(traceback.format_exc())
load_completed = True
return False
# Check for timeout
if load_timed_out:
return False
# Ensure plugins have a reference to the app # Ensure plugins have a reference to the app
plugin_instance.app = self.getApp() try:
logger.info(f"Set app reference for plugin: {module_name}") plugin_instance.app = self.getApp()
logger.info(f"Set app reference for plugin: {module_name}")
if hasattr(plugin_instance, 'set_app'): if hasattr(plugin_instance, 'set_app'):
plugin_instance.set_app(self.getApp()) plugin_instance.set_app(self.getApp())
logger.info(f"Called set_app() for plugin: {module_name}") logger.info(f"Called set_app() for plugin: {module_name}")
if hasattr(plugin_instance, 'set_plugin_info'): if hasattr(plugin_instance, 'set_plugin_info'):
plugin_instance.set_plugin_info(pluginInfo) plugin_instance.set_plugin_info(pluginInfo)
logger.info(f"Called set_plugin_info() for plugin: {module_name}") logger.info(f"Called set_plugin_info() for plugin: {module_name}")
except Exception as e:
logger.error(f"Error setting up plugin instance for {module_name}: {e}")
import traceback
logger.error(traceback.format_exc())
# Check for timeout
if load_timed_out:
return False
# Log plugin methods for debugging # Log plugin methods for debugging
if PLUGIN_DEBUG: if PLUGIN_DEBUG:
logger.debug(f"Plugin instance methods: {[m for m in dir(plugin_instance) if not m.startswith('_')]}") try:
logger.debug(f"Checking for activate method: {'activate' in dir(plugin_instance)}") logger.debug(f"Plugin instance methods: {[m for m in dir(plugin_instance) if not m.startswith('_')]}")
logger.debug(f"Checking for activate method: {'activate' in dir(plugin_instance)}")
except Exception as e:
logger.error(f"Error logging plugin debug info for {module_name}: {e}")
# Register with pluggy and activate # Register with pluggy and activate
if self.plugin_manager is None: if self.plugin_manager is None:
@ -475,12 +682,49 @@ class PluginSystemManager:
load_completed = True load_completed = True
return False return False
logger.info(f"Registering plugin with pluggy: {module_name}") # Check for timeout
self.plugin_manager.register(plugin_instance) if load_timed_out:
return False
try: try:
logger.info(f"Registering plugin with pluggy: {module_name}")
self.plugin_manager.register(plugin_instance)
except Exception as e:
logger.error(f"Error registering plugin {module_name} with pluggy: {e}")
import traceback
logger.error(traceback.format_exc())
load_completed = True
return False
# Check for timeout
if load_timed_out:
return False
try:
# Use a separate thread with timeout to activate the plugin
activation_success = [False]
def activate_with_timeout():
try:
self.plugin_manager.hook.activate(plugin=plugin_instance)
activation_success[0] = True
except Exception as e:
logger.error(f"Error in plugin activation thread for {module_name}: {e}")
import traceback
logger.error(traceback.format_exc())
logger.info(f"Activating plugin: {module_name}") logger.info(f"Activating plugin: {module_name}")
self.plugin_manager.hook.activate(plugin=plugin_instance) activate_thread = threading.Thread(target=activate_with_timeout)
activate_thread.daemon = True
activate_thread.start()
activate_thread.join(3) # 3 second timeout for activation
if not activation_success[0]:
logger.error(f"Plugin activation timed out or failed for {module_name}")
# We still consider this partially successful - the plugin is loaded
# but not activated. Mark it as not loaded, but don't halt the program.
load_completed = True
return False
except Exception as e: except Exception as e:
logger.error(f"Error activating plugin {module_name}: {e}") logger.error(f"Error activating plugin {module_name}: {e}")
import traceback import traceback