[orca] Add timestamps to debugging output



commit 8bfaf372bb55bbac93ebb3a40d7783febd0b6b58
Author: Joanmarie Diggs <jdiggs igalia com>
Date:   Thu Nov 26 15:24:29 2015 -0500

    Add timestamps to debugging output

 src/orca/debug.py                                  |   26 ++-
 src/orca/event_manager.py                          |  156 ++++++-------
 src/orca/generator.py                              |   36 +---
 src/orca/orca.py                                   |   70 +++---
 src/orca/script.py                                 |   26 +--
 src/orca/script_manager.py                         |   48 ++--
 src/orca/script_utilities.py                       |  158 ++++++--------
 src/orca/scripts/apps/Thunderbird/script.py        |    4 +-
 src/orca/scripts/apps/soffice/script.py            |    4 +-
 src/orca/scripts/apps/soffice/script_utilities.py  |    7 +-
 src/orca/scripts/apps/soffice/spellcheck.py        |    4 +-
 src/orca/scripts/default.py                        |   84 +++----
 src/orca/scripts/toolkits/Gecko/script.py          |   44 ++--
 .../scripts/toolkits/Gecko/script_utilities.py     |    2 +-
 src/orca/scripts/toolkits/WebKitGtk/script.py      |    2 +-
 src/orca/scripts/toolkits/clutter/script.py        |   22 +-
 src/orca/scripts/web/script.py                     |  242 ++++++++++----------
 src/orca/scripts/web/script_utilities.py           |  154 ++++++------
 src/orca/scripts/web/speech_generator.py           |   19 +-
 src/orca/settings_manager.py                       |   12 +-
 src/orca/speech.py                                 |   36 ++--
 src/orca/speechdispatcherfactory.py                |   34 ++--
 22 files changed, 559 insertions(+), 631 deletions(-)
---
diff --git a/src/orca/debug.py b/src/orca/debug.py
index ea9fd82..7538ce5 100644
--- a/src/orca/debug.py
+++ b/src/orca/debug.py
@@ -29,6 +29,7 @@ __copyright__ = "Copyright (c) 2005-2008 Sun Microsystems Inc."
 __license__   = "LGPL"
 
 import inspect
+import time
 import traceback
 import os
 import pyatspi
@@ -193,7 +194,7 @@ def printStack(level):
         traceback.print_stack(None, 100, debugFile)
         println(level)
 
-def println(level, text = ""):
+def println(level, text="", timestamp=False):
     """Prints the text to stderr unless debug is enabled.
 
     If debug is enabled the text will be redirected to the
@@ -206,6 +207,8 @@ def println(level, text = ""):
 
     if level >= debugLevel:
         text = text.replace("\ufffc", "[OBJ]")
+        if timestamp:
+            text = "%s - %s" % (time.strftime("%H:%M:%S"), text)
         if debugFile:
             try:
                 debugFile.writelines([text, "\n"])
@@ -248,7 +251,7 @@ def printResult(level, result=None):
     string = '%s\n%s %s' % (callString, 'RESULT:', result)
     println(level, '%s' % string)
 
-def printObjectEvent(level, event, sourceInfo=None):
+def printObjectEvent(level, event, sourceInfo=None, timestamp=False):
     """Prints out an Python Event object.  The given level may be
     overridden if the eventDebugLevel is greater.  Furthermore, only
     events with event types matching the eventDebugFilter regular
@@ -265,14 +268,14 @@ def printObjectEvent(level, event, sourceInfo=None):
 
     level = max(level, eventDebugLevel)
 
-    text = "OBJECT EVENT: %-40s detail=(%d,%d,%s)" \
+    text = "OBJECT EVENT: %s (%d, %d, %s)" \
            % (event.type, event.detail1, event.detail2, event.any_data)
-    println(level, text)
+    println(level, text, timestamp)
 
     if sourceInfo:
-        println(level, "             %s" % sourceInfo)
+        println(level, "             %s" % sourceInfo, timestamp)
 
-def printInputEvent(level, string):
+def printInputEvent(level, string, timestamp=False):
     """Prints out an input event.  The given level may be overridden
     if the eventDebugLevel (see setEventDebugLevel) is greater.
 
@@ -281,9 +284,9 @@ def printInputEvent(level, string):
     - string: the string representing the input event
     """
 
-    println(max(level, eventDebugLevel), string)
+    println(max(level, eventDebugLevel), string, timestamp)
 
-def printDetails(level, indent, accessible, includeApp=True):
+def printDetails(level, indent, accessible, includeApp=True, timestamp=False):
     """Lists the details of the given accessible with the given
     indentation.
 
@@ -296,7 +299,8 @@ def printDetails(level, indent, accessible, includeApp=True):
 
     if level >= debugLevel and accessible:
         println(level,
-                getAccessibleDetails(level, accessible, indent, includeApp))
+                getAccessibleDetails(level, accessible, indent, includeApp),
+                timestamp)
 
 def getAccessibleDetails(level, acc, indent="", includeApp=True):
     """Returns a string, suitable for printing, that describes the
@@ -364,9 +368,9 @@ def getAccessibleDetails(level, acc, indent="", includeApp=True):
         iface_string = "(exception calling listInterfaces)"
 
     try:
-        string += "name='%s' role='%s' state='%s' relations='%s' interfaces='%s'" \
+        string += "name='%s' role='%s' state='%s' \n%srelations='%s' interfaces='%s'" \
                   % (acc.name or 'None', acc.getRoleName(),
-                     state_string, rel_string, iface_string)
+                     state_string, indent, rel_string, iface_string)
     except:
         string += "(exception fetching data)"
 
diff --git a/src/orca/event_manager.py b/src/orca/event_manager.py
index b1a5e1a..727ed3b 100644
--- a/src/orca/event_manager.py
+++ b/src/orca/event_manager.py
@@ -44,8 +44,8 @@ class EventManager:
     EMBEDDED_OBJECT_CHARACTER = '\ufffc'
 
     def __init__(self, asyncMode=True):
-        debug.println(debug.LEVEL_FINEST, 'INFO: Initializing event manager')
-        debug.println(debug.LEVEL_FINEST, 'INFO: Async Mode is %s' % asyncMode)
+        debug.println(debug.LEVEL_INFO, 'EVENT MANAGER: Initializing', True)
+        debug.println(debug.LEVEL_INFO, 'EVENT MANAGER: Async Mode is %s' % asyncMode, True)
         self._asyncMode = asyncMode
         self._scriptListenerCounts = {}
         self.registry = pyatspi.Registry
@@ -60,28 +60,28 @@ class EventManager:
         self._ignoredEvents = ['object:bounds-changed',
                                'object:state-changed:defunct',
                                'object:property-change:accessible-parent']
-        debug.println(debug.LEVEL_FINEST, 'INFO: Event manager initialized')
+        debug.println(debug.LEVEL_INFO, 'Event manager initialized', True)
 
     def activate(self):
         """Called when this presentation manager is activated."""
 
-        debug.println(debug.LEVEL_FINEST, 'INFO: Activating event manager')
+        debug.println(debug.LEVEL_INFO, 'EVENT MANAGER: Activating', True)
         self._registerListener("window:activate")
         self._registerListener("window:deactivate")
         self._registerListener("object:children-changed")
         self._registerListener("mouse:button")
         self._active = True
-        debug.println(debug.LEVEL_FINEST, 'INFO: Event manager activated')
+        debug.println(debug.LEVEL_INFO, 'EVENT MANAGER: Activated', True)
 
     def deactivate(self):
         """Called when this event manager is deactivated."""
 
-        debug.println(debug.LEVEL_FINEST, 'INFO: Dectivating event manager')
+        debug.println(debug.LEVEL_INFO, 'EVENT MANAGER: Dectivating', True)
         self._active = False
         for eventType in list(self._scriptListenerCounts.keys()):
             self.registry.deregisterEventListener(self._enqueue, eventType)
         self._scriptListenerCounts = {}
-        debug.println(debug.LEVEL_FINEST, 'INFO: Event manager deactivated')
+        debug.println(debug.LEVEL_INFO, 'EVENT MANAGER: Deactivated', True)
 
     def ignoreEventTypes(self, eventTypeList):
         for eventType in eventTypeList:
@@ -96,38 +96,39 @@ class EventManager:
     def _ignore(self, event):
         """Returns True if this event should be ignored."""
 
-        msg = '\nINFO: %s for %s in %s' % (event.type, event.source, event.host_application)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, '')
+        msg = 'EVENT MANAGER: %s for %s in %s' % (event.type, event.source, event.host_application)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if not self._active:
-            msg = 'INFO: Ignoring because event manager is not active'
-            debug.println(debug.LEVEL_INFO, msg)
+            msg = 'EVENT MANAGER: Ignoring because event manager is not active'
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if list(filter(event.type.startswith, self._ignoredEvents)):
-            msg = 'INFO: Ignoring because event type is ignored'
-            debug.println(debug.LEVEL_INFO, msg)
+            msg = 'EVENT MANAGER: Ignoring because event type is ignored'
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if event.type.startswith('window'):
-            msg = 'INFO: Not ignoring because event type is never ignored'
-            debug.println(debug.LEVEL_INFO, msg)
+            msg = 'EVENT MANAGER: Not ignoring because event type is never ignored'
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         # This should ultimately be changed as there are valid reasons
         # to handle these events at the application level.
         if event.type.startswith('object:children-changed:remove') \
            and event.source != self.registry.getDesktop(0):
-            msg = 'INFO: Ignoring because event type is ignored'
-            debug.println(debug.LEVEL_INFO, msg)
+            msg = 'EVENT MANAGER: Ignoring because event type is ignored'
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if event.type.startswith('object:text-changed') and event.type.endswith('system'):
             # We should also get children-changed events telling us the same thing.
             # Getting a bunch of both can result in a flood that grinds us to a halt.
             if event.any_data == self.EMBEDDED_OBJECT_CHARACTER:
-                msg = 'INFO: Text changed event for embedded object. Who cares?'
-                debug.println(debug.LEVEL_INFO, msg)
+                msg = 'EVENT MANAGER: Text changed event for embedded object. Who cares?'
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return True
 
         try:
@@ -143,18 +144,18 @@ class EventManager:
             msg = 'ERROR: %s from potentially-defunct source %s in app %s (%s, %s, %s)' % \
                   (event.type, event.source, event.host_application, event.detail1,
                    event.detail2, event.any_data)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
         if state.contains(pyatspi.STATE_DEFUNCT):
             msg = 'ERROR: %s from defunct source %s in app %s (%s, %s, %s)' % \
                   (event.type, event.source, event.host_application, event.detail1,
                    event.detail2, event.any_data)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if role in [pyatspi.ROLE_FILLER]:
-            msg = 'INFO: Ignoring because events from this role are ignored'
-            debug.println(debug.LEVEL_INFO, msg)
+            msg = 'EVENT MANAGER: Ignoring because events from this role are ignored'
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if event.type.startswith('object:state-changed:showing'):
@@ -165,9 +166,9 @@ class EventManager:
                             pyatspi.ROLE_PANEL,
                             pyatspi.ROLE_STATUS_BAR,
                             pyatspi.ROLE_TOOL_TIP]:
-                msg = 'INFO: %s for %s in app %s. Who cares?' % \
+                msg = 'EVENT MANAGER: %s for %s in app %s. Who cares?' % \
                       (event.type, event.source, event.host_application)
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return True
 
         if event.type.startswith('object:children-changed:add') \
@@ -175,7 +176,7 @@ class EventManager:
             if not event.any_data:
                 msg = 'ERROR: %s without child from source %s in app %s' % \
                       (event.type, event.source, event.host_application)
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return True
             try:
                 state = event.any_data.getState()
@@ -183,12 +184,12 @@ class EventManager:
             except:
                 msg = 'ERROR: %s with potentially-defunct child %s from source %s in app %s' % \
                       (event.type, event.any_data, event.source, event.host_application)
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return True
             if state.contains(pyatspi.STATE_DEFUNCT):
                 msg = 'ERROR: %s with defunct child %s from source %s in app %s' % \
                       (event.type, event.any_data, event.source, event.host_application)
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return True
 
             # This should be safe. We do not have a reason to present a newly-added,
@@ -197,13 +198,13 @@ class EventManager:
             # reason for ignoring it here rather than quickly processing it is the
             # potential for event floods like we're seeing from matrix.org.
             if role == pyatspi.ROLE_IMAGE:
-                msg = 'INFO: %s for child image %s from source %s in app %s. Who cares?' % \
+                msg = 'EVENT MANAGER: %s for child image %s from source %s in app %s. Who cares?' % \
                       (event.type, event.any_data, event.source, event.host_application)
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return True
 
-        msg = 'INFO: Not ignoring due to lack of cause'
-        debug.println(debug.LEVEL_INFO, msg)
+        msg = 'EVENT MANAGER: Not ignoring due to lack of cause'
+        debug.println(debug.LEVEL_INFO, msg, True)
         return False
 
     def _addToQueue(self, event, asyncMode):
@@ -246,13 +247,12 @@ class EventManager:
         else:
             return
 
-        eType = str(e.type).upper()
         if isEnqueue:
-            string = "----------> QUEUEING %s %s" % (eType, data.upper())
+            string = "EVENT MANAGER: Queueing %s %s" % (e.type, data)
         else:
-            string = "DEQUEUED %s %s <----------" % (eType, data.upper())
+            string = "EVENT MANAGER: Dequeued %s %s" % (e.type, data)
 
-        debug.println(debug.LEVEL_ALL, string)
+        debug.println(debug.LEVEL_INFO, string, True)
 
     def _enqueue(self, e):
         """Handles the enqueueing of all events destined for scripts.
@@ -263,9 +263,9 @@ class EventManager:
 
         if debug.debugEventQueue:
             if self._enqueueCount:
-                msg = "_enqueue entered before exiting (count = %d)" \
+                msg = "EVENT MANAGER: _enqueue entered before exiting (count = %d)" \
                     % self._enqueueCount
-                debug.println(debug.LEVEL_ALL, msg)
+                debug.println(debug.LEVEL_ALL, msg, True)
             self._enqueueCount += 1
 
         inputEvents = (input_event.KeyboardEvent, input_event.BrailleEvent)
@@ -275,7 +275,7 @@ class EventManager:
             ignore = isObjectEvent and self._ignore(e)
         except:
             msg = 'ERROR: Exception evaluating event: %s' % e
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             ignore = True
         if ignore:
             if debug.debugEventQueue:
@@ -310,8 +310,8 @@ class EventManager:
         rerun = True
 
         if debug.debugEventQueue:
-            debug.println(debug.LEVEL_ALL,
-                          "event_manager._dequeue %d" % self._dequeueCount)
+            msg = 'EVENT MANAGER: Dequeue %d' % self._dequeueCount
+            debug.println(debug.LEVEL_ALL, msg, True)
             self._dequeueCount += 1
 
         try:
@@ -361,8 +361,8 @@ class EventManager:
                 rerun = False # destroy and don't call again
             self._gidleLock.release()
         except queue.Empty:
-            debug.println(debug.LEVEL_SEVERE,
-                          "event_manager._dequeue: the event queue is empty!")
+            msg = 'EVENT MANAGER: Attempted dequeue, but the event queue is empty'
+            debug.println(debug.LEVEL_SEVERE, msg, True)
             self._gidleId = 0
             rerun = False # destroy and don't call again
         except:
@@ -370,8 +370,8 @@ class EventManager:
 
         if debug.debugEventQueue:
             self._dequeueCount -= 1
-            debug.println(debug.LEVEL_ALL,
-                          "Leaving _dequeue. Count: %d" % self._dequeueCount)
+            msg = 'EVENT MANAGER: Leaving _dequeue. Count: %d' % self._dequeueCount
+            debug.println(debug.LEVEL_ALL, msg, True)
 
         return rerun
 
@@ -382,9 +382,8 @@ class EventManager:
         - eventType: the event type.
         """
 
-        debug.println(debug.LEVEL_FINEST,
-                      'INFO: Event manager registering listener for: %s' \
-                       % eventType)
+        msg = 'EVENT MANAGER: registering listener for: %s' % eventType
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if eventType in self._scriptListenerCounts:
             self._scriptListenerCounts[eventType] += 1
@@ -399,9 +398,8 @@ class EventManager:
         - eventType: the event type.
         """
 
-        debug.println(debug.LEVEL_FINEST,
-                      'INFO: Event manager deregistering listener for: %s' \
-                       % eventType)
+        msg = 'EVENT MANAGER: deregistering listener for: %s' % eventType
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if not eventType in self._scriptListenerCounts:
             return
@@ -419,9 +417,8 @@ class EventManager:
         - script: the script.
         """
 
