1# Copyright (c) 2017 The Chromium OS Authors. All rights reserved.
2# Use of this source code is governed by a BSD-style license that can be
3# found in the LICENSE file.
4
5"""Utility class to parse the output of a gtest suite run."""
6
7import re
8
9
10class gtest_parser(object):
11    """This class knows how to understand GTest test output.
12
13    The code was borrowed with minor changes from chrome utility gtest_command.
14        http://src.chromium.org/viewvc/chrome/trunk/tools/build/scripts/master/
15        log_parser/gtest_command.py?view=markup
16    """
17
18    def __init__(self):
19        # State tracking for log parsing
20        self._current_test = ''
21        self._failure_description = []
22        self._current_suppression_hash = ''
23        self._current_suppression = []
24
25        # Line number currently being processed.
26        self._line_number = 0
27
28        # List of parsing errors, as human-readable strings.
29        self.internal_error_lines = []
30
31        # Tests are stored here as 'test.name': (status, [description]).
32        # The status should be one of ('started', 'OK', 'failed', 'timeout').
33        # The description is a list of lines detailing the test's error, as
34        # reported in the log.
35        self._test_status = {}
36
37        # Suppressions are stored here as 'hash': [suppression].
38        self._suppressions = {}
39
40        # This may be either text or a number. It will be used in the phrase
41        # '%s disabled' or '%s flaky' on the waterfall display.
42        self.disabled_tests = 0
43        self.flaky_tests = 0
44
45        # Regular expressions for parsing GTest logs. Test names look like
46        #   SomeTestCase.SomeTest
47        #   SomeName/SomeTestCase.SomeTest/1
48        # This regexp also matches SomeName.SomeTest/1, which should be
49        # harmless.
50        test_name_regexp = r'((\w+/)?\w+\.\w+(\.\w+)?(/\d+)?)'
51        self._test_start = re.compile('\[\s+RUN\s+\] ' + test_name_regexp)
52        self._test_ok = re.compile('\[\s+OK\s+\] ' + test_name_regexp)
53        self._test_fail = re.compile('\[\s+FAILED\s+\] ' + test_name_regexp)
54        self._test_timeout = re.compile(
55            'Test timeout \([0-9]+ ms\) exceeded for ' + test_name_regexp)
56        self._disabled = re.compile('  YOU HAVE (\d+) DISABLED TEST')
57        self._flaky = re.compile('  YOU HAVE (\d+) FLAKY TEST')
58
59        self._suppression_start = re.compile(
60            'Suppression \(error hash=#([0-9A-F]+)#\):')
61        self._suppression_end = re.compile('^}\s*$')
62
63        self._master_name_re = re.compile('\[Running for master: "([^"]*)"')
64        self.master_name = ''
65
66        self._error_logging_start_re = re.compile('=' * 70)
67        self._error_logging_test_name_re = re.compile(
68            '[FAIL|ERROR]: ' + test_name_regexp)
69        self._error_logging_end_re = re.compile('-' * 70)
70        self._error_logging_first_dash_found = False
71
72    def _TestsByStatus(self, status, include_fails, include_flaky):
73        """Returns list of tests with the given status.
74
75        Args:
76            status: test results status to search for.
77            include_fails: If False, tests containing 'FAILS_' anywhere in
78                their names will be excluded from the list.
79            include_flaky: If False, tests containing 'FLAKY_' anywhere in
80                their names will be excluded from the list.
81        Returns:
82            List of tests with the status.
83        """
84        test_list = [x[0] for x in self._test_status.items()
85                     if self._StatusOfTest(x[0]) == status]
86
87        if not include_fails:
88            test_list = [x for x in test_list if x.find('FAILS_') == -1]
89        if not include_flaky:
90            test_list = [x for x in test_list if x.find('FLAKY_') == -1]
91
92        return test_list
93
94    def _StatusOfTest(self, test):
95        """Returns the status code for the given test, or 'not known'."""
96        test_status = self._test_status.get(test, ('not known', []))
97        return test_status[0]
98
99    def _RecordError(self, line, reason):
100        """Record a log line that produced a parsing error.
101
102        Args:
103            line: text of the line at which the error occurred.
104            reason: a string describing the error.
105        """
106        self.internal_error_lines.append("%s: %s [%s]" % (self._line_number,
107                                                          line.strip(),
108                                                          reason))
109
110    def TotalTests(self):
111        """Returns the number of parsed tests."""
112        return len(self._test_status)
113
114    def PassedTests(self):
115        """Returns list of tests that passed."""
116        return self._TestsByStatus('OK', False, False)
117
118    def FailedTests(self, include_fails=False, include_flaky=False):
119        """Returns list of tests that failed, timed out, or didn't finish.
120
121        This list will be incorrect until the complete log has been processed,
122        because it will show currently running tests as having failed.
123
124        Args:
125            include_fails: If true, all failing tests with FAILS_ in their
126                names will be included. Otherwise, they will only be included
127                if they crashed.
128            include_flaky: If true, all failing tests with FLAKY_ in their
129                names will be included. Otherwise, they will only be included
130                if they crashed.
131        Returns:
132            List of failed tests.
133        """
134        return (self._TestsByStatus('failed', include_fails, include_flaky) +
135                self._TestsByStatus('timeout', include_fails, include_flaky) +
136                self._TestsByStatus('started', include_fails, include_flaky))
137
138    def FailureDescription(self, test):
139        """Returns a list containing the failure description for the given test.
140
141        If the test didn't fail or timeout, returns [].
142        Args:
143            test: Name to test to find failure reason.
144        Returns:
145            List of test name, and failure string.
146        """
147        test_status = self._test_status.get(test, ('', []))
148        return test_status[1]
149
150    def SuppressionHashes(self):
151        """Returns list of suppression hashes found in the log."""
152        return self._suppressions.keys()
153
154    def Suppression(self, suppression_hash):
155        """Returns a list containing the suppression for a given hash.
156
157        If the suppression hash doesn't exist, returns [].
158
159        Args:
160            suppression_hash: name of hash.
161        Returns:
162            List of suppression for the hash.
163        """
164        return self._suppressions.get(suppression_hash, [])
165
166    def ProcessLogLine(self, line):
167        """This is called once with each line of the test log."""
168
169        # Track line number for error messages.
170        self._line_number += 1
171
172        if not self.master_name:
173            results = self._master_name_re.search(line)
174            if results:
175                self.master_name = results.group(1)
176
177        # Is it a line reporting disabled tests?
178        results = self._disabled.search(line)
179        if results:
180            try:
181                disabled = int(results.group(1))
182            except ValueError:
183                disabled = 0
184            if disabled > 0 and isinstance(self.disabled_tests, int):
185                self.disabled_tests += disabled
186            else:
187                # If we can't parse the line, at least give a heads-up. This is
188                # a safety net for a case that shouldn't happen but isn't a
189                # fatal error.
190                self.disabled_tests = 'some'
191            return
192
193        # Is it a line reporting flaky tests?
194        results = self._flaky.search(line)
195        if results:
196            try:
197                flaky = int(results.group(1))
198            except ValueError:
199                flaky = 0
200            if flaky > 0 and isinstance(self.flaky_tests, int):
201                self.flaky_tests = flaky
202            else:
203                # If we can't parse the line, at least give a heads-up. This is
204                # a safety net for a case that shouldn't happen but isn't a
205                # fatal error.
206                self.flaky_tests = 'some'
207            return
208
209        # Is it the start of a test?
210        results = self._test_start.search(line)
211        if results:
212            test_name = results.group(1)
213            if test_name in self._test_status:
214                self._RecordError(line, 'test started more than once')
215                return
216            if self._current_test:
217                status = self._StatusOfTest(self._current_test)
218                if status in ('OK', 'failed', 'timeout'):
219                    self._RecordError(line, 'start while in status %s' % status)
220                    return
221                if status not in ('failed', 'timeout'):
222                    self._test_status[self._current_test] = (
223                        'failed', self._failure_description)
224            self._test_status[test_name] = ('started', ['Did not complete.'])
225            self._current_test = test_name
226            self._failure_description = []
227            return
228
229        # Is it a test success line?
230        results = self._test_ok.search(line)
231        if results:
232            test_name = results.group(1)
233            status = self._StatusOfTest(test_name)
234            if status != 'started':
235                self._RecordError(line, 'success while in status %s' % status)
236                return
237            self._test_status[test_name] = ('OK', [])
238            self._failure_description = []
239            self._current_test = ''
240            return
241
242        # Is it a test failure line?
243        results = self._test_fail.search(line)
244        if results:
245            test_name = results.group(1)
246            status = self._StatusOfTest(test_name)
247            if status not in ('started', 'failed', 'timeout'):
248                self._RecordError(line, 'failure while in status %s' % status)
249                return
250            # Don't overwrite the failure description when a failing test is
251            # listed a second time in the summary, or if it was already
252            # recorded as timing out.
253            if status not in ('failed', 'timeout'):
254                self._test_status[test_name] = ('failed',
255                                                self._failure_description)
256            self._failure_description = []
257            self._current_test = ''
258            return
259
260        # Is it a test timeout line?
261        results = self._test_timeout.search(line)
262        if results:
263            test_name = results.group(1)
264            status = self._StatusOfTest(test_name)
265            if status not in ('started', 'failed'):
266                self._RecordError(line, 'timeout while in status %s' % status)
267                return
268            self._test_status[test_name] = (
269                'timeout', self._failure_description + ['Killed (timed out).'])
270            self._failure_description = []
271            self._current_test = ''
272            return
273
274        # Is it the start of a new valgrind suppression?
275        results = self._suppression_start.search(line)
276        if results:
277            suppression_hash = results.group(1)
278            if suppression_hash in self._suppressions:
279                self._RecordError(line, 'suppression reported more than once')
280                return
281            self._suppressions[suppression_hash] = []
282            self._current_suppression_hash = suppression_hash
283            self._current_suppression = [line]
284            return
285
286        # Is it the end of a valgrind suppression?
287        results = self._suppression_end.search(line)
288        if results and self._current_suppression_hash:
289            self._current_suppression.append(line)
290            self._suppressions[self._current_suppression_hash] = (
291                self._current_suppression)
292            self._current_suppression_hash = ''
293            self._current_suppression = []
294            return
295
296        # Is it the start of a test summary error message?
297        results = self._error_logging_test_name_re.search(line)
298        if results:
299            test_name = results.group(1)
300            self._test_status[test_name] = ('failed', ['Output not found.'])
301            self._current_test = test_name
302            self._failure_description = []
303            self._error_logging_first_dash_found = False
304            return
305
306        # Is it the start of the next test summary signaling the end
307        # of the previous message?
308        results = self._error_logging_start_re.search(line)
309        if results and self._current_test:
310            self._test_status[self._current_test] = ('failed',
311                                                     self._failure_description)
312            self._failure_description = []
313            self._current_test = ''
314            return
315
316        # Is it the end of the extra test failure summaries?
317        results = self._error_logging_end_re.search(line)
318        if results and self._current_test:
319            if self._error_logging_first_dash_found:
320                self._test_status[self._current_test] = (
321                    'failed', self._failure_description)
322                self._failure_description = []
323                self._current_test = ''
324            self._error_logging_first_dash_found = True
325            return
326
327        # Random line: if we're in a suppression, collect it. Suppressions are
328        # generated after all tests are finished, so this should always belong
329        # to the current suppression hash.
330        if self._current_suppression_hash:
331            self._current_suppression.append(line)
332            return
333
334        # Random line: if we're in a test, collect it for the failure
335        # description. Tests may run simultaneously, so this might be off, but
336        # it's worth a try.
337        if self._current_test:
338            self._failure_description.append(line)
339