def testAddKeyWord(self):
signal = FailureSignal()
signal.AddKeyword(' ')
signal.AddKeyword('a')
signal.AddKeyword('b')
signal.AddKeyword('a')
self.assertEqual({'a': 2, 'b': 1}, signal.keywords)
def testAddEdge(self):
signal = FailureSignal()
signal.AddEdge({
'rule': "CXX",
'output_nodes': ['b.o'],
'dependencies': ['b.h']
})
signal.AddEdge({
'rule': "CXX",
'output_nodes': ['a.o', 'aa.o'],
'dependencies': ['a.h', 'a.c']
})
signal.AddEdge({
'rule': "CXX",
'output_nodes': ['a.o', 'aa.o'],
'dependencies': ['a.h', 'a.c']
})
self.assertEqual([{
"rule": 'CXX',
"output_nodes": ['b.o'],
'dependencies': ['b.h']
}, {
'rule': 'CXX',
'output_nodes': ['a.o', 'aa.o'],
'dependencies': ['a.h', 'a.c']
}], signal.failed_edges)
def Extract(self, failure_log, *_):
signal = FailureSignal()
failure_log_lines = failure_log.splitlines()
i = 0
end_index = len(failure_log_lines)
while i < end_index:
line = failure_log_lines[i]
cpp_stacktrace_match = extractor_util.CPP_STACK_TRACE_FRAME_PATTERN.match(
line)
if cpp_stacktrace_match:
# Handle cpp failure stacktraces.
start = i
for line in failure_log_lines[start:]: # pragma: no cover
if extractor_util.CPP_STACK_TRACE_FRAME_PATTERN.match(
line):
i += 1
else:
break
end = i
if (start >= 1 and self.INDIRECT_LEAK_MARKER_PATTERN.match(
failure_log_lines[start - 1])):
# Ignore stack trace of an indirect leak.
continue
cpp_stacktrace_frames = failure_log_lines[start:end]
self._ExtractCppFiles(cpp_stacktrace_frames, signal)
elif extractor_util.PYTHON_STACK_TRACE_START_PATTERN.search(line):
# Handle python failure stacktraces.
i += 1
start = i
while i < end_index: # pragma: no cover
line = failure_log_lines[i]
if (extractor_util.PYTHON_STACK_TRACE_FRAME_PATTERN_1.
search(line) or extractor_util.
PYTHON_STACK_TRACE_FRAME_PATTERN_2.search(line)):
i += 2
else:
break
end = i
python_stacktrace_frames = failure_log_lines[start:end]
self._ExtractPythonFiles(python_stacktrace_frames, signal)
elif 'GMOCK WARNING' in line:
# Ignore GMOCK WARNING statements.
start = i
for l in failure_log_lines[start:]: # pragma: no cover
if ('You can safely ignore the above warning unless this call '
'should not happen.') in l:
# The end line in GMOCK WARNING statements.
break
i += 1
else:
if line and not extractor_util.ShouldIgnoreLine(line):
self.ExtractFiles(line, signal)
i += 1
return signal
def testCheckNinjaDependencies(self):
failed_edges = [{
'dependencies': [
'src/a/b/f1.cc', 'd/e/a2_test.cc', 'b/c/f2.cc', 'd/e/f3.h',
'x/y/f4.py', 'f5_impl.cc'
]
}]
failure_signal = FailureSignal()
failure_signal.failed_edges = failed_edges
change_log_json = {
'revision':
'12',
'touched_files': [
{
'change_type': ChangeType.ADD,
'old_path': '/dev/null',
'new_path': 'a/b/f1.cc'
},
{
'change_type': ChangeType.ADD,
'old_path': '/dev/null',
'new_path': 'd/e/a2.cc'
},
{
'change_type': ChangeType.MODIFY,
'old_path': 'a/b/c/f2.h',
'new_path': 'a/b/c/f2.h'
},
{
'change_type': ChangeType.MODIFY,
'old_path': 'd/e/f3.h',
'new_path': 'd/e/f3.h'
},
{
'change_type': ChangeType.DELETE,
'old_path': 'x/y/f4.py',
'new_path': '/dev/null'
},
{
'change_type': ChangeType.DELETE,
'old_path': 'h/f5.h',
'new_path': '/dev/null'
},
{
'change_type': ChangeType.RENAME,
'old_path': 't/y/x.cc',
'new_path': 's/z/x.cc'
},
]
}
deps_info = {}
justification = build_failure_analysis.CheckFiles(
failure_signal, ChangeLogFromDict(change_log_json), deps_info,
True)
self.assertIsNotNone(justification)
# The score is 2 because:
# CL only touches dependencies
self.assertEqual(2, justification['score'])
def testAddTarget(self):
signal = FailureSignal()
signal.AddTarget({'target': 'a.exe'})
signal.AddTarget({'target': 'b.o', 'source': 'b.cpp'})
signal.AddTarget({'target': 'b.o', 'source': 'b.cpp'})
self.assertEqual([{
'target': 'a.exe'
}, {
'target': 'b.o',
'source': 'b.cpp'
}], signal.failed_targets)
def testMergeFrom(self):
test_signals = [
{
'files': {
'a.cc': [2],
'd.cc': []
},
'keywords': {},
'failed_targets': [{
'target': 'a.o',
'source': 'a.cc'
}, {
'target': 'b.o',
'source': 'b.cc'
}]
},
{
'files': {
'a.cc': [2, 3, 4],
'b.cc': [],
'd.cc': [1]
},
'keywords': {},
'failed_targets': [{
'target': 'a.o',
'source': 'a.cc'
}, {
'target': 'c.exe'
}]
},
]
step_signal = FailureSignal()
for test_signal in test_signals:
step_signal.MergeFrom(test_signal)
expected_step_signal_files = {
'a.cc': [2, 3, 4],
'd.cc': [1],
'b.cc': []
}
expected_step_failed_targets = [{
'target': 'a.o',
'source': 'a.cc'
}, {
'target': 'b.o',
'source': 'b.cc'
}, {
'target': 'c.exe'
}]
self.assertEqual(expected_step_signal_files, step_signal.files)
self.assertEqual(expected_step_failed_targets,
step_signal.failed_targets)
def Extract(self, failure_log, *_):
signal = FailureSignal()
for line in reversed(failure_log.splitlines()):
if line.startswith('FAILED'): # pragma: no cover
# This is where the failure message starts.
# As we do reverse check, we should stop here.
break
# Extract files.
for match in extractor_util.FILE_PATH_LINE_PATTERN.finditer(line):
file_path, line_number = match.groups()
signal.AddFile(extractor_util.NormalizeFilePath(file_path),
line_number)
return signal
def Extract(self, failure_log, *_):
signal = FailureSignal()
log_lines = failure_log.splitlines()
index = len(log_lines) - 1
while index >= 0: # pragma: no cover
# Start at the bottom of the log and read up.
line = log_lines[index]
if line:
if self.STOP_MARKER.search(line):
break
if not self._ShouldIgnoreLine(line):
self.ExtractFiles(line, signal)
index -= 1
return signal
def Extract(self, failure_log, test_name, step_name, bot_name,
master_name):
signal = FailureSignal()
failure_started = False
if (master_name == self.MAC_MASTER_NAME_FOR_COMPILE
and bot_name in self.IOS_BUILDER_NAMES_FOR_COMPILE):
error_lines = []
for line in reversed(failure_log.splitlines()):
if (not failure_started
and self.ERROR_LINE_END_PATTERN.match(line)):
failure_started = True
continue
if failure_started:
if line.startswith(self.IOS_ERROR_LINE_START_PREFIX):
failure_started = False
for l in error_lines[:-4]:
self.ExtractFiles(l, signal)
error_lines = []
else:
error_lines.append(line)
else:
for line in failure_log.splitlines():
if line.startswith(self.FAILURE_START_LINE_PREFIX):
if not failure_started:
failure_started = True
continue # pragma: no cover
elif failure_started and self.ERROR_LINE_END_PATTERN.match(
line):
failure_started = False
elif failure_started and line.startswith(
self.NINJA_FAILURE_END_LINE_PREFIX
): # pragma: no cover
break
if failure_started or line.startswith(
self.NINJA_ERROR_LINE_PREFIX):
# either within the compile errors or is a ninja error.
self.ExtractFiles(line, signal)
return signal
def testExtractFiles(self):
cases = {
'a/b/c.h:1 at d/e/f.cpp(2)': {
'a/b/c.h': [1],
'd/e/f.cpp': [2]
},
'blabla telemetry/decorators.py:55': {
'telemetry/decorators.py': [55]
},
'File "telemetry/core/web_contents.py", line 78, in pythonMethod': {
'telemetry/core/web_contents.py': [78]
},
'File "/b/build/slave/bot/build/src/a/b.py", line 246, in RunPage': {
'a/b.py': [246]
}
}
extractor = Extractor()
for case in cases:
signal = FailureSignal()
extractor.ExtractFiles(case, signal)
self.assertEqual(cases[case], signal.ToDict()['files'])
def Extract(self, failure_log, *_):
signal = FailureSignal()
log_lines = failure_log.splitlines()
index = 0
start = index
end = len(log_lines)
while index < end: # pragma: no cover
line = log_lines[index]
if line.startswith(self.TEST_START_MARKER):
start = index + 1
elif line.startswith(self.TEST_FAILED_MARKER):
# Extract the test that failed as a possible signal.
match = self.JAVA_TEST_NAME_PATTERN.search(line)
self.ExtractJavaFileMatch(match, signal)
# Extract the rest of the stacks associated with this failure.
test_failure_lines = log_lines[start:index]
self.ProcessTestFailure(test_failure_lines, signal)
index += 1
return signal
def Extract(self, failure_log, *_):
signal = FailureSignal()
failure_started = False
for line in failure_log.splitlines():
if line.startswith(self.BEGINNING_MARKER):
failure_started = True
continue
# Skip hints.
if line.startswith(self.HINT_MARKER):
continue
if self.END_MARKER.match(line):
failure_started = False
continue
# Begin extracting file names.
if failure_started:
self.ExtractFiles(line, signal)
return signal
def _ExtractNinjaOutputJson(self, ninja_output, bot_name, master_name):
signal = FailureSignal()
strict_regex = waterfall_config.EnableStrictRegexForCompileLinkFailures(
master_name, bot_name)
failed_output_nodes = []
for failure in ninja_output['failures']:
lines = failure['output'].splitlines()
del failure['output']
failure['dependencies'] = map(extractor_util.NormalizeFilePath,
failure['dependencies'])
signal.AddEdge(failure)
if lines:
if strict_regex:
self.ExtractFailedOutputNodes(lines[0], signal)
else:
self.GetFailedTarget(lines[0], signal)
for line in lines[1:]:
self.ExtractFiles(line, signal)
failed_output_nodes.extend(failure['output_nodes'])
signal.failed_output_nodes = sorted(set(failed_output_nodes))
return signal
def Extract(self, failure_log, *_):
signal = FailureSignal()
failure_started = False
in_failure_stacktrace_within_range = False
java_stack_frame_index = 0
for line in failure_log.splitlines(): # pragma: no cover
if not failure_started and line.endswith('Detailed Logs'):
failure_started = True
continue
if failure_started:
if (not in_failure_stacktrace_within_range and
self.JAVA_STACK_TRACE_BEGINNING_MARKER.match(line)):
in_failure_stacktrace_within_range = True
java_stack_frame_index = 0
continue
if line.endswith('Summary'):
break
if in_failure_stacktrace_within_range:
match = extractor_util.JAVA_STACK_TRACE_FRAME_PATTERN.search(
line)
if match:
self.ExtractJavaFileMatch(match, signal)
java_stack_frame_index += 1
# Only extract the top several frames of each stack.
if (java_stack_frame_index >=
extractor_util.JAVA_MAXIMUM_NUMBER_STACK_FRAMES
):
in_failure_stacktrace_within_range = False
return signal
def run(self, failure_info):
"""Extracts failure signals from failed steps.
Args:
failure_info (dict): Output of pipeline DetectFirstFailurePipeline.run().
Returns:
A dict like below:
{
'step_name1': waterfall.failure_signal.FailureSignal.ToDict(),
...
}
"""
signals = {}
if not failure_info['failed'] or not failure_info['chromium_revision']:
# Bail out if no failed step or no chromium revision.
return signals
# Bail out on infra failure
if failure_info.get('failure_type') == failure_type.INFRA:
return 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', []):
if not waterfall_config.StepIsSupportedForMaster(
step_name, master_name):
# Bail out if the step is not supported.
continue
step = WfStep.Get(master_name, builder_name, build_number,
step_name)
if step and step.log_data:
failure_log = step.log_data
else:
# TODO: do test-level analysis instead of step-level.
# TODO: Use swarming test result instead of archived gtest results
gtest_result = buildbot.GetGtestResultLog(
master_name, builder_name, build_number, step_name)
if gtest_result:
failure_log = _GetReliableTestFailureLog(gtest_result)
if gtest_result is None or failure_log == 'invalid':
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:
failure_log = buildbot.GetStepLog(
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.
failure_log = 'Stdio log is too large for urlfetch.'
if not failure_log: # pragma: no cover
raise pipeline.Retry(
'Failed to pull stdio of step %s of master %s' %
(step_name, master_name))
# 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 = _ExtractStorablePortionOfLog(failure_log)
try:
step.put()
except Exception as e: # pragma: no cover
# Sometimes, the step log is too large to save in datastore.
logging.exception(e)
# TODO: save result in datastore?
if step.isolated:
try:
json_failure_log = (json.loads(failure_log)
if failure_log != 'flaky' else {})
except ValueError: # pragma: no cover
json_failure_log = {}
logging.warning('failure_log %s is not valid JSON.' %
failure_log)
signals[step_name] = {'tests': {}}
step_signal = FailureSignal()
for test_name, test_failure_log in json_failure_log.iteritems(
):
signals[step_name]['tests'][
test_name] = extractors.ExtractSignal(
master_name, builder_name, step_name, test_name,
base64.b64decode(test_failure_log)).ToDict()
# Save signals in test failure log to step level.
step_signal.MergeFrom(
signals[step_name]['tests'][test_name])
signals[step_name]['files'] = step_signal.files
signals[step_name]['keywords'] = step_signal.keywords
else:
signals[step_name] = extractors.ExtractSignal(
master_name, builder_name, step_name, None,
failure_log).ToDict()
return signals
def Extract(self, failure_log, test_name, step_name, bot_name,
master_name):
signal = FailureSignal()
failure_started = False
is_build_command_line = False
failed_output_nodes = []
if (master_name == self.MAC_MASTER_NAME_FOR_COMPILE
and bot_name in self.IOS_BUILDER_NAMES_FOR_COMPILE):
error_lines = []
for line in reversed(failure_log.splitlines()):
if (not failure_started
and self.ERROR_LINE_END_PATTERN1.match(line)):
failure_started = True
continue
if failure_started:
if line.startswith(self.IOS_ERROR_LINE_START_PREFIX):
failure_started = False
for l in error_lines[:-4]:
self.ExtractFiles(l, signal)
error_lines = []
else:
error_lines.append(line)
else:
strict_regex = waterfall_config.EnableStrictRegexForCompileLinkFailures(
master_name, bot_name)
for line in failure_log.splitlines():
if line.startswith(self.FAILURE_START_LINE_PREFIX):
if not failure_started:
failure_started = True
line = line[len(self.FAILURE_START_LINE_PREFIX):]
failed_output_nodes.extend(
self._GetFailedOutputNodes(line))
is_build_command_line = True
continue
elif is_build_command_line:
if strict_regex:
self.ExtractFailedOutputNodes(line, signal)
else:
self.GetFailedTarget(line, signal)
is_build_command_line = False
continue
elif self.FAILURE_WITH_ERROR_PATTERN.match(line):
# It is possible the target and source file associated with a compile
# failure is logged outside a 'FAILED: ... 1 error generated' block,
# so extract targets regardless of failure_started.
if not strict_regex:
self.GetFailedTarget(line, signal)
elif (failure_started
and (self.ERROR_LINE_END_PATTERN1.match(line)
or self.ERROR_LINE_END_PATTERN2.search(line)
or self.OUTSIDE_FAILURE_LINE_PATTERN.match(line))):
failure_started = False
elif failure_started and line.startswith(
self.NINJA_FAILURE_END_LINE_PREFIX
): # pragma: no cover
break
if failure_started or line.startswith(
self.NINJA_ERROR_LINE_PREFIX):
# either within the compile errors or is a ninja error.
self.ExtractFiles(line, signal)
signal.failed_output_nodes = sorted(set(failed_output_nodes))
return signal
def ExtractSignalsForTestFailure(failure_info, http_client):
signals = {}
master_name = failure_info.master_name
builder_name = failure_info.builder_name
build_number = failure_info.build_number
failed_steps = failure_info.failed_steps or {}
for step_name in failed_steps:
failure_log = None
if not failed_steps[step_name].supported:
# Bail out if the step is not supported.
continue
# 1. Tries to get stored failure log from step.
step = (WfStep.Get(master_name, builder_name, build_number, step_name)
or WfStep.Create(master_name, builder_name, build_number,
step_name))
if step.log_data and step.log_data != constants.TOO_LARGE_LOG:
failure_log = step.log_data
else:
json_formatted_log = True
# 2. Gets test results.
list_isolated_data = failed_steps[step_name].list_isolated_data
list_isolated_data = (list_isolated_data.ToSerializable()
if list_isolated_data else [])
merged_test_results = (
swarmed_test_util.RetrieveShardedTestResultsFromIsolatedServer(
list_isolated_data, http_client))
if merged_test_results:
test_results = test_results_util.GetTestResultObject(
merged_test_results)
if test_results:
failure_log, _ = (
test_results_service.
GetFailedTestsInformationFromTestResult(test_results))
failure_log = json.dumps(
failure_log
) if failure_log else constants.FLAKY_FAILURE_LOG
else:
failure_log = constants.WRONG_FORMAT_LOG
if not merged_test_results or failure_log in [
constants.INVALID_FAILURE_LOG, constants.WRONG_FORMAT_LOG
]:
# 3. Gets stdout log.
json_formatted_log = False
failure_log = extract_signal.GetStdoutLog(
master_name, builder_name, build_number, step_name,
http_client)
try:
if not failure_log:
raise extract_signal.FailedToGetFailureLogError(
'Failed to pull failure log (stdio or ninja output) of step %s of'
' %s/%s/%d' %
(step_name, master_name, builder_name, build_number))
except extract_signal.FailedToGetFailureLogError:
return {}
# Save step log in datastore and avoid downloading again during retry.
step.log_data = extract_signal.ExtractStorablePortionOfLog(
failure_log, json_formatted_log
) if step.log_data != constants.TOO_LARGE_LOG else step.log_data
step.isolated = step.isolated or json_formatted_log
try:
step.put()
except Exception as e: # pragma: no cover
# Sometimes, the step log is too large to save in datastore.
logging.exception(e)
if step.isolated:
try:
json_failure_log = (json.loads(failure_log) if
failure_log != constants.FLAKY_FAILURE_LOG
else {})
except ValueError:
json_failure_log = {}
logging.warning('failure_log %s is not valid JSON.' %
failure_log)
signals[step_name] = {'tests': {}}
step_signal = FailureSignal()
for test_name, test_failure_log in json_failure_log.iteritems():
signals[step_name]['tests'][
test_name] = extractors.ExtractSignal(
master_name, builder_name, step_name, test_name,
base64.b64decode(test_failure_log)).ToDict()
# Save signals in test failure log to step level.
step_signal.MergeFrom(signals[step_name]['tests'][test_name])
signals[step_name]['files'] = step_signal.files
else:
signals[step_name] = extractors.ExtractSignal(
master_name, builder_name, step_name, None,
failure_log).ToDict()
return signals
def testAddFileWithoutLineNumber(self):
signal = FailureSignal()
signal.AddFile('a.cc', None)
self.assertEqual({'a.cc': []}, signal.files)
def testAddFileWithLineNumber(self):
signal = FailureSignal()
signal.AddFile('a.cc', 1)
signal.AddFile('a.cc', 11)
signal.AddFile('a.cc', 11)
self.assertEqual({'a.cc': [1, 11]}, signal.files)
def testAddTest(self):
signal = FailureSignal()
signal.AddTest('suite.name1')
signal.AddTest('suite.name2')
self.assertEqual(['suite.name1', 'suite.name2'], signal.tests)
def testMergeFrom(self):
test_signals = [
{
'files': {
'a.cc': [2],
'd.cc': []
},
'keywords': {},
'failed_targets': [{
'target': 'a.o',
'source': 'a.cc'
}, {
'target': 'b.o',
'source': 'b.cc'
}],
'failed_edges': [{
'rule': 'CXX',
'output_nodes': ['a.o', 'aa.o'],
'dependencies': ['a.h', 'a.c']
}]
},
{
'files': {
'a.cc': [2, 3, 4],
'b.cc': [],
'd.cc': [1]
},
'keywords': {},
'failed_targets': [{
'target': 'a.o',
'source': 'a.cc'
}, {
'target': 'c.exe'
}],
'failed_edges': [{
'rule': 'LINK',
'output_nodes': ['b.o'],
'dependencies': []
}]
},
]
step_signal = FailureSignal()
for test_signal in test_signals:
step_signal.MergeFrom(test_signal)
expected_step_signal_files = {
'a.cc': [2, 3, 4],
'd.cc': [1],
'b.cc': []
}
expected_step_failed_targets = [{
'target': 'a.o',
'source': 'a.cc'
}, {
'target': 'b.o',
'source': 'b.cc'
}, {
'target': 'c.exe'
}]
expected_step_failed_edges = [{
'rule': 'CXX',
'output_nodes': ['a.o', 'aa.o'],
'dependencies': ['a.h', 'a.c']
}, {
'rule': 'LINK',
'output_nodes': ['b.o'],
'dependencies': []
}]
self.assertEqual(expected_step_signal_files, step_signal.files)
self.assertEqual(expected_step_failed_targets,
step_signal.failed_targets)
self.assertEqual(expected_step_failed_edges, step_signal.failed_edges)