[Findit] Adding improved error detection to MonitorTryJobPipeline

appengine/findit/waterfall/monitor_try_job_pipeline.py

 # Copyright 2015 The Chromium Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
 from datetime import datetime
+import json
+import re
 import time
 
 from common.pipeline_wrapper import BasePipeline
 from common.pipeline_wrapper import pipeline
 from common.waterfall import buildbucket_client
 from common.waterfall.buildbucket_client import BuildbucketBuild
 from model import analysis_status
+from model import try_job_error
 from model.wf_try_job import WfTryJob
 from model.wf_try_job_data import WfTryJobData
 from waterfall import waterfall_config
 from waterfall.try_job_type import TryJobType
 
 
 class MonitorTryJobPipeline(BasePipeline):
   """A pipeline for monitoring a try job and recording results when it's done.
 
   The result will be stored to compile_results or test_results according to
   which type of build failure we are running try job for.
   """
 
-  TIMEOUT = 'TIMEOUT'
+  UNKNOWN = 'UNKNOWN'
 
   @staticmethod
   def _MicrosecondsToDatetime(microseconds):
     """Returns a datetime given the number of microseconds, or None."""
     if microseconds:
       return datetime.utcfromtimestamp(float(microseconds) / 1000000)
     return None
 
   @staticmethod
-  def _GetError(buildbucket_error, timed_out):
-    # TODO(lijeffrey): Currently only timeouts (Findit abandoned monitoring the
-    # try job after waiting too long for it to complete) and errors reported
-    # directly in the buildbucket_client request are captured. Several other
-    # failures can be derrived from the response in the build too which should
-    # be determined here.
+  def _GetError(buildbucket_response, buildbucket_error, timed_out):
+    """Determines whether or not a try job error occurred.
+
+    Args:
+      buildbucket_response: A dict of the json response from buildbucket.
+      buildbucket_error: A BuildBucketError object returned from the call to
+        buildbucket_client.GetTryJobs()
+      timed_out: A bool whether or not Findit abandoned monitoring the try job.
+
+    Returns:
+      A tuple containing an error dict and number representing an error code, or
+      (None, None) if no error was determined to have occurred.
+    """
+
     if buildbucket_error:
-      return {
-          'message': buildbucket_error.message,
-          'reason': buildbucket_error.reason
-      }
+      return (
+          {
+              'message': buildbucket_error.message,
+              'reason': buildbucket_error.reason
+          },
+          try_job_error.BUILDBUCKET_ERROR)
 
     if timed_out:
-      return {
-          'message': 'Try job monitoring was abandoned.',
-          'reason': MonitorTryJobPipeline.TIMEOUT
-      }
+      return (
+          {
+              'message': 'Try job monitoring was abandoned.',
+              'reason': 'Timeout after %s hours' % (
+                  waterfall_config.GetTryJobSettings().get('job_timeout_hours'))
+          },
+          try_job_error.TIMEOUT)
+
+    if buildbucket_response:
+      # If there is no explicit timeout or reason specified, check the last
+      # build response for errors.
+      result_details_json = json.loads(
+          buildbucket_response.get('result_details_json', '{}')) or {}
+
+      # Check result_details_json for any obvious errors.
+      error = result_details_json.get('error', {})
+      if error:
+        root_cause = error.get('message')
+        if root_cause:
+          error_dict = {
+              'message': 'Try job could not be triggered.',
+              'reason': root_cause
+          }
+          trybot_not_found_pattern = re.compile(r'Builder [^\s-]+ not found')
+
+          if trybot_not_found_pattern.match(root_cause):
+            error_code = try_job_error.TRYBOT_NOT_FOUND

[stgao, 2016/04/25 23:44:39]

Why we want to handle this case specially?

[lijeffrey, 2016/04/26 00:50:08]

This case should be rare and never occur once it's detected and the config
updated. I've renamed it BUILDBUCKET_REPORTED_ERROR for cases where the error is
reported in the result_details_json, since there may be other types of failures
that are reported here.

+          else:
+            error_code = try_job_error.UNKNOWN
+
+          return error_dict, error_code
+
+        return (
+            {
+                'message': 'Try job error was detected.',
+                'reason': MonitorTryJobPipeline.UNKNOWN
+            },
+            try_job_error.UNKNOWN)
+
+      # Check the report to see if anything went wrong.
+      report = result_details_json.get('properties', {}).get('report')
+      if report:
+        if ('infra_failed' in report.get('result', {}).itervalues() or
+            report.get('metadata', {}).get('infra_failure')):

[stgao, 2016/04/25 23:44:39]

It is not added to findit/chromium/test.py yet.

[stgao, 2016/04/25 23:44:39]

Why we need to check both?

[lijeffrey, 2016/04/26 00:50:08]

Done. Good point, I think just metadata should be sufficient which should
account for test.py once the change is made to add it to that recipe.

+          # Check for any infra issues caught by the recipe.
+          return (
+              {
+                  'message': ('Try job encountered an infra issue during '
+                              'execution.'),
+                  'reason': MonitorTryJobPipeline.UNKNOWN
+              },
+              try_job_error.INFRA_FAILURE)
+      else:
+        # A report should always be included as prt of the properties. If it is
+        # missing something is wrong.
+        return (
+            {
+                'message': 'No result report was found.',
+                'reason': MonitorTryJobPipeline.UNKNOWN
+            },
+            try_job_error.UNKNOWN)
+
+    return None, None
 
   @staticmethod
   def _UpdateTryJobMetadata(try_job_data, start_time, buildbucket_build,
                             buildbucket_error, timed_out):
+    buildbucket_response = {}
     if buildbucket_build:
       try_job_data.request_time = MonitorTryJobPipeline._MicrosecondsToDatetime(
           buildbucket_build.request_time)
       # If start_time is unavailable, fallback to request_time.
       try_job_data.start_time = start_time or try_job_data.request_time
       try_job_data.end_time = MonitorTryJobPipeline._MicrosecondsToDatetime(
           buildbucket_build.end_time)
       try_job_data.number_of_commits_analyzed = len(
           buildbucket_build.report.get('result', {}))
       try_job_data.try_job_url = buildbucket_build.url
       try_job_data.regression_range_size = buildbucket_build.report.get(
           'metadata', {}).get('regression_range_size')
       try_job_data.last_buildbucket_response = buildbucket_build.response
+      buildbucket_response = buildbucket_build.response
 
-    error = MonitorTryJobPipeline._GetError(buildbucket_error, timed_out)
+    error_dict, error_code = MonitorTryJobPipeline._GetError(
+        buildbucket_response, buildbucket_error, timed_out)
 
-    if error:
-      try_job_data.error = error
+    if error_dict:
+      try_job_data.error = error_dict
+      try_job_data.error_code = error_code
 
     try_job_data.put()
 
   def _UpdateTryJobResult(
       self, status, master_name, builder_name, build_number, try_job_type,
       try_job_id, try_job_url, result_content=None):
     """Updates try job result based on responsed try job status and result."""
     result = {
         'report': result_content,
         'url': try_job_url,
@@ skipping 81 matching lines @@
           already_set_started = True
 
       if time.time() > deadline:  # pragma: no cover
         self._UpdateTryJobMetadata(try_job_data, start_time, build, error, True)
         # Explicitly abort the whole pipeline.
         raise pipeline.Abort(
             'Try job %s timed out after %d hours.' % (
                 try_job_id, timeout_hours))
 
       time.sleep(pipeline_wait_seconds)  # pragma: no cover