From b7b2dc40de355add3634cc972fc31521a8daeed3 Mon Sep 17 00:00:00 2001
From: Chris Manchester <cmanchester@mozilla.com>
Date: Fri, 17 Oct 2014 11:59:15 -0400
Subject: [PATCH] Bug 1079635 - Implement a verbose option for the
 machformatter for those debugging tests locally.;r=jgraham

---
 .../mozlog/mozlog/structured/commandline.py   | 35 ++++++++++++-------
 .../structured/formatters/machformatter.py    | 24 +++++++++----
 2 files changed, 40 insertions(+), 19 deletions(-)

diff --git a/testing/mozbase/mozlog/mozlog/structured/commandline.py b/testing/mozbase/mozlog/mozlog/structured/commandline.py
index 9cf83c873fed..06c15badd0ed 100644
--- a/testing/mozbase/mozlog/mozlog/structured/commandline.py
+++ b/testing/mozbase/mozlog/mozlog/structured/commandline.py
@@ -22,11 +22,24 @@ log_formatters = {
 def level_filter_wrapper(formatter, level):
     return handlers.LogLevelFilter(formatter, level)
 
+def verbose_wrapper(formatter, verbose):
+    formatter.verbose = verbose
+    return formatter
+
+formatter_option_defaults = {
+    'verbose': False,
+    'level': 'info',
+}
+
 fmt_options = {
-    # <option name>: (<wrapper function>, description, <applicable formatters>)
+    # <option name>: (<wrapper function>, description, <applicable formatters>, action)
+    # "action" is used by the commandline parser in use.
+    'verbose': (verbose_wrapper,
+                "Enables verbose mode for the given formatter.",
+                ["mach"], "store_true"),
     'level': (level_filter_wrapper,
               "A least log level to subscribe to for the given formatter (debug, info, error, etc.)",
-              ["mach", "tbpl"]),
+              ["mach", "tbpl"], "store"),
 }
 
 
@@ -61,10 +74,10 @@ def add_logging_group(parser):
         for name, (cls, help_str) in log_formatters.iteritems():
             group.add_option("--log-" + name, action="append", type="str",
                              help=help_str)
-        for optname, (cls, help_str, formatters) in fmt_options.iteritems():
+        for optname, (cls, help_str, formatters, action) in fmt_options.iteritems():
             for fmt in formatters:
-                group.add_option("--log-%s-%s" % (fmt, optname), action="store",
-                                 type="str", help=help_str)
+                group.add_option("--log-%s-%s" % (fmt, optname), action=action,
+                                 help=help_str, default=None)
         parser.add_option_group(group)
     else:
         group = parser.add_argument_group(group_name,
@@ -73,10 +86,10 @@ def add_logging_group(parser):
             group.add_argument("--log-" + name, action="append", type=log_file,
                                help=help_str)
 
-        for optname, (cls, help_str, formatters) in fmt_options.iteritems():
+        for optname, (cls, help_str, formatters, action) in fmt_options.iteritems():
             for fmt in formatters:
-                group.add_argument("--log-%s-%s" % (fmt, optname), action="store",
-                                   type=str, help=help_str)
+                group.add_argument("--log-%s-%s" % (fmt, optname), action=action,
+                                   help=help_str, default=None)
 
 
 def setup_handlers(logger, formatters, formatter_options):
@@ -125,13 +138,9 @@ def setup_logging(suite, args, defaults=None):
     :rtype: StructuredLogger
     """
 
-    _option_defaults = {
-        'level': 'info',
-    }
-
     logger = StructuredLogger(suite)
     # Keep track of any options passed for formatters.
-    formatter_options = defaultdict(lambda: _option_defaults.copy())
+    formatter_options = defaultdict(lambda: formatter_option_defaults.copy())
     # Keep track of formatters and list of streams specified.
     formatters = {}
     found = False
diff --git a/testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py b/testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
index 223da502f9b3..5358c577912c 100644
--- a/testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
+++ b/testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
@@ -43,6 +43,7 @@ class MachFormatter(base.BaseFormatter):
         self.has_unexpected = {}
         self.last_time = None
         self.terminal = terminal
+        self.verbose = False
 
         self.summary_values = {"tests": 0,
                                "subtests": 0,
@@ -74,7 +75,8 @@ class MachFormatter(base.BaseFormatter):
                     color = self.terminal.green
                 else:
                     color = self.terminal.red
-            elif data["action"] in ("suite_start", "suite_end", "test_start"):
+            elif data["action"] in ("suite_start", "suite_end",
+                                    "test_start", "test_status"):
                 color = self.terminal.yellow
             elif data["action"] == "crash":
                 color = self.terminal.red
@@ -231,16 +233,26 @@ class MachFormatter(base.BaseFormatter):
                 message += "\n"
             message += data["stack"]
 
-        if "expected" in data:
-            self.status_buffer[test]["unexpected"].append((data["subtest"],
-                                                           data["status"],
-                                                           data["expected"],
-                                                           message))
         if data["status"] == "PASS":
             self.status_buffer[test]["pass"] += 1
 
         self._update_summary(data)
 
+        rv = None
+        status, subtest = data["status"], data["subtest"]
+        unexpected = "expected" in data
+        if self.verbose:
+            color = self.terminal.red if unexpected else self.terminal.green
+            rv = " ".join([subtest, color(status), message])
+        elif unexpected:
+            # We only append an unexpected summary if it was not logged
+            # directly by verbose mode.
+            self.status_buffer[test]["unexpected"].append((subtest,
+                                                           status,
+                                                           data["expected"],
+                                                           message))
+        return rv
+
     def _update_summary(self, data):
         if "expected" in data:
             self.summary_values["unexpected"][data["status"]] += 1