[Findit] Use step level analysis to exclude flaky test failures.

appengine/findit/waterfall/extract_signal_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.
 
+import cStringIO
 import logging
+import json
 
 from google.appengine.api.urlfetch import ResponseTooLargeError
 
 from pipeline_utils.appengine_third_party_pipeline_src_pipeline import pipeline
 
 from common.http_client_appengine import HttpClientAppengine as HttpClient
 from model.wf_step import WfStep
 from waterfall import buildbot
 from waterfall import extractors
 from waterfall import lock_util
@@ skipping 22 matching lines @@
 
     lines = log_data.split('\n')
     size = 0
     for line_index in reversed(range(len(lines))):
       size += len(lines[line_index]) + 1
       if size > ExtractSignalPipeline.LOG_DATA_BYTE_LIMIT:
         return '\n'.join(lines[line_index + 1:])
     else:
       return log_data  # pragma: no cover - this won't be reached.
 
+  @staticmethod
+  def _GetTestLevelFailures(gtest_result):

[stgao, 2015/05/22 01:30:37]

Maybe rename it to _GetReliableTestFailureLog? or FailureOutput?

+    """Analyze the step log and extract reliable failures only.

[stgao, 2015/05/22 01:30:37]

not step log.

[chanli, 2015/05/22 18:43:27]

I think it actually is the 'archived' step log. isn't it?

+
+    Args:
+      gtest_result (file): A JSON file for failed step log.

[stgao, 2015/05/22 01:30:37]

This is not a file, it is a string in JSON format.

+
+    Returns:
+      A string contains the names of reliable test failures and output_snippets.
+    """
+

[stgao, 2015/05/22 01:30:37]

no empty line here.

+    step_failure_data = json.loads(gtest_result)
+    sio = cStringIO.StringIO()
+    for iteration in step_failure_data['gtest_results']['per_iteration_data']:
+      for key in iteration.keys():  # Keys are test names.

[stgao, 2015/05/22 01:30:37]

key -> test_name

That makes the code more clear.

+        is_reliable_failure = True
+
+        for test in iteration[key]:
+          # We will ignore the test if some of the attempts were success.
+          if test['status'] == 'SUCCESS':
+            is_reliable_failure = False
+            break
+
+        if is_reliable_failure: # All attempts failed, it's a reliable failure.

[stgao, 2015/05/22 01:30:37]

comment style.

+          for test in iteration[key]:
+            sio.write("'%s': %s\n" % (key, test['output_snippet']))
+
+    failed_test_log = sio.getvalue()
+    sio.close()
+
+    return failed_test_log
 
   # Arguments number differs from overridden method - pylint: disable=W0221
   def run(self, failure_info):
     """
     Args:
       failure_info (dict): Output of pipeline DetectFirstFailurePipeline.run().
 
     Returns:
       A dict like below:
       {
         'step_name1': waterfall.failure_signal.FailureSignal.ToDict(),
         ...
       }
     """
     signals = {}
 
     master_name = failure_info['master_name']
     builder_name = failure_info['builder_name']
     build_number = failure_info['build_number']
     for step_name in failure_info.get('failed_steps', []):
       step = WfStep.Get(master_name, builder_name, build_number, step_name)
       if step and step.log_data:
-        stdio_log = step.log_data
+        test_failure_log = step.log_data

[stgao, 2015/05/22 01:30:37]

failure_log? Because it could be compile step too, not just test step.

       else:
-        if not lock_util.WaitUntilDownloadAllowed(
-            master_name):  # pragma: no cover
-          raise pipeline.Retry('Failed to pull stdio of step %s of master %s'
-                               % (step_name, master_name))
+        # TODO: add test level log info to signal.
+        gtest_result = buildbot.GetGtestResultLog(
+              master_name, builder_name, build_number, step_name)
+        if gtest_result:
+          test_failure_log = self._GetTestLevelFailures(gtest_result)
+        else:
+          if not lock_util.WaitUntilDownloadAllowed(
+              master_name):  # pragma: no cover
+            raise pipeline.Retry('Failed to pull log of step %s of master %s'
+                                 % (step_name, master_name))
+          try:
+            test_failure_log = buildbot.GetStepStdio(
+                master_name, builder_name, build_number, step_name,
+                self.HTTP_CLIENT)
+          except ResponseTooLargeError:  # pragma: no cover.
+            logging.exception(
+                'Log of step "%s" is too large for urlfetch.', step_name)
+            # If the stdio log of a step is too large, we don't want to pull it
+            # again in next run, because that might lead to DDoS to the master.

[stgao, 2015/05/22 01:30:37]

Please keep the original TODO here. See my last comment.

+            test_failure_log = 'Stdio log is too large for urlfetch.'
 
-        # TODO: do test-level analysis instead of step-level.
-        try:
-          stdio_log = buildbot.GetStepStdio(
-              master_name, builder_name, build_number, step_name,
-              self.HTTP_CLIENT)
-        except ResponseTooLargeError:  # pragma: no cover.
-          logging.exception(
-              'Log of step "%s" is too large for urlfetch.', step_name)
-          # If the stdio log of a step is too large, we don't want to pull it
-          # again in next run, because that might lead to DDoS to the master.
-          # TODO: Use archived stdio logs in Google Storage instead.
-          stdio_log = 'Stdio log is too large for urlfetch.'
+          if not test_failure_log:  # pragma: no cover
+            raise pipeline.Retry('Failed to pull stdio of step %s of master %s'

[Sharu Jiang, 2015/05/22 17:54:30]

I think if we fail to get result from self._GetTestLevelFailures,
test_failure_log may also be empty, should we check that?

[chanli, 2015/05/22 18:43:27]

We will go to stdio log if we failed retrieving data from archived step log. 

[Sharu Jiang, 2015/05/22 20:09:36]

I mean even though we have gtest_result, we may not get any test_failure_log,
for example if all the tests are unreliable

+                                 % (step_name, master_name))
 
-        if not stdio_log:  # pragma: no cover
-          raise pipeline.Retry('Failed to pull stdio of step %s of master %s'
-                               % (step_name, master_name))
-
-        # Save stdio in datastore and avoid downloading again during retry.
+        # Save step log in datastore and avoid downloading again during retry.
         if not step:  # pragma: no cover
           step = WfStep.Create(
               master_name, builder_name, build_number, step_name)
 
-        step.log_data = self._ExtractStorablePortionOfLog(stdio_log)
+        step.log_data = self._ExtractStorablePortionOfLog(test_failure_log)
+
         try:
           step.put()
         except Exception as e:  # pragma: no cover
-          # Sometimes, the stdio log is too large to save in datastore.
+          # Sometimes, the step log is too large to save in datastore.
           logging.exception(e)
 
       # TODO: save result in datastore?
       signals[step_name] = extractors.ExtractSignal(
-          master_name, builder_name, step_name, None, stdio_log).ToDict()
+          master_name, builder_name, step_name, None,
+          str(test_failure_log)).ToDict()

[stgao, 2015/05/22 01:30:37]

Why we need str here? Same reason as you told me?

[chanli, 2015/05/22 18:43:27]

No... I forgot this one. Fixed.

 
     return signals