Bug 1367745 - Make sure 'process_output' messages are logged at the proper mozharness level, r=jgraham
authorAndrew Halberstadt <ahalberstadt@mozilla.com>
Tue, 23 May 2017 09:05:57 -0400
changeset 409483 454c9ae2e8ba7ed202c114776ac001e2880c6edf
parent 409482 b71563f2795878de5a203333a115e87622dce39b
child 409484 2c04fc5bb9fc195124f7ca1c2a0e019fb4022667
push id7391
push usermtabara@mozilla.com
push dateMon, 12 Jun 2017 13:08:53 +0000
treeherdermozilla-beta@2191d7f87e2e [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjgraham
bugs1367745
milestone55.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1367745 - Make sure 'process_output' messages are logged at the proper mozharness level, r=jgraham In addition to saving the log level of 'process_output' messages, this will also start passing 'log' messages through the error lists. This means mozharness will start using 'log' errors when determining the tbpl_status and worst_log_level. MozReview-Commit-ID: CZnH6aI1Wo0
testing/mozharness/mozharness/base/log.py
testing/mozharness/mozharness/mozilla/structuredlog.py
--- a/testing/mozharness/mozharness/base/log.py
+++ b/testing/mozharness/mozharness/base/log.py
@@ -291,16 +291,20 @@ class OutputParser(LogMixin):
         self.worst_log_level = INFO
 
     def parse_single_line(self, line):
         """ parse a console output line and check if it matches one in `error_list`,
         if so then log it according to `log_output`.
 
         Args:
             line (str): command line output to parse.
+
+        Returns:
+            If the line hits a match in the error_list, the new log level the line was
+            (or should be) logged at is returned. Otherwise, returns None.
         """
         for error_check in self.error_list:
             # TODO buffer for context_lines.
             match = False
             if 'substr' in error_check:
                 if error_check['substr'] in line:
                     match = True
             elif 'regex' in error_check:
@@ -320,20 +324,20 @@ class OutputParser(LogMixin):
                     else:
                         self.log(message, level=log_level)
                 if log_level in (ERROR, CRITICAL, FATAL):
                     self.num_errors += 1
                 if log_level == WARNING:
                     self.num_warnings += 1
                 self.worst_log_level = self.worst_level(log_level,
                                                         self.worst_log_level)
-                break
-        else:
-            if self.log_output:
-                self.info(' %s' % line)
+                return log_level
+
+        if self.log_output:
+            self.info(' %s' % line)
 
     def add_lines(self, output):
         """ process a string or list of strings, decode them to utf-8,strip
         them of any trailing whitespaces and parse them using `parse_single_line`
 
         strings consisting only of whitespaces are ignored.
 
         Args:
--- a/testing/mozharness/mozharness/mozilla/structuredlog.py
+++ b/testing/mozharness/mozharness/mozilla/structuredlog.py
@@ -44,17 +44,17 @@ class StructuredOutputParser(OutputParse
             import mozlog
         except ImportError:
             self.fatal("A script class using structured logging must inherit "
                        "from the MozbaseMixin to ensure that mozlog is available.")
         return mozlog
 
     def _handle_unstructured_output(self, line, log_output=True):
         self.log_output = log_output
-        super(StructuredOutputParser, self).parse_single_line(line)
+        return super(StructuredOutputParser, self).parse_single_line(line)
 
     def parse_single_line(self, line):
         """Parses a line of log output from the child process and passes
         it to mozlog to update the overall status of the run.
         Re-emits the logged line in human-readable format.
         """
         level = INFO
         tbpl_level = TBPL_SUCCESS
@@ -75,23 +75,29 @@ class StructuredOutputParser(OutputParse
                 self.update_levels(TBPL_FAILURE, log.CRITICAL)
             else:
                 self._handle_unstructured_output(line)
             return
 
         self.handler(data)
 
         action = data["action"]
-        if action == "process_output":
-            # Run process output through the error lists, but make sure the super parser
-            # doesn't print them to stdout (they should go through the log formatter).
-            self._handle_unstructured_output(data['data'], log_output=False)
+        if action in ('log', 'process_output'):
+            if action == 'log':
+                message = data['message']
+                level = getattr(log, data['level'].upper())
+            else:
+                message = data['data']
 
-        if action == "log":
-            level = getattr(log, data["level"].upper())
+            # Run log and process_output actions through the error lists, but make sure
+            # the super parser doesn't print them to stdout (they should go through the
+            # log formatter).
+            error_level = self._handle_unstructured_output(message, log_output=False)
+            if error_level is not None:
+                level = self.worst_level(error_level, level)
 
         log_data = self.formatter(data)
         if log_data is not None:
             self.log(log_data, level=level)
             self.update_levels(tbpl_level, level)
 
     def evaluate_parser(self, return_code, success_codes=None):
         success_codes = success_codes or [0]