GNOME.org
 

[orca] And still more debugging....

commit 5b3d0019f6e948e7eabaf79415139001bad5d528
Author: Joanmarie Diggs <jdiggs igalia com>
Date:   Mon Feb 1 16:01:44 2021 +0100

    And still more debugging....

 src/orca/braille.py         | 96 +++++++++++++++++++++++++++++++++++++++------
 src/orca/debug.py           | 19 +++++----
 src/orca/orca.py            | 12 +++++-
 src/orca/orca_bin.py.in     |  9 ++++-
 src/orca/scripts/default.py | 16 +++++++-
 5 files changed, 128 insertions(+), 24 deletions(-)
---
diff --git a/src/orca/braille.py b/src/orca/braille.py
index 854c63416..32f794370 100644
--- a/src/orca/braille.py
+++ b/src/orca/braille.py
@@ -55,13 +55,16 @@ _monitor = None
 _settingsManager = settings_manager.getManager()
 
 try:
+    msg = "BRAILLE: About to import brlapi."
+    debug.println(debug.LEVEL_INFO, msg, True)
+
     import brlapi
     _brlAPI = None
     _brlAPIAvailable = True
     _brlAPIRunning = False
     _brlAPISourceId = 0
 except:
-    msg = "BRAILLE: Could not import brlapi"
+    msg = "BRAILLE: Could not import brlapi."
     debug.println(debug.LEVEL_INFO, msg, True)
     _brlAPIAvailable = False
     _brlAPIRunning = False
@@ -70,6 +73,8 @@ else:
     debug.println(debug.LEVEL_INFO, msg, True)
 
 try:
+    msg = "BRAILLE: About to import louis."
+    debug.println(debug.LEVEL_INFO, msg, True)
     import louis
 except:
     msg = "BRAILLE: Could not import liblouis"
@@ -1127,15 +1132,22 @@ def setFocus(region, panToFocus=True, getLinkMask=True):
 def _idleBraille():
     """Try to hand off control to other screen readers without completely
     shutting down the BrlAPI connection"""
+
     global idle
 
     if not idle:
         try:
+            msg = "BRAILLE: Attempting to idle braille."
+            debug.println(debug.LEVEL_INFO, msg, True)
             _brlAPI.setParameter(brlapi.PARAM_CLIENT_PRIORITY, 0, False, 0)
             idle = True
         except:
-            # BrlAPI before 0.8
+            msg = "BRAILLE: Idling braille failled. This requires BrlAPI >= 0.8."
+            debug.println(debug.LEVEL_INFO, msg, True)
             pass
+        else:
+            msg = "BRAILLE: Idling braille succeeded."
+            debug.println(debug.LEVEL_INFO, msg, True)
 
     return idle
 
@@ -1160,27 +1172,45 @@ def _enableBraille():
     """Re-enable Braille output after making it idle or clearing it"""
     global idle
 
+    msg = "BRAILLE: Enabling braille. BrlAPI running: %s" % _brlAPIRunning
+    debug.println(debug.LEVEL_INFO, msg, True)
+
     if not _brlAPIRunning:
+        msg = "BRAILLE: Need to initialize first."
+        debug.println(debug.LEVEL_INFO, msg, True)
         init(_callback)
 
     if _brlAPIRunning:
         if idle:
+            msg = "BRAILLE: Is running, but idling."
+            debug.println(debug.LEVEL_INFO, msg, True)
             try:
                 # Restore default priority
+                msg = "BRAILLE: Attempting to de-idle braille."
+                debug.println(debug.LEVEL_INFO, msg, True)
                 _brlAPI.setParameter(brlapi.PARAM_CLIENT_PRIORITY, 0, False, 50)
                 idle = False
             except:
                 msg = "BRAILLE: could not restore priority"
                 debug.println(debug.LEVEL_INFO, msg, True)
+            else:
+                msg = "BRAILLE: De-idle succeeded."
+                debug.println(debug.LEVEL_INFO, msg, True)
 
 def disableBraille():
     """Hand off control to other screen readers, shutting down the BrlAPI
     connection if needed"""
+
     global idle
 
