[orca/gnome-3-4] Adding yet more debugging output to hunt down crazy bugs

[Joanmarie Diggs <joanied src gnome org>]

commit d1e803d65f58897143706e1fe396fd551a37ea83
Author: Joanmarie Diggs <jdiggs igalia com>
Date:   Thu Apr 5 18:41:14 2012 -0400

    Adding yet more debugging output to hunt down crazy bugs

 src/orca/dbusserver.py       |    1 +
 src/orca/event_manager.py    |   33 +++++++++++++++++++++++++++++++++
 src/orca/orca.py             |   17 +++++++++++++++++
 src/orca/script_manager.py   |    6 ++++++
 src/orca/settings_manager.py |    4 ++++
 5 files changed, 61 insertions(+), 0 deletions(-)
---
diff --git a/src/orca/dbusserver.py b/src/orca/dbusserver.py
index 2572a9c..e3bf32e 100644
--- a/src/orca/dbusserver.py
+++ b/src/orca/dbusserver.py
@@ -170,6 +170,7 @@ def shutdown():
 def main():
     import pyatspi
     init()
+    debug.println(debug.LEVEL_FINEST, 'INFO: dbusserver starting registry')
     pyatspi.Registry.start()
 
 if __name__ == "__main__":
diff --git a/src/orca/event_manager.py b/src/orca/event_manager.py
index 4263bc4..b498694 100644
--- a/src/orca/event_manager.py
+++ b/src/orca/event_manager.py
@@ -46,6 +46,7 @@ class EventManager:
 
     def __init__(self):
 
+        debug.println(debug.LEVEL_FINEST, 'INFO: Initializing event manager')
         self._scriptListenerCounts = {}
         self.registry = pyatspi.Registry
         self._enqueueCount = 0
@@ -54,10 +55,13 @@ class EventManager:
         self._gidleId        = 0
         self._gidleLock      = threading.Lock()
         self.noFocusTimestamp = 0.0
+        debug.println(debug.LEVEL_FINEST, 'INFO: Event manager initialized')
 
     def activate(self):
         """Called when this presentation manager is activated."""
 
+        debug.println(debug.LEVEL_FINEST, 'INFO: Activating event manager')
+
         global _scriptManager
         _scriptManager = getattr(orca, '_scriptManager')
 
@@ -69,13 +73,16 @@ class EventManager:
         self._registerListener("window:deactivate")
         self._registerListener("object:children-changed")
         self._registerListener("mouse:button")
+        debug.println(debug.LEVEL_FINEST, 'INFO: Event manager activated')
 
     def deactivate(self):
         """Called when this event manager is deactivated."""
 
+        debug.println(debug.LEVEL_FINEST, 'INFO: Dectivating event manager')
         for eventType in self._scriptListenerCounts.keys():
             self.registry.deregisterEventListener(self._enqueue, eventType)
         self._scriptListenerCounts = {}
+        debug.println(debug.LEVEL_FINEST, 'INFO: Event manager deactivated')
 
     def _ignore(self, event):
         """Returns True if this event should be ignored."""
@@ -274,6 +281,10 @@ class EventManager:
         - eventType: the event type.
         """
 
+        debug.println(debug.LEVEL_FINEST,
+                      'INFO: Event manager registering listener for: %s' \
+                       % eventType)
+
         if eventType in self._scriptListenerCounts:
             self._scriptListenerCounts[eventType] += 1
         else:
@@ -287,6 +298,10 @@ class EventManager:
         - eventType: the event type.
         """
 
+        debug.println(debug.LEVEL_FINEST,
+                      'INFO: Event manager deregistering listener for: %s' \
+                       % eventType)
+
         if not eventType in self._scriptListenerCounts:
             return
 
@@ -303,6 +318,10 @@ class EventManager:
         - script: the script.
         """
 
+        debug.println(debug.LEVEL_FINEST,
+                      'INFO: Event manager registering listeners for: %s' \
+                       % script)
+
         for eventType in script.listeners.keys():
             self._registerListener(eventType)
 
@@ -314,6 +333,10 @@ class EventManager:
         - script: the script.
         """
 
+        debug.println(debug.LEVEL_FINEST,
+                      'INFO: Event manager deregistering listeners for: %s' \
+                       % script)
+
         for eventType in script.listeners.keys():
             self._deregisterListener(eventType)
 
@@ -332,6 +355,11 @@ class EventManager:
     def registerKeystrokeListener(self, function, mask=None, kind=None):
         """Register the keystroke listener on behalf of the caller."""
 
+        debug.println(
+            debug.LEVEL_FINEST,
+            'INFO: Event manager registering keystroke listener function: %s' \
+             % function)
+
         if mask == None:
             mask = range(256)
 
@@ -343,6 +371,11 @@ class EventManager:
     def deregisterKeystrokeListener(self, function, mask=None, kind=None):
         """Deregister the keystroke listener on behalf of the caller."""
 
+        debug.println(
+            debug.LEVEL_FINEST,
+            'INFO: Event manager deregistering keystroke listener function: %s'\
+             % function)
+
         if mask == None:
             mask = range(256)
 