-        debug.println(debug.LEVEL_FINEST,
-                      'INFO: Event manager registering listeners for: %s' \
-                       % script)
+        msg = 'EVENT MANAGER: registering listeners for: %s' % script
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         for eventType in list(script.listeners.keys()):
             self._registerListener(eventType)
@@ -434,9 +431,8 @@ class EventManager:
         - script: the script.
         """
 
-        debug.println(debug.LEVEL_FINEST,
-                      'INFO: Event manager deregistering listeners for: %s' \
-                       % script)
+        msg = 'EVENT MANAGER: deregistering listeners for: %s' % script
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         for eventType in list(script.listeners.keys()):
             self._deregisterListener(eventType)
@@ -456,10 +452,8 @@ 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)
+        msg = 'EVENT MANAGER: registering keystroke listener function: %s' % function
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if mask == None:
             mask = list(range(256))
@@ -472,10 +466,8 @@ 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)
+        msg = 'EVENT MANAGER: deregistering keystroke listener function: %s' % function
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if mask == None:
             mask = list(range(256))
@@ -534,18 +526,18 @@ class EventManager:
             app = event.host_application or event.source.getApplication()
             if app and app.getState().contains(pyatspi.STATE_DEFUNCT):
                 msg = 'WARNING: App is defunct. Cannot get script for event.'
-                debug.println(debug.LEVEL_WARNING, msg)
+                debug.println(debug.LEVEL_WARNING, msg, True)
                 return None
         except:
             msg = 'WARNING: Exception when getting script for event.'
-            debug.println(debug.LEVEL_WARNING, msg)
+            debug.println(debug.LEVEL_WARNING, msg, True)
         else:
-            msg = 'INFO: Getting script for %s from %s' % (event.type, app)
-            debug.println(debug.LEVEL_INFO, msg)
+            msg = 'EVENT MANAGER: Getting script for %s' % app
+            debug.println(debug.LEVEL_INFO, msg, True)
             script = _scriptManager.getScript(app, event.source)
 
-        msg = 'INFO: Script for %s from %s is %s' % (event.type, app, script)
-        debug.println(debug.LEVEL_INFO, msg)
+        msg = 'EVENT MANAGER: Script is %s' % script
+        debug.println(debug.LEVEL_INFO, msg, True)
         return script
 
     def _isActivatableEvent(self, event, script=None):
@@ -607,7 +599,7 @@ class EventManager:
         - e: an at-spi event.
         """
 
-        debug.printObjectEvent(debug.LEVEL_FINEST, event)
+        debug.printObjectEvent(debug.LEVEL_INFO, event, timestamp=True)
         eType = event.type
 
         if eType.startswith("object:children-changed:remove"):
@@ -635,8 +627,8 @@ class EventManager:
         try:
             state = event.source.getState()
         except (LookupError, RuntimeError):
-            debug.println(debug.LEVEL_WARNING,
-                          "Error while processing event: %s" % eType)
+            msg = 'ERROR: Could not process event: %s' % eType
+            debug.println(debug.LEVEL_WARNING, msg, True)
             if eType.startswith("window:deactivate"):
                 orca_state.locusOfFocus = None
                 orca_state.activeWindow = None
@@ -645,24 +637,26 @@ class EventManager:
             return
 
         if state and state.contains(pyatspi.STATE_DEFUNCT):
-            debug.println(debug.LEVEL_FINEST, "IGNORING DEFUNCT OBJECT")
+            msg = 'EVENT MANAGER: Ignoring defunct object: %s' % event.source
+            debug.println(debug.LEVEL_INFO, msg, True)
             if eType.startswith("window:deactivate"):
                 orca_state.locusOfFocus = None
                 orca_state.activeWindow = None
             return
 
         if state and state.contains(pyatspi.STATE_ICONIFIED):
-            debug.println(debug.LEVEL_FINEST, "IGNORING ICONIFIED OBJECT")
+            msg = 'EVENT MANAGER: Ignoring iconified object: %s' % event.source
+            debug.println(debug.LEVEL_INFO, True)
             return
 
         if not debug.eventDebugFilter or debug.eventDebugFilter.match(eType) \
            and not eType.startswith("mouse:"):
-            debug.printDetails(debug.LEVEL_FINEST, "    ", event.source)
+            debug.printDetails(debug.LEVEL_INFO, ' ' * 11, event.source)
 
         script = self._getScriptForEvent(event)
         if not script:
             msg = 'ERROR: Could not get script for %s' % event
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         setNewActiveScript, reason = self._isActivatableEvent(event, script)
@@ -671,20 +665,20 @@ class EventManager:
                 app = event.host_application or event.source.getApplication()
             except:
                 msg = 'ERROR: Could not get application for %s' % event.source
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return
             try:
                 _scriptManager.setActiveScript(script, reason)
             except:
                 msg = 'ERROR: Could not set active script for %s' % event.source
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return
 
         try:
             script.processObjectEvent(event)
         except:
             msg = 'ERROR: Could not process %s' % event.type
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             debug.printException(debug.LEVEL_INFO)
 
     def processKeyboardEvent(self, keyboardEvent):
diff --git a/src/orca/generator.py b/src/orca/generator.py
index 0192dcc..08eb0a6 100644
--- a/src/orca/generator.py
+++ b/src/orca/generator.py
@@ -123,16 +123,9 @@ class Generator:
                             arg = arg.replace("' is not defined", "")
                             if arg not in self._methodsDict:
                                 debug.printException(debug.LEVEL_SEVERE)
-                                debug.println(
-                                    debug.LEVEL_SEVERE,
-                                    "Unable to find function for '%s'\n" % arg)
                             globalsDict[arg] = []
                         except:
                             debug.printException(debug.LEVEL_SEVERE)
-                            debug.println(
-                                debug.LEVEL_SEVERE,
-                                "While processing '%s' '%s' '%s' '%s'" \
-                                % (roleKey, key, evalString, globalsDict))
                             break
 
     def _overrideRole(self, newRole, args):
@@ -188,8 +181,8 @@ class Generator:
         try:
             globalsDict['role'] = args.get('role', obj.getRole())
         except:
-            msg = 'Cannot generate presentation for: %s. Aborting' % obj
-            debug.println(debug.LEVEL_FINEST, msg)
+            msg = 'ERROR: Cannot generate presentation for: %s. Aborting' % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
             return result
         try:
             # We sometimes want to override the role.  We'll keep the
@@ -226,17 +219,8 @@ class Generator:
             else:
                 firstTimeCalled = False
 
-            details = debug.getAccessibleDetails(debug.LEVEL_ALL, obj)
-            duration = "%.4f" % (time.time() - startTime)
-            debug.println(debug.LEVEL_ALL, "\nPREPARATION TIME: %s" % duration)
-            debug.println(
-                debug.LEVEL_ALL,
-                "generate %s for %s %s\n(args=%s)\nusing '%s'" \
-                % (self._mode,
-                   args['formatType'], 
-                   details,
-                   repr(args),
-                   formatting))
+            msg = '%s GENERATOR: Starting generation for %s' % (self._mode.upper(), obj)
+            debug.println(debug.LEVEL_INFO, msg, True)
 
             assert(formatting)
             while True:
@@ -252,24 +236,22 @@ class Generator:
                     arg = arg.replace("' is not defined", "")
                     if arg not in self._methodsDict:
                         debug.printException(debug.LEVEL_SEVERE)
-                        debug.println(
-                            debug.LEVEL_SEVERE,
-                            "Unable to find function for '%s'\n" % arg)
                         break
                     globalsDict[arg] = self._methodsDict[arg](obj, **args)
                     duration = "%.4f" % (time.time() - currentTime)
                     debug.println(debug.LEVEL_ALL,
-                                  "GENERATION  TIME: %s  ---->  %s=%s" \
+                                  "           GENERATION TIME: %s  ---->  %s=%s" \
                                   % (duration, arg, repr(globalsDict[arg])))
+
         except:
             debug.printException(debug.LEVEL_SEVERE)
             result = []
 
         duration = "%.4f" % (time.time() - startTime)
-        debug.println(debug.LEVEL_ALL, "COMPLETION  TIME: %s" % duration)
-        debug.println(debug.LEVEL_ALL, "generate %s results:" % self._mode)
+        debug.println(debug.LEVEL_ALL, "           COMPLETION TIME: %s" % duration)
+        debug.println(debug.LEVEL_ALL, "%s GENERATOR: Results:" % self._mode.upper(), True)
         for element in result:
-            debug.println(debug.LEVEL_ALL, "  %s" % element)
+            debug.println(debug.LEVEL_ALL, "           %s" % element)
 
         return result
 
diff --git a/src/orca/orca.py b/src/orca/orca.py
index 9283f8b..14096e1 100644
--- a/src/orca/orca.py
+++ b/src/orca/orca.py
@@ -139,8 +139,8 @@ def setLocusOfFocus(event, obj, notifyScript=True, force=False):
     """
 
     if not force and obj == orca_state.locusOfFocus:
-        msg = "INFO: Setting locusOfFocus to existing locusOfFocus"
-        debug.println(debug.LEVEL_INFO, msg)
+        msg = "ORCA: Setting locusOfFocus to existing locusOfFocus"
+        debug.println(debug.LEVEL_INFO, msg, True)
         return
 
     if event and (orca_state.activeScript and not orca_state.activeScript.app):
@@ -151,36 +151,36 @@ def setLocusOfFocus(event, obj, notifyScript=True, force=False):
     try:
         oldFocus.getRole()
     except:
-        msg = "INFO: Old locusOfFocus is null or defunct"
-        debug.println(debug.LEVEL_INFO, msg)
+        msg = "ORCA: Old locusOfFocus is null or defunct"
+        debug.println(debug.LEVEL_INFO, msg, True)
         oldFocus = None
 
     if not obj:
-        msg = "INFO: New locusOfFocus is null (being cleared)"
-        debug.println(debug.LEVEL_INFO, msg)
+        msg = "ORCA: New locusOfFocus is null (being cleared)"
+        debug.println(debug.LEVEL_INFO, msg, True)
         orca_state.locusOfFocus = None
         return
 
     if orca_state.activeScript:
         if orca_state.activeScript.utilities.isZombie(obj):
             msg = "ERROR: New locusOfFocus (%s) is zombie. Not updating." % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
         if orca_state.activeScript.utilities.isDead(obj):
             msg = "ERROR: New locusOfFocus (%s) is dead. Not updating." % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
-    msg = "INFO: Changing locusOfFocus from %s to %s" % (oldFocus, obj)
-    debug.println(debug.LEVEL_INFO, msg)
+    msg = "ORCA: Changing locusOfFocus from %s to %s" % (oldFocus, obj)
+    debug.println(debug.LEVEL_INFO, msg, True)
     orca_state.locusOfFocus = obj
 
     if not notifyScript:
         return
 
     if not orca_state.activeScript:
-        msg = "INFO: Cannot notify active script because there isn't one"
-        debug.println(debug.LEVEL_INFO, msg)
+        msg = "ORCA: Cannot notify active script because there isn't one"
+        debug.println(debug.LEVEL_INFO, msg, True)
         return
 
     orca_state.activeScript.locusOfFocusChanged(event, oldFocus, orca_state.locusOfFocus)
@@ -406,7 +406,7 @@ 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')
+    debug.println(debug.LEVEL_INFO, 'ORCA: Loading User Settings', True)
 
     global _userSettings
 
@@ -425,7 +425,7 @@ def loadUserSettings(script=None, inputEvent=None, skipReloadMessage=False):
             _settingsManager.setProfile(_profile)
             reloaded = True
         except ImportError:
-            debug.printException(debug.LEVEL_FINEST)
+            debug.printException(debug.LEVEL_INFO)
         except:
             debug.printException(debug.LEVEL_SEVERE)
     else:
@@ -433,7 +433,7 @@ def loadUserSettings(script=None, inputEvent=None, skipReloadMessage=False):
         try:
             _userSettings = _settingsManager.getGeneralSettings(_profile)
         except ImportError:
-            debug.printException(debug.LEVEL_FINEST)
+            debug.printException(debug.LEVEL_INFO)
         except:
             debug.printException(debug.LEVEL_SEVERE)
 
@@ -447,23 +447,19 @@ def loadUserSettings(script=None, inputEvent=None, skipReloadMessage=False):
             speech.init()
             if reloaded and not skipReloadMessage:
                 script.speakMessage(messages.SETTINGS_RELOADED)
-            debug.println(debug.LEVEL_CONFIGURATION,
-                          "Speech module has been initialized.")
         except:
             debug.printException(debug.LEVEL_SEVERE)
-            debug.println(debug.LEVEL_SEVERE,
-                          "Could not initialize connection to speech.")
     else:
-        debug.println(debug.LEVEL_CONFIGURATION,
-                      "Speech module has NOT been initialized.")
+        msg = 'ORCA: Speech is not enabled in settings'
+        debug.println(debug.LEVEL_INFO, msg, True)
 
     if _settingsManager.getSetting('enableBraille'):
         try:
             braille.init(_processBrailleEvent, settings.tty)
         except:
             debug.printException(debug.LEVEL_WARNING)
-            debug.println(debug.LEVEL_WARNING,
-                          "Could not initialize connection to braille.")
+            msg = 'ORCA: Could not initialize connection to braille.'
+            debug.println(debug.LEVEL_WARNING, msg, True)
 
     # I'm not sure where else this should go. But it doesn't really look
     # right here.
@@ -486,7 +482,7 @@ def loadUserSettings(script=None, inputEvent=None, skipReloadMessage=False):
     _scriptManager.activate()
     _eventManager.activate()
 
-    debug.println(debug.LEVEL_FINEST, 'INFO: User Settings Loaded')
+    debug.println(debug.LEVEL_INFO, 'ORCA: User Settings Loaded', True)
 
     return True
 
@@ -589,7 +585,7 @@ def init(registry):
     module has already been initialized.
     """
 
-    debug.println(debug.LEVEL_FINEST, 'INFO: Initializing Orca module')
+    debug.println(debug.LEVEL_INFO, 'ORCA: Initializing', True)
 
     global _initialized
 
@@ -615,7 +611,7 @@ def init(registry):
     if a11yAppSettings:
         a11yAppSettings.connect('changed', onEnabledChanged)
 
-    debug.println(debug.LEVEL_FINEST, 'INFO: Orca module initialized')
+    debug.println(debug.LEVEL_INFO, 'ORCA: Initialized', True)
 
     return True
 
@@ -623,7 +619,7 @@ def start(registry, cacheValues):
     """Starts Orca.
     """
 
-    debug.println(debug.LEVEL_FINEST, 'INFO: Starting Orca')
+    debug.println(debug.LEVEL_INFO, 'ORCA: Starting', True)
 
     if not _initialized:
         init(registry)
@@ -640,7 +636,7 @@ def start(registry, cacheValues):
     if cacheValues:
         pyatspi.setCacheLevel(pyatspi.CACHE_PROPERTIES)
 
-    debug.println(debug.LEVEL_FINEST, 'INFO: Orca starting registry')
+    debug.println(debug.LEVEL_INFO, 'ORCA: Starting registry', True)
     registry.start(gil=False)
 
 def die(exitCode=1):
@@ -656,8 +652,8 @@ def die(exitCode=1):
         os.kill(pid, signal.SIGTERM)
 
 def timeout(signum=None, frame=None):
-    debug.println(debug.LEVEL_SEVERE,
-                  "TIMEOUT: something has hung.  Aborting.")
+    msg = 'TIMEOUT: something has hung. Aborting.'
+    debug.println(debug.LEVEL_SEVERE, msg, True)
     debug.printStack(debug.LEVEL_ALL)
     debug.examineProcesses()
     die(EXIT_CODE_HANG)