+    msg = "BRAILLE: Disabling braille. BrlAPI running: %s" % _brlAPIRunning
+    debug.println(debug.LEVEL_INFO, msg, True)
+
     if _brlAPIRunning and not idle:
-        if not _idleBraille() and \
-            not _settingsManager.getSetting('enableBraille'):
+        msg = "BRAILLE: BrlApi running and not idle."
+        debug.println(debug.LEVEL_INFO, msg, True)
+
+        if not _idleBraille() and not _settingsManager.getSetting('enableBraille'):
             # BrlAPI before 0.8 and we really want to shut down
             msg = "BRAILLE: could not go idle, completely shut down"
             debug.println(debug.LEVEL_INFO, msg, True)
@@ -1188,6 +1218,10 @@ def disableBraille():
 
 def checkBrailleSetting():
     """Disable Braille if it got disabled in the preferences"""
+
+    msg = "BRAILLE: Checking braille setting."
+    debug.println(debug.LEVEL_INFO, msg, True)
+
     if not _settingsManager.getSetting('enableBraille'):
         disableBraille()
 
@@ -1771,26 +1805,37 @@ def setupKeyRanges(keys):
     Arguments:
     -keys: a list of BrlAPI commands.
     """
+
+    msg = "BRAILLE: Setting up key ranges."
+    debug.println(debug.LEVEL_INFO, msg, True)
+
     if not _brlAPIRunning:
         init(_callback)
+
     if not _brlAPIRunning:
+        msg = "BRAILLE: Not setting up key ranges: BrlAPI not running."
+        debug.println(debug.LEVEL_INFO, msg, True)
         return
 
-    # First, start by ignoring everything.
-    #
+    msg = "BRAILLE: Ignoring all key ranges."
+    debug.println(debug.LEVEL_INFO, msg, True)
     _brlAPI.ignoreKeys(brlapi.rangeType_all, [0])
 
-    # Next, enable cursor routing keys.
-    #
     keySet = [brlapi.KEY_TYPE_CMD | brlapi.KEY_CMD_ROUTE]
 
-    # Finally, enable the commands we care about.
-    #
+    msg = "BRAILLE: Enabling commands:"
+    debug.println(debug.LEVEL_INFO, msg, True)
+
     for key in keys:
         keySet.append(brlapi.KEY_TYPE_CMD | key)
 
+    msg = "BRAILLE: Sending keys to BrlAPI."
+    debug.println(debug.LEVEL_INFO, msg, True)
     _brlAPI.acceptKeys(brlapi.rangeType_command, keySet)
 
+    msg = "BRAILLE: Key ranges set up."
+    debug.println(debug.LEVEL_INFO, msg, True)
+
 def init(callback=None):
     """Initializes the braille module, connecting to the BrlTTY driver.
 
