From 73ddc181143b7d9d0f134330ec3f0cc9f98757bb Mon Sep 17 00:00:00 2001 From: Storm Dragon Date: Fri, 16 Jan 2026 11:41:49 -0500 Subject: [PATCH] Refactor complete. We should be in very good shape moving forward. --- AGENTS.md | 1 + src/cthulhu/debug.py | 25 ++++++-- src/cthulhu/event_manager.py | 12 ++-- src/cthulhu/focus_manager.py | 93 ++++++++++----------------- src/cthulhu/input_event.py | 28 ++++++--- src/cthulhu/script_manager.py | 80 ++++++++++-------------- src/cthulhu/scripts/web/script.py | 100 ++++++++++++++---------------- 7 files changed, 164 insertions(+), 175 deletions(-) diff --git a/AGENTS.md b/AGENTS.md index 08afdb0..79b236e 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -20,6 +20,7 @@ This repository is a screen reader. Prioritize accessibility, correctness, and s - variables: `camelCase` - functions/methods: `snake_case` - classes: `PascalCase` +- Keep changes clean and well-structured; avoid layering short-term workarounds when a focused fix is possible. - Add debug logs where helpful for troubleshooting. When adding timestamps to logs, use: `"Message [timestamp]"` (message first). ## Accessibility requirements (high priority) diff --git a/src/cthulhu/debug.py b/src/cthulhu/debug.py index 48f241e..f1195b5 100644 --- a/src/cthulhu/debug.py +++ b/src/cthulhu/debug.py @@ -255,14 +255,31 @@ def _asString(obj): return str(obj) +def _format_tokens(tokens): + text = " ".join(map(_asString, tokens)) + text = re.sub(r"[ \u00A0]+", " ", text) + text = re.sub(r" (?=[,.:)])(?![\n])", "", text) + return text + +def format_log_message(prefix, message, reason=None): + text = f"{prefix}: {message}" + if reason: + text = f"{text} (reason={reason})" + return text + +def print_log(level, prefix, message, reason=None, timestamp=False, stack=False): + text = format_log_message(prefix, message, reason) + printMessage(level, text, timestamp, stack) + +def print_log_tokens(level, prefix, tokens, reason=None, timestamp=False, stack=False): + text = format_log_message(prefix, _format_tokens(tokens), reason) + printMessage(level, text, timestamp, stack) + def printTokens(level, tokens, timestamp=False, stack=False): if level < debugLevel: return - text = " ".join(map(_asString, tokens)) - text = re.sub(r"[ \u00A0]+", " ", text) - text = re.sub(r" (?=[,.:)])(?![\n])", "", text) - println(level, text, timestamp, stack) + println(level, _format_tokens(tokens), timestamp, stack) def print_tokens(level, tokens, timestamp=False, stack=False): return printTokens(level, tokens, timestamp, stack) diff --git a/src/cthulhu/event_manager.py b/src/cthulhu/event_manager.py index 3afb875..416d30e 100644 --- a/src/cthulhu/event_manager.py +++ b/src/cthulhu/event_manager.py @@ -238,12 +238,12 @@ class EventManager: debug.printTokens(debug.LEVEL_INFO, tokens, True) def _log_ignore(reason, message): - msg = f"EVENT MANAGER: Ignoring ({reason}) - {message}" - debug.printMessage(debug.LEVEL_INFO, msg, True) + debug.print_log(debug.LEVEL_INFO, "EVENT MANAGER", + f"Ignoring - {message}", reason, True) def _log_allow(reason, message): - msg = f"EVENT MANAGER: Not ignoring ({reason}) - {message}" - debug.printMessage(debug.LEVEL_INFO, msg, True) + debug.print_log(debug.LEVEL_INFO, "EVENT MANAGER", + f"Not ignoring - {message}", reason, True) def _ignore_with_reason(reason, message): _log_ignore(reason, message) @@ -1103,8 +1103,8 @@ class EventManager: return setNewActiveScript, reason = self._isActivatableEvent(event, script) - msg = f'EVENT MANAGER: Change active script: {setNewActiveScript} ({reason})' - debug.printMessage(debug.LEVEL_INFO, msg, True) + debug.print_log(debug.LEVEL_INFO, "EVENT MANAGER", + f"Change active script: {setNewActiveScript}", reason, True) if setNewActiveScript: try: diff --git a/src/cthulhu/focus_manager.py b/src/cthulhu/focus_manager.py index ac49038..fbf3df0 100644 --- a/src/cthulhu/focus_manager.py +++ b/src/cthulhu/focus_manager.py @@ -59,6 +59,12 @@ def _get_ax_utilities(): from .ax_utilities import AXUtilities return AXUtilities +def _log(message, reason=None, timestamp=True, stack=False): + debug.print_log(debug.LEVEL_INFO, "FOCUS MANAGER", message, reason, timestamp, stack) + +def _log_tokens(tokens, reason=None, timestamp=True, stack=False): + debug.print_log_tokens(debug.LEVEL_INFO, "FOCUS MANAGER", tokens, reason, timestamp, stack) + if TYPE_CHECKING: from .input_event import InputEvent from .scripts import default @@ -84,18 +90,14 @@ class FocusManager: self._last_cursor_position: tuple[Optional[Atspi.Accessible], int] = (None, -1) self._penultimate_cursor_position: tuple[Optional[Atspi.Accessible], int] = (None, -1) - msg = "FOCUS MANAGER: Registering D-Bus commands." - debug.print_message(debug.LEVEL_INFO, msg, True) + _log("Registering D-Bus commands.") controller = dbus_service.get_remote_controller() controller.register_decorated_module("FocusManager", self) def clear_state(self, reason: str = "") -> None: """Clears everything we're tracking.""" - msg = "FOCUS MANAGER: Clearing all state" - if reason: - msg += f": {reason}" - debug.print_message(debug.LEVEL_INFO, msg, True) + _log("Clearing all state", reason) self._focus = None self._window = None self._object_of_interest = None @@ -109,8 +111,7 @@ class FocusManager: """Returns the focused object in the active window.""" result = _get_ax_utilities().get_focused_object(self._window) - tokens = ["FOCUS MANAGER: Focused object in", self._window, "is", result] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Focused object in", self._window, "is", result]) return result def focus_and_window_are_unknown(self) -> bool: @@ -118,8 +119,7 @@ class FocusManager: result = self._focus is None and self._window is None if result: - msg = "FOCUS MANAGER: Focus and window are unknown" - debug.print_message(debug.LEVEL_INFO, msg, True) + _log("Focus and window are unknown") return result @@ -129,8 +129,7 @@ class FocusManager: if not AXObject.is_dead(self._focus): return False - msg = "FOCUS MANAGER: Focus is dead" - debug.print_message(debug.LEVEL_INFO, msg, True) + _log("Focus is dead", "dead-focus") return True def focus_is_active_window(self) -> bool: @@ -165,8 +164,7 @@ class FocusManager: obj.emit("mode-changed::" + mode, 1, "") if mode != self._active_mode: - tokens = ["FOCUS MANAGER: Switching mode from", self._active_mode, "to", mode] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Switching mode from", self._active_mode, "to", mode]) self._active_mode = mode cthulhu_state.activeMode = mode if mode == FLAT_REVIEW: @@ -174,15 +172,12 @@ class FocusManager: else: braille.setBrlapiPriority() - tokens = ["FOCUS MANAGER: Region of interest:", obj, f"({start_offset}, {end_offset})"] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Region of interest:", obj, f"({start_offset}, {end_offset})"]) if obj is not None: obj.emit("region-changed", start_offset, end_offset) if obj != self._object_of_interest: - tokens = ["FOCUS MANAGER: Switching object of interest from", - self._object_of_interest, "to", obj] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Switching object of interest from", self._object_of_interest, "to", obj]) self._object_of_interest = obj cthulhu_state.objOfInterest = obj @@ -196,32 +191,27 @@ class FocusManager: ) -> tuple[Optional[str], Optional[Atspi.Accessible]]: """Returns the current mode and associated object of interest""" - tokens = ["FOCUS MANAGER: Active mode:", self._active_mode, - "Object of interest:", self._object_of_interest] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Active mode:", self._active_mode, "Object of interest:", self._object_of_interest]) return self._active_mode, self._object_of_interest def get_penultimate_cursor_position(self) -> tuple[Optional[Atspi.Accessible], int]: """Returns the penultimate cursor position as a tuple of (object, offset).""" obj, offset = self._penultimate_cursor_position - tokens = ["FOCUS MANAGER: Penultimate cursor position:", obj, offset] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Penultimate cursor position:", obj, offset]) return obj, offset def get_last_cursor_position(self) -> tuple[Optional[Atspi.Accessible], int]: """Returns the last cursor position as a tuple of (object, offset).""" obj, offset = self._last_cursor_position - tokens = ["FOCUS MANAGER: Last cursor position:", obj, offset] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Last cursor position:", obj, offset]) return obj, offset def set_last_cursor_position(self, obj: Optional[Atspi.Accessible], offset: int) -> None: """Sets the last cursor position as a tuple of (object, offset).""" - tokens = ["FOCUS MANAGER: Setting last cursor position to", obj, offset] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Setting last cursor position to", obj, offset]) self._penultimate_cursor_position = self._last_cursor_position self._last_cursor_position = obj, offset @@ -229,22 +219,19 @@ class FocusManager: """Returns the last known cell coordinates as a tuple of (row, column).""" row, column = self._last_cell_coordinates - msg = f"FOCUS MANAGER: Last known cell coordinates: row={row}, column={column}" - debug.print_message(debug.LEVEL_INFO, msg, True) + _log(f"Last known cell coordinates: row={row}, column={column}") return row, column def set_last_cell_coordinates(self, row: int, column: int) -> None: """Sets the last known cell coordinates as a tuple of (row, column).""" - msg = f"FOCUS MANAGER: Setting last cell coordinates to row={row}, column={column}" - debug.print_message(debug.LEVEL_INFO, msg, True) + _log(f"Setting last cell coordinates to row={row}, column={column}") self._last_cell_coordinates = row, column def get_locus_of_focus(self) -> Optional[Atspi.Accessible]: """Returns the current locus of focus (i.e. the object with visual focus).""" - tokens = ["FOCUS MANAGER: Locus of focus is", self._focus] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Locus of focus is", self._focus]) return self._focus def set_locus_of_focus( @@ -256,8 +243,7 @@ class FocusManager: ) -> None: """Sets the locus of focus (i.e., the object with visual focus).""" - tokens = ["FOCUS MANAGER: Request to set locus of focus to", obj] - debug.print_tokens(debug.LEVEL_INFO, tokens, True, True) + _log_tokens(["Request to set locus of focus to", obj], stack=True) # We clear the cache on the locus of focus because too many apps and toolkits fail # to emit the correct accessibility events. We do so recursively on table cells @@ -265,8 +251,7 @@ class FocusManager: recursive = _get_ax_utilities().is_table_cell(obj) AXObject.clear_cache(obj, recursive, "Setting locus of focus.") if not force and obj == self._focus: - msg = "FOCUS MANAGER: Setting locus of focus to existing locus of focus" - debug.print_message(debug.LEVEL_INFO, msg, True) + _log("Setting locus of focus to existing locus of focus", "no-change") return # We save the current row and column of a newly focused or selected table cell so that on @@ -298,26 +283,21 @@ class FocusManager: old_focus = None if obj is None: - msg = "FOCUS MANAGER: New locus of focus is null (being cleared)" - debug.print_message(debug.LEVEL_INFO, msg, True) + _log("New locus of focus is null (being cleared)", "clearing") self._focus = None cthulhu_state.locusOfFocus = None return if AXObject.is_dead(obj): - tokens = ["FOCUS MANAGER: New locus of focus (", obj, ") is dead. Not updating."] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["New locus of focus", obj, "is dead. Not updating."], "dead") return if script is not None: if not AXObject.is_valid(obj): - tokens = ["FOCUS MANAGER: New locus of focus (", obj, ") is invalid. Not updating."] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["New locus of focus", obj, "is invalid. Not updating."], "invalid") return - tokens = ["FOCUS MANAGER: Changing locus of focus from", old_focus, - "to", obj, ". Notify:", notify_script] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Changing locus of focus from", old_focus, "to", obj, ". Notify:", notify_script]) self._focus = obj cthulhu_state.locusOfFocus = obj @@ -325,8 +305,7 @@ class FocusManager: return if script is None: - msg = "FOCUS MANAGER: Cannot notify active script because there isn't one" - debug.print_message(debug.LEVEL_INFO, msg, True) + _log("Cannot notify active script because there isn't one", "no-active-script") return self.emit_region_changed(obj, mode=FOCUS_TRACKING) @@ -337,15 +316,13 @@ class FocusManager: AXObject.clear_cache(self._window, False, "Ensuring the active window is really active.") is_active = _get_ax_utilities().is_active(self._window) - tokens = ["FOCUS MANAGER:", self._window, "is active:", is_active] - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens([self._window, "is active:", is_active]) return is_active def get_active_window(self) -> Optional[Atspi.Accessible]: """Returns the currently-active window (i.e. without searching or verifying).""" - tokens = ["FOCUS MANAGER: Active window is", self._window] - debug.print_tokens(debug.LEVEL_INFO, tokens, True, True) + _log_tokens(["Active window is", self._window], stack=True) return self._window def set_active_window( @@ -357,14 +334,13 @@ class FocusManager: ) -> None: """Sets the active window.""" - tokens = ["FOCUS MANAGER: Request to set active window to", frame] + tokens = ["Request to set active window to", frame] if app is not None: tokens.extend(["in", app]) - debug.print_tokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(tokens) if frame == self._window: - msg = "FOCUS MANAGER: Setting active window to existing active window" - debug.print_message(debug.LEVEL_INFO, msg, True) + _log("Setting active window to existing active window", "no-change") elif frame is None: self._window = None cthulhu_state.activeWindow = None @@ -375,8 +351,7 @@ class FocusManager: if set_window_as_focus: self.set_locus_of_focus(None, self._window, notify_script) elif not (self.focus_is_active_window() or self.focus_is_in_active_window()): - tokens = ["FOCUS MANAGER: Focus", self._focus, "is not in", self._window] - debug.print_tokens(debug.LEVEL_INFO, tokens, True, True) + _log_tokens(["Focus", self._focus, "is not in", self._window], stack=True) # Don't update the focus to the active window if we can't get to the active window # from the focused object. https://bugreports.qt.io/browse/QTBUG-130116 diff --git a/src/cthulhu/input_event.py b/src/cthulhu/input_event.py index c6d6e8a..b3a753e 100644 --- a/src/cthulhu/input_event.py +++ b/src/cthulhu/input_event.py @@ -796,8 +796,12 @@ class KeyboardEvent(InputEvent): """Returns True if this event should be consumed.""" # Debug logging to understand handler matching - debugMsg = f"shouldConsume: key='{self.event_string}' hw_code={self.hw_code} modifiers={self.modifiers}" - debug.printMessage(debug.LEVEL_INFO, debugMsg, True) + debug.print_log( + debug.LEVEL_INFO, + "INPUT EVENT", + f"shouldConsume: key='{self.event_string}' hw_code={self.hw_code} modifiers={self.modifiers}", + timestamp=True, + ) if not self.timestamp: return False, 'No timestamp' @@ -810,10 +814,14 @@ class KeyboardEvent(InputEvent): self._script = script_manager.get_manager().get_default_script() globalHandlerUsed = True else: - debug.printMessage(debug.LEVEL_INFO, "shouldConsume: No active script", True) + debug.print_log(debug.LEVEL_INFO, "INPUT EVENT", + "shouldConsume: No active script", + reason="no-active-script", timestamp=True) return False, 'No active script when received' - debug.printMessage(debug.LEVEL_INFO, f"shouldConsume: Active script={self._script.__class__.__name__}", True) + debug.print_log(debug.LEVEL_INFO, "INPUT EVENT", + f"shouldConsume: Active script={self._script.__class__.__name__}", + timestamp=True) if self.is_duplicate: return False, 'Is duplicate' @@ -827,15 +835,21 @@ class KeyboardEvent(InputEvent): globalHandlerUsed = globalHandlerUsed or self._resolveHandler() if self._handler: - debug.printMessage(debug.LEVEL_INFO, f"shouldConsume: Handler found: {self._handler.description}", True) + debug.print_log(debug.LEVEL_INFO, "INPUT EVENT", + f"shouldConsume: Handler found: {self._handler.description}", + timestamp=True) else: - debug.printMessage(debug.LEVEL_INFO, "shouldConsume: No handler found", True) + debug.print_log(debug.LEVEL_INFO, "INPUT EVENT", + "shouldConsume: No handler found", + reason="no-handler", timestamp=True) self._script.updateKeyboardEventState(self, self._handler) scriptConsumes = self._script.shouldConsumeKeyboardEvent(self, self._handler) if globalHandlerUsed: scriptConsumes = True - debug.printMessage(debug.LEVEL_INFO, f"shouldConsume: scriptConsumes={scriptConsumes}", True) + debug.print_log(debug.LEVEL_INFO, "INPUT EVENT", + f"shouldConsume: scriptConsumes={scriptConsumes}", + timestamp=True) if self._isReleaseForLastNonModifierKeyEvent(): return scriptConsumes, 'Is release for last non-modifier keyevent' diff --git a/src/cthulhu/script_manager.py b/src/cthulhu/script_manager.py index 7413583..bf36bbf 100644 --- a/src/cthulhu/script_manager.py +++ b/src/cthulhu/script_manager.py @@ -41,10 +41,16 @@ def _get_ax_utilities(): from .ax_utilities import AXUtilities return AXUtilities +def _log(message, reason=None, timestamp=True, stack=False): + debug.print_log(debug.LEVEL_INFO, "SCRIPT MANAGER", message, reason, timestamp, stack) + +def _log_tokens(tokens, reason=None, timestamp=True, stack=False): + debug.print_log_tokens(debug.LEVEL_INFO, "SCRIPT MANAGER", tokens, reason, timestamp, stack) + class ScriptManager: def __init__(self, app): # Added app argument - debug.printMessage(debug.LEVEL_INFO, "SCRIPT MANAGER: Initializing", True) + _log("Initializing") self.app = app # Store app instance self.appScripts = {} self.toolkitScripts = {} @@ -74,22 +80,22 @@ class ScriptManager: self.set_active_script(None, "lifecycle: init") self._active = False - debug.printMessage(debug.LEVEL_INFO, "SCRIPT MANAGER: Initialized", True) + _log("Initialized") def activate(self): """Called when this script manager is activated.""" - debug.printMessage(debug.LEVEL_INFO, "SCRIPT MANAGER: Activating", True) + _log("Activating") self._defaultScript = self.get_script(None) self._defaultScript.registerEventListeners() self.set_active_script(self._defaultScript, "lifecycle: activate") self._active = True - debug.printMessage(debug.LEVEL_INFO, "SCRIPT MANAGER: Activated", True) + _log("Activated") def deactivate(self): """Called when this script manager is deactivated.""" - debug.printMessage(debug.LEVEL_INFO, "SCRIPT MANAGER: Deactivating", True) + _log("Deactivating") if self._defaultScript: self._defaultScript.deregisterEventListeners() self._defaultScript = None @@ -98,20 +104,18 @@ class ScriptManager: self.toolkitScripts = {} self.customScripts = {} self._active = False - debug.printMessage(debug.LEVEL_INFO, "SCRIPT MANAGER: Deactivated", True) + _log("Deactivated") def get_module_name(self, app): """Returns the module name of the script to use for application app.""" if app is None: - msg = "SCRIPT MANAGER: Cannot get module name for null app" - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Cannot get module name for null app", "null-app") return None name = AXObject.get_name(app) if not name: - msg = "SCRIPT MANAGER: Cannot get module name for nameless app" - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Cannot get module name for nameless app", "nameless-app") return None pid = AXObject.get_process_id(app) @@ -136,8 +140,7 @@ class ScriptManager: name = names[0] break - tokens = ["SCRIPT MANAGER: Mapped", app, "to", name] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Mapped", app, "to", name]) return name def _toolkit_for_object(self, obj): @@ -169,8 +172,7 @@ class ScriptManager: except OSError: debug.examineProcesses() - tokens = ["SCRIPT MANAGER: Found", moduleName] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Found", moduleName]) try: if hasattr(module, 'get_script'): script = module.get_script(app) @@ -178,8 +180,7 @@ class ScriptManager: script = module.Script(app) break except Exception as error: - tokens = ["SCRIPT MANAGER: Could not load", moduleName, ":", error] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Could not load", moduleName, ":", error], "load-failed") return script @@ -202,8 +203,7 @@ class ScriptManager: if not script: script = self.get_default_script(app) - tokens = ["SCRIPT MANAGER: Default script created for", app, "(obj: ", obj, ")"] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Default script created for", app, "(obj:", obj, ")"]) return script @@ -230,14 +230,12 @@ class ScriptManager: if newScript: return newScript - tokens = ["WARNING: Failed to get a replacement script for", script.app] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Failed to get a replacement script for", script.app], "replacement-missing") return script def get_script_for_mouse_button_event(self, event): isActive = _get_ax_utilities().is_active(cthulhu_state.activeWindow) - tokens = ["SCRIPT MANAGER:", cthulhu_state.activeWindow, "is active:", isActive] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens([cthulhu_state.activeWindow, "is active:", isActive]) if isActive and cthulhu_state.activeScript: return cthulhu_state.activeScript @@ -297,8 +295,7 @@ class ScriptManager: appScript = self._create_script(app, None) self.appScripts[app] = appScript except Exception as error: - tokens = ["SCRIPT MANAGER: Exception getting app script for", app, ":", error] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Exception getting app script for", app, ":", error], "app-script-error") appScript = self.get_default_script() if customScript: @@ -351,8 +348,7 @@ class ScriptManager: from . import cthulhu cthulhu.cthulhuApp.getSignalManager().emitSignal('active-script-changed', newScript) - tokens = ["SCRIPT MANAGER: Setting active script to", newScript, "reason:", reason] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Setting active script to", newScript], reason) self._log_active_state(reason) def activate_script_for_context(self, app, obj, reason=None): @@ -361,14 +357,12 @@ class ScriptManager: return script def _log_active_state(self, reason=None): - tokens = [ - "SCRIPT MANAGER: Active state:", - "window", cthulhu_state.activeWindow, - "focus", cthulhu_state.locusOfFocus, - "script", cthulhu_state.activeScript, - "reason", reason - ] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens( + ["Active state:", "window", cthulhu_state.activeWindow, + "focus", cthulhu_state.locusOfFocus, + "script", cthulhu_state.activeScript], + reason + ) def _get_script_for_app_replicant(self, app): if not self._active: @@ -385,8 +379,7 @@ class ScriptManager: if a != app and _get_ax_utilities().is_application_in_desktop(a): if script.app is None: script.app = a - tokens = ["SCRIPT MANAGER: Script for app replicant:", script, script.app] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Script for app replicant:", script, script.app]) return script return None @@ -396,8 +389,7 @@ class ScriptManager: deleting any scripts as necessary. """ - msg = "SCRIPT MANAGER: Checking and cleaning up scripts." - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Checking and cleaning up scripts.") appList = list(self.appScripts.keys()) for app in appList: @@ -407,21 +399,17 @@ class ScriptManager: try: appScript = self.appScripts.pop(app) except KeyError: - tokens = ["SCRIPT MANAGER:", app, "not found in appScripts"] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens([app, "not found in appScripts"]) continue - tokens = ["SCRIPT MANAGER: Old script for app found:", appScript, appScript.app] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Old script for app found:", appScript, appScript.app]) newScript = self._get_script_for_app_replicant(app) if newScript: - tokens = ["SCRIPT MANAGER: Transferring attributes:", newScript, newScript.app] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Transferring attributes:", newScript, newScript.app]) attrs = appScript.getTransferableAttributes() for attr, value in attrs.items(): - tokens = ["SCRIPT MANAGER: Setting", attr, "to", value] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Setting", attr, "to", value]) setattr(newScript, attr, value) del appScript diff --git a/src/cthulhu/scripts/web/script.py b/src/cthulhu/scripts/web/script.py index b530021..b944c33 100644 --- a/src/cthulhu/scripts/web/script.py +++ b/src/cthulhu/scripts/web/script.py @@ -70,6 +70,12 @@ from .script_utilities import Utilities _settingsManager = None # Removed - use cthulhu.cthulhuApp.settingsManager +def _log(message, reason=None, timestamp=True, stack=False): + debug.print_log(debug.LEVEL_INFO, "WEB", message, reason, timestamp, stack) + +def _log_tokens(tokens, reason=None, timestamp=True, stack=False): + debug.print_log_tokens(debug.LEVEL_INFO, "WEB", tokens, reason, timestamp, stack) + class Script(default.Script): @@ -126,14 +132,13 @@ class Script(default.Script): def activate(self): """Called when this script is activated.""" - tokens = ["WEB: Activating script for", self.app] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Activating script for", self.app]) focus = cthulhu_state.locusOfFocus inApp = AXObject.get_application(focus) == self.app if focus else False inDoc = self._focusInDocumentContent() suspend = not (inDoc and inApp) - reason = f"script activation, not in document content in this app: {suspend}" + reason = "activation-outside-document" if suspend else "activation-in-document" self._setNavigationSuspended(suspend, reason) @@ -176,8 +181,7 @@ class Script(default.Script): self.structuralNavigation.enabled = self._structNavWasEnabled self._structNavWasEnabled = None - tokens = ["WEB: Navigation suspended:", suspend, reason] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Navigation suspended:", suspend], reason) def _focusInDocumentContent(self): focus = cthulhu_state.locusOfFocus @@ -902,24 +906,20 @@ class Script(default.Script): """Returns True if we should use focus mode in obj.""" if self._focusModeIsSticky: - msg = "WEB: Using focus mode because focus mode is sticky" - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Using focus mode", "focus-mode-sticky") return True if self._browseModeIsSticky: - msg = "WEB: Not using focus mode because browse mode is sticky" - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using focus mode", "browse-mode-sticky") return False if self.inSayAll(): - msg = "WEB: Not using focus mode because we're in SayAll." - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using focus mode", "say-all") return False if not cthulhu.cthulhuApp.settingsManager.getSetting('structNavTriggersFocusMode') \ and self._lastCommandWasStructNav: - msg = "WEB: Not using focus mode due to struct nav settings" - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using focus mode", "struct-nav-settings") return False if prevObj and AXObject.is_dead(prevObj): @@ -928,39 +928,32 @@ class Script(default.Script): if not cthulhu.cthulhuApp.settingsManager.getSetting('caretNavTriggersFocusMode') \ and self._lastCommandWasCaretNav \ and not self.utilities.isNavigableToolTipDescendant(prevObj): - msg = "WEB: Not using focus mode due to caret nav settings" - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using focus mode", "caret-nav-settings") return False if not cthulhu.cthulhuApp.settingsManager.getSetting('nativeNavTriggersFocusMode') \ and not (self._lastCommandWasStructNav or self._lastCommandWasCaretNav): - msg = "WEB: Not changing focus/browse mode due to native nav settings" - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not changing focus/browse mode", "native-nav-settings") return self._inFocusMode if self.utilities.isFocusModeWidget(obj): - tokens = ["WEB: Using focus mode because", obj, "is a focus mode widget"] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Using focus mode for", obj], "focus-mode-widget") return True doNotToggle = AXUtilities.is_link(obj) or AXUtilities.is_radio_button(obj) if self._inFocusMode and doNotToggle and self.utilities.lastInputEventWasUnmodifiedArrow(): - tokens = ["WEB: Staying in focus mode due to arrowing in role of", obj] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Staying in focus mode due to arrowing in role of", obj], "arrowing") return True if self._inFocusMode and self.utilities.isWebAppDescendant(obj): if self.utilities.forceBrowseModeForWebAppDescendant(obj): - tokens = ["WEB: Forcing browse mode for web app descendant", obj] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Forcing browse mode for web app descendant", obj], "web-app-forced-browse") return False - msg = "WEB: Staying in focus mode because we're inside a web application" - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Staying in focus mode because we're inside a web application", "web-app-context") return True - tokens = ["WEB: Not using focus mode for", obj, "due to lack of cause"] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens(["Not using focus mode for", obj], "no-cause") return False def speakContents(self, contents, **args): @@ -1209,14 +1202,12 @@ class Script(default.Script): if not cthulhu.cthulhuApp.settingsManager.getSetting('caretNavigationEnabled'): if debugOutput: - msg = "WEB: Not using caret navigation: it's not enabled." - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using caret navigation", "disabled") return False if self._inFocusMode: if debugOutput: - msg = "WEB: Not using caret navigation: focus mode is active." - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using caret navigation", "focus-mode") return False inDoc = self._focusInDocumentContent() @@ -1226,27 +1217,29 @@ class Script(default.Script): self._setNavigationSuspended(False, "focus confirmed in document content") else: if debugOutput: - msg = "WEB: Not using caret navigation: navigation suspended." - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using caret navigation", "suspended") return False if not inDoc: if debugOutput: - tokens = ["WEB: Not using caret navigation: locusOfFocus", - cthulhu_state.locusOfFocus, "is not in document content."] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens( + ["Not using caret navigation because locusOfFocus", cthulhu_state.locusOfFocus, + "is not in document content."], + "focus-not-document" + ) return False if keyboardEvent and keyboardEvent.modifiers & keybindings.SHIFT_MODIFIER_MASK: if debugOutput: - msg = "WEB: Not using caret navigation: shift was used." - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using caret navigation", "shift-modifier") return False if debugOutput: - tokens = ["WEB: Using caret navigation: in browse mode and locusOfFocus", - cthulhu_state.locusOfFocus, "is in document content."] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens( + ["Using caret navigation with locusOfFocus", cthulhu_state.locusOfFocus, + "in document content."], + "enabled" + ) return True def useStructuralNavigationModel(self, debugOutput=True): @@ -1254,14 +1247,12 @@ class Script(default.Script): if not self.structuralNavigation.enabled: if debugOutput: - msg = "WEB: Not using structural navigation: it's not enabled." - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using structural navigation", "disabled") return False if self._inFocusMode: if debugOutput: - msg = "WEB: Not using structural navigation: focus mode is active." - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using structural navigation", "focus-mode") return False inDoc = self._focusInDocumentContent() @@ -1271,21 +1262,24 @@ class Script(default.Script): self._setNavigationSuspended(False, "focus confirmed in document content") else: if debugOutput: - msg = "WEB: Not using structural navigation: navigation suspended." - debug.printMessage(debug.LEVEL_INFO, msg, True) + _log("Not using structural navigation", "suspended") return False if not inDoc: if debugOutput: - tokens = ["WEB: Not using structural navigation: locusOfFocus", - cthulhu_state.locusOfFocus, "is not in document content."] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens( + ["Not using structural navigation because locusOfFocus", + cthulhu_state.locusOfFocus, "is not in document content."], + "focus-not-document" + ) return False if debugOutput: - tokens = ["WEB: Using structural navigation: in browse mode and locusOfFocus", - cthulhu_state.locusOfFocus, "is in document content."] - debug.printTokens(debug.LEVEL_INFO, tokens, True) + _log_tokens( + ["Using structural navigation with locusOfFocus", cthulhu_state.locusOfFocus, + "in document content."], + "enabled" + ) return True def getTextLineAtCaret(self, obj, offset=None, startOffset=None, endOffset=None):