@@ -669,7 +665,7 @@ def shutdown(script=None, inputEvent=None):
     was never initialized.
     """
 
-    debug.println(debug.LEVEL_FINEST, 'INFO: Shutting down Orca')
+    debug.println(debug.LEVEL_INFO, 'ORCA: Shutting down', True)
 
     global _initialized
 
@@ -702,10 +698,10 @@ def shutdown(script=None, inputEvent=None):
     _initialized = False
     _restoreXmodmap(_orcaModifiers)
 
-    debug.println(debug.LEVEL_FINEST, 'INFO: Orca stopping registry')
+    debug.println(debug.LEVEL_INFO, 'ORCA: Stopping registry', True)
     pyatspi.Registry.stop()
 
-    debug.println(debug.LEVEL_FINEST, 'INFO: Orca shutdown complete')
+    debug.println(debug.LEVEL_INFO, 'ORCA: Shutdown complete', True)
 
     return True
 
@@ -713,12 +709,8 @@ exitCount = 0
 def shutdownOnSignal(signum, frame):
     global exitCount
 
-    debug.println(debug.LEVEL_ALL,
-                  "Shutting down and exiting due to signal = %d" \
-                  % signum)
-
-    debug.println(debug.LEVEL_ALL, "Current stack is:")
-    debug.printStack(debug.LEVEL_ALL)
+    msg = 'ORCA: Shutting down and exiting due to signal=%d' % signum
+    debug.println(debug.LEVEL_INFO, msg, True)
 
     # Well...we'll try to exit nicely, but if we keep getting called,
     # something bad is happening, so just quit.
diff --git a/src/orca/script.py b/src/orca/script.py
index cbd1641..e4abebd 100644
--- a/src/orca/script.py
+++ b/src/orca/script.py
@@ -81,8 +81,8 @@ class Script:
             try:
                 self.name = self.app.name
             except (LookupError, RuntimeError):
-                msg = 'script.__init__: Error trying to get app.name'
-                debug.println(debug.LEVEL_FINE, msg)
+                msg = 'ERROR: Could not get name of script app %s'
+                debug.println(debug.LEVEL_INFO, msg, True)
                 self.name = "default"
         else:
             self.name = "default"
@@ -124,7 +124,8 @@ class Script:
         self.findCommandRun = False
         self._lastCommandWasStructNav = False
 
-        debug.println(debug.LEVEL_FINE, "NEW SCRIPT: %s" % self.name)
+        msg = 'SCRIPT: %s initialized' % self.name
+        debug.println(debug.LEVEL_INFO, msg, True)
 
     def getListeners(self):
         """Sets up the AT-SPI event listeners for this script.
@@ -333,8 +334,8 @@ class Script:
         try:
             role = event.source.getRole()
         except (LookupError, RuntimeError):
-            msg = 'script.processObjectEvent: Error getting role'
-            debug.println(debug.LEVEL_FINE, msg)
+            msg = 'ERROR: Exception getting role for %s' % event.source
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         # Check to see if we really want to process this event.
@@ -410,12 +411,10 @@ class Script:
             reason = "appears to be duplicate state-changed event"
 
         if skip:
-            debug.println(debug.LEVEL_FINE,
-                          "script.skipObjectEvent: skipped due to %s:" \
-                          % reason)
-            debug.println(debug.LEVEL_FINE,
-                          "\tType: %s\n\tSource: %s\n\tDetail1: %s"
-                          % (cachedEvent.type, cachedEvent.source, cachedEvent.detail1))
+            eventDetails = '           %s' % str(cachedEvent).replace('\t', ' ' * 11)
+            msg = 'SCRIPT: Skipping object event due to %s\n%s' % (reason, eventDetails)
+            debug.println(debug.LEVEL_INFO, msg, True)
+
         return skip
 
     def checkKeyboardEventData(self, keyboardEvent):
@@ -435,9 +434,8 @@ class Script:
             from gi.repository import Gdk
             keyboardEvent.keyval_name = Gdk.keyval_name(keyboardEvent.id)
         except:
-            debug.println(debug.LEVEL_FINE,
-                          "Could not obtain keyval_name for id: %d" \
-                          % keyboardEvent.id)
+            msg = 'ERROR: Exception getting keyval_name for id: %d' % keyboardEvent.id
+            debug.println(debug.LEVEL_INFO, msg, True)
 
     def consumesKeyboardEvent(self, keyboardEvent):
         """Called when a key is pressed on the keyboard.
diff --git a/src/orca/script_manager.py b/src/orca/script_manager.py
index 981c95c..4fa5e71 100644
--- a/src/orca/script_manager.py
+++ b/src/orca/script_manager.py
@@ -33,7 +33,7 @@ from .scripts import apps, toolkits
 class ScriptManager:
 
     def __init__(self):
-        debug.println(debug.LEVEL_FINEST, 'INFO: Initializing script manager')
+        debug.println(debug.LEVEL_INFO, 'SCRIPT MANAGER: Initializing', True)
         self.appScripts = {}
         self.toolkitScripts = {}
         self._appModules = apps.__all__
@@ -65,28 +65,28 @@ class ScriptManager:
              'gnome-terminal-server': 'gnome-terminal'}
 
         self.setActiveScript(None, "__init__")
-        debug.println(debug.LEVEL_FINEST, 'INFO: Script manager initialized')
+        debug.println(debug.LEVEL_INFO, 'SCRIPT MANAGER: Initialized', True)
 
     def activate(self):
         """Called when this script manager is activated."""
 
-        debug.println(debug.LEVEL_FINEST, 'INFO: Activating script manager')
+        debug.println(debug.LEVEL_INFO, 'SCRIPT MANAGER: Activating', True)
         self._defaultScript = self.getScript(None)
         self._defaultScript.registerEventListeners()
         self.setActiveScript(self._defaultScript, "activate")
-        debug.println(debug.LEVEL_FINEST, 'INFO: Script manager activated')
+        debug.println(debug.LEVEL_INFO, 'SCRIPT MANAGER: Activated', True)
 
     def deactivate(self):
         """Called when this script manager is deactivated."""
 
-        debug.println(debug.LEVEL_FINEST, 'INFO: Dectivating script manager')
+        debug.println(debug.LEVEL_INFO, 'SCRIPT MANAGER: Dectivating', True)
         if self._defaultScript:
             self._defaultScript.deregisterEventListeners()
         self._defaultScript = None
         self.setActiveScript(None, "deactivate")
         self.appScripts = {}
         self.toolkitScripts = {}
-        debug.println(debug.LEVEL_FINEST, 'INFO: Script manager deactivated')
+        debug.println(debug.LEVEL_INFO, 'SCRIPT MANAGER: Deactivated', True)
 
     def getModuleName(self, app):
         """Returns the module name of the script to use for application app."""
@@ -95,8 +95,8 @@ class ScriptManager:
             appAndNameExist = app != None and app.name != ''
         except (LookupError, RuntimeError):
             appAndNameExist = False
-            debug.println(debug.LEVEL_FINEST,
-                          "getModuleName: %s no longer exists" % app)
+            msg = 'ERROR: %s no longer exists' % app
+            debug.println(debug.LEVEL_INFO, msg, True)
 
         if not appAndNameExist:
             return None
@@ -116,8 +116,8 @@ class ScriptManager:
                     name = names[0]
                     break
 
-        debug.println(debug.LEVEL_FINEST, "mapped %s to %s" % (app.name, name))
-
+        msg = 'SCRIPT MANAGER: mapped %s to %s' % (app.name, name)
+        debug.println(debug.LEVEL_INFO, msg, True)
         return name
 
     def _toolkitForObject(self, obj):
@@ -145,28 +145,24 @@ class ScriptManager:
         script = None
         for package in self._scriptPackages:
             moduleName = '.'.join((package, name))
-            debug.println(debug.LEVEL_FINE, "Looking for %s" % moduleName)
             try:
                 module = importlib.import_module(moduleName)
             except ImportError:
-                debug.println(
-                    debug.LEVEL_FINE, "Could not import %s" % moduleName)
                 continue
             except OSError:
                 debug.examineProcesses()
 
-            debug.println(debug.LEVEL_FINE, "Found %s" % moduleName)
+            debug.println(debug.LEVEL_INFO, 'SCRIPT MANAGER: Found %s' % moduleName, True)
             try:
                 if hasattr(module, 'getScript'):
                     script = module.getScript(app)
                 else:
                     script = module.Script(app)
-                debug.println(debug.LEVEL_FINE, "Loaded %s" % moduleName)
                 break
             except:
-                debug.printException(debug.LEVEL_FINEST)
-                debug.println(
-                    debug.LEVEL_FINEST, "Could not load %s" % moduleName)
+                debug.printException(debug.LEVEL_INFO)
+                msg = 'ERROR: Could not load %s' % moduleName
+                debug.println(debug.LEVEL_INFO, msg, True)
 
         return script
 
@@ -186,15 +182,16 @@ class ScriptManager:
         try:
             toolkitName = getattr(app, "toolkitName", None)
         except (LookupError, RuntimeError):
-            msg = "Error getting toolkitName for: %s" % app
-            debug.println(debug.LEVEL_FINE, msg)
+            msg = 'ERROR: Exception getting toolkitName for: %s' % app
+            debug.println(debug.LEVEL_INFO, msg, True)
         else:
             if app and toolkitName:
                 script = self._newNamedScript(app, toolkitName)
 
         if not script:
             script = self.getDefaultScript(app)
-            debug.println(debug.LEVEL_FINE, "Default script created")
+            msg = 'SCRIPT MANAGER: Default script created'
+            debug.println(debug.LEVEL_INFO, msg, True)
 
         return script
 
@@ -241,9 +238,9 @@ class ScriptManager:
                 appScript = self._createScript(app, None)
                 self.appScripts[app] = appScript
         except:
-            msg = "WARNING: Exception getting app script."
+            msg = 'WARNING: Exception getting app script.'
             debug.printException(debug.LEVEL_ALL)
-            debug.println(debug.LEVEL_WARNING, msg)
+            debug.println(debug.LEVEL_WARNING, msg, True)
             appScript = self.getDefaultScript()
 
         # Only defer to the toolkit script for this object if the app script
@@ -272,8 +269,9 @@ class ScriptManager:
             return
 
         newScript.activate()
-        debug.println(debug.LEVEL_FINE, "ACTIVE SCRIPT: %s (reason=%s)" \
-                          % (newScript.name, reason))
+        msg = 'SCRIPT MANAGER: Setting active script: %s (reason=%s)' % \
+              (newScript.name, reason)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
     def reclaimScripts(self):
         """Compares the list of known scripts to the list of known apps,
diff --git a/src/orca/script_utilities.py b/src/orca/script_utilities.py
index 2bdd439..44503bf 100644
--- a/src/orca/script_utilities.py
+++ b/src/orca/script_utilities.py
@@ -105,7 +105,7 @@ class Utilities:
             state = obj.getState()
         except:
             msg = "ERROR: Exception getting state of %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if not state.contains(pyatspi.STATE_ACTIVE):
@@ -123,11 +123,11 @@ class Utilities:
         window.clearCache()
         if not self._isActiveAndShowingAndNotIconified(window):
             msg = "INFO: %s is not active and showing, or is iconified" % window
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         msg = "INFO: %s can be active window" % window
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         return True
 
     def activeWindow(self, *apps):
@@ -140,12 +140,12 @@ class Utilities:
 
         if not candidates:
             msg = "ERROR: Unable to find active window from %s" % list(map(str, apps))
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return None
 
         if len(candidates) == 1:
             msg = "INFO: Active window is %s" % candidates[0]
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return candidates[0]
 
         # Sorting by size in a lame attempt to filter out the "desktop" frame of various
@@ -155,10 +155,10 @@ class Utilities:
         # This is why we can't have nice things.
         candidates = sorted(candidates, key=functools.cmp_to_key(self.sizeComparison))
         msg = "WARNING: These windows all claim to be active: %s" % list(map(str, candidates))
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         msg = "INFO: Active window is (hopefully) %s" % candidates[0]
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         return candidates[0]
 
     @staticmethod
@@ -297,8 +297,8 @@ class Utilities:
         - b: Accessible
         """
 
-        debug.println(debug.LEVEL_FINEST,
-                      "script_utilities.commonAncestor...")
+        msg = 'INFO: Looking for common ancestor of %s and %s' % (a, b)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         # Don't do any Zombie checks here, as tempting and logical as it
         # may seem as it can lead to chattiness.
@@ -339,9 +339,8 @@ class Utilities:
             else:
                 break
 
-        debug.println(debug.LEVEL_FINEST,
-                      "...script_utilities.commonAncestor")
-
+        msg = 'INFO: Common ancestor of %s and %s is %s' % (a, b, commonAncestor)
+        debug.println(debug.LEVEL_INFO, msg, True)
         return commonAncestor
 
     def componentAtDesktopCoords(self, parent, x, y):
@@ -796,21 +795,21 @@ class Utilities:
             value = obj.queryValue()
         except NotImplementedError:
             msg = "ERROR: %s doesn't implement AtspiValue" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
         except:
             msg = "ERROR: Exception getting value for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
         else:
             try:
                 if value.maximumValue == value.minimumValue:
                     msg = "INFO: %s is busy indicator" % obj
-                    debug.println(debug.LEVEL_INFO, msg)
+                    debug.println(debug.LEVEL_INFO, msg, True)
                     return False
             except:
                 msg = "INFO: %s is either busy indicator or broken" % obj
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return False
 
         return True
@@ -901,11 +900,11 @@ class Utilities:
             minval, val, maxval =  value.minimumValue, value.currentValue, value.maximumValue
         except NotImplementedError:
             msg = "ERROR: %s doesn't implement AtspiValue" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return None
         except:
             msg = "ERROR: Exception getting value for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return None
 
         return int((val / (maxval - minval)) * 100)
@@ -983,11 +982,11 @@ class Utilities:
                 table = obj.queryTable()
             except NotImplementedError:
                 msg = 'ERROR: Table %s does not implement table interface' % obj
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 layoutOnly = True
             except:
                 msg = 'ERROR: Exception querying table interface of %s' % obj
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 layoutOnly = True
             else:
                 if not (table.nRows and table.nColumns):
@@ -1033,9 +1032,8 @@ class Utilities:
                 layoutOnly = True
 
         if layoutOnly:
-            debug.println(debug.LEVEL_FINEST,
-                          "Object deemed to be for layout purposes only: %s" \
-                          % obj)
+            msg = 'INFO: %s is deemed to be layout only' % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
 
         return layoutOnly
 
@@ -1062,7 +1060,8 @@ class Utilities:
         try:
             role = obj.getRole()
         except (LookupError, RuntimeError):
-            debug.println(debug.LEVEL_FINE, 'Error - isLink getting role')
+            msg = 'ERROR: Exception getting role for %s' % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         return role == pyatspi.ROLE_LINK
@@ -1076,11 +1075,6 @@ class Utilities:
         state = obj.getState()
         readOnly = state.contains(pyatspi.STATE_FOCUSABLE) \
                    and not state.contains(pyatspi.STATE_EDITABLE)
-        details = debug.getAccessibleDetails(debug.LEVEL_ALL, obj)
-        debug.println(debug.LEVEL_ALL,
-                      "isReadOnlyTextArea=%s for %s" \
-                      % (readOnly, details))
-
         return readOnly
 
     def _hasSamePath(self, obj1, obj2):
@@ -1166,15 +1160,7 @@ class Utilities:
         as a list of Accessible objects.
         """
 