@@ -1914,6 +1959,9 @@ def shutdown():
     was run.
     """
 
+    msg = "BRAILLE: Attempting braille shutdown."
+    debug.println(debug.LEVEL_INFO, msg, True)
+
     global _brlAPI
     global _brlAPIRunning
     global _brlAPISourceId
@@ -1922,22 +1970,46 @@ def shutdown():
 
     if _brlAPIRunning:
         _brlAPIRunning = False
+
+        msg = "BRAILLE: Removing BrlAPI Source ID."
+        debug.println(debug.LEVEL_INFO, msg, True)
+
         GLib.source_remove(_brlAPISourceId)
         _brlAPISourceId = 0
+
         try:
+            msg = "BRAILLE: Attempting to leave TTY mode."
+            debug.println(debug.LEVEL_INFO, msg, True)
             _brlAPI.leaveTtyMode()
         except:
-            pass
+            msg = "BRAILLE: Exception leaving TTY mode."
+            debug.println(debug.LEVEL_INFO, msg, True)
+        else:
+            msg = "BRAILLE: Leaving TTY mode succeeded."
+            debug.println(debug.LEVEL_INFO, msg, True)
+
         try:
+            msg = "BRAILLE: Attempting to close connection."
+            debug.println(debug.LEVEL_INFO, msg, True)
             _brlAPI.closeConnection()
         except:
-            pass
+            msg = "BRAILLE: Exception closing connection."
+            debug.println(debug.LEVEL_INFO, msg, True)
+        else:
+            msg = "BRAILLE: Closing connection succeeded."
+            debug.println(debug.LEVEL_INFO, msg, True)
+
         _brlAPI = None
+
         if _monitor:
             _monitor.destroy()
             _monitor = None
         _displaySize = [DEFAULT_DISPLAY_SIZE, 1]
     else:
+        msg = "BRAILLE: Braille was not running."
+        debug.println(debug.LEVEL_INFO, msg, True)
         return False
 
+    msg = "BRAILLE: Braille shutdown complete."
+    debug.println(debug.LEVEL_INFO, msg, True)
     return True
diff --git a/src/orca/debug.py b/src/orca/debug.py
index 8ba8e660f..e79482ed4 100644
--- a/src/orca/debug.py
+++ b/src/orca/debug.py
@@ -527,9 +527,14 @@ def pidOf(procName):
     openFile.close()
     return [int(p) for p in pids.split()]
 
-def examineProcesses():
+def examineProcesses(force=False):
+    if force:
+        level = LEVEL_OFF
+    else:
+        level = LEVEL_ALL
+
     desktop = pyatspi.Registry.getDesktop(0)
-    println(LEVEL_ALL, 'INFO: Desktop has %i apps:' % desktop.childCount)
+    println(level, 'INFO: Desktop has %i apps:' % desktop.childCount, True)
     for i, app in enumerate(desktop):
         pid = app.get_process_id()
         cmd = getCmdline(pid)
@@ -541,19 +546,19 @@ def examineProcesses():
         else:
             if name == '':
                 name = 'WARNING: Possible hang'
-        println(LEVEL_ALL, '%3i. %s (pid: %s) %s file descriptors: %i' \
-                    % (i+1, name, pid, cmd, fds))
+        println(level, '%3i. %s (pid: %s) %s file descriptors: %i' \
+                    % (i+1, name, pid, cmd, fds), True)
 
     # Other 'suspect' processes which might not show up as accessible apps.
     otherApps = ['apport']
     for app in otherApps:
         pids = pidOf(app)
         if not pids:
-            println(LEVEL_ALL, 'INFO: no pid for %s' % app)
+            println(level, 'INFO: no pid for %s' % app, True)
             continue
 
         for pid in pids:
             cmd = getCmdline(pid)
             fds = getOpenFDCount(pid)
-            println(LEVEL_ALL, 'INFO: %s (pid: %s) %s file descriptors: %i' \
-                        % (app, pid, cmd, fds))
+            println(level, 'INFO: %s (pid: %s) %s file descriptors: %i' \
+                        % (app, pid, cmd, fds), True)
diff --git a/src/orca/orca.py b/src/orca/orca.py
index 2da51c385..99e2d73c1 100644
--- a/src/orca/orca.py
+++ b/src/orca/orca.py
@@ -425,6 +425,8 @@ def loadUserSettings(script=None, inputEvent=None, skipReloadMessage=False):
     _settingsManager.loadAppSettings(script)
 
     if _settingsManager.getSetting('enableSpeech'):
+        msg = 'ORCA: About to enable speech'
+        debug.println(debug.LEVEL_INFO, msg, True)
         try:
             speech.init()
             if reloaded and not skipReloadMessage:
@@ -436,12 +438,18 @@ def loadUserSettings(script=None, inputEvent=None, skipReloadMessage=False):
         debug.println(debug.LEVEL_INFO, msg, True)
 
     if _settingsManager.getSetting('enableBraille'):
+        msg = 'ORCA: About to enable braille'
+        debug.println(debug.LEVEL_INFO, msg, True)
         try:
             braille.init(_processBrailleEvent)
         except:
             debug.printException(debug.LEVEL_WARNING)
             msg = 'ORCA: Could not initialize connection to braille.'
             debug.println(debug.LEVEL_WARNING, msg, True)
+    else:
+        msg = 'ORCA: Braille is not enabled in settings'
+        debug.println(debug.LEVEL_INFO, msg, True)
+
 
     if _settingsManager.getSetting('enableMouseReview'):
         mouse_review.reviewer.activate()
@@ -650,8 +658,8 @@ def die(exitCode=1):
 def timeout(signum=None, frame=None):
     msg = 'TIMEOUT: something has hung. Aborting.'
     debug.println(debug.LEVEL_SEVERE, msg, True)
-    debug.printStack(debug.LEVEL_ALL)
-    debug.examineProcesses()
+    debug.printStack(debug.LEVEL_SEVERE)
+    debug.examineProcesses(force=True)
     die(EXIT_CODE_HANG)
 
 def shutdown(script=None, inputEvent=None):
diff --git a/src/orca/orca_bin.py.in b/src/orca/orca_bin.py.in
index 6cf8523ca..b590f81fa 100644
--- a/src/orca/orca_bin.py.in
+++ b/src/orca/orca_bin.py.in
@@ -39,9 +39,12 @@ sys.prefix = '@prefix@'
 pythondir = '@pythondir@'.replace('${prefix}', '@prefix@')
 sys.path.insert(1, pythondir)
 
+# Do not import Orca here. It is imported in main(). The reason why is that
+# start-up failures due to imports in orca.py are not getting output, making
+# them challenging to debug when they cannot be reproduced locally.
+
 from orca import debug
 from orca import messages
-from orca import orca
 from orca import settings
 from orca.orca_platform import version
 
@@ -244,6 +247,8 @@ def main():
         return 1
 
     debug.println(debug.LEVEL_INFO, "INFO: Preparing to launch.", True)
+
+    from orca import orca
     manager = orca.getSettingsManager()
 
     if not manager:
@@ -269,7 +274,7 @@ def main():
         print(messages.CLI_OTHER_ORCAS_ERROR)
         return 1
 
-    debug.println(debug.LEVEL_INFO, "INFO: About to launch Orca,", True)
+    debug.println(debug.LEVEL_INFO, "INFO: About to launch Orca.", True)
     return orca.main()
 
 if __name__ == "__main__":
diff --git a/src/orca/scripts/default.py b/src/orca/scripts/default.py
index 5f76af466..698769bef 100644
--- a/src/orca/scripts/default.py
+++ b/src/orca/scripts/default.py
@@ -30,10 +30,10 @@ __copyright__ = "Copyright (c) 2004-2009 Sun Microsystems Inc." \
                 "Copyright (c) 2010 Joanmarie Diggs"
 __license__   = "LGPL"
 
+import pyatspi
 import re
 import time
 
-import pyatspi
 import orca.braille as braille
 import orca.cmdnames as cmdnames
 import orca.debug as debug
@@ -683,6 +683,10 @@ class Script(script.Script):
         Returns a dictionary where the keys are BrlTTY commands and the
         values are InputEventHandler instances.
         """
