[orca] Add more debugging

[Joanmarie Diggs <joanied src gnome org>]

commit 8f2823acac505d5b980e7a6afb39513faa90e3e2
Author: Joanmarie Diggs <jdiggs igalia com>
Date:   Sat May 9 16:23:08 2020 -0400

    Add more debugging

 src/orca/generator.py                    | 28 +++++++++++++++++++++-------
 src/orca/script_utilities.py             |  5 +++++
 src/orca/scripts/default.py              |  4 ++++
 src/orca/scripts/web/speech_generator.py |  5 +----
 src/orca/speech_generator.py             | 24 ++++++++++++++++++++++++
 5 files changed, 55 insertions(+), 11 deletions(-)
---
diff --git a/src/orca/generator.py b/src/orca/generator.py
index 94f1964cd..862b6ae2d 100644
--- a/src/orca/generator.py
+++ b/src/orca/generator.py
@@ -236,6 +236,7 @@ class Generator:
             msg = '%s GENERATOR: Starting generation for %s' % (self._mode.upper(), obj)
             debug.println(debug.LEVEL_INFO, msg, True)
 
+            debuginfo = lambda x: self._resultElementToString(x, False)
             assert(formatting)
             while True:
                 currentTime = time.time()
@@ -253,9 +254,11 @@ class Generator:
                         break
                     globalsDict[arg] = self._methodsDict[arg](obj, **args)
                     duration = "%.4f" % (time.time() - currentTime)
-                    debug.println(debug.LEVEL_ALL,
-                                  "%sGENERATION TIME: %s  ---->  %s=%s" \
-                                  % (' ' * 18, duration, arg, repr(globalsDict[arg])))
+                    if isinstance(globalsDict[arg], list):
+                        stringResult = " ".join(filter(lambda x: x, map(debuginfo, globalsDict[arg])))
+                        debug.println(debug.LEVEL_ALL,
+                                      "%sGENERATION TIME: %s  ---->  %s=[%s]" \
+                                      % (" " * 18, duration, arg, stringResult))
 
         except:
             debug.printException(debug.LEVEL_SEVERE)
@@ -263,15 +266,26 @@ class Generator:
 
         duration = "%.4f" % (time.time() - startTime)
         debug.println(debug.LEVEL_ALL, "%sCOMPLETION TIME: %s" % (' ' * 18, duration))
-        debug.println(debug.LEVEL_ALL, "%s GENERATOR: Results:" % self._mode.upper(), True)
-        for element in result:
-            debug.println(debug.LEVEL_ALL, "%s%s" % (' ' * 18, element))
-
+        self._debugResultInfo(result)
         if args.get('isProgressBarUpdate') and result:
             self.setProgressBarUpdateTimeAndValue(obj)
 
         return result
 
+    def _resultElementToString(self, element, includeAll=True):
+        if not includeAll:
+            return str(element)
+
+        return "\n%s'%s'" % (" " * 18, element)
+
+    def _debugResultInfo(self, result):
+        if debug.LEVEL_ALL < debug.debugLevel:
+            return
+
+        info = "%s%s GENERATOR: Results: " % (" " * 18, self._mode.upper())
+        info += "%s" % " ".join(map(self._resultElementToString, result))
+        debug.println(debug.LEVEL_ALL, info)
+
     #####################################################################
     #                                                                   #
     # Name, role, and label information                                 #
diff --git a/src/orca/script_utilities.py b/src/orca/script_utilities.py
index b19e4bf4d..6a15af114 100644
--- a/src/orca/script_utilities.py
+++ b/src/orca/script_utilities.py
@@ -2203,11 +2203,16 @@ class Utilities:
         if not (obj and obj.getRole() == pyatspi.ROLE_STATUS_BAR):
             return []
 
+        start = time.time()
         items = self._script.pointOfReference.get('statusBarItems')
         if not items:
             items = self.getOnScreenObjects(obj)
             self._script.pointOfReference['statusBarItems'] = items
 
+        end = time.time()
+        msg = "INFO: Time getting status bar items: %.4f" % (end - start)
+        debug.println(debug.LEVEL_INFO, msg, True)
+
         return items
 
     def statusBar(self, obj):
diff --git a/src/orca/scripts/default.py b/src/orca/scripts/default.py
index e92c0db87..c8b613e43 100644
--- a/src/orca/scripts/default.py
+++ b/src/orca/scripts/default.py
@@ -1246,7 +1246,11 @@ class Script(script.Script):
 
         frame, dialog = self.utilities.frameAndDialog(obj)
         if frame:
+            start = time.time()
             statusbar = self.utilities.statusBar(frame)
+            end = time.time()
+            msg = "DEFAULT: Time searching for status bar: %.4f" % (end - start)
+            debug.println(debug.LEVEL_INFO, msg, True)
             if statusbar:
                 self.pointOfReference['statusBarItems'] = None
                 self.presentObject(statusbar)
diff --git a/src/orca/scripts/web/speech_generator.py b/src/orca/scripts/web/speech_generator.py
index 04f6f71ef..dc141ded6 100644
--- a/src/orca/scripts/web/speech_generator.py
+++ b/src/orca/scripts/web/speech_generator.py
@@ -755,11 +755,8 @@ class SpeechGenerator(speech_generator.SpeechGenerator):
             result = list(filter(lambda x: x, super().generateSpeech(obj, **args)))
 
         self._restoreRole(oldRole, args)
-        msg = "WEB: Speech generation for document object %s complete:" % obj
+        msg = "WEB: Speech generation for document object %s complete." % obj
         debug.println(debug.LEVEL_INFO, msg, True)
-        for element in result:
-            debug.println(debug.LEVEL_ALL, "%s%s" % (' ' * 18, element))
-
         return result
 
     def generateContents(self, contents, **args):
diff --git a/src/orca/speech_generator.py b/src/orca/speech_generator.py
index 1c9ae18e9..1374f8bed 100644
--- a/src/orca/speech_generator.py
+++ b/src/orca/speech_generator.py
@@ -44,6 +44,9 @@ class Pause:
     def __init__(self):
         pass
 
+    def __str__(self):
+        return "PAUSE"
+
 PAUSE = [Pause()]
 
 class LineBreak:
@@ -113,6 +116,27 @@ class SpeechGenerator(generator.Generator):
     def generateSpeech(self, obj, **args):
         return self.generate(obj, **args)
 
+    def _resultElementToString(self, element, includeAll=True):
+        if debug.LEVEL_ALL < debug.debugLevel:
+            return element
+
+        if isinstance(element, str):
+            return super()._resultElementToString(element, includeAll)
+
+        if not isinstance(element, acss.ACSS):
+            return str(element)
+
+        if not includeAll:
+            return ""
+
+        voices = {"default": self.voice(DEFAULT)[0],
+                  "system": self.voice(SYSTEM)[0],
+                  "hyperlink": self.voice(HYPERLINK)[0],
+                  "uppercase": self.voice(UPPERCASE)[0]}
+
+        voicetypes = [k for k in voices if voices.get(k) == element]
+        return "Voice(s): (%s)" % ", ".join(voicetypes)
+
     #####################################################################
     #                                                                   #
     # Name, role, and label information                                 #