lib/results_lib.py

# Copyright (c) 2011 The Chromium OS Authors. All rights reserved.
# Use of this source code is governed by a BSD-style license that can be
# found in the LICENSE file.

"""Classes for collecting results of our BuildStages as they run."""

import collections
import datetime
import math
import os

from chromite.lib import constants
from chromite.lib import failures_lib
from chromite.lib import cros_build_lib
from chromite.lib import cros_logging as logging

def _GetCheckpointFile(buildroot):
  return os.path.join(buildroot, '.completed_stages')


def WriteCheckpoint(buildroot):
  """Drops a completed stages file with current state."""
  completed_stages_file = _GetCheckpointFile(buildroot)
  with open(completed_stages_file, 'w+') as save_file:
    Results.SaveCompletedStages(save_file)


def LoadCheckpoint(buildroot):
  """Restore completed stage info from checkpoint file."""
  completed_stages_file = _GetCheckpointFile(buildroot)
  if not os.path.exists(completed_stages_file):
    logging.warning('Checkpoint file not found in buildroot %s', buildroot)
    return

  with open(completed_stages_file, 'r') as load_file:
    Results.RestoreCompletedStages(load_file)


class RecordedTraceback(object):
  """This class represents a traceback recorded in the list of results."""

  def __init__(self, failed_stage, failed_prefix, exception, traceback):
    """Construct a RecordedTraceback object.

    Args:
      failed_stage: The stage that failed during the build. E.g., HWTest [bvt]
      failed_prefix: The prefix of the stage that failed. E.g., HWTest
      exception: The raw exception object.
      traceback: The full stack trace for the failure, as a string.
    """
    self.failed_stage = failed_stage
    self.failed_prefix = failed_prefix
    self.exception = exception
    self.traceback = traceback


_result_fields = ['name', 'result', 'description', 'prefix', 'board', 'time']
Result = collections.namedtuple('Result', _result_fields)


class _Results(object):
  """Static class that collects the results of our BuildStages as they run."""

  SUCCESS = 'Stage was successful'
  FORGIVEN = 'Stage failed but was optional'
  SKIPPED = 'Stage was skipped'
  NON_FAILURE_TYPES = (SUCCESS, FORGIVEN, SKIPPED)

  SPLIT_TOKEN = r'\_O_/'

  def __init__(self):
    # List of results for all stages that's built up as we run. Members are of
    #  the form ('name', SUCCESS | FORGIVEN | Exception, None | description)
    self._results_log = []

    # A list of instances of failure_message_lib.StageFailureMessage to present
    # the exceptions threw by failed stages.
    self._failure_message_results = []

    # Stages run in a previous run and restored. Stored as a dictionary of
    # names to previous records.
    self._previous = {}

    self.start_time = datetime.datetime.now()

  def Clear(self):
    """Clear existing stage results."""
    self.__init__()

  def PreviouslyCompletedRecord(self, name):
    """Check to see if this stage was previously completed.

    Returns:
      A boolean showing the stage was successful in the previous run.
    """
    return self._previous.get(name)

  def BuildSucceededSoFar(self, buildstore=None, buildbucket_id=None,
                          name=None):
    """Return true if all stages so far have passing states.

    This method returns true if all was successful or forgiven or skipped.

    Args:
      buildstore: A BuildStore instance to make DB calls.
      buildbucket_id: buildbucket_id of the build to check.
      name: stage name of current stage.
    """
    build_succeess = all(entry.result in self.NON_FAILURE_TYPES
                         for entry in self._results_log)

    # When timeout happens and background tasks are killed, the statuses
    # of the background stage tasks may get lost. BuildSucceededSoFar may
    # still return build_succeess = True when the killed stage tasks were
    # failed. Add one more verification step in _BuildSucceededFromCIDB to
    # check the stage status in CIDB.
    return (build_succeess and
            self._BuildSucceededFromCIDB(buildstore=buildstore,
                                         buildbucket_id=buildbucket_id,
                                         name=name))

  def _BuildSucceededFromCIDB(self, buildstore=None, buildbucket_id=None,
                              name=None):
    """Return True if all stages recorded in buildbucket have passing states.

    Args:
      buildstore: A BuildStore instance to make DB calls.
      buildbucket_id: buildbucket_id of the build to check.
      name: stage name of current stage.
    """
    if (buildstore is not None and buildstore.AreClientsReady()
        and buildbucket_id is not None):
      stages = buildstore.GetBuildsStages(buildbucket_ids=[buildbucket_id])
      for stage in stages:
        if name is not None and stage['name'] == name:
          logging.info("Ignore status of %s as it's the current stage.",
                       stage['name'])
          continue
        if stage['status'] not in constants.BUILDER_NON_FAILURE_STATUSES:
          logging.warning('Failure in previous stage %s with status %s.',
                          stage['name'], stage['status'])
          return False

    return True

  def StageHasResults(self, name):
    """Return true if stage has posted results."""
    return name in [entry.name for entry in self._results_log]

  def _RecordStageFailureMessage(self, name, exception, prefix=None,
                                 build_stage_id=None):
    self._failure_message_results.append(
        failures_lib.GetStageFailureMessageFromException(
            name, build_stage_id, exception, stage_prefix_name=prefix))

  def Record(self, name, result, description=None, prefix=None, board='',
             time=0, build_stage_id=None):
    """Store off an additional stage result.

    Args:
      name: The name of the stage (e.g. HWTest [bvt])
      result:
        Result should be one of:
          Results.SUCCESS if the stage was successful.
          Results.SKIPPED if the stage was skipped.
          Results.FORGIVEN if the stage had warnings.
          Otherwise, it should be the exception stage errored with.
      description:
        The textual backtrace of the exception, or None
      prefix: The prefix of the stage (e.g. HWTest). Defaults to
        the value of name.
      board: The board associated with the stage, if any. Defaults to ''.
      time: How long the result took to complete.
      build_stage_id: The id of the failed build stage to record, default to
        None.
    """
    if prefix is None:
      prefix = name

    # Convert exception to stage_failure_message and record it.
    if isinstance(result, BaseException):
      self._RecordStageFailureMessage(name, result, prefix=prefix,
                                      build_stage_id=build_stage_id)

    result = Result(name, result, description, prefix, board, time)
    self._results_log.append(result)

  def GetStageFailureMessage(self):
    return self._failure_message_results

  def Get(self):
    """Fetch stage results.

    Returns:
      A list with one entry per stage run with a result.
    """
    return self._results_log

  def GetPrevious(self):
    """Fetch stage results.

    Returns:
      A list of stages names that were completed in a previous run.
    """
    return self._previous

  def SaveCompletedStages(self, out):
    """Save the successfully completed stages to the provided file |out|."""
    for entry in self._results_log:
      if entry.result != self.SUCCESS:
        break
      out.write(self.SPLIT_TOKEN.join(str(x) for x in entry) + '\n')

  def RestoreCompletedStages(self, out):
    """Load the successfully completed stages from the provided file |out|."""
    # Read the file, and strip off the newlines.
    for line in out:
      record = line.strip().split(self.SPLIT_TOKEN)
      if len(record) != len(_result_fields):
        logging.warning('State file does not match expected format, ignoring.')
        # Wipe any partial state.
        self._previous = {}
        break

      self._previous[record[0]] = Result(*record)

  def GetTracebacks(self):
    """Get a list of the exceptions that failed the build.

    Returns:
      A list of RecordedTraceback objects.
    """
    tracebacks = []
    for entry in self._results_log:
      # If entry.result is not in NON_FAILURE_TYPES, then the stage failed, and
      # entry.result is the exception object and entry.description is a string
      # containing the full traceback.
      if entry.result not in self.NON_FAILURE_TYPES:
        traceback = RecordedTraceback(entry.name, entry.prefix, entry.result,
                                      entry.description)
        tracebacks.append(traceback)
    return tracebacks

  def Report(self, out, current_version=None):
    """Generate a user friendly text display of the results data.

    Args:
      out: Output stream to write to (e.g. sys.stdout).
      current_version: Chrome OS version associated with this report.
    """
    results = self._results_log

    line = '*' * 60 + '\n'
    edge = '*' * 2

    if current_version:
      out.write(line)
      out.write(edge +
                ' RELEASE VERSION: ' +
                current_version +
                '\n')

    out.write(line)
    out.write(edge + ' Stage Results\n')
    warnings = False

    for entry in results:
      name, result, run_time = (entry.name, entry.result, entry.time)
      timestr = datetime.timedelta(seconds=math.ceil(run_time))

      # Don't print data on skipped stages.
      if result == self.SKIPPED:
        continue

      out.write(line)
      details = ''
      if result == self.SUCCESS:
        status = 'PASS'
      elif result == self.FORGIVEN:
        status = 'FAILED BUT FORGIVEN'
        warnings = True
      else:
        status = 'FAIL'
        if isinstance(result, cros_build_lib.RunCommandError):
          # If there was a run error, give just the command that failed, not
          # its full argument list, since those are usually too long.
          details = ' in %s' % result.result.cmd[0]
        elif isinstance(result, failures_lib.BuildScriptFailure):
          # BuildScriptFailure errors publish a 'short' name of the
          # command that failed.
          details = ' in %s' % result.shortname
        else:
          # There was a normal error. Give the type of exception.
          details = ' with %s' % type(result).__name__

      out.write('%s %s %s (%s)%s\n' % (edge, status, name, timestr, details))

    out.write(line)

    for x in self.GetTracebacks():
      if x.failed_stage and x.traceback:
        out.write('\nFailed in stage %s:\n\n' % x.failed_stage)
        out.write(x.traceback)
        out.write('\n')

    if warnings:
      logging.PrintBuildbotStepWarnings(out)


Results = _Results()