+
+        msg = 'DEFAULT: Getting braille bindings.'
+        debug.println(debug.LEVEL_INFO, msg, True)
+
         brailleBindings = script.Script.getBrailleBindings(self)
         try:
             brailleBindings[braille.brlapi.KEY_CMD_HWINLT]     = \
@@ -724,6 +728,10 @@ class Script(script.Script):
             msg = 'ERROR: Exception getting braille bindings in %s' % self
             debug.println(debug.LEVEL_INFO, msg, True)
             debug.printException(debug.LEVEL_CONFIGURATION)
+
+        msg = 'DEFAULT: Finished getting braille bindings.'
+        debug.println(debug.LEVEL_INFO, msg, True)
+
         return brailleBindings
 
     def deactivate(self):
@@ -855,12 +863,18 @@ class Script(script.Script):
     def activate(self):
         """Called when this script is activated."""
 
+        msg = 'DEFAULT: activating script for %s' % self.app
+        debug.println(debug.LEVEL_INFO, msg, True)
+
         _settingsManager.loadAppSettings(self)
         braille.checkBrailleSetting()
         braille.setupKeyRanges(self.brailleBindings.keys())
         speech.updatePunctuationLevel()
         speech.updateCapitalizationStyle()
 
+        msg = 'DEFAULT: Script for %s activated' % self.app
+        debug.println(debug.LEVEL_INFO, msg, True)
+
     def updateBraille(self, obj, **args):
         """Updates the braille display to show the give object.
[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]