Improved debugging to help track down this bug.

This commit is contained in:
Storm Dragon 2025-06-05 04:02:28 -04:00
parent 314aa18a1b
commit 48d99e8813
4 changed files with 120 additions and 5 deletions

View File

@ -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

View File

@ -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):

View File

@ -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
@ -335,12 +336,19 @@ class PluginSystemManager:
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]
if missing_plugins:
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?

View File

@ -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