diff --git a/src/orca/orca.py b/src/orca/orca.py
index 0c28998..1a80323 100644
--- a/src/orca/orca.py
+++ b/src/orca/orca.py
@@ -736,6 +736,8 @@ def loadUserSettings(script=None, inputEvent=None, skipReloadMessage=False):
     Returns True to indicate the input event has been consumed.
     """
 
+    debug.println(debug.LEVEL_FINEST, 'INFO: Loading User Settings')
+
     global _userSettings
 
     # Shutdown the output drivers and give them a chance to die.
@@ -841,6 +843,8 @@ def loadUserSettings(script=None, inputEvent=None, skipReloadMessage=False):
         dbusserver.init()
     httpserver.init()
 
+    debug.println(debug.LEVEL_FINEST, 'INFO: User Settings Loaded')
+
     return True
 
 def showAppPreferencesGUI(script=None, inputEvent=None):
@@ -1193,6 +1197,8 @@ def init(registry):
     module has already been initialized.
     """
 
+    debug.println(debug.LEVEL_FINEST, 'INFO: Initializing Orca module')
+
     global _initialized
 
     if _initialized and _settingsManager.isScreenReaderServiceEnabled():
@@ -1216,12 +1222,17 @@ def init(registry):
     # so that we respond when gnome-control-center is used to stop Orca.
     if a11yAppSettings:
         a11yAppSettings.connect('changed', onEnabledChanged)
+
+    debug.println(debug.LEVEL_FINEST, 'INFO: Orca module initialized')
+
     return True
 
 def start(registry):
     """Starts Orca.
     """
 
+    debug.println(debug.LEVEL_FINEST, 'INFO: Starting Orca')
+
     if not _initialized:
         init(registry)
 
@@ -1239,6 +1250,7 @@ def start(registry):
     if settings.cacheValues:
         pyatspi.setCacheLevel(pyatspi.CACHE_PROPERTIES)
 
+    debug.println(debug.LEVEL_FINEST, 'INFO: Orca starting registry')
     registry.start(gil=settings.useGILIdleHandler)
 
 def die(exitCode=1):
@@ -1266,6 +1278,8 @@ def shutdown(script=None, inputEvent=None):
     was never initialized.
     """
 
+    debug.println(debug.LEVEL_FINEST, 'INFO: Shutting down Orca')
+
     global _initialized
 
     if not _initialized:
@@ -1297,8 +1311,11 @@ def shutdown(script=None, inputEvent=None):
     _initialized = False
     _restoreXmodmap(_orcaModifiers)
 
+    debug.println(debug.LEVEL_FINEST, 'INFO: Orca stopping registry')
     pyatspi.Registry.stop()
 
+    debug.println(debug.LEVEL_FINEST, 'INFO: Orca shutdown complete')
+
     return True
 
 exitCount = 0
diff --git a/src/orca/script_manager.py b/src/orca/script_manager.py
index 00a50fd..047874c 100644
--- a/src/orca/script_manager.py
+++ b/src/orca/script_manager.py
@@ -36,6 +36,7 @@ _eventManager = getattr(orca, '_eventManager')
 class ScriptManager:
 
     def __init__(self):
+        debug.println(debug.LEVEL_FINEST, 'INFO: Initializing script manager')
         self.appScripts = {}
         self.toolkitScripts = {}
         self._appModules = apps.__all__
@@ -69,20 +70,25 @@ class ScriptManager:
              'clutter':          'CALLY'}
 
         self.setActiveScript(None, "__init__")
+        debug.println(debug.LEVEL_FINEST, 'INFO: Script manager initialized')
 
     def activate(self):
         """Called when this script manager is activated."""
 
+        debug.println(debug.LEVEL_FINEST, 'INFO: Activating script manager')
         self._defaultScript  = None
         self.setActiveScript(self.getScript(None), "activate")
+        debug.println(debug.LEVEL_FINEST, 'INFO: Script manager activated')
 
     def deactivate(self):
         """Called when this script manager is deactivated."""
 
+        debug.println(debug.LEVEL_FINEST, 'INFO: Dectivating script manager')
         self._defaultScript  = None
         self.setActiveScript(None, "deactivate")
         self.appScripts = {}
         self.toolkitScripts = {}
+        debug.println(debug.LEVEL_FINEST, 'INFO: Script manager deactivated')
 
     def getModuleName(self, app):
         """Returns the module name of the script to use for application app."""
diff --git a/src/orca/settings_manager.py b/src/orca/settings_manager.py
index 8ffd6a5..aef2117 100644
--- a/src/orca/settings_manager.py
+++ b/src/orca/settings_manager.py
@@ -66,6 +66,8 @@ class SettingsManager(object):
         backend='json'
         """
 
+        debug.println(debug.LEVEL_FINEST, 'INFO: Initializing settings manager')
+
         self.backendModule = None
         self._backend = None
         self.profile = None
@@ -129,6 +131,8 @@ class SettingsManager(object):
         self.settingsPackages = ["app-settings"]
         self._knownAppSettings = {}
 
+        debug.println(debug.LEVEL_FINEST, 'INFO: Settings manager initialized')
+
     def _loadBackend(self):
         """Load specific backend for manage user settings"""