-        debug.println(debug.LEVEL_FINEST,
-                      "knownApplications...")
-
-        apps = [x for x in pyatspi.Registry.getDesktop(0) if x is not None]
-
-        debug.println(debug.LEVEL_FINEST,
-                      "...knownApplications")
-
-        return apps
+        return [x for x in pyatspi.Registry.getDesktop(0) if x is not None]
 
     def labelsForObject(self, obj):
         """Return a list of the objects that are labelling this object.
@@ -1192,14 +1178,13 @@ class Utilities:
         try:
             relations = obj.getRelationSet()
         except (LookupError, RuntimeError):
-            debug.println(debug.LEVEL_SEVERE,
-                          "labelsForObject() - Error getting RelationSet")
+            msg = 'ERROR: Exception getting relationset for %s' % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
             return label
 
         allTargets = []
         for relation in relations:
-            if relation.getRelationType() \
-                   == pyatspi.RELATION_LABELLED_BY:
+            if relation.getRelationType() == pyatspi.RELATION_LABELLED_BY:
 
                 # The object can be labelled by more than one thing, so we just
                 # get all the labels (from unique objects) and append them
@@ -1359,8 +1344,8 @@ class Utilities:
             try:
                 relations = node.getRelationSet()
             except (LookupError, RuntimeError):
-                debug.println(debug.LEVEL_SEVERE,
-                              "nodeLevel() - Error getting RelationSet")
+                msg = 'ERROR: Exception getting relationset for %s' % node
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return -1
             node = None
             for relation in relations:
@@ -1372,15 +1357,16 @@ class Utilities:
             # We want to avoid situations where something gives us an
             # infinite cycle of nodes.  Bon Echo has been seen to do
             # this (see bug 351847).
-            #
-            if (len(nodes) > 100) or nodes.count(node):
-                debug.println(debug.LEVEL_WARNING,
-                              "nodeLevel detected a cycle!!!")
+            if nodes.count(node):
+                msg = 'ERROR: %s is already in the list of nodes for %s' % (node, obj)
+                debug.println(debug.LEVEL_INFO, msg, True)
+                done = True
+            if len(nodes) > 100:
+                msg = 'INFO: More than 100 nodes found for %s' % obj
+                debug.println(debug.LEVEL_INFO, msg, True)
                 done = True
             elif node:
                 nodes.append(node)
-                debug.println(debug.LEVEL_FINEST,
-                              "nodeLevel %d" % len(nodes))
             else:
                 done = True
 
@@ -1429,7 +1415,8 @@ class Utilities:
         try:
             state = obj.getState()
         except:
-            debug.printException(debug.LEVEL_WARNING)
+            msg = "ERROR: Exception getting state of %s" % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
         else:
             return state.contains(pyatspi.STATE_SHOWING)
@@ -1442,8 +1429,8 @@ class Utilities:
             if not (obj and obj.parent and obj.childCount):
                 return False
         except:
-            msg = "INFO: Exception getting parent and childCount for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            msg = "ERROR: Exception getting parent and childCount for %s" % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         role = obj.getRole()
@@ -1597,9 +1584,6 @@ class Utilities:
                     else:
                         newX = currentX + gridSize
                 else:
-                    debug.println(debug.LEVEL_FINEST,
-                            "script_utilities.showingDescendants failed. " \
-                            "Last valid child at index %d" % index)
                     break
                 if newX <= currentX:
                     currentX += gridSize
@@ -1758,7 +1742,7 @@ class Utilities:
             extents = obj.queryComponent().getExtents(0)
         except:
             msg = "ERROR: Exception getting extents for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         return not (extents.width and extents.height)
@@ -2004,7 +1988,7 @@ class Utilities:
             hyperlink = obj.queryHyperlink()
         except NotImplementedError:
             msg = "INFO: %s does not implement the hyperlink interface" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
         else:
             # We need to make sure that this is an embedded object in
             # some accessible text (as opposed to an imagemap link).
@@ -2014,10 +1998,10 @@ class Utilities:
                 offset = hyperlink.startIndex
             except:
                 msg = "ERROR: Exception getting startIndex for %s in parent %s" % (obj, obj.parent)
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
             else:
                 msg = "INFO: startIndex of %s is %i" % (obj, offset)
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
 
         return offset
 
@@ -2138,15 +2122,7 @@ class Utilities:
         nSelections = textObj.getNSelections()
         for i in range(0, nSelections):
             [startOffset, endOffset] = textObj.getSelection(i)
-
-            debug.println(debug.LEVEL_FINEST,
-                "getSelectedText: selection start=%d, end=%d" % \
-                (startOffset, endOffset))
-
             selectedText = textObj.getText(startOffset, endOffset)
-            debug.println(debug.LEVEL_FINEST,
-                "getSelectedText: selected text=<%s>" % selectedText)
-
             if i > 0:
                 textContents += " "
             textContents += selectedText
@@ -2776,9 +2752,6 @@ class Utilities:
         mnemonic = self.labelFromKeySequence(mnemonic)
         accelerator = self.labelFromKeySequence(accelerator)
 
-        debug.println(debug.LEVEL_FINEST, "script_utilities.getKeyBinding: " \
-                      + repr([mnemonic, fullShortcut, accelerator]))
-
         if self.KEY_BINDING not in self._script.generatorCache:
             self._script.generatorCache[self.KEY_BINDING] = {}
 
@@ -2843,27 +2816,26 @@ class Utilities:
             maxValue = value.maximumValue
         except (LookupError, RuntimeError):
             maxValue = 0.0
-            debug.println(debug.LEVEL_FINEST, "VALUE WARNING: " \
-                          "Error accessing maximumValue for %s" % obj)
+            msg = 'ERROR: Exception getting maximumValue for %s' % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
         try:
             minValue = value.minimumValue
         except (LookupError, RuntimeError):
             minValue = 0.0
-            debug.println(debug.LEVEL_FINEST, "VALUE WARNING: " \
-                          "Error accessing minimumValue for %s" % obj)
+            msg = 'ERROR: Exception getting minimumValue for %s' % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
         try:
             minIncrement = value.minimumIncrement
         except (LookupError, RuntimeError):
             minIncrement = (maxValue - minValue) / 100.0
-            debug.println(debug.LEVEL_FINEST, "VALUE WARNING: " \
-                          "Error accessing minimumIncrement for %s" % obj)
-
+            msg = 'ERROR: Exception getting minimumIncrement for %s' % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
         if minIncrement != 0.0:
             try:
                 decimalPlaces = math.ceil(max(0, -math.log10(minIncrement)))
             except ValueError:
-                debug.println(debug.LEVEL_FINEST, "VALUE WARNING: " \
-                    "Error calculating decimal places for %s" % obj)
+                msg = 'ERROR: Exception calculating decimal places for %s' % obj
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return ""
         elif abs(currentValue) < 1:
             decimalPlaces = 1
@@ -2924,16 +2896,16 @@ class Utilities:
             selection = obj.querySelection()
         except NotImplementedError:
             msg = "INFO: %s does not implement the selection interface" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return []
         except:
             msg = "ERROR: Exception querying selection interface for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return []
 
         count = selection.nSelectedChildren
         msg = "INFO: %s reports %i selected children" % (obj, count)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         children = []
         for x in range(count):
@@ -2948,7 +2920,7 @@ class Utilities:
                 children = pyatspi.findAllDescendants(obj, pred)
             except:
                 msg = "ERROR: Exception calling findAllDescendants on %s" % obj
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
 
         if role == pyatspi.ROLE_COMBO_BOX \
            and children and children[0].getRole() == pyatspi.ROLE_MENU:
@@ -2959,7 +2931,7 @@ class Utilities:
                     children = pyatspi.findAllDescendants(obj, pred)
                 except:
                     msg = "ERROR: Exception calling findAllDescendants on %s" % obj
-                    debug.println(debug.LEVEL_INFO, msg)
+                    debug.println(debug.LEVEL_INFO, msg, True)
 
         return children
 
@@ -2968,7 +2940,7 @@ class Utilities:
         child = pyatspi.findDescendant(obj, isFocused)
         if child == obj:
             msg = "ERROR: focused child of %s is %s" % (obj, child)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return None
 
         return child
@@ -3145,7 +3117,7 @@ class Utilities:
         try:
             name = obj.name
         except:
-            debug.println(debug.LEVEL_INFO, "DEAD: %s" % obj)
+            debug.println(debug.LEVEL_INFO, "DEAD: %s" % obj, True)
             return True
 
         return False
@@ -3156,7 +3128,7 @@ class Utilities:
             state = obj.getState()
             role = obj.getRole()
         except:
-            debug.println(debug.LEVEL_INFO, "ZOMBIE: %s is null or dead" % obj)
+            debug.println(debug.LEVEL_INFO, "ZOMBIE: %s is null or dead" % obj, True)
             return True
 
         topLevelRoles = [pyatspi.ROLE_APPLICATION,
@@ -3166,13 +3138,13 @@ class Utilities:
                          pyatspi.ROLE_WINDOW,
                          pyatspi.ROLE_FRAME]
         if index == -1 and role not in topLevelRoles:
-            debug.println(debug.LEVEL_INFO, "ZOMBIE: %s's index is -1" % obj)
+            debug.println(debug.LEVEL_INFO, "ZOMBIE: %s's index is -1" % obj, True)
             return True
         if state.contains(pyatspi.STATE_DEFUNCT):
-            debug.println(debug.LEVEL_INFO, "ZOMBIE: %s is defunct" % obj)
+            debug.println(debug.LEVEL_INFO, "ZOMBIE: %s is defunct" % obj, True)
             return True
         if state.contains(pyatspi.STATE_INVALID):
-            debug.println(debug.LEVEL_INFO, "ZOMBIE: %s is invalid" % obj)
+            debug.println(debug.LEVEL_INFO, "ZOMBIE: %s is invalid" % obj, True)
             return True
 
         return False
@@ -3196,11 +3168,11 @@ class Utilities:
                 replicant = pyatspi.findDescendant(root, isSame)
             except:
                 msg = "INFO: Exception from findDescendant for %s" % root
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 replicant = None
 
         msg = "HACK: Returning %s as replicant for Zombie %s" % (replicant, obj)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         return replicant
 
     def getFunctionalChildCount(self, obj):
diff --git a/src/orca/scripts/apps/Thunderbird/script.py b/src/orca/scripts/apps/Thunderbird/script.py
index 0f90cfe..abe23fd 100644
--- a/src/orca/scripts/apps/Thunderbird/script.py
+++ b/src/orca/scripts/apps/Thunderbird/script.py
@@ -358,14 +358,14 @@ class Script(Gecko.Script):
         self.updateBraille(obj)
         if not _settingsManager.getSetting('sayAllOnLoad'):
             msg = "THUNDERBIRD: SayAllOnLoad is False. Presenting line."
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             contents = self.utilities.getLineContentsAtOffset(obj, offset)
             self.speakContents(contents)
             return
 
         if _settingsManager.getSetting('enableSpeech'):
             msg = "THUNDERBIRD: SayAllOnLoad is True and speech is enabled"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.sayAll(None)
 
     def sayCharacter(self, obj):
diff --git a/src/orca/scripts/apps/soffice/script.py b/src/orca/scripts/apps/soffice/script.py
index 32dcc7a..5225a3e 100644
--- a/src/orca/scripts/apps/soffice/script.py
+++ b/src/orca/scripts/apps/soffice/script.py
@@ -806,11 +806,11 @@ class Script(default.Script):
 
         if self.utilities.isSpreadSheetCell(orca_state.locusOfFocus):
             msg = "SOFFICE: locusOfFocus %s is spreadsheet cell" % orca_state.locusOfFocus
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
 
             if not self.utilities.isCellBeingEdited(event.source):
                 msg = "SOFFICE: Event ignored: Source is not cell being edited."
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return
 
         super().onCaretMoved(event)
diff --git a/src/orca/scripts/apps/soffice/script_utilities.py 
b/src/orca/scripts/apps/soffice/script_utilities.py
index 16d68f4..271c2be 100644
--- a/src/orca/scripts/apps/soffice/script_utilities.py
+++ b/src/orca/scripts/apps/soffice/script_utilities.py
@@ -106,10 +106,6 @@ class Utilities(script_utilities.Utilities):
         state = obj.getState()
         readOnly = state.contains(pyatspi.STATE_FOCUSABLE) \
                    and not state.contains(pyatspi.STATE_EDITABLE)
-        details = debug.getAccessibleDetails(debug.LEVEL_ALL, obj)
-        debug.println(debug.LEVEL_ALL,
-                      "soffice - isReadOnlyTextArea=%s for %s" % \
-                      (readOnly, details))
 
         return readOnly
 
@@ -372,7 +368,8 @@ class Utilities(script_utilities.Utilities):
                 break
 
         if not toolbar:
-            debug.println(debug.LEVEL_INFO, "Calc inputline toolbar not found.")
+            msg = "ERROR: Calc inputline toolbar not found."
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         isParagraph = lambda x: x and x.getRole() == pyatspi.ROLE_PARAGRAPH
diff --git a/src/orca/scripts/apps/soffice/spellcheck.py b/src/orca/scripts/apps/soffice/spellcheck.py
index b572b65..4c95e34 100644
--- a/src/orca/scripts/apps/soffice/spellcheck.py
+++ b/src/orca/scripts/apps/soffice/spellcheck.py
@@ -77,8 +77,8 @@ class SpellCheck(spellcheck.SpellCheck):
                 string = text.getText(start, end)
                 break
         else:
-            msg = "INFO: No text attributes for word in %s." % self._errorWidget
-            debug.println(debug.LEVEL_INFO, msg)
+            msg = "SOFFICE: No text attributes for word in %s." % self._errorWidget
+            debug.println(debug.LEVEL_INFO, msg, True)
             string = text.getText(0, -1)
 
         return string
diff --git a/src/orca/scripts/default.py b/src/orca/scripts/default.py
index 5daee8c..bc99506 100644
--- a/src/orca/scripts/default.py
+++ b/src/orca/scripts/default.py
@@ -641,8 +641,8 @@ class Script(script.Script):
         try:
             keyBindings = _settingsManager.overrideKeyBindings(self, keyBindings)
         except:
-            debug.println(debug.LEVEL_WARNING,
-                          "WARNING: problem overriding keybindings:")
+            msg = 'ERROR: Exception when overriding keybindings in %s' % self
+            debug.println(debug.LEVEL_WARNING, msg, True)
             debug.printException(debug.LEVEL_WARNING)
 
         return keyBindings
@@ -699,11 +699,11 @@ class Script(script.Script):
             brailleBindings[braille.brlapi.KEY_CMD_CUTLINE] = \
                 self.inputEventHandlers["processBrailleCutLineHandler"]
         except AttributeError:
-            debug.println(debug.LEVEL_CONFIGURATION,
-                          "WARNING: braille bindings unavailable:")
+            msg = 'DEFAULT: Braille bindings unavailable in %s' % self
+            debug.println(debug.LEVEL_INFO, msg, True)
         except:
-            debug.println(debug.LEVEL_CONFIGURATION,
-                          "WARNING: braille bindings unavailable:")
+            msg = 'ERROR: Exception getting braille bindings in %s' % self
+            debug.println(debug.LEVEL_INFO, msg, True)
             debug.printException(debug.LEVEL_CONFIGURATION)
         return brailleBindings
 
@@ -751,8 +751,8 @@ class Script(script.Script):
             try:
                 names[hash(orca_state.activeWindow)] = orca_state.activeWindow.name
             except:
-                msg = "DEFAULT: Exception getting name for %s" % orca_state.activeWindow
-                debug.println(debug.LEVEL_INFO, msg)
+                msg = "ERROR: Exception getting name for %s" % orca_state.activeWindow
+                debug.println(debug.LEVEL_INFO, msg, True)
 
         self.pointOfReference['names'] = names
 
@@ -854,7 +854,7 @@ class Script(script.Script):
 
         if not _settingsManager.getSetting('enableBraille') \
            and not _settingsManager.getSetting('enableBrailleMonitor'):
-            debug.println(debug.LEVEL_INFO, "BRAILLE: update disabled")
+            debug.println(debug.LEVEL_INFO, "BRAILLE: update disabled", True)
             return
 
         if not obj:
@@ -2103,13 +2103,13 @@ class Script(script.Script):
         if event.source.getRole() == pyatspi.ROLE_FRAME:
             if event.source == orca_state.activeWindow and not event.detail1:
                 msg = "DEFAULT: Event is for active window. Clearing state."
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 orca_state.activeWindow = None
                 return
 
             if event.detail1:
                 msg = "DEFAULT: Updating active window to event source."
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 self.windowActivateTime = time.time()
                 orca.setLocusOfFocus(event, event.source)
                 orca_state.activeWindow = event.source
@@ -2179,20 +2179,20 @@ class Script(script.Script):
         obj, offset = self.pointOfReference.get("lastCursorPosition", (None, -1))
         if offset == event.detail1 and obj == event.source:
             msg = "DEFAULT: Event is for last saved cursor position"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         if event.source != orca_state.locusOfFocus \
            and event.source.getState().contains(pyatspi.STATE_FOCUSED):
             msg = "DEFAULT: Updating locusOfFocus from %s to %s" % \
                   (orca_state.locusOfFocus, event.source)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, event.source, False)
 
         if event.source != orca_state.locusOfFocus:
             msg = "DEFAULT: Event source (%s) is not locusOfFocus (%s)" \
                   % (event.source, orca_state.locusOfFocus)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         if self.flatReviewContext:
@@ -2203,17 +2203,17 @@ class Script(script.Script):
             caretOffset = text.caretOffset
         except:
             msg = "DEFAULT: Exception getting caretOffset for %s" % event.source
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         self._saveLastCursorPosition(event.source, text.caretOffset)
         if text.getNSelections():
             msg = "DEFAULT: Event source has text selections"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         msg = "DEFAULT: Presenting text at new caret position"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         self._presentTextAtNewCaretPosition(event)
 
     def onDocumentReload(self, event):
@@ -2312,23 +2312,23 @@ class Script(script.Script):
         oldName = names.get(hash(obj))
         if oldName == event.any_data:
             msg = "DEFAULT: Old name (%s) is the same as new name" % oldName
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         role = obj.getRole()
         if role in [pyatspi.ROLE_COMBO_BOX, pyatspi.ROLE_TABLE_CELL]:
             msg = "DEFAULT: Event is redundant notification for this role"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         if role == pyatspi.ROLE_FRAME:
             if obj != orca_state.activeWindow:
                 msg = "DEFAULT: Event is for frame other than the active window"
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return
         elif obj != orca_state.locusOfFocus:
             msg = "DEFAULT: Event is for object other than the locusOfFocus"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         names[hash(obj)] = event.any_data
@@ -2454,7 +2454,7 @@ class Script(script.Script):
             role = obj.getRole()
         except:
             msg = "DEFAULT: Exception getting childCount and role for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         if childCount and role != pyatspi.ROLE_COMBO_BOX:
@@ -2843,11 +2843,11 @@ class Script(script.Script):
 
         isProgressBarUpdate, msg = self.utilities.isProgressBarUpdate(obj, event)
         msg = "DEFAULT: Is progress bar update: %s, %s" % (isProgressBarUpdate, msg)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if not isProgressBarUpdate and obj != orca_state.locusOfFocus:
             msg = "DEFAULT: Source != locusOfFocus (%s)" % orca_state.locusOfFocus
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         if isProgressBarUpdate:
@@ -3103,16 +3103,16 @@ class Script(script.Script):
     def inSayAll(self):
         if self._inSayAll:
             msg = "DEFAULT: In SayAll"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self._sayAllIsInterrupted:
             msg = "DEFAULT: SayAll is interrupted"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         msg = "DEFAULT: Not in SayAll"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         return False
 
     def echoPreviousSentence(self, obj):
@@ -3290,8 +3290,7 @@ class Script(script.Script):
             speechResult = self.whereAmI.getWhereAmI(obj, True)
             if speechResult:
                 brailleResult = speechResult[0]
-        debug.println(debug.LEVEL_FINEST,
-                      "presentToolTip: text='%s'" % speechResult)
+
         if speechResult:
             speech.speak(speechResult)
         if brailleResult:
@@ -3330,13 +3329,6 @@ class Script(script.Script):
             voice = self.voices[settings.DEFAULT_VOICE]
 
         speakBlankLines = _settingsManager.getSetting('speakBlankLines')
-        debug.println(debug.LEVEL_FINEST, \
-            "sayCharacter: char=<%s>, startOffset=%d, " % \
-            (character, startOffset))
-        debug.println(debug.LEVEL_FINEST, \
-            "caretOffset=%d, endOffset=%d, speakBlankLines=%s" % \
-            (offset, endOffset, speakBlankLines))
-
         if character == "\n":
             line = text.getTextAtOffset(max(0, offset),
                                         pyatspi.TEXT_BOUNDARY_LINE_START)
@@ -3369,13 +3361,6 @@ class Script(script.Script):
         # Get the AccessibleText interface of the provided object
         #
         [line, caretOffset, startOffset] = self.getTextLineAtCaret(obj)
-        debug.println(debug.LEVEL_FINEST, \
-            "sayLine: line=<%s>, len=%d, start=%d, " % \
-            (line, len(line), startOffset))
-        debug.println(debug.LEVEL_FINEST, \
-            "caret=%d, speakBlankLines=%s" % \
-            (caretOffset, _settingsManager.getSetting('speakBlankLines')))
-
         if len(line) and line != "\n":
             if line.isupper():
                 voice = self.voices[settings.UPPERCASE_VOICE]
@@ -3532,7 +3517,7 @@ class Script(script.Script):
 
         if not _settingsManager.getSetting('enableBraille') \
            and not _settingsManager.getSetting('enableBrailleMonitor'):
-            debug.println(debug.LEVEL_INFO, "BRAILLE: update review disabled")
+            debug.println(debug.LEVEL_INFO, "BRAILLE: update review disabled", True)
             return
 
         context = self.getFlatReviewContext()
@@ -3751,7 +3736,7 @@ class Script(script.Script):
         self._sayAllContexts = []
 
         msg = "DEFAULT: textLines complete. Verifying SayAll status"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         self.inSayAll()
 
     def getTextLineAtCaret(self, obj, offset=None, startOffset=None, endOffset=None):
@@ -4025,9 +4010,6 @@ class Script(script.Script):
         elif not event.isPressedKey():
             return False
 
-        debug.println(debug.LEVEL_FINEST,
-                      "Script.presentKeyboardEvent: %s" % event.event_string)
-
         braille.displayKeyEvent(event)
         orcaModifierPressed = event.isOrcaModifier() and event.isPressedKey()
         if event.isCharacterEchoable() and not orcaModifierPressed:
@@ -4171,7 +4153,7 @@ class Script(script.Script):
 
         if not _settingsManager.getSetting('enableBraille') \
            and not _settingsManager.getSetting('enableBrailleMonitor'):
-            debug.println(debug.LEVEL_INFO, "BRAILLE: display message disabled")
+            debug.println(debug.LEVEL_INFO, "BRAILLE: display message disabled", True)
             return
 
         braille.displayMessage(message, cursor, flashTime)
@@ -4195,7 +4177,7 @@ class Script(script.Script):
 
         if not _settingsManager.getSetting('enableBraille') \
            and not _settingsManager.getSetting('enableBrailleMonitor'):
-            debug.println(debug.LEVEL_INFO, "BRAILLE: display regions disabled")
+            debug.println(debug.LEVEL_INFO, "BRAILLE: display regions disabled", True)
             return
 
         braille.displayRegions(regionInfo, flashTime)
@@ -4358,7 +4340,7 @@ class Script(script.Script):
 
         if not _settingsManager.getSetting('enableBraille') \
            and not _settingsManager.getSetting('enableBrailleMonitor'):
-            debug.println(debug.LEVEL_INFO, "BRAILLE: update caret disabled")
+            debug.println(debug.LEVEL_INFO, "BRAILLE: update caret disabled", True)
             return
 
         brailleNeedsRepainting = True
diff --git a/src/orca/scripts/toolkits/Gecko/script.py b/src/orca/scripts/toolkits/Gecko/script.py
index bf9fd8d..1c7ab5a 100644
--- a/src/orca/scripts/toolkits/Gecko/script.py
+++ b/src/orca/scripts/toolkits/Gecko/script.py
@@ -63,7 +63,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.locusOfFocusChanged(self, event, oldFocus, newFocus)
 
     def onActiveChanged(self, event):
@@ -73,7 +73,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onActiveChanged(self, event)
 
     def onBusyChanged(self, event):
@@ -83,7 +83,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onBusyChanged(self, event)
 
     def onCaretMoved(self, event):
@@ -93,7 +93,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onCaretMoved(self, event)
 
     def onCheckedChanged(self, event):
@@ -103,7 +103,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onCheckedChanged(self, event)
 
     def onChildrenChanged(self, event):
@@ -113,7 +113,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onChildrenChanged(self, event)
 
     def onDocumentLoadComplete(self, event):
@@ -123,7 +123,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onDocumentLoadComplete(self, event)
 
     def onDocumentLoadStopped(self, event):
@@ -133,7 +133,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onDocumentLoadStopped(self, event)
 
     def onDocumentReload(self, event):
@@ -143,7 +143,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onDocumentReload(self, event)
 
     def onFocus(self, event):
@@ -198,11 +198,11 @@ class Script(web.Script):
         if event.source.getRole() == pyatspi.ROLE_PANEL:
             if orca_state.locusOfFocus == orca_state.activeWindow:
                 msg = "GECKO: Ignoring event believed to be noise."
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onFocusedChanged(self, event)
 
     def onMouseButton(self, event):
@@ -212,7 +212,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onMouseButton(self, event)
 
     def onNameChanged(self, event):
@@ -222,7 +222,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onNameChanged(self, event)
 
     def onSelectedChanged(self, event):
@@ -232,7 +232,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onSelectedChanged(self, event)
 
     def onSelectionChanged(self, event):
@@ -242,7 +242,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onSelectionChanged(self, event)
 
     def onShowingChanged(self, event):
@@ -253,12 +253,12 @@ class Script(web.Script):
 
         if event.detail1 and self.utilities.isTopLevelChromeAlert(event.source):
             msg = "GECKO: Event handled: Presenting event source"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.presentObject(event.source)
             return True
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onShowingChanged(self, event)
 
     def onTextDeleted(self, event):
@@ -268,7 +268,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onTextDeleted(self, event)
 
     def onTextInserted(self, event):
@@ -278,7 +278,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onTextInserted(self, event)
 
     def onTextSelectionChanged(self, event):
@@ -288,7 +288,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onTextSelectionChanged(self, event)
 
     def onWindowActivated(self, event):
@@ -298,7 +298,7 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onWindowActivated(self, event)
 
     def onWindowDeactivated(self, event):
@@ -308,5 +308,5 @@ class Script(web.Script):
             return
 
         msg = "GECKO: Passing along event to default script"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         default.Script.onWindowDeactivated(self, event)
diff --git a/src/orca/scripts/toolkits/Gecko/script_utilities.py 
b/src/orca/scripts/toolkits/Gecko/script_utilities.py
index 4455ada..65b2341 100644
--- a/src/orca/scripts/toolkits/Gecko/script_utilities.py
+++ b/src/orca/scripts/toolkits/Gecko/script_utilities.py
@@ -58,7 +58,7 @@ class Utilities(web.Utilities):
             attrs = obj.getAttributes()
         except:
             msg = "GECKO: Exception getting attributes for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return -1
         for attr in attrs:
             if attr.startswith("level:"):
diff --git a/src/orca/scripts/toolkits/WebKitGtk/script.py b/src/orca/scripts/toolkits/WebKitGtk/script.py
index 096ba9c..d31582b 100644
--- a/src/orca/scripts/toolkits/WebKitGtk/script.py
+++ b/src/orca/scripts/toolkits/WebKitGtk/script.py
@@ -619,7 +619,7 @@ class Script(default.Script):
 
         if not _settingsManager.getSetting('enableBraille') \
            and not _settingsManager.getSetting('enableBrailleMonitor'):
-            debug.println(debug.LEVEL_INFO, "BRAILLE: update disabled")
+            debug.println(debug.LEVEL_INFO, "BRAILLE: update disabled", True)
             return
 
         if not obj:
diff --git a/src/orca/scripts/toolkits/clutter/script.py b/src/orca/scripts/toolkits/clutter/script.py
index fe03c90..65c5406 100644
--- a/src/orca/scripts/toolkits/clutter/script.py
+++ b/src/orca/scripts/toolkits/clutter/script.py
@@ -126,13 +126,12 @@ class Script(default.Script):
                                                      modifiers,
                                                      group)
         except:
-            debug.println(debug.LEVEL_FINE,
-                          "Could not compute keyval with modifiers")
+            msg = 'ERROR: Exception computing keyval with modifiers'
+            debug.println(debug.LEVEL_INFO, msg, True)
 
-        string = "prev keyval=%d" % keyboardEvent.id
-        string = string + " post keyval=%d" % keyval
-
-        debug.println(debug.LEVEL_FINE, string)
+        msg = 'CLUTTER: Checked keyboard event data: ' \
+              'prev keyval=%d; post keyval=%d' % (keyboardEvent.id, keyval)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         keyboardEvent.id = keyval
 
@@ -142,13 +141,16 @@ class Script(default.Script):
         # guess-code here I will maintain that in this way
         #
         if (keyboardEvent.event_string == ""):
-            debug.println (debug.LEVEL_FINE, "Computing event_string")
+            msg = 'CLUTTER: Keyboard Event event_string is empty. Computing.'
+            debug.println(debug.LEVEL_INFO, msg, True)
             try:
                 keyboardEvent.event_string = Gdk.keyval_name(keyboardEvent.id)
+                msg = 'CLUTTER: New event string: %s' % keyboardEvent.event_string
+                debug.println(debug.LEVEL_INFO, msg, True)
             except:
-                debug.println(debug.LEVEL_FINE,
-                              "Could not obtain keyval_name for id: %d" \
-                                  % keyboardEvent.id)
+                msg = 'ERROR: Exception obtaining keyval_name for id: %d' \
+                      % keyboardEvent.id
+                debug.println(debug.LEVEL_INFO, msg, True)
 
             # at-spi uses event_string to compute is_text, so if it is
             # NULL we should compute again with the proper
diff --git a/src/orca/scripts/web/script.py b/src/orca/scripts/web/script.py
index 56c3647..30af7f1 100644
--- a/src/orca/scripts/web/script.py
+++ b/src/orca/scripts/web/script.py
@@ -500,7 +500,7 @@ class Script(default.Script):
 
         if not self.utilities.inDocumentContent():
             msg = "WEB: textLines called for non-document content %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             super().textLines(obj, offset)
             return
 
@@ -552,7 +552,7 @@ class Script(default.Script):
         self._sayAllContexts = []
 
         msg = "WEB: textLines complete. Verifying SayAll status"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         self.inSayAll()
 
     def presentFindResults(self, obj, offset):
@@ -592,12 +592,12 @@ class Script(default.Script):
 
         if not self.utilities.inDocumentContent():
             msg = "WEB: SayAll called for non-document content %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return super().sayAll(inputEvent, obj, offset)
 
         obj = obj or orca_state.locusOfFocus
         msg = "WEB: SayAll called for document content %s" % obj
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         speech.sayAll(self.textLines(obj, offset), self.__sayAllProgressCallback)
         return True
 
@@ -752,7 +752,7 @@ class Script(default.Script):
 
         if not _settingsManager.getSetting('enableBraille') \
            and not _settingsManager.getSetting('enableBrailleMonitor'):
-            debug.println(debug.LEVEL_INFO, "BRAILLE: disabled")
+            debug.println(debug.LEVEL_INFO, "BRAILLE: disabled", True)
             return
 
         if not (self._lastCommandWasCaretNav or self._lastCommandWasStructNav) \
@@ -769,7 +769,7 @@ class Script(default.Script):
 
         if not _settingsManager.getSetting('enableBraille') \
            and not _settingsManager.getSetting('enableBrailleMonitor'):
-            debug.println(debug.LEVEL_INFO, "BRAILLE: disabled")
+            debug.println(debug.LEVEL_INFO, "BRAILLE: disabled", True)
             return
 
         line = self.getNewBrailleLine(clearBraille=True, addLine=True)
@@ -965,19 +965,19 @@ class Script(default.Script):
 
         if newFocus and self.utilities.isZombie(newFocus):
             msg = "WEB: New focus is Zombie: %s" % newFocus
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not self.utilities.inDocumentContent(newFocus):
             msg = "WEB: Locus of focus changed to non-document obj"
             self._madeFindAnnouncement = False
             self._inFocusMode = False
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if oldFocus and self.utilities.isZombie(oldFocus):
             msg = "WEB: Old focus is Zombie: %s. Clearing oldFocus." % oldFocus
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             oldFocus = None
 
         caretOffset = 0
@@ -986,7 +986,7 @@ class Script(default.Script):
 
         if newFocus.getRole() == pyatspi.ROLE_UNKNOWN:
             msg = "WEB: Event source has bogus role. Likely browser bug."
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             newFocus, offset = self.utilities.findFirstCaretContext(newFocus, 0)
 
         text = self.utilities.queryNonEmptyText(newFocus)
@@ -997,12 +997,18 @@ class Script(default.Script):
         self.updateBraille(newFocus)
 
         if self.utilities.isAnchor(newFocus):
+            msg = "WEB: New focus %s is anchor. Generating line contents." % newFocus
+            debug.println(debug.LEVEL_INFO, msg, True)
             contents = self.utilities.getLineContentsAtOffset(newFocus, 0)
             utterances = self.speechGenerator.generateContents(contents)
         elif newFocus.getRole() == pyatspi.ROLE_HEADING:
+            msg = "WEB: New focus %s is heading. Generating object contents." % newFocus
+            debug.println(debug.LEVEL_INFO, msg, True)
             contents = self.utilities.getObjectContentsAtOffset(newFocus, 0)
             utterances = self.speechGenerator.generateContents(contents)
         else:
+            msg = "WEB: New focus %s is not a special case. Generating speech." % newFocus
+            debug.println(debug.LEVEL_INFO, msg, True)
             utterances = self.speechGenerator.generateSpeech(newFocus, priorObj=oldFocus)
 
         speech.speak(utterances)
@@ -1024,18 +1030,18 @@ class Script(default.Script):
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if not event.detail1:
             msg = "WEB: Ignoring because event source is now inactive"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         role = event.source.getRole()
         if role in [pyatspi.ROLE_DIALOG, pyatspi.ROLE_ALERT]:
             msg = "WEB: Event handled: Setting locusOfFocus to event source"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, event.source)
             return True
 
@@ -1046,17 +1052,17 @@ class Script(default.Script):
 
         if event.detail1 and self._loadingDocumentContent:
             msg = "WEB: Ignoring: Already loading document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if self.utilities.getDocumentForObject(event.source.parent):
             msg = "WEB: Ignoring: Event source is nested document"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         self._loadingDocumentContent = event.detail1
@@ -1088,7 +1094,7 @@ class Script(default.Script):
 
         if not sourceIsBusy and self.utilities.isTopLevelWebApp(event.source):
             msg = "WEB: Setting locusOfFocus to %s with sticky focus mode" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, obj)
             self.enableStickyFocusMode(None, True)
             return True
@@ -1098,44 +1104,44 @@ class Script(default.Script):
 
         if not obj:
             msg = "WEB: Could not get caret context"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.isFocusModeWidget(obj):
             msg = "WEB: Setting locus of focus to focusModeWidget %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, obj)
             return True
 
         state = obj.getState()
         if self.utilities.isLink(obj) and state.contains(pyatspi.STATE_FOCUSED):
             msg = "WEB: Setting locus of focus to focused link %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, obj)
             return True
 
         if offset > 0:
             msg = "WEB: Setting locus of focus to context obj %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, obj)
             return True
 
         self.updateBraille(obj)
         if state.contains(pyatspi.STATE_FOCUSABLE) and not self.utilities.isDocument(obj):
             msg = "WEB: Not doing SayAll due to focusable context obj %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             speech.speak(self.speechGenerator.generateSpeech(obj))
         elif not _settingsManager.getSetting('sayAllOnLoad'):
             msg = "WEB: Not doing SayAll due to sayAllOnLoad being False"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.speakContents(self.utilities.getLineContentsAtOffset(obj, offset))
         elif _settingsManager.getSetting('enableSpeech'):
             msg = "WEB: Doing SayAll"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.sayAll(None)
         else:
             msg = "WEB: Not doing SayAll due to enableSpeech being False"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
 
         return True
 
@@ -1144,50 +1150,50 @@ class Script(default.Script):
 
         if self.utilities.isZombie(event.source):
             msg = "WEB: Event source is Zombie"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if self._lastCommandWasCaretNav:
             msg = "WEB: Event ignored: Last command was caret nav"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self._lastCommandWasStructNav:
             msg = "WEB: Event ignored: Last command was struct nav"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self._lastCommandWasMouseButton:
             msg = "WEB: Event handled: Last command was mouse button"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, event.source)
             self.utilities.setCaretContext(event.source, event.detail1)
             return True
 
         if self.utilities.inFindToolbar() and not self._madeFindAnnouncement:
             msg = "WEB: Event handled: Presenting find results"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.presentFindResults(event.source, event.detail1)
             return True
 
         if self.utilities.eventIsAutocompleteNoise(event):
             msg = "WEB: Event ignored: Autocomplete noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.textEventIsForNonNavigableTextObject(event):
             msg = "WEB: Event ignored: Event source is non-navigable text object"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.textEventIsDueToInsertion(event):
             msg = "WEB: Event handled: Updating position due to insertion"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self._saveLastCursorPosition(event.source, event.detail1)
             return True
 
@@ -1195,7 +1201,7 @@ class Script(default.Script):
 
         if self.utilities.caretMovedToSamePageFragment(event):
             msg = "WEB: Event handled: Caret moved to fragment"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, obj)
             self.utilities.setCaretContext(obj, offset)
             return True
@@ -1204,36 +1210,36 @@ class Script(default.Script):
         if not text:
             if event.source.getRole() == pyatspi.ROLE_LINK:
                 msg = "WEB: Event handled: Was for non-text link"
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 orca.setLocusOfFocus(event, event.source)
                 self.utilities.setCaretContext(event.source, event.detail1)
             else:
                 msg = "WEB: Event ignored: Was for non-text non-link"
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         char = text.getText(event.detail1, event.detail1+1)
         isEditable = obj.getState().contains(pyatspi.STATE_EDITABLE)
         if not char and not isEditable:
             msg = "WEB: Event ignored: Was for empty char in non-editable text"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if char == self.EMBEDDED_OBJECT_CHARACTER:
             if not self.utilities.isTextBlockElement(obj):
                 msg = "WEB: Event ignored: Was for embedded non-textblock"
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return True
 
             msg = "WEB: Setting locusOfFocus, context to: %s, %i" % (obj, offset)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, obj)
             self.utilities.setCaretContext(obj, offset)
             return True
 
         if self.utilities.treatEventAsSpinnerValueChange(event):
             msg = "WEB: Event handled as the value-change event we wish we'd get"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.updateBraille(event.source)
             self._presentTextAtNewCaretPosition(event)
             return True
@@ -1244,12 +1250,12 @@ class Script(default.Script):
             self.utilities.setCaretContext(event.source, event.detail1)
             msg = "WEB: Setting locusOfFocus, context to: %s, %i" % \
                   (event.source, event.detail1)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         self.utilities.setCaretContext(obj, offset)
         msg = "WEB: Setting context to: %s, %i" % (obj, offset)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         return False
 
     def onCheckedChanged(self, event):
@@ -1257,25 +1263,25 @@ class Script(default.Script):
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         obj, offset = self.utilities.getCaretContext()
         if obj != event.source:
             msg = "WEB: Event source is not context object"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         oldObj, oldState = self.pointOfReference.get('checkedChange', (None, 0))
         if hash(oldObj) == hash(obj) and oldState == event.detail1:
             msg = "WEB: Ignoring event, state hasn't changed"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         role = obj.getRole()
         if not (self._lastCommandWasCaretNav and role == pyatspi.ROLE_RADIO_BUTTON):
             msg = "WEB: Event is something default can handle"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         self.updateBraille(obj)
@@ -1288,33 +1294,33 @@ class Script(default.Script):
 
         if self.utilities.eventIsChromeNoise(event):
             msg = "WEB: Ignoring event believed to be chrome noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         document = self.utilities.getDocumentForObject(event.source)
         if document:
             msg = "WEB: Clearing structural navigation cache for %s" % document
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.structuralNavigation.clearCache(document)
         else:
             msg = "WEB: Could not get document for event source"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if self.utilities.handleAsLiveRegion(event):
             msg = "WEB: Event to be handled as live region"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.liveRegionManager.handleEvent(event)
             return True
 
         if self._loadingDocumentContent:
             msg = "WEB: Ignoring because document content is being loaded."
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.isZombie(document):
             msg = "WEB: Ignoring because %s is zombified." % document
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         try:
@@ -1322,25 +1328,25 @@ class Script(default.Script):
         except:
             docIsBusy = False
             msg = "WEB: Exception getting state of %s" % document
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
         if docIsBusy:
             msg = "WEB: Ignoring because %s is busy." % document
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not event.any_data or self.utilities.isZombie(event.any_data):
             msg = "WEB: Ignoring because any data is null or zombified."
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         obj, offset = self.utilities.getCaretContext()
         contextDocument = self.utilities.getDocumentForObject(obj)
         if obj and document == contextDocument and self.utilities.isZombie(obj):
             msg = "WEB: Context obj %s is Zombie." % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             if self._inFocusMode:
                 msg = "WEB: Not looking for replicant due to focus mode."
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return False
 
             replicant = self.utilities.findReplicant(event.source, obj)
@@ -1349,7 +1355,7 @@ class Script(default.Script):
                 # focus or setting the caret in it. Doing so will only serve
                 # to anger it.
                 msg = "WEB: Event handled by updating locusOfFocus and context"
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 orca.setLocusOfFocus(event, replicant, False)
                 self.utilities.setCaretContext(replicant, offset)
                 return True
@@ -1357,7 +1363,7 @@ class Script(default.Script):
         child = event.any_data
         if child.getRole() in [pyatspi.ROLE_ALERT, pyatspi.ROLE_DIALOG]:
             msg = "WEB: Setting locusOfFocus to event.any_data"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, child)
             return True
 
@@ -1376,7 +1382,7 @@ class Script(default.Script):
         """Callback for document:load-complete accessibility events."""
 
         msg = "WEB: Updating loading state and resetting live regions"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         self._loadingDocumentContent = False
         self.liveRegionManager.reset()
         return True
@@ -1385,7 +1391,7 @@ class Script(default.Script):
         """Callback for document:load-stopped accessibility events."""
 
         msg = "WEB: Updating loading state"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         self._loadingDocumentContent = False
         return True
 
@@ -1393,7 +1399,7 @@ class Script(default.Script):
         """Callback for document:reload accessibility events."""
 
         msg = "WEB: Updating loading state"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         self._loadingDocumentContent = True
         return True
 
@@ -1402,70 +1408,70 @@ class Script(default.Script):
 
         if not event.detail1:
             msg = "WEB: Ignoring because event source lost focus"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.isZombie(event.source):
             msg = "WEB: Event source is Zombie"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         document = self.utilities.getDocumentForObject(event.source)
         if not document:
             msg = "WEB: Could not get document for event source"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if self.utilities.isTopLevelWebApp(document):
             msg = "WEB: Event handled: Setting locusOfFocus to event source"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, event.source)
             return True
 
         state = event.source.getState()
         if state.contains(pyatspi.STATE_EDITABLE):
             msg = "WEB: Event source is editable"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         role = event.source.getRole()
         if role in [pyatspi.ROLE_DIALOG, pyatspi.ROLE_ALERT]:
             msg = "WEB: Event handled: Setting locusOfFocus to event source"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             orca.setLocusOfFocus(event, event.source)
             return True
 
         if self._lastCommandWasCaretNav:
             msg = "WEB: Event ignored: Last command was caret nav"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self._lastCommandWasStructNav:
             msg = "WEB: Event ignored: Last command was struct nav"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not state.contains(pyatspi.STATE_FOCUSABLE) \
            and not state.contains(pyatspi.STATE_FOCUSED):
             msg = "WEB: Event ignored: Source is not focusable or focused"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not role in [pyatspi.ROLE_DOCUMENT_FRAME, pyatspi.ROLE_DOCUMENT_WEB]:
             msg = "WEB: Deferring to other scripts for handling non-document source"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         obj, offset = self.utilities.getCaretContext(event.source)
         if obj and self.utilities.isZombie(obj):
             msg = "WEB: Clearing context - obj is zombie"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.utilities.clearCaretContext()
             obj, offset = self.utilities.getCaretContext(event.source)
 
         if not obj:
             msg = "WEB: Unable to get non-null, non-zombie context object"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         wasFocused = obj.getState().contains(pyatspi.STATE_FOCUSED)
@@ -1473,7 +1479,7 @@ class Script(default.Script):
         isFocused = obj.getState().contains(pyatspi.STATE_FOCUSED)
         if wasFocused != isFocused:
             msg = "WEB: Focused state of %s changed to %s" % (obj, isFocused)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if self.utilities.isAnchor(obj):
@@ -1486,7 +1492,7 @@ class Script(default.Script):
             return False
 
         msg = "WEB: Event handled: Setting locusOfFocus to %s (%s)" % (obj, cause)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         orca.setLocusOfFocus(event, obj)
         return True
 
@@ -1503,12 +1509,12 @@ class Script(default.Script):
 
         if self.utilities.eventIsChromeNoise(event):
             msg = "WEB: Ignoring event believed to be chrome noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if event.source.getRole() == pyatspi.ROLE_FRAME:
             msg = "WEB: Flusing messages from live region manager"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.liveRegionManager.flushMessages()
 
         return True
@@ -1518,17 +1524,17 @@ class Script(default.Script):
 
         if self.utilities.eventIsChromeAutocompleteNoise(event):
             msg = "WEB: Ignoring event believed to be chrome autocomplete noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if orca_state.locusOfFocus != event.source:
             msg = "WEB: Ignoring because event source is not locusOfFocus"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         return False
@@ -1538,25 +1544,25 @@ class Script(default.Script):
 
         if self.utilities.eventIsChromeAutocompleteNoise(event):
             msg = "WEB: Ignoring event believed to be chrome autocomplete noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if not self.utilities.inDocumentContent(orca_state.locusOfFocus):
             msg = "WEB: Event ignored: locusOfFocus (%s) is not in document content" \
                   % orca_state.locusOfFocus
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         obj, offset = self.utilities.getCaretContext()
         ancestor = self.utilities.commonAncestor(obj, event.source)
         if ancestor and self.utilities.isTextBlockElement(ancestor):
             msg = "WEB: Ignoring: Common ancestor of context and event source is text block"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         return False
@@ -1566,7 +1572,7 @@ class Script(default.Script):
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         return True
@@ -1576,36 +1582,36 @@ class Script(default.Script):
 
         if self.utilities.isZombie(event.source):
             msg = "WEB: Event source is Zombie"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.eventIsChromeNoise(event):
             msg = "WEB: Ignoring event believed to be chrome noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if self.utilities.eventIsAutocompleteNoise(event):
             msg = "WEB: Ignoring event believed to be autocomplete noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.eventIsSpinnerNoise(event):
             msg = "WEB: Ignoring: Event believed to be spinner noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.textEventIsDueToInsertion(event):
             msg = "WEB: Ignoring event believed to be due to text insertion"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         msg = "WEB: Clearing content cache due to text deletion"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         self.utilities.clearContentCache()
 
         state = event.source.getState()
@@ -1613,11 +1619,11 @@ class Script(default.Script):
             if self._inMouseOverObject \
                and self.utilities.isZombie(self._lastMouseOverObject):
                 msg = "WEB: Restoring pre-mouseover context"
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 self.restorePreMouseOverContext()
 
             msg = "WEB: Done processing non-editable source"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         return False
@@ -1627,62 +1633,62 @@ class Script(default.Script):
 
         if self.utilities.isZombie(event.source):
             msg = "WEB: Event source is Zombie"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.eventIsChromeNoise(event):
             msg = "WEB: Ignoring event believed to be chrome noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if self.utilities.eventIsAutocompleteNoise(event):
             msg = "WEB: Ignoring: Event believed to be autocomplete noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.eventIsSpinnerNoise(event):
             msg = "WEB: Ignoring: Event believed to be spinner noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         # TODO - JD: As an experiment, we're stopping these at the event manager.
         # If that works, this can be removed.
         if self.utilities.eventIsEOCAdded(event):
             msg = "WEB: Ignoring: Event was for embedded object char"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         msg = "WEB: Clearing content cache due to text insertion"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         self.utilities.clearContentCache()
 
         if self.utilities.handleAsLiveRegion(event):
             msg = "WEB: Event to be handled as live region"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.liveRegionManager.handleEvent(event)
             return True
 
         text = self.utilities.queryNonEmptyText(event.source)
         if not text:
             msg = "WEB: Ignoring: Event source is not a text object"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         state = event.source.getState()
         if not state.contains(pyatspi.STATE_EDITABLE):
             if event.source != orca_state.locusOfFocus:
                 msg = "WEB: Done processing non-editable, non-locusOfFocus source"
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return True
 
             if self.utilities.isClickableElement(event.source):
                 msg = "WEB: Event handled: Re-setting locusOfFocus to changed clickable"
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 orca.setLocusOfFocus(None, event.source, force=True)
                 return True
 
@@ -1693,17 +1699,17 @@ class Script(default.Script):
 
         if self.utilities.isZombie(event.source):
             msg = "WEB: Event source is Zombie"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if not self.utilities.inDocumentContent(event.source):
             msg = "WEB: Event source is not in document content"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if self.utilities.inFindToolbar():
             msg = "WEB: Event handled: Presenting find results"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.presentFindResults(event.source, -1)
             self._saveFocusedObjectInfo(orca_state.locusOfFocus)
             return True
@@ -1711,35 +1717,35 @@ class Script(default.Script):
         if not self.utilities.inDocumentContent(orca_state.locusOfFocus):
             msg = "WEB: Event ignored: locusOfFocus (%s) is not in document content" \
                   % orca_state.locusOfFocus
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.eventIsAutocompleteNoise(event):
             msg = "WEB: Ignoring: Event believed to be autocomplete noise"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         if self.utilities.textEventIsForNonNavigableTextObject(event):
             msg = "WEB: Ignoring event for non-navigable text object"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         text = self.utilities.queryNonEmptyText(event.source)
         if not text:
             msg = "WEB: Ignoring: Event source is not a text object"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         char = text.getText(event.detail1, event.detail1+1)
         if char == self.EMBEDDED_OBJECT_CHARACTER:
             msg = "WEB: Ignoring: Event offset is at embedded object"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         obj, offset = self.utilities.getCaretContext()
         if obj and obj.parent and event.source in [obj.parent, obj.parent.parent]:
             msg = "WEB: Ignoring: Source is context ancestor"
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         return False
@@ -1748,7 +1754,7 @@ class Script(default.Script):
         """Callback for window:activate accessibility events."""
 
         msg = "WEB: Calling default onWindowActivated"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         super().onWindowActivated(event)
         return True
 
@@ -1756,7 +1762,7 @@ class Script(default.Script):
         """Callback for window:deactivate accessibility events."""
 
         msg = "WEB: Clearing command state"
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         self._lastCommandWasCaretNav = False
         self._lastCommandWasStructNav = False
         self._lastCommandWasMouseButton = False
diff --git a/src/orca/scripts/web/script_utilities.py b/src/orca/scripts/web/script_utilities.py
index 0a986a5..2bbcd14 100644
--- a/src/orca/scripts/web/script_utilities.py
+++ b/src/orca/scripts/web/script_utilities.py
@@ -92,7 +92,7 @@ class Utilities(script_utilities.Utilities):
             self._caretContexts.pop(key, None)
 
     def clearCachedObjects(self):
-        debug.println(debug.LEVEL_INFO, "WEB: cleaning up cached objects")
+        debug.println(debug.LEVEL_INFO, "WEB: cleaning up cached objects", True)
         self._inDocumentContent = {}
         self._inTopLevelWebApp = {}
         self._isTextBlockElement = {}
@@ -137,7 +137,7 @@ class Utilities(script_utilities.Utilities):
             rv = obj.getRole() in roles
         except:
             msg = "WEB: Exception getting role for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             rv = False
 
         return rv
@@ -164,12 +164,12 @@ class Utilities(script_utilities.Utilities):
 
         if self.isDocument(obj):
             msg = "WEB: %s is document" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return obj
 
         document = pyatspi.findAncestor(obj, self.isDocument)
         msg = "WEB: Document for %s is %s" % (obj, document)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         return document
 
     def _getDocumentsEmbeddedBy(self, frame):
@@ -191,15 +191,15 @@ class Utilities(script_utilities.Utilities):
             window = orca_state.activeWindow
         else:
             msg = "WARNING: %s is not in %s" % (orca_state.activeWindow, app)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             window = self.activeWindow(app)
             try:
                 self._script.app = window.getApplication()
                 msg = "WEB: updating script's app to %s" % self._script.app
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
             except:
                 msg = "ERROR: Exception getting app for %s" % window
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
             else:
                 orca_state.activeWindow = window
 
@@ -233,7 +233,7 @@ class Utilities(script_utilities.Utilities):
             state = obj.getState()
         except:
             msg = "WEB: Exception getting state for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return
 
         orca.setLocusOfFocus(None, obj, notifyScript=False)
@@ -242,11 +242,11 @@ class Utilities(script_utilities.Utilities):
                 obj.queryComponent().grabFocus()
             except NotImplementedError:
                 msg = "WEB: %s does not implement the component interface" % obj
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return
             except:
                 msg = "WEB: Exception grabbing focus on %s" % obj
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return
 
         text = self.queryNonEmptyText(obj)
@@ -533,7 +533,7 @@ class Utilities(script_utilities.Utilities):
             pass
         except:
             msg = "WEB: Exception getting range extents for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return [0, 0, 0, 0]
 
         role = obj.getRole()
@@ -544,22 +544,22 @@ class Utilities(script_utilities.Utilities):
                 ext = obj.parent.queryComponent().getExtents(0)
             except NotImplementedError:
                 msg = "WEB: %s does not implement the component interface" % obj.parent
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return [0, 0, 0, 0]
             except:
                 msg = "WEB: Exception getting extents for %s" % obj.parent
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return [0, 0, 0, 0]
         else:
             try:
                 ext = obj.queryComponent().getExtents(0)
             except NotImplementedError:
                 msg = "WEB: %s does not implement the component interface" % obj
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return [0, 0, 0, 0]
             except:
                 msg = "WEB: Exception getting extents for %s" % obj
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return [0, 0, 0, 0]
 
         return [ext.x, ext.y, ext.width, ext.height]
@@ -761,7 +761,7 @@ class Utilities(script_utilities.Utilities):
         if not obj:
             msg = "WEB: Results for text at offset %i for %s using %s:\n" \
                   "     String: '', Start: 0, End: 0. (obj is None)" % (offset, obj, boundary)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return '', 0, 0
 
         text = self.queryNonEmptyText(obj)
@@ -769,7 +769,7 @@ class Utilities(script_utilities.Utilities):
             msg = "WEB: Results for text at offset %i for %s using %s:\n" \
                   "     String: '', Start: 0, End: 1. (queryNonEmptyText() returned None)" \
                   % (offset, obj, boundary)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return '', 0, 1
 
         if boundary == pyatspi.TEXT_BOUNDARY_CHAR:
@@ -777,7 +777,7 @@ class Utilities(script_utilities.Utilities):
             s = string.replace(self.EMBEDDED_OBJECT_CHARACTER, "[OBJ]").replace("\n", "\\n")
             msg = "WEB: Results for text at offset %i for %s using %s:\n" \
                   "     String: '%s', Start: %i, End: %i." % (offset, obj, boundary, s, start, end)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return string, start, end
 
         if not boundary:
@@ -785,7 +785,7 @@ class Utilities(script_utilities.Utilities):
             s = string.replace(self.EMBEDDED_OBJECT_CHARACTER, "[OBJ]").replace("\n", "\\n")
             msg = "WEB: Results for text at offset %i for %s using %s:\n" \
                   "     String: '%s', Start: %i, End: %i." % (offset, obj, boundary, s, start, end)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return string, start, end
 
         if boundary == pyatspi.TEXT_BOUNDARY_SENTENCE_START \
@@ -797,7 +797,7 @@ class Utilities(script_utilities.Utilities):
                 s = string.replace(self.EMBEDDED_OBJECT_CHARACTER, "[OBJ]").replace("\n", "\\n")
                 msg = "WEB: Results for text at offset %i for %s using %s:\n" \
                       "     String: '%s', Start: %i, End: %i." % (offset, obj, boundary, s, start, end)
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return string, start, end
 
         offset = max(0, offset)
@@ -809,7 +809,7 @@ class Utilities(script_utilities.Utilities):
             msg = "WEB: Results for text at offset %i for %s using %s:\n" \
                   "     String: '%s', Start: %i, End: %i.\n" \
                   "     Not checking for broken text." % (offset, obj, boundary, s, start, end)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return string, start, end
 
         needSadHack = False
@@ -823,7 +823,7 @@ class Utilities(script_utilities.Utilities):
                   "      The bug is the above results should be the same.\n" \
                   "      This very likely needs to be fixed by the toolkit." \
                   % (obj, boundary, offset, s1, start, end, start, s2, testStart, testEnd)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             needSadHack = True
         elif not string and 0 <= offset < text.characterCount:
             s1 = string.replace(self.EMBEDDED_OBJECT_CHARACTER, "[OBJ]").replace("\n", "\\n")
@@ -834,7 +834,7 @@ class Utilities(script_utilities.Utilities):
                   "      Character count: %i, Full text: '%s'.\n" \
                   "      This very likely needs to be fixed by the toolkit." \
                   % (offset, obj, boundary, s1, start, end, text.characterCount, s2)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             needSadHack = True
         elif not (start <= offset < end):
             s1 = string.replace(self.EMBEDDED_OBJECT_CHARACTER, "[OBJ]").replace("\n", "\\n")
@@ -843,7 +843,7 @@ class Utilities(script_utilities.Utilities):
                   "      The bug is the range returned is outside of the offset.\n" \
                   "      This very likely needs to be fixed by the toolkit." \
                   % (offset, obj, boundary, s1, start, end)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             needSadHack = True
 
         if needSadHack:
@@ -851,13 +851,13 @@ class Utilities(script_utilities.Utilities):
             s = sadString.replace(self.EMBEDDED_OBJECT_CHARACTER, "[OBJ]").replace("\n", "\\n")
             msg = "HACK: Attempting to recover from above failure.\n" \
                   "      String: '%s', Start: %i, End: %i." % (s, sadStart, sadEnd)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return sadString, sadStart, sadEnd
 
         s = string.replace(self.EMBEDDED_OBJECT_CHARACTER, "[OBJ]").replace("\n", "\\n")
         msg = "WEB: Results for text at offset %i for %s using %s:\n" \
               "     String: '%s', Start: %i, End: %i." % (offset, obj, boundary, s, start, end)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
         return string, start, end
 
     def _getContentsForObj(self, obj, offset, boundary):
@@ -1213,42 +1213,42 @@ class Utilities(script_utilities.Utilities):
             obj, offset = self.getCaretContext()
 
         msg = "WEB: Current context is: %s, %i" % (obj, offset)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if obj and self.isZombie(obj):
             msg = "WEB: Current context obj %s is zombie. Clearing cache." % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.clearCachedObjects()
 
             obj, offset = self.getCaretContext()
             msg = "WEB: Now Current context is: %s, %i" % (obj, offset)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
 
         line = self.getLineContentsAtOffset(obj, offset, layoutMode, useCache)
         msg = "WEB: Line contents for %s, %i: %s" % (obj, offset, line)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if not (line and line[0]):
             return []
 
         firstObj, firstOffset = line[0][0], line[0][1]
         msg = "WEB: First context on line is: %s, %i" % (firstObj, firstOffset)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         obj, offset = self.previousContext(firstObj, firstOffset, True)
         if not obj and firstObj:
             msg = "WEB: Previous context is: %s, %i. Trying again." % (obj, offset)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.clearCachedObjects()
             obj, offset = self.previousContext(firstObj, firstOffset, True)
 
         msg = "WEB: Previous context is: %s, %i" % (obj, offset)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         contents = self.getLineContentsAtOffset(obj, offset, layoutMode, useCache)
         if not contents:
             msg = "WEB: Could not get line contents for %s, %i" % (obj, offset)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return []
 
         return contents
@@ -1258,20 +1258,20 @@ class Utilities(script_utilities.Utilities):
             obj, offset = self.getCaretContext()
 
         msg = "WEB: Current context is: %s, %i" % (obj, offset)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if obj and self.isZombie(obj):
             msg = "WEB: Current context obj %s is zombie. Clearing cache." % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.clearCachedObjects()
 
             obj, offset = self.getCaretContext()
             msg = "WEB: Now Current context is: %s, %i" % (obj, offset)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
 
         line = self.getLineContentsAtOffset(obj, offset, layoutMode, useCache)
         msg = "WEB: Line contents for %s, %i: %s" % (obj, offset, line)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         if not (line and line[0]):
             return []
@@ -1282,22 +1282,22 @@ class Utilities(script_utilities.Utilities):
         else:
             lastObj, lastOffset = line[-1][0], line[-1][2] - 1
         msg = "WEB: Last context on line is: %s, %i" % (lastObj, lastOffset)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         obj, offset = self.nextContext(lastObj, lastOffset, True)
         if not obj and lastObj:
             msg = "WEB: Next context is: %s, %i. Trying again." % (obj, offset)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             self.clearCachedObjects()
             obj, offset = self.nextContext(lastObj, lastOffset, True)
 
         msg = "WEB: Next context is: %s, %i" % (obj, offset)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         contents = self.getLineContentsAtOffset(obj, offset, layoutMode, useCache)
         if not contents:
             msg = "WEB: Could not get line contents for %s, %i" % (obj, offset)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return []
 
         return contents
@@ -1323,14 +1323,14 @@ class Utilities(script_utilities.Utilities):
             role = obj.getRole()
         except:
             msg = "WEB: Exception getting role for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if role == pyatspi.ROLE_EMBEDDED and not self.getDocumentForObject(obj.parent):
             uri = self.documentFrameURI()
             rv = bool(uri and uri.startswith("http"))
             msg = "WEB: %s is top-level web application: %s (URI: %s)" % (obj, rv, uri)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return rv
 
         return False
@@ -1341,7 +1341,7 @@ class Utilities(script_utilities.Utilities):
             state = obj.getState()
         except:
             msg = "WEB: Exception getting role and state for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if state.contains(pyatspi.STATE_EDITABLE) \
@@ -1391,7 +1391,7 @@ class Utilities(script_utilities.Utilities):
             state = obj.getState()
         except:
             msg = "WEB: Exception getting role and state for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         textBlockElements = [pyatspi.ROLE_CAPTION,
@@ -1442,7 +1442,7 @@ class Utilities(script_utilities.Utilities):
             childCount = obj.childCount
         except:
             msg = "WEB: Exception getting role and childCount for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         rv = False
@@ -1872,7 +1872,7 @@ class Utilities(script_utilities.Utilities):
         if (obj and obj.getRole() in docRoles):
             if obj.parent is None:
                 msg = "WEB: %s is a detatched document" % obj
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return True
 
         return False
@@ -1884,7 +1884,7 @@ class Utilities(script_utilities.Utilities):
             iframes = pyatspi.findAllDescendants(root, isIframe)
         except:
             msg = "WEB: Exception getting descendant iframes of %s" % root
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return None
 
         for iframe in iframes:
@@ -1893,7 +1893,7 @@ class Utilities(script_utilities.Utilities):
                 self._isBrokenChildParentTree(obj, iframe)
 
                 msg = "WEB: Returning %s as iframe parent of detached %s" % (iframe, obj)
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
                 return iframe
 
         return None
@@ -1906,25 +1906,25 @@ class Utilities(script_utilities.Utilities):
             childIsChildOfParent = child in parent
         except:
             msg = "WEB: Exception checking if %s is in %s" % (child, parent)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             childIsChildOfParent = False
         else:
             msg = "WEB: %s is child of %s: %s" % (child, parent, childIsChildOfParent)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
 
         try:
             parentIsParentOfChild = child.parent == parent
         except:
             msg = "WEB: Exception getting parent of %s" % child
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             parentIsParentOfChild = False
         else:
             msg = "WEB: %s is parent of %s: %s" % (parent, child, parentIsParentOfChild)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
 
         if parentIsParentOfChild != childIsChildOfParent:
             msg = "FAIL: The above is broken and likely needs to be fixed by the toolkit."
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
 
         return False
@@ -2117,7 +2117,7 @@ class Utilities(script_utilities.Utilities):
             canvases = pyatspi.findAllDescendants(obj, isCanvas)
         except:
             msg = "WEB: Exception getting descendant canvases of %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             rv = False
         else:
             rv = len(list(filter(self.isUselessImage, canvases))) > 0
@@ -2171,11 +2171,11 @@ class Utilities(script_utilities.Utilities):
             childCount = obj.childCount
         except:
             msg = "WEB: Exception getting childCount for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             childCount = 0
         if childCount and obj[0] is None:
             msg = "ERROR: %s reports %i children, but obj[0] is None" % (obj, childCount)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             rv = True
 
         self._isParentOfNullChild[hash(obj)] = rv
@@ -2234,7 +2234,7 @@ class Utilities(script_utilities.Utilities):
             name = obj.name
         except:
             msg = "WEB: Exception getting name for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
         else:
             if name:
                 return False
@@ -2248,7 +2248,7 @@ class Utilities(script_utilities.Utilities):
             role = obj.getRole()
         except:
             msg = "WEB: Exception getting role for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         # TODO - JD: This is private.
@@ -2309,7 +2309,7 @@ class Utilities(script_utilities.Utilities):
             role = event.source.getRole()
         except:
             msg = "WEB: Exception getting role for %s" % event.source
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         eType = event.type
@@ -2354,14 +2354,14 @@ class Utilities(script_utilities.Utilities):
             focusState = orca_state.locusOfFocus.getState()
         except:
             msg = "WEB: Exception getting role and state for %s" % orca_state.locusOfFocus
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         try:
             role = event.source.getRole()
         except:
             msg = "WEB: Exception getting role for %s" % event.source
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return False
 
         if role in [pyatspi.ROLE_MENU, pyatspi.ROLE_MENU_ITEM] \
@@ -2436,11 +2436,11 @@ class Utilities(script_utilities.Utilities):
             start, end = hyperlink.startIndex, hyperlink.endIndex
         except NotImplementedError:
             msg = "WEB: %s does not implement the hyperlink interface" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return -1, -1
         except:
             msg = "WEB: Exception getting hyperlink indices for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return -1, -1
 
         return start, end
@@ -2466,11 +2466,11 @@ class Utilities(script_utilities.Utilities):
             hypertext = obj.queryHypertext()
         except NotImplementedError:
             msg = "WEB: %s does not implement the hypertext interface" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return -1
         except:
             msg = "WEB: Exception querying hypertext interface for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return -1
 
         return hypertext.getLinkIndex(offset)
@@ -2506,7 +2506,7 @@ class Utilities(script_utilities.Utilities):
             childCount = obj.childCount
         except:
             msg = "WEB: Exception getting childCount for %s" % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return True
         if not childCount or self.isParentOfNullChild(obj):
             return True
@@ -2604,7 +2604,7 @@ class Utilities(script_utilities.Utilities):
             role = obj.getRole()
         except:
             msg = "WEB: Exception getting first caret context for %s %i" % (obj, offset)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return None, -1
 
         lookInChild = [pyatspi.ROLE_LIST,
@@ -2613,7 +2613,7 @@ class Utilities(script_utilities.Utilities):
                        pyatspi.ROLE_TABLE_ROW]
         if role in lookInChild and obj.childCount and not self.treatAsDiv(obj):
             msg = "WEB: First caret context for %s, %i will look in child %s" % (obj, offset, obj[0])
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return self.findFirstCaretContext(obj[0], 0)
 
         text = self.queryNonEmptyText(obj)
@@ -2622,29 +2622,29 @@ class Utilities(script_utilities.Utilities):
                 nextObj, nextOffset = self.nextContext(obj, offset)
                 if nextObj:
                     msg = "WEB: First caret context for %s, %i is %s, %i" % (obj, offset, nextObj, 
nextOffset)
-                    debug.println(debug.LEVEL_INFO, msg)
+                    debug.println(debug.LEVEL_INFO, msg, True)
                     return nextObj, nextOffset
 
             msg = "WEB: First caret context for %s, %i is %s, %i" % (obj, offset, obj, 0)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return obj, 0
 
         if offset >= text.characterCount:
             msg = "WEB: First caret context for %s, %i is %s, %i" % (obj, offset, obj, text.characterCount)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return obj, text.characterCount
 
         allText = text.getText(0, -1)
         offset = max (0, offset)
         if allText[offset] != self.EMBEDDED_OBJECT_CHARACTER:
             msg = "WEB: First caret context for %s, %i is %s, %i" % (obj, offset, obj, offset)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return obj, offset
 
         child = self.getChildAtOffset(obj, offset)
         if not child:
             msg = "WEB: First caret context for %s, %i is %s, %i" % (obj, offset, None, -1)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             return None, -1
 
         return self.findFirstCaretContext(child, 0)
@@ -2703,7 +2703,7 @@ class Utilities(script_utilities.Utilities):
                 parentChildCount = parent.childCount
             except:
                 msg = "WEB: Exception getting childCount for %s" % parent
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
             else:
                 if 0 < index < parentChildCount:
                     return self.findNextCaretInOrder(parent[index], -1)
@@ -2767,7 +2767,7 @@ class Utilities(script_utilities.Utilities):
                 parentChildCount = parent.childCount
             except:
                 msg = "WEB: Exception getting childCount for %s" % parent
-                debug.println(debug.LEVEL_INFO, msg)
+                debug.println(debug.LEVEL_INFO, msg, True)
             else:
                 if 0 <= index < parentChildCount:
                     return self.findPreviousCaretInOrder(parent[index], -1)
diff --git a/src/orca/scripts/web/speech_generator.py b/src/orca/scripts/web/speech_generator.py
index 88d0593..38d22f3 100644
--- a/src/orca/scripts/web/speech_generator.py
+++ b/src/orca/scripts/web/speech_generator.py
@@ -430,12 +430,12 @@ class SpeechGenerator(speech_generator.SpeechGenerator):
 
     def generateSpeech(self, obj, **args):
         if not self._script.utilities.inDocumentContent(obj):
-            msg = "\nINFO: %s is not in document content. Calling default speech generator." % obj
-            debug.println(debug.LEVEL_INFO, msg)
+            msg = "WEB: %s is not in document content. Calling default speech generator." % obj
+            debug.println(debug.LEVEL_INFO, msg, True)
             return super().generateSpeech(obj, **args)
 
-        msg = "\nINFO: Generating speech for document object %s" % obj
-        debug.println(debug.LEVEL_INFO, msg)
+        msg = "WEB: Generating speech for document object %s" % obj
+        debug.println(debug.LEVEL_INFO, msg, True)
 
         result = []
         if args.get('formatType') == 'detailedWhereAmI':
@@ -453,8 +453,11 @@ class SpeechGenerator(speech_generator.SpeechGenerator):
         result = list(filter(lambda x: x, result))
         self._restoreRole(oldRole, args)
 
-        msg = "\nINFO: Speech generation for document object %s complete:\n%s\n" % (obj, result)
+        msg = "WEB: Speech generation for document object %s complete:" % obj
         debug.println(debug.LEVEL_INFO, msg)
+        for element in result:
+            debug.println(debug.LEVEL_ALL, "           %s" % element)
+
         return result
 
     def generateContents(self, contents, **args):
@@ -463,13 +466,13 @@ class SpeechGenerator(speech_generator.SpeechGenerator):
 
         result = []
         contents = self._script.utilities.filterContentsForPresentation(contents, False)
-        msg = "INFO: Generating speech contents (length: %i)" % len(contents)
-        debug.println(debug.LEVEL_INFO, msg)
+        msg = "WEB: Generating speech contents (length: %i)" % len(contents)
+        debug.println(debug.LEVEL_INFO, msg, True)
         for i, content in enumerate(contents):
             obj, start, end, string = content
             msg = "ITEM %i: %s, start: %i, end: %i, string: '%s'" \
                   % (i, obj, start, end, string)
-            debug.println(debug.LEVEL_INFO, msg)
+            debug.println(debug.LEVEL_INFO, msg, True)
             utterance = self.generateSpeech(
                 obj, startOffset=start, endOffset=end, string=string,
                 index=i, total=len(contents), **args)
diff --git a/src/orca/settings_manager.py b/src/orca/settings_manager.py
index f1e3762..c602392 100644
--- a/src/orca/settings_manager.py
+++ b/src/orca/settings_manager.py
@@ -72,7 +72,7 @@ class SettingsManager(object):
         backend='json'
         """
 
-        debug.println(debug.LEVEL_FINEST, 'INFO: Initializing settings manager')
+        debug.println(debug.LEVEL_INFO, 'SETTINGS MANAGER: Initializing', True)
 
         self.backendModule = None
         self._backend = None
@@ -115,10 +115,10 @@ class SettingsManager(object):
         # For handling the currently-"classic" application settings
         self.settingsPackages = ["app-settings"]
 
-        debug.println(debug.LEVEL_FINEST, 'INFO: Settings manager initialized')
+        debug.println(debug.LEVEL_INFO, 'SETTINGS MANAGER: Initialized', True)
 
     def activate(self, prefsDir=None, customSettings={}):
-        debug.println(debug.LEVEL_FINEST, 'INFO: Activating settings manager')
+        debug.println(debug.LEVEL_INFO, 'SETTINGS MANAGER: Activating', True)
 
         self.customizedSettings.update(customSettings)
         self._prefsDir = prefsDir \
@@ -141,7 +141,7 @@ class SettingsManager(object):
         #
         self._createDefaults()
 
-        debug.println(debug.LEVEL_FINEST, 'INFO: Settings manager activated')
+        debug.println(debug.LEVEL_INFO, 'SETTINGS MANAGER: Activated', True)
 
         # Set the active profile and load its stored settings
         if self.profile is None:
@@ -242,7 +242,7 @@ class SettingsManager(object):
         success = False
         pathList = [self._prefsDir]
         try:
-            msg = "Attempt to load orca-customizations "
+            msg = "SETTINGS MANAGER: Attempt to load orca-customizations "
             (fileHnd, moduleName, desc) = \
                 imp.find_module("orca-customizations", pathList)
             msg += "from %s " % moduleName
@@ -256,7 +256,7 @@ class SettingsManager(object):
             msg += "succeeded."
             fileHnd.close()
             success = True
-        debug.println(debug.LEVEL_ALL, msg)
+        debug.println(debug.LEVEL_ALL, msg, True)
         return success
 
     def getPrefsDir(self):
diff --git a/src/orca/speech.py b/src/orca/speech.py
index ca981b5..e5295fa 100644
--- a/src/orca/speech.py
+++ b/src/orca/speech.py
@@ -69,9 +69,6 @@ def _initSpeechServer(moduleName, speechServerInfo):
     if not moduleName:
         return
 
-    debug.println(debug.LEVEL_CONFIGURATION,
-                  "Trying to use speech server factory: %s" % moduleName)
-
     factory = None
     try:
         factory = importlib.import_module('orca.%s' % moduleName)
@@ -90,15 +87,16 @@ def _initSpeechServer(moduleName, speechServerInfo):
     if not _speechserver:
         _speechserver = factory.SpeechServer.getSpeechServer()
         if speechServerInfo:
-            debug.println(debug.LEVEL_CONFIGURATION,
-                          "Invalid speechServerInfo: %s" % speechServerInfo)
+            msg = 'SPEECH: Invalid speechServerInfo: %s' % speechServerInfo
+            debug.println(debug.LEVEL_INFO, msg, True)
 
     if not _speechserver:
-        raise Exception("No speech server for factory: %s" % moduleName)
+        raise Exception("ERROR: No speech server for factory: %s" % moduleName)
 
 def init():
-
+    debug.println(debug.LEVEL_INFO, 'SPEECH: Initializing', True)
     if _speechserver:
+        debug.println(debug.LEVEL_INFO, 'SPEECH: Already initialized', True)
         return
 
     try:
@@ -117,10 +115,13 @@ def init():
                     debug.printException(debug.LEVEL_SEVERE)
 
     if _speechserver:
-        debug.println(debug.LEVEL_CONFIGURATION,
-                      "Using speech server factory: %s" % moduleName)
+        msg = 'SPEECH: Using speech server factory: %s' % moduleName
+        debug.println(debug.LEVEL_INFO, msg, True)
     else:
-        debug.println(debug.LEVEL_CONFIGURATION, "Speech not available.")
+        msg = 'SPEECH: Not available'
+        debug.println(debug.LEVEL_INFO, msg, True)
+
+    debug.println(debug.LEVEL_INFO, 'SPEECH: Initialized', True)
 
 def __resolveACSS(acss=None):
     if acss:
@@ -137,7 +138,7 @@ def sayAll(utteranceIterator, progressCallback):
     else:
         for [context, acss] in utteranceIterator:
             logLine = "SPEECH OUTPUT: '" + context.utterance + "'"
-            debug.println(debug.LEVEL_INFO, logLine)
+            debug.println(debug.LEVEL_INFO, logLine, True)
             log.info(logLine)
 
 def _speak(text, acss, interrupt):
@@ -152,7 +153,7 @@ def _speak(text, acss, interrupt):
                     extraDebug = " voice=%s" % key
                 break
 
-    debug.println(debug.LEVEL_INFO, logLine + extraDebug + str(acss))
+    debug.println(debug.LEVEL_INFO, logLine + extraDebug + str(acss), True)
     log.info(logLine + extraDebug)
 
     if _speechserver:
@@ -173,10 +174,10 @@ def speak(content, acss=None, interrupt=True):
 
     validTypes = (str, list, speech_generator.Pause,
                   speech_generator.LineBreak, ACSS)
-    error = "bad content sent to speech.speak: '%s'"
+    error = "SPEECH: bad content sent to speak(): '%s'"
     if not isinstance(content, validTypes):
         debug.printStack(debug.LEVEL_WARNING)
-        debug.println(debug.LEVEL_WARNING, error % content)
+        debug.println(debug.LEVEL_WARNING, error % content, True)
         return
 
     if isinstance(content, str):
@@ -188,7 +189,7 @@ def speak(content, acss=None, interrupt=True):
     activeVoice = ACSS(acss)
     for element in content:
         if not isinstance(element, validTypes):
-            debug.println(debug.LEVEL_WARNING, error % element)
+            debug.println(debug.LEVEL_WARNING, error % element, True)
         elif isinstance(element, list):
             speak(element, acss, interrupt)
         elif isinstance(element, str):
@@ -230,7 +231,7 @@ def speakKeyEvent(event):
     lockingStateString = event.getLockingStateString()
     msg = "%s %s" % (keyname, lockingStateString)
     logLine = "SPEECH OUTPUT: '%s'" % msg
-    debug.println(debug.LEVEL_INFO, logLine)
+    debug.println(debug.LEVEL_INFO, logLine, True)
     log.info(logLine)
 
     if _speechserver:
@@ -250,7 +251,8 @@ def speakCharacter(character, acss=None):
     if settings.silenceSpeech:
         return
 
-    debug.println(debug.LEVEL_INFO, "SPEECH OUTPUT: '" + character + "' " + str(acss))
+    msg = "SPEECH OUTPUT: '" + character + "' " + str(acss)
+    debug.println(debug.LEVEL_INFO, msg, True)
     log.info("SPEECH OUTPUT: '%s'" % character)
 
     if _speechserver:
diff --git a/src/orca/speechdispatcherfactory.py b/src/orca/speechdispatcherfactory.py
index 9d53df0..a282564 100644
--- a/src/orca/speechdispatcherfactory.py
+++ b/src/orca/speechdispatcherfactory.py
@@ -128,12 +128,12 @@ class SpeechServer(speechserver.SpeechServer):
             (ACSS.FAMILY, self._set_family),
             )
         if not _speechd_available:
-            debug.println(debug.LEVEL_WARNING,
-                          "Speech Dispatcher interface not installed.")
+            msg = 'ERROR: Speech Dispatcher is not available'
+            debug.println(debug.LEVEL_WARNING, msg, True)
             return
         if not _speechd_version_ok:
-            debug.println(debug.LEVEL_WARNING,
-                        "Speech Dispatcher version 0.6.2 or later is required.")
+            msg = 'ERROR: Speech Dispatcher version 0.6.2 or later is required.'
+            debug.println(debug.LEVEL_WARNING, msg, True)
             return
         # The following constants must be initialized in runtime since they
         # depend on the speechd module being available.
@@ -155,9 +155,9 @@ class SpeechServer(speechserver.SpeechServer):
         try:
             self._init()
         except:
-            debug.println(debug.LEVEL_WARNING,
-                          "Speech Dispatcher service failed to connect:")
             debug.printException(debug.LEVEL_WARNING)
+            msg = 'ERROR: Speech Dispatcher service failed to connect'
+            debug.println(debug.LEVEL_WARNING, msg, True)
         else:
             SpeechServer._active_servers[serverId] = self
 
@@ -193,9 +193,8 @@ class SpeechServer(speechserver.SpeechServer):
             try:
                 return command(*args, **kwargs)
             except speechd.SSIPCommunicationError:
-                debug.println(debug.LEVEL_CONFIGURATION,
-                              "Speech Dispatcher connection lost. "
-                              "Trying to reconnect.")
+                msg = "SPEECH DISPATCHER: Connection lost. Trying to reconnect."
+                debug.println(debug.LEVEL_INFO, msg, True)
                 self.reset()
                 return command(*args, **kwargs)
             except:
@@ -254,7 +253,7 @@ class SpeechServer(speechserver.SpeechServer):
                self._current_voice_properties.get(ACSS.AVERAGE_PITCH),
                sd_rate,
                sd_pitch)
-        debug.println(debug.LEVEL_INFO, msg)
+        debug.println(debug.LEVEL_INFO, msg, True)
 
     def _apply_acss(self, acss):
         if acss is None:
@@ -377,9 +376,8 @@ class SpeechServer(speechserver.SpeechServer):
         except KeyError:
             rate = 50
         acss[ACSS.RATE] = max(0, min(99, rate + delta))
-        debug.println(debug.LEVEL_CONFIGURATION,
-                      "Speech rate is now %d" % rate)
-
+        msg = 'SPEECH DISPATCHER: Rate set to %d' % rate
+        debug.println(debug.LEVEL_INFO, msg, True)
         self.speak(decrease and messages.SPEECH_SLOWER \
                    or messages.SPEECH_FASTER, acss=acss)
 
@@ -391,9 +389,8 @@ class SpeechServer(speechserver.SpeechServer):
         except KeyError:
             pitch = 5
         acss[ACSS.AVERAGE_PITCH] = max(0, min(9, pitch + delta))
-        debug.println(debug.LEVEL_CONFIGURATION,
-                      "Speech pitch is now %d" % pitch)
-
+        msg = 'SPEECH DISPATCHER: Pitch set to %d' % pitch
+        debug.println(debug.LEVEL_INFO, msg, True)
         self.speak(decrease and messages.SPEECH_LOWER \
                    or messages.SPEECH_HIGHER, acss=acss)
 
@@ -405,9 +402,8 @@ class SpeechServer(speechserver.SpeechServer):
         except KeyError:
             volume = 5
         acss[ACSS.GAIN] = max(0, min(9, volume + delta))
-        debug.println(debug.LEVEL_CONFIGURATION,
-                      "Speech volume is now %d" % volume)
-
+        msg = 'SPEECH DISPATCHER: Volume set to %d' % volume
+        debug.println(debug.LEVEL_INFO, msg, True)
         self.speak(decrease and messages.SPEECH_SOFTER \
                    or messages.SPEECH_LOUDER, acss=acss)
 


[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]