blob: 82314e0c757062829a6340ed447b665399789a56 [file] [log] [blame]
# -*- coding: utf-8 -*-
# Copyright 2017 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.
"""Invokes git bisect to find culprit commit."""
from __future__ import print_function
import datetime
from chromite.cros_bisect import common
from chromite.lib import cros_build_lib
from chromite.lib import cros_logging as logging
from chromite.lib import git
class GitBisectorException(Exception):
"""Exception raised for GitBisector error."""
class GitBisector(common.OptionsChecker):
"""Bisects suspicious commits in a git repository.
Before bisect, it does sanity check for the given good and bad commit. Then
it extracts metric scores for both commits as baseline to determine the
upcoming bisect candidate's status.
It finds first bad commit within given good and bad commit using "git bisect"
command. For each commit, it uses builder to build package to verify and
deploy it to DUT (device under test). And asks evaluator to extract score
of the commit. It is treated as good commit i the score is closer to user
specified good commit.
Finally, it outputs git bisect result.
REQUIRED_ARGS = ('good', 'bad', 'remote', 'eval_repeat', 'auto_threshold',
'board', 'eval_raise_on_error', 'skip_failed_commit')
def __init__(self, options, builder, evaluator):
options: An argparse.Namespace to hold command line arguments. Should
* good: Last known good commit.
* bad: Last known bad commit.
* remote: DUT (refer lib.commandline.Device).
* eval_repeat: Run test for N times. None means 1.
* auto_threshold: True to set threshold automatically without prompt.
* board: board name of the DUT.
* eval_raise_on_error: If set, raises if evaluation failed.
* skip_failed_commit: If set, mark the failed commit (build failed /
no result) as 'skip' instead of 'bad'.
builder: Builder to build/deploy image. Should contain repo_dir.
evaluator: Evaluator to get score
super(GitBisector, self).__init__(options)
self.good_commit = options.good
self.bad_commit = options.bad
self.remote = options.remote
self.eval_repeat = options.eval_repeat
self.builder = builder
self.evaluator = evaluator
self.repo_dir = self.builder.repo_dir
self.auto_threshold = options.auto_threshold
self.board = options.board
self.eval_raise_on_error = options.eval_raise_on_error
self.skip_failed_commit = options.skip_failed_commit
# Initialized in ObtainBisectBoundaryScore().
self.good_commit_info = None
self.bad_commit_info = None
# Record bisect log (list of CommitInfo).
self.bisect_log = []
# If the distance between current commit's score and given good commit is
# shorter than threshold, treat the commit as good one. Its default value
# comes from evaluator's THRESHOLD constant. If it is None (undefined),
# the bisector will prompt user to input threshold after obtaining both
# sides' score.
self.threshold = evaluator.THRESHOLD
# Set auto_threshold to True if the threshold is preset.
if self.threshold is not None:
self.auto_threshold = True
# Init with empty CommitInfo. Will update in UpdateCurrentCommit().
self.current_commit = common.CommitInfo()
def SetUp(self):
"""Sets up environment to bisect."""'Set up builder environment.')
def CheckCommitFormat(commit):
"""Checks if commit is the acceptable format.
For git_bisector, commit should be SHA1. Child class may override it.
commit: commit string.
Normalized commit. None if the format is unacceptable.
if git.IsSHA1(commit, full=False):
return commit
return None
def Git(self, command):
"""Wrapper of git.RunGit.
It passes self.repo_dir as git_repo to git.RunGit. Also, it
sets check=False so when git encounters an error, instead of
raising RunCommandError, it returns CommandResult with non-zero return code.
command: git command.
A CommandResult object.
return git.RunGit(self.repo_dir, command, check=False)
def UpdateCurrentCommit(self):
"""Updates self.current_commit."""
result = self.Git(['show', '--no-patch', '--format=%h %ct %s'])
if result.returncode != 0:
logging.error('Failed to update current commit info.')
fields = result.output.strip().split()
if len(fields) < 3:
logging.error('Failed to update current commit info.')
sha1 = fields[0]
timestamp = int(fields[1])
title = ' '.join(fields[2:])
self.current_commit = common.CommitInfo(sha1=sha1, title=title,
def GetCommitTimestamp(self, sha1):
"""Obtains given commit's timestamp.
sha1: Commit's SHA1 to look up.
timestamp in integer. None if the commit does not exist.
result = self.Git(['show', '--no-patch', '--format=%ct', sha1])
if result.returncode == 0:
return int(result.output.strip())
except ValueError:
return None
def SanityCheck(self):
"""Checks if both last-known-good and bad commits exists.
Also, last-known-good commit should be earlier than bad one.
True if both last-known-good and bad commits exist.
"""'Perform sanity check on good commit %s and bad commit %s',
self.good_commit, self.bad_commit)
# Builder is lazy syncing to HEAD. Sync to HEAD if good_commit or bad_commit
# does not exist in repo.
if (not git.DoesCommitExistInRepo(self.repo_dir, self.good_commit) or
not git.DoesCommitExistInRepo(self.repo_dir, self.bad_commit)):
'Either good commit (%s) or bad commit (%s) not found in repo. '
'Try syncing to HEAD first.', self.good_commit, self.bad_commit)
'Both good commit (%s) and bad commit (%s) are found in repo. '
'No need to update repo.', self.good_commit, self.bad_commit)
good_commit_timestamp = self.GetCommitTimestamp(self.good_commit)
if not good_commit_timestamp:
logging.error('Sanity check failed: good commit %s does not exist.',
return False
bad_commit_timestamp = self.GetCommitTimestamp(self.bad_commit)
if not bad_commit_timestamp:
logging.error('Sanity check failed: bad commit %s does not exist.',
return False
# TODO(deanliao): Consider the case that we want to find a commit that
# fixed a problem.
if bad_commit_timestamp < good_commit_timestamp:
'Sanity check failed: good commit (%s) timestamp: %s should be '
'earlier than bad commit (%s): %s',
self.good_commit, good_commit_timestamp,
self.bad_commit, bad_commit_timestamp)
return False
return True
def ObtainBisectBoundaryScoreImpl(self, good_side):
"""The worker of obtaining score of either last-known-good or bad commit.
It is used to be overridden by derived class without re-implement
good_side: True if it evaluates score for last-known-good. False for
last-known-bad commit.
Evaluated score.
commit = self.good_commit if good_side else self.bad_commit
commit_label = 'good' if good_side else 'bad'
logging.notice('Obtaining score of %s commit: %s', commit_label, commit)
self.Git(['checkout', commit])
return self.BuildDeployEval()
def ObtainBisectBoundaryScore(self):
"""Evaluates last known good and bad commit.
In order to give user a reference when setting threshold, evaluates
designated benchmark on both last-known-good and last-known-bad commits.
It builds, deploys and evaluates both good and bad images on the DUT.
good_score = self.ObtainBisectBoundaryScoreImpl(True)
self.good_commit_info = self.current_commit
self.good_commit_info.label = 'last-known-good '
if good_score is None:
logging.error('Unable to obtain last-known-good score.')
return False
bad_score = self.ObtainBisectBoundaryScoreImpl(False)
self.bad_commit_info = self.current_commit
self.bad_commit_info.label = 'last-known-bad '
if bad_score is None:
logging.error('Unable to obtain last-known-bad score.')
return False
if good_score == bad_score:
'Last-known-good %s should be different from last-known-bad %s',
good_score, bad_score)
return False
return True
def GetThresholdFromUser(self):
"""Gets threshold that decides good/bad commit.
It gives user the measured last known good and bad score's statistics to
help user determine a reasonable threshold.
If self.auto_threshold is set, instead of prompting user to pick threshold,
it uses half of distance between good and bad commit score as threshold.
# If threshold is assigned, skip it.
if self.threshold is not None:
return True
good_score = self.good_commit_info.score
bad_score = self.bad_commit_info.score
logging.notice('Good commit score mean: %.3f STD: %.3f\n'
'Bad commit score mean: %.3f STD: %.3f',
good_score.mean, good_score.std,
bad_score.mean, bad_score.std)
if self.auto_threshold:
splitter = (good_score.mean + bad_score.mean) / 2.0
self.threshold = abs(good_score.mean - splitter)
logging.notice('Automatically pick threshold: %.3f', self.threshold)
return True
ref_score_min = min(good_score.mean, bad_score.mean)
ref_score_max = max(good_score.mean, bad_score.mean)
success = False
retry = 3
for _ in range(retry):
splitter = float(cros_build_lib.GetInput(
'Please give a threshold that tell apart good and bad commit '
'(within range [%.3f, %.3f]: ' % (ref_score_min, ref_score_max)))
except ValueError:
logging.error('Threshold should be a floating number.')
if ref_score_min <= splitter <= ref_score_max:
self.threshold = abs(good_score.mean - splitter)
success = True
logging.error('Threshold should be within range [%.3f, %.3f]',
ref_score_min, ref_score_max)
logging.error('Wrong threshold input for %d times. Terminate.', retry)
return success
def BuildDeploy(self):
"""Builds with current commit and deploys to DUT.
It is the default behavior of BuildDeployEval().
True if the builder successfully builds and deploys to DUT.
False otherwise.
# TODO(deanliao): Handle build/deploy fail case.
build_label = self.current_commit.sha1
build_to_deploy = self.builder.Build(build_label)
if not build_to_deploy:
return False
return self.builder.Deploy(self.remote, build_to_deploy, build_label)
def BuildDeployEval(self, eval_label=None, customize_build_deploy=None):
"""Builds the image, deploys to DUT and evaluates performance.
build_deploy: If set, builds current commit and deploys it to DUT.
eval_label: Label for the evaluation. Default: current commit SHA1.
customize_build_deploy: Method object if specified, call it instead of
default self.BuildDeploy().
Evaluation result.
GitBisectorException if self.eval_raise_on_error and score is empty.
if not eval_label:
eval_label = self.current_commit.sha1
score = self.evaluator.CheckLastEvaluate(eval_label, self.eval_repeat)
if score:'Found last evaluated result for %s: %s', eval_label,
self.current_commit.score = score
if customize_build_deploy:
build_deploy_result = customize_build_deploy()
build_deploy_result = self.BuildDeploy()
if build_deploy_result:
self.current_commit.score = self.evaluator.Evaluate(
self.remote, eval_label, self.eval_repeat)
logging.error('Builder fails to build/deploy for %s', eval_label)
self.current_commit.score = common.Score()
if not self.current_commit.score and self.eval_raise_on_error:
raise GitBisectorException('Unable to obtain evaluation score')
return self.current_commit.score
def LabelBuild(self, score):
"""Determines if a build is good.
score: evaluation score of the build.
'good' if the score is closer to given good one; otherwise (including
score is None), 'bad'.
Note that if self.skip_failed_commit is set, returns 'skip' for empty
label = 'bad'
if not score:
if self.skip_failed_commit:
label = 'skip'
logging.error('No score. Marked as %s', label)
return label
good_score = self.good_commit_info.score
bad_score = self.bad_commit_info.score
ref_score_min = min(good_score.mean, bad_score.mean)
ref_score_max = max(good_score.mean, bad_score.mean)
if ref_score_min < score.mean < ref_score_max:
# Within (good_score, bad_score)
if abs(good_score.mean - score.mean) <= self.threshold:
label = 'good'
dist_good = abs(good_score.mean - score.mean)
dist_bad = abs(bad_score.mean - score.mean)
if dist_good < dist_bad:
label = 'good''Score %.3f marked as %s', score.mean, label)
return label
def GitBisect(self, bisect_op):
"""Calls git bisect and logs result.
bisect_op: git bisect subcommand list.
A CommandResult object.
done: True if bisect ends.
command = ['bisect'] + bisect_op
command_str = cros_build_lib.CmdToStr(['git'] + command)
result = self.Git(command)
done = False
log_msg = [command_str]
if result.output:
log_msg.append('(output): %s' % result.output.strip())
if result.error:
log_msg.append('(error): %s' % result.error.strip())
if result.returncode != 0:
log_msg.append('(returncode): %d' % result.returncode)
log_msg = '\n'.join(log_msg)
if result.error or result.returncode != 0:
if result.output:
if 'is the first bad commit' in result.output.splitlines()[0]:
done = True
return result, done
def CommitInfoToStr(info):
"""Converts CommitInfo to string.
info: A CommitInfo object.
Stringfied CommitInfo.
timestamp = datetime.datetime.fromtimestamp(info.timestamp).isoformat(' ')
score = 'Score(mean: %.3f std: %.3f)' % (info.score.mean, info.score.std)
return ' '.join([info.label, timestamp, score, info.sha1, info.title])
def PrepareBisect(self):
"""Performs sanity checks and obtains bisect boundary score before bisect.
False if there's something wrong.
return (self.SanityCheck() and
self.ObtainBisectBoundaryScore() and
def Run(self):
"""Bisects culprit commit.
Culprit commit's SHA1. None if culprit not found.
if not self.PrepareBisect():
return None
bisect_done = False
culprit_commit = None
nth_bisect = 0
with cros_build_lib.TimedSection() as timer:
self.GitBisect(['bad', self.bad_commit])
self.GitBisect(['good', self.good_commit])
while not bisect_done:
metric_score = self.BuildDeployEval()
bisect_op = self.LabelBuild(metric_score)
nth_bisect += 1
self.current_commit.label = '%2d-th-bisect-%-4s' % (nth_bisect,
logging.notice('Mark %s as %s. Score: %s', self.current_commit.sha1,
bisect_op, metric_score)
bisect_result, bisect_done = self.GitBisect([bisect_op])
if bisect_done:
culprit_commit = bisect_result.output.splitlines()[1:]
if bisect_done:'git bisect done. Elapsed time: %s',
# Emit bisect report.
self.bisect_log.sort(key=lambda x: x.timestamp)
'Bisect log (sort by time):\n' +
'\n'.join(self.CommitInfoToStr(x) for x in self.bisect_log))
if culprit_commit:
logging.notice('\n'.join(['Culprit commit:'] + culprit_commit))
# First line: commit <SHA>
return culprit_commit[0].split()[1]
logging.notice('Culprit not found.')
return None