From 48d99e8813e3c3276b592d8938aa4d41c2ce546c Mon Sep 17 00:00:00 2001 From: Storm Dragon Date: Thu, 5 Jun 2025 04:02:28 -0400 Subject: [PATCH] Improved debugging to help track down this bug. --- src/cthulhu/cthulhu.py | 27 +++++++++++ src/cthulhu/keybindings.py | 39 +++++++++++++++- src/cthulhu/plugin_system_manager.py | 10 +++- src/cthulhu/plugins/DisplayVersion/plugin.py | 49 ++++++++++++++++++-- 4 files changed, 120 insertions(+), 5 deletions(-) diff --git a/src/cthulhu/cthulhu.py b/src/cthulhu/cthulhu.py index c963877..28025f9 100644 --- a/src/cthulhu/cthulhu.py +++ b/src/cthulhu/cthulhu.py @@ -49,27 +49,42 @@ class APIHelper: def registerGestureByString(self, function, name, gestureString, inputEventType='default', normalizer='cthulhu', learnModeEnabled=True, contextName=None): """Register a gesture by string.""" + import logging + logger = logging.getLogger(__name__) + + logger.info(f"=== APIHelper.registerGestureByString called ===") + logger.info(f"gestureString: {gestureString}") + logger.info(f"name: {name}") + logger.info(f"contextName: {contextName}") + if not gestureString.startswith("kb:"): + logger.warning(f"Gesture string doesn't start with 'kb:': {gestureString}") return None # Extract the key portion from the gesture string key = gestureString.split(":", 1)[1] + logger.info(f"Extracted key: {key}") # Handle Cthulhu modifier specially if "cthulhu+" in key.lower(): from . import keybindings key_parts = key.lower().split("+") + logger.info(f"Key parts: {key_parts}") # Start with the base Cthulhu modifier modifiers = keybindings.CTHULHU_MODIFIER_MASK # Extract the final key (without modifiers) final_key = key_parts[-1] + logger.info(f"Final key: {final_key}") # Check for additional modifiers and combine them properly if "shift" in key_parts: # Use the pre-defined combined mask rather than trying to OR them modifiers = keybindings.CTHULHU_SHIFT_MODIFIER_MASK + logger.info(f"Using CTHULHU_SHIFT_MODIFIER_MASK: {modifiers}") + else: + logger.info(f"Using CTHULHU_MODIFIER_MASK: {modifiers}") # Create a keybinding handler class GestureHandler: @@ -79,6 +94,7 @@ class APIHelper: def __call__(self, script, inputEvent): try: + logger.info(f"=== DisplayVersion keybinding handler called! ===") return function(script, inputEvent) except Exception as e: import logging @@ -86,6 +102,7 @@ class APIHelper: return True handler = GestureHandler(function, name) + logger.info(f"Created handler: {handler}") # Create the binding object regardless of whether there's an active script # This allows plugins to define bindings that will work when a script becomes active @@ -97,25 +114,35 @@ class APIHelper: modifiers, handler) + logger.info(f"Created binding: keysym={binding.keysymstring}, modifiers={binding.modifiers}, mask={binding.modifier_mask}") + # Store binding for later reference if contextName not in self._gestureBindings: self._gestureBindings[contextName] = [] self._gestureBindings[contextName].append(binding) + logger.info(f"Stored binding in context '{contextName}'") # Only add to active script if one exists if cthulhu_state.activeScript: + logger.info(f"Adding binding to active script: {cthulhu_state.activeScript}") bindings = cthulhu_state.activeScript.getKeyBindings() bindings.add(binding) # Register key grab at the system level grab_ids = self.app.addKeyGrab(binding) + logger.info(f"Key grab IDs: {grab_ids}") # For later removal if grab_ids: binding._grab_ids = grab_ids + else: + logger.warning("No active script available - binding stored for later registration") debug.printMessage(debug.LEVEL_INFO, f"Created binding: {binding.keysymstring} with modifiers {binding.modifiers}", True) + logger.info("=== APIHelper.registerGestureByString completed ===") return binding + else: + logger.warning(f"Key doesn't contain 'cthulhu+': {key}") return None diff --git a/src/cthulhu/keybindings.py b/src/cthulhu/keybindings.py index b8fae42..3819439 100644 --- a/src/cthulhu/keybindings.py +++ b/src/cthulhu/keybindings.py @@ -472,13 +472,37 @@ class KeyBindings: import logging logger = logging.getLogger(__name__) - logger.info(f"Looking for handler for key: {keyboardEvent.hw_code} with modifiers {keyboardEvent.modifiers}") + + # Check if this might be the DisplayVersion key combination + event_str = keyboardEvent.event_string if hasattr(keyboardEvent, 'event_string') else 'unknown' + if event_str.lower() == 'v': + logger.info(f"=== KeyBindings.getInputHandler: Looking for handler ===") + logger.info(f"Event string: {event_str}") + logger.info(f"Hardware code: {keyboardEvent.hw_code}") + logger.info(f"Modifiers: {keyboardEvent.modifiers}") + logger.info(f"Total keybindings to check: {len(self.keyBindings)}") + + with open('/tmp/keybinding_lookup.log', 'a') as f: + f.write(f"=== Looking for 'v' key handler ===\n") + f.write(f"Event string: {event_str}\n") + f.write(f"Hardware code: {keyboardEvent.hw_code}\n") + f.write(f"Modifiers: {keyboardEvent.modifiers}\n") + f.write(f"Total keybindings: {len(self.keyBindings)}\n") + + # Log all keybindings for comparison + for i, kb in enumerate(self.keyBindings): + if 'v' in kb.keysymstring.lower() or 'version' in kb.handler.description.lower(): + logger.info(f"Binding {i}: keysym={kb.keysymstring}, modifiers={kb.modifiers}, mask={kb.modifier_mask}, desc={kb.handler.description}") + with open('/tmp/keybinding_lookup.log', 'a') as f: + f.write(f"Found V-related binding {i}: keysym={kb.keysymstring}, modifiers={kb.modifiers}, mask={kb.modifier_mask}, desc={kb.handler.description}\n") matches = [] candidates = [] clickCount = keyboardEvent.getClickCount() for keyBinding in self.keyBindings: if keyBinding.matches(keyboardEvent.hw_code, keyboardEvent.modifiers): + if event_str.lower() == 'v': + logger.info(f"MATCH found! keysym={keyBinding.keysymstring}, desc={keyBinding.handler.description}") if keyBinding.modifier_mask == keyboardEvent.modifiers and \ keyBinding.click_count == clickCount: matches.append(keyBinding) @@ -488,8 +512,17 @@ class KeyBindings: if keyBinding.keysymstring: candidates.append(keyBinding) + if event_str.lower() == 'v': + logger.info(f"Exact matches: {len(matches)}") + logger.info(f"Candidates: {len(candidates)}") + with open('/tmp/keybinding_lookup.log', 'a') as f: + f.write(f"Exact matches: {len(matches)}\n") + f.write(f"Candidates: {len(candidates)}\n") + self._checkMatchingBindings(keyboardEvent, matches) if matches: + if event_str.lower() == 'v': + logger.info(f"Returning exact match handler: {matches[0].handler.description}") return matches[0].handler if keyboardEvent.isKeyPadKeyWithNumlockOn(): @@ -503,8 +536,12 @@ class KeyBindings: self._checkMatchingBindings(keyboardEvent, candidates) for candidate in candidates: if candidate.click_count <= clickCount: + if event_str.lower() == 'v': + logger.info(f"Returning candidate handler: {candidate.handler.description}") return candidate.handler + if event_str.lower() == 'v': + logger.info("No handler found!") return None def load(self, keymap, handlers): diff --git a/src/cthulhu/plugin_system_manager.py b/src/cthulhu/plugin_system_manager.py index 04407fd..7f3f2d1 100644 --- a/src/cthulhu/plugin_system_manager.py +++ b/src/cthulhu/plugin_system_manager.py @@ -321,6 +321,7 @@ class PluginSystemManager: def setActivePlugins(self, activePlugins): """Set active plugins and sync their state.""" + logger.info(f"=== PluginSystemManager.setActivePlugins called ===") logger.info(f"Setting active plugins: {activePlugins}") # Make sure we have scanned for plugins first @@ -334,6 +335,12 @@ class PluginSystemManager: 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}") + + # Check specifically for DisplayVersion + if 'DisplayVersion' in self._active_plugins: + logger.info("DisplayVersion is in active plugins list!") + else: + logger.warning("DisplayVersion is NOT in active plugins list!") # Find missing plugins missing_plugins = [p for p in self._active_plugins if p not in available_plugins] @@ -341,6 +348,7 @@ class PluginSystemManager: logger.warning(f"Active plugins not found: {missing_plugins}") self.syncAllPluginsActive() + logger.info("=== PluginSystemManager.setActivePlugins completed ===") def setPluginActive(self, pluginInfo, active): """Set the active state of a plugin.""" @@ -429,7 +437,7 @@ class PluginSystemManager: return False module_name = pluginInfo.get_module_name() - logger.info(f"Attempting to load plugin: {module_name}") + logger.info(f"=== PluginSystemManager.loadPlugin starting for: {module_name} ===") try: # Already loaded? diff --git a/src/cthulhu/plugins/DisplayVersion/plugin.py b/src/cthulhu/plugins/DisplayVersion/plugin.py index 75ab90a..e9aea2d 100644 --- a/src/cthulhu/plugins/DisplayVersion/plugin.py +++ b/src/cthulhu/plugins/DisplayVersion/plugin.py @@ -32,15 +32,58 @@ class DisplayVersion(Plugin): return try: - logger.info("Activating DisplayVersion plugin") + logger.info("=== DisplayVersion plugin activation starting ===") + logger.info(f"Plugin name: {self.name}") + logger.info(f"App reference: {self.app}") + + # Also write to a debug file + with open('/tmp/displayversion_debug.log', 'a') as f: + f.write("=== DisplayVersion plugin activation starting ===\n") + f.write(f"Plugin name: {self.name}\n") + f.write(f"App reference: {self.app}\n") + + # Check if we have access to the API helper + if not self.app: + logger.error("DisplayVersion: No app reference available!") + return + + api_helper = self.app.getAPIHelper() + if not api_helper: + logger.error("DisplayVersion: No API helper available!") + return + + logger.info(f"API helper: {api_helper}") # Register keyboard shortcut + gesture_string = 'kb:cthulhu+shift+v' + logger.info(f"DisplayVersion: Attempting to register gesture: {gesture_string}") + self._kb_binding = self.registerGestureByString( self.speakText, f'Cthulhu screen reader version {cthulhuVersion.version}-{cthulhuVersion.codeName}', - 'kb:cthulhu+shift+v' + gesture_string ) - logger.info(f"Registered keybinding: {self._kb_binding}") + + logger.info(f"DisplayVersion: Registered keybinding result: {self._kb_binding}") + if self._kb_binding: + logger.info(f"Binding keysymstring: {self._kb_binding.keysymstring}") + logger.info(f"Binding modifiers: {self._kb_binding.modifiers}") + logger.info(f"Binding modifier_mask: {self._kb_binding.modifier_mask}") + logger.info(f"Binding handler: {self._kb_binding.handler}") + + with open('/tmp/displayversion_debug.log', 'a') as f: + f.write(f"SUCCESS: Keybinding created!\n") + f.write(f" keysymstring: {self._kb_binding.keysymstring}\n") + f.write(f" modifiers: {self._kb_binding.modifiers}\n") + f.write(f" modifier_mask: {self._kb_binding.modifier_mask}\n") + else: + logger.error("DisplayVersion: Failed to create keybinding!") + with open('/tmp/displayversion_debug.log', 'a') as f: + f.write("ERROR: Failed to create keybinding!\n") + + logger.info("=== DisplayVersion plugin activation completed ===") + with open('/tmp/displayversion_debug.log', 'a') as f: + f.write("=== DisplayVersion plugin activation completed ===\n\n") except Exception as e: logger.error(f"Error activating DisplayVersion plugin: {e}") import traceback