123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330 |
- # Copyright (c) 2016 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 re
- from test_result_util import ResultCollection, TestResult, TestStatus
- # These labels should match the ones output by gtest's JSON.
- TEST_UNKNOWN_LABEL = 'UNKNOWN'
- TEST_SUCCESS_LABEL = 'SUCCESS'
- TEST_FAILURE_LABEL = 'FAILURE'
- TEST_CRASH_LABEL = 'CRASH'
- TEST_TIMEOUT_LABEL = 'TIMEOUT'
- TEST_WARNING_LABEL = 'WARNING'
- class XCTestLogParser(object):
- """This helper class process XCTest test output."""
- def __init__(self):
- # Test results from the parser.
- self._result_collection = ResultCollection()
- # State tracking for log parsing
- self.completed = False
- self._current_test = ''
- self._failure_description = []
- self._current_report_hash = ''
- self._current_report = []
- self._parsing_failures = False
- # Line number currently being processed.
- self._line_number = 0
- # List of parsing errors, as human-readable strings.
- self._internal_error_lines = []
- # Tests are stored here as 'test.name': (status, [description]).
- # The status should be one of ('started', 'OK', 'failed', 'timeout',
- # 'warning'). Warning indicates that a test did not pass when run in
- # parallel with other tests but passed when run alone. The description is
- # a list of lines detailing the test's error, as reported in the log.
- self._test_status = {}
- # This may be either text or a number. It will be used in the phrase
- # '%s disabled' or '%s flaky' on the waterfall display.
- self._disabled_tests = 0
- self._flaky_tests = 0
- test_name_regexp = r'\-\[(\w+)\s(\w+)\]'
- self._test_name = re.compile(test_name_regexp)
- self._test_start = re.compile(
- r'Test Case \'' + test_name_regexp + '\' started\.')
- self._test_ok = re.compile(
- r'Test Case \'' + test_name_regexp +
- '\' passed\s+\(\d+\.\d+\s+seconds\)?.')
- self._test_fail = re.compile(
- r'Test Case \'' + test_name_regexp +
- '\' failed\s+\(\d+\.\d+\s+seconds\)?.')
- self._test_execute_succeeded = re.compile(
- r'\*\*\s+TEST\s+EXECUTE\s+SUCCEEDED\s+\*\*')
- self._test_execute_failed = re.compile(
- r'\*\*\s+TEST\s+EXECUTE\s+FAILED\s+\*\*')
- self._retry_message = re.compile('RETRYING FAILED TESTS:')
- self.retrying_failed = False
- self._system_alert_present_message = re.compile(
- r'\bSystem alert view is present, so skipping all tests\b')
- self.system_alert_present = False
- self.TEST_STATUS_MAP = {
- 'OK': TEST_SUCCESS_LABEL,
- 'failed': TEST_FAILURE_LABEL,
- 'timeout': TEST_TIMEOUT_LABEL,
- 'warning': TEST_WARNING_LABEL
- }
- def Finalize(self):
- """Finalize for |self._result_collection|.
- Called at the end to add unfinished tests and crash status for
- self._result_collection.
- """
- for test in self.RunningTests():
- self._result_collection.add_test_result(
- TestResult(test[0], TestStatus.CRASH, test_log='Did not complete.'))
- if not self.completed:
- self._result_collection.crashed = True
- def GetResultCollection(self):
- return self._result_collection
- def GetCurrentTest(self):
- return self._current_test
- def _StatusOfTest(self, test):
- """Returns the status code for the given test, or 'not known'."""
- test_status = self._test_status.get(test, ('not known', []))
- return test_status[0]
- def _TestsByStatus(self, status, include_fails, include_flaky):
- """Returns list of tests with the given status.
- Args:
- include_fails: If False, tests containing 'FAILS_' anywhere in their
- names will be excluded from the list.
- include_flaky: If False, tests containing 'FLAKY_' anywhere in their
- names will be excluded from the list.
- """
- test_list = [x[0] for x in self._test_status.items()
- if self._StatusOfTest(x[0]) == status]
- if not include_fails:
- test_list = [x for x in test_list if x.find('FAILS_') == -1]
- if not include_flaky:
- test_list = [x for x in test_list if x.find('FLAKY_') == -1]
- return test_list
- def _RecordError(self, line, reason):
- """Record a log line that produced a parsing error.
- Args:
- line: text of the line at which the error occurred
- reason: a string describing the error
- """
- self._internal_error_lines.append('%s: %s [%s]' %
- (self._line_number, line.strip(), reason))
- def RunningTests(self):
- """Returns list of tests that appear to be currently running."""
- return self._TestsByStatus('started', True, True)
- def ParsingErrors(self):
- """Returns a list of lines that have caused parsing errors."""
- return self._internal_error_lines
- def ClearParsingErrors(self):
- """Clears the currently stored parsing errors."""
- self._internal_error_lines = ['Cleared.']
- def PassedTests(self, include_fails=False, include_flaky=False):
- """Returns list of tests that passed."""
- return self._TestsByStatus('OK', include_fails, include_flaky)
- def FailedTests(self, include_fails=False, include_flaky=False):
- """Returns list of tests that failed, timed out, or didn't finish
- (crashed).
- This list will be incorrect until the complete log has been processed,
- because it will show currently running tests as having failed.
- Args:
- include_fails: If true, all failing tests with FAILS_ in their names will
- be included. Otherwise, they will only be included if they crashed or
- timed out.
- include_flaky: If true, all failing tests with FLAKY_ in their names will
- be included. Otherwise, they will only be included if they crashed or
- timed out.
- """
- return (self._TestsByStatus('failed', include_fails, include_flaky) +
- self._TestsByStatus('timeout', True, True) +
- self._TestsByStatus('warning', include_fails, include_flaky) +
- self.RunningTests())
- def TriesForTest(self, test):
- """Returns a list containing the state for all tries of the given test.
- This parser doesn't support retries so a single result is returned."""
- return [self.TEST_STATUS_MAP.get(self._StatusOfTest(test),
- TEST_UNKNOWN_LABEL)]
- def FailureDescription(self, test):
- """Returns a list containing the failure description for the given test.
- If the test didn't fail or timeout, returns [].
- """
- test_status = self._test_status.get(test, ('', []))
- return ['%s: ' % test] + test_status[1]
- def CompletedWithoutFailure(self):
- """Returns True if all tests completed and no tests failed unexpectedly."""
- return self.completed and not self.FailedTests()
- def SystemAlertPresent(self):
- """Returns a bool indicating whether a system alert is shown on device."""
- return self.system_alert_present
- def ProcessLine(self, line):
- """This is called once with each line of the test log."""
- # Track line number for error messages.
- self._line_number += 1
- # Some tests (net_unittests in particular) run subprocesses which can write
- # stuff to shared stdout buffer. Sometimes such output appears between new
- # line and gtest directives ('[ RUN ]', etc) which breaks the parser.
- # Code below tries to detect such cases and recognize a mixed line as two
- # separate lines.
- # List of regexps that parses expects to find at the start of a line but
- # which can be somewhere in the middle.
- gtest_regexps = [
- self._test_start,
- self._test_ok,
- self._test_fail,
- self._test_execute_failed,
- self._test_execute_succeeded,
- ]
- for regexp in gtest_regexps:
- match = regexp.search(line)
- if match:
- break
- if not match or match.start() == 0:
- self._ProcessLine(line)
- else:
- self._ProcessLine(line[:match.start()])
- self._ProcessLine(line[match.start():])
- def _ProcessLine(self, line):
- """Parses the line and changes the state of parsed tests accordingly.
- Will recognize newly started tests, OK or FAILED statuses, timeouts, etc.
- """
- # Is it a line declaring end of all tests?
- succeeded = self._test_execute_succeeded.match(line)
- failed = self._test_execute_failed.match(line)
- if succeeded or failed:
- self.completed = True
- self._current_test = ''
- return
- # Is it a line declaring a system alert is shown on the device?
- results = self._system_alert_present_message.search(line)
- if results:
- self.system_alert_present = True
- self._current_test = ''
- return
- # Is it the start of a test?
- results = self._test_start.match(line)
- if results:
- if self._current_test:
- if self._test_status[self._current_test][0] == 'started':
- self._test_status[self._current_test] = (
- 'timeout', self._failure_description)
- self._result_collection.add_test_result(
- TestResult(
- self._current_test,
- TestStatus.ABORT,
- test_log='\n'.join(self._failure_description)))
- test_name = '%s/%s' % (results.group(1), results.group(2))
- self._test_status[test_name] = ('started', ['Did not complete.'])
- self._current_test = test_name
- if self.retrying_failed:
- self._failure_description = self._test_status[test_name][1]
- self._failure_description.extend(['', 'RETRY OUTPUT:', ''])
- else:
- self._failure_description = []
- return
- # Is it a test success line?
- results = self._test_ok.match(line)
- if results:
- test_name = '%s/%s' % (results.group(1), results.group(2))
- status = self._StatusOfTest(test_name)
- if status != 'started':
- self._RecordError(line, 'success while in status %s' % status)
- if self.retrying_failed:
- self._test_status[test_name] = ('warning', self._failure_description)
- # This is a passed result. Previous failures were reported in separate
- # TestResult objects.
- self._result_collection.add_test_result(
- TestResult(
- test_name,
- TestStatus.PASS,
- test_log='\n'.join(self._failure_description)))
- else:
- self._test_status[test_name] = ('OK', [])
- self._result_collection.add_test_result(
- TestResult(test_name, TestStatus.PASS))
- self._failure_description = []
- self._current_test = ''
- return
- # Is it a test failure line?
- results = self._test_fail.match(line)
- if results:
- test_name = '%s/%s' % (results.group(1), results.group(2))
- status = self._StatusOfTest(test_name)
- if status not in ('started', 'failed', 'timeout'):
- self._RecordError(line, 'failure while in status %s' % status)
- if self._current_test != test_name:
- if self._current_test:
- self._RecordError(
- line,
- '%s failure while in test %s' % (test_name, self._current_test))
- return
- # Don't overwrite the failure description when a failing test is listed a
- # second time in the summary, or if it was already recorded as timing
- # out.
- if status not in ('failed', 'timeout'):
- self._test_status[test_name] = ('failed', self._failure_description)
- # Add to |test_results| regardless whether the test ran before.
- self._result_collection.add_test_result(
- TestResult(
- test_name,
- TestStatus.FAIL,
- test_log='\n'.join(self._failure_description)))
- self._failure_description = []
- self._current_test = ''
- return
- # Is it the start of the retry tests?
- results = self._retry_message.match(line)
- if results:
- self.retrying_failed = True
- return
- # Random line: if we're in a test, collect it for the failure description.
- # Tests may run simultaneously, so this might be off, but it's worth a try.
- # This also won't work if a test times out before it begins running.
- if self._current_test:
- self._failure_description.append(line)
|