• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1# Copyright 2016 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# repohooks/pre-upload.py currently does not run pylint. But for developers who
6# want to check their code manually we disable several harmless pylint warnings
7# which just distract from more serious remaining issues.
8#
9# The instance variable _android_cts is not defined in __init__().
10# pylint: disable=attribute-defined-outside-init
11#
12# Many short variable names don't follow the naming convention.
13# pylint: disable=invalid-name
14
15import logging
16import os
17import shutil
18
19from autotest_lib.client.common_lib import error
20from autotest_lib.server import utils
21from autotest_lib.server.cros import tradefed_test
22
23# Notice if there are only a few failures each RETRY step currently (08/01/2016)
24# takes a bit more than 6 minutes (mostly for reboot, login, starting ARC).
25# In other words a RETRY of 10 takes about 1h, which is well within the limit of
26# the 4h TIMEOUT. Nevertheless RETRY steps will cause the test to end with a
27# test warning and should be treated as serious bugs.
28# Finally, if we have a true test hang or even reboot, tradefed currently will
29# likely hang unit the TIMEOUT hits and no RETRY steps will happen.
30_CTS_MAX_RETRY = {'dev': 9, 'beta': 9, 'stable': 9}
31# Maximum default time allowed for each individual CTS package.
32_CTS_TIMEOUT_SECONDS = (4 * 3600)
33
34# Public download locations for android cts bundles.
35_DL_CTS = 'https://dl.google.com/dl/android/cts/'
36_CTS_URI = {
37    'arm' : _DL_CTS + 'android-cts-6.0_r16-linux_x86-arm.zip',
38    'x86' : _DL_CTS + 'android-cts-6.0_r16-linux_x86-x86.zip',
39    'media' : _DL_CTS + 'android-cts-media-1.3.zip'
40}
41
42
43class cheets_CTS(tradefed_test.TradefedTest):
44    """Sets up tradefed to run CTS tests."""
45    version = 1
46
47    def setup(self, bundle=None, uri=None):
48        """Download and install a zipfile bundle from Google Storage.
49
50        @param bundle: bundle name, which needs to be key of the _CTS_URI
51                       dictionary. Can be 'arm', 'x86' and undefined.
52        @param uri: URI of CTS bundle. Required if |abi| is undefined.
53        """
54        if bundle in _CTS_URI:
55            self._android_cts = self._install_bundle(_CTS_URI[bundle])
56        else:
57            self._android_cts = self._install_bundle(uri)
58
59        self._cts_tradefed = os.path.join(
60                self._android_cts,
61                'android-cts',
62                'tools',
63                'cts-tradefed')
64        logging.info('CTS-tradefed path: %s', self._cts_tradefed)
65
66        # Load waivers and manual tests so TF doesn't re-run them.
67        self.waivers_and_manual_tests = self._get_expected_failures(
68                                                'expectations')
69        # Load packages with no tests.
70        self.notest_packages = self._get_expected_failures('notest_packages')
71
72    def _clean_repository(self):
73        """Ensures all old logs, results and plans are deleted.
74
75        This function should be called at the start of each autotest iteration.
76        """
77        logging.info('Cleaning up repository.')
78        repository = os.path.join(self._android_cts, 'android-cts',
79                'repository')
80        for directory in ['logs', 'results']:
81            path = os.path.join(repository, directory)
82            if os.path.exists(path):
83                shutil.rmtree(path)
84            self._safe_makedirs(path)
85
86    def _install_plan(self, plan):
87        logging.info('Install plan: %s', plan)
88        plans_dir = os.path.join(self._android_cts, 'android-cts',
89                'repository', 'plans')
90        src_plan_file = os.path.join(self.bindir, 'plans', '%s.xml' % plan)
91        shutil.copy(src_plan_file, plans_dir)
92
93    def _tradefed_run_command(self,
94                              package=None,
95                              plan=None,
96                              session_id=None,
97                              test_class=None,
98                              test_method=None):
99
100        """Builds the CTS tradefed 'run' command line.
101
102        There are five different usages:
103
104        1. Test a package: assign the package name via |package|.
105        2. Test a plan: assign the plan name via |plan|.
106        3. Continue a session: assign the session ID via |session_id|.
107        4. Run all test cases of a class: assign the class name via
108           |test_class|.
109        5. Run a specific test case: assign the class name and method name in
110           |test_class| and |test_method|.
111
112        @param package: the name of test package to be run.
113        @param plan: name of the plan to be run.
114        @param session_id: tradefed session id to continue.
115        @param test_class: the name of the class of which all test cases will
116                           be run.
117        @param test_name: the name of the method of |test_class| to be run.
118                          Must be used with |test_class|.
119        @return: list of command tokens for the 'run' command.
120        """
121        if package is not None:
122            cmd = ['run', 'commandAndExit', 'cts', '--package', package]
123        elif plan is not None:
124            cmd = ['run', 'commandAndExit', 'cts', '--plan', plan]
125        elif session_id is not None:
126            cmd = ['run', 'commandAndExit', 'cts', '--continue-session',
127                   '%d' % session_id]
128        elif test_class is not None:
129            cmd = ['run', 'commandAndExit', 'cts', '-c', test_class]
130            if test_method is not None:
131                cmd += ['-m', test_method]
132        else:
133            logging.warning('Running all tests. This can take several days.')
134            cmd = ['run', 'commandAndExit', 'cts', '--plan', 'CTS']
135        # Automated media download is broken, so disable it. Instead we handle
136        # this explicitly via _push_media(). This has the benefit of being
137        # cached on the dev server. b/27245577
138        cmd.append('--skip-media-download')
139
140        # If we are running outside of the lab we can collect more data.
141        if not utils.is_in_container():
142            logging.info('Running outside of lab, adding extra debug options.')
143            cmd.append('--log-level-display=DEBUG')
144            cmd.append('--screenshot-on-failure')
145            cmd.append('--collect-deqp-logs')
146        # At early stage, cts-tradefed tries to reboot the device by
147        # "adb reboot" command. In a real Android device case, when the
148        # rebooting is completed, adb connection is re-established
149        # automatically, and cts-tradefed expects that behavior.
150        # However, in ARC, it doesn't work, so the whole test process
151        # is just stuck. Here, disable the feature.
152        cmd.append('--disable-reboot')
153        # Create a logcat file for each individual failure.
154        cmd.append('--logcat-on-failure')
155        return cmd
156
157    def _run_cts_tradefed(self, commands, datetime_id=None):
158        """Runs tradefed, collects logs and returns the result counts.
159
160        Assumes that only last entry of |commands| actually runs tests and has
161        interesting output (results, logs) for collection. Ignores all other
162        commands for this purpose.
163
164        @param commands: List of lists of command tokens.
165        @param datetime_id: For 'continue' datetime of previous run is known.
166                            Knowing it makes collecting logs more robust.
167        @return: tuple of (tests, pass, fail, notexecuted) counts.
168        """
169        for command in commands:
170            # Assume only last command actually runs tests and has interesting
171            # output (results, logs) for collection.
172            logging.info('RUN: ./cts-tradefed %s', ' '.join(command))
173            output = self._run(
174                self._cts_tradefed,
175                args=tuple(command),
176                timeout=self._timeout,
177                verbose=True,
178                ignore_status=False,
179                # Make sure to tee tradefed stdout/stderr to autotest logs
180                # continuously during the test run.
181                stdout_tee=utils.TEE_TO_LOGS,
182                stderr_tee=utils.TEE_TO_LOGS)
183            logging.info('END: ./cts-tradefed %s\n', ' '.join(command))
184        result_destination = os.path.join(self.resultsdir, 'android-cts')
185        # Gather the global log first. Datetime parsing below can abort the test
186        # if tradefed startup had failed. Even then the global log is useful.
187        self._collect_tradefed_global_log(output, result_destination)
188        if not datetime_id:
189            # Parse stdout to obtain datetime of the session. This is needed to
190            # locate result xml files and logs.
191            datetime_id = self._parse_tradefed_datetime(output, self.summary)
192        # Collect tradefed logs for autotest.
193        tradefed = os.path.join(self._android_cts, 'android-cts', 'repository')
194        self._collect_logs(tradefed, datetime_id, result_destination)
195        return self._parse_result(output, self.waivers_and_manual_tests)
196
197    def _tradefed_continue(self, session_id, datetime_id=None):
198        """Continues a previously started session.
199
200        Attempts to run all 'notexecuted' tests.
201        @param session_id: tradefed session id to continue.
202        @param datetime_id: datetime of run to continue.
203        @return: tuple of (tests, pass, fail, notexecuted) counts.
204        """
205        # The list command is not required. It allows the reader to inspect the
206        # tradefed state when examining the autotest logs.
207        commands = [
208                ['list', 'results'],
209                self._tradefed_run_command(session_id=session_id)]
210        return self._run_cts_tradefed(commands, datetime_id)
211
212    def _tradefed_retry(self, test_name, session_id):
213        """Retries failing tests in session.
214
215        It is assumed that there are no notexecuted tests of session_id,
216        otherwise some tests will be missed and never run.
217
218        @param test_name: the name of test to be retried.
219        @param session_id: tradefed session id to retry.
220        @return: tuple of (new session_id, tests, pass, fail, notexecuted).
221        """
222        # Creating new test plan for retry.
223        derivedplan = 'retry.%s.%s' % (test_name, session_id)
224        logging.info('Retrying failures using derived plan %s.', derivedplan)
225        # The list commands are not required. It allows the reader to inspect
226        # the tradefed state when examining the autotest logs.
227        commands = [
228                ['list', 'plans'],
229                ['add', 'derivedplan', '--plan', derivedplan, '--session', '%d'
230                        % session_id, '-r', 'fail'],
231                ['list', 'plans'],
232                ['list', 'results'],
233                self._tradefed_run_command(plan=derivedplan)]
234        counts = self._run_cts_tradefed(commands)
235        # TODO(ihf): Consider if diffing/parsing output of "list results" for
236        # new session_id might be more reliable. For now just assume simple
237        # increment. This works if only one tradefed instance is active and
238        # only a single run command is executing at any moment.
239        session_id += 1
240        return (session_id, counts)
241
242    def _get_release_channel(self):
243        """Returns the DUT channel of the image ('dev', 'beta', 'stable')."""
244        # TODO(ihf): check CHROMEOS_RELEASE_DESCRIPTION and return channel.
245        return 'dev'
246
247    def _get_channel_retry(self):
248        """Returns the maximum number of retries for DUT image channel."""
249        channel = self._get_release_channel()
250        if channel in _CTS_MAX_RETRY:
251            return _CTS_MAX_RETRY[channel]
252        retry = _CTS_MAX_RETRY['dev']
253        logging.warning('Could not establish channel. Using retry=%d.', retry)
254        return retry
255
256    def run_once(self,
257                 target_package=None,
258                 target_plan=None,
259                 target_class=None,
260                 target_method=None,
261                 needs_push_media=False,
262                 max_retry=None,
263                 timeout=_CTS_TIMEOUT_SECONDS):
264        """Runs the specified CTS once, but with several retries.
265
266        There are four usages:
267        1. Test the whole package named |target_package|.
268        2. Test with a plan named |target_plan|.
269        3. Run all the test cases of class named |target_class|.
270        4. Run a specific test method named |target_method| of class
271           |target_class|.
272
273        @param target_package: the name of test package to run.
274        @param target_plan: the name of the test plan to run.
275        @param target_class: the name of the class to be tested.
276        @param target_method: the name of the method to be tested.
277        @param needs_push_media: need to push test media streams.
278        @param max_retry: number of retry steps before reporting results.
279        @param timeout: time after which tradefed can be interrupted.
280        """
281        # Don't download media for tests that don't need it. b/29371037
282        # TODO(ihf): This can be removed once the control file generator is
283        # aware of this constraint.
284        if target_package is not None and target_package.startswith(
285                'android.mediastress'):
286            needs_push_media = True
287
288        # On dev and beta channels timeouts are sharp, lenient on stable.
289        self._timeout = timeout
290        if self._get_release_channel == 'stable':
291            self._timeout += 3600
292        # Retries depend on channel.
293        self._max_retry = (
294            max_retry if max_retry is not None else self._get_channel_retry())
295        session_id = 0
296
297        steps = -1  # For historic reasons the first iteration is not counted.
298        pushed_media = False
299        total_tests = 0
300        self.summary = ''
301        if target_package is not None:
302            test_name = 'package.%s' % target_package
303            test_command = self._tradefed_run_command(package=target_package)
304        elif target_plan is not None:
305            test_name = 'plan.%s' % target_plan
306            test_command = self._tradefed_run_command(plan=target_plan)
307        elif target_class is not None:
308            test_name = 'testcase.%s' % target_class
309            if target_method is not None:
310                test_name += '.' + target_method
311            test_command = self._tradefed_run_command(
312                test_class=target_class, test_method=target_method)
313        else:
314            test_command = self._tradefed_run_command()
315            test_name = 'all_CTS'
316
317        # Unconditionally run CTS package until we see some tests executed.
318        while steps < self._max_retry and total_tests == 0:
319            steps += 1
320            with self._login_chrome(dont_override_profile=pushed_media):
321                self._ready_arc()
322
323                # Only push media for tests that need it. b/29371037
324                if needs_push_media and not pushed_media:
325                    self._push_media(_CTS_URI)
326                    # copy_media.sh is not lazy, but we try to be.
327                    pushed_media = True
328
329                # Start each valid iteration with a clean repository. This
330                # allows us to track session_id blindly.
331                self._clean_repository()
332                if target_plan is not None:
333                    self._install_plan(target_plan)
334                logging.info('Running %s:', test_name)
335
336                # The list command is not required. It allows the reader to
337                # inspect the tradefed state when examining the autotest logs.
338                commands = [['list', 'results'], test_command]
339                counts = self._run_cts_tradefed(commands)
340                tests, passed, failed, notexecuted, waived = counts
341                logging.info('RESULT: tests=%d, passed=%d, failed=%d, '
342                        'notexecuted=%d, waived=%d', *counts)
343                self.summary += 'run(t=%d, p=%d, f=%d, ne=%d, w=%d)' % counts
344                if tests == 0 and target_package in self.notest_packages:
345                    logging.info('Package has no tests as expected.')
346                    return
347                if tests > 0 and target_package in self.notest_packages:
348                    # We expected no tests, but the new bundle drop must have
349                    # added some for us. Alert us to the situation.
350                    raise error.TestFail('Failed: Remove package %s from '
351                                         'notest_packages directory!' %
352                                         target_package)
353                if tests == 0 and target_package not in self.notest_packages:
354                    logging.error('Did not find any tests in package. Hoping '
355                                  'this is transient. Retry after reboot.')
356                # An internal self-check. We really should never hit this.
357                if tests != passed + failed + notexecuted:
358                    raise error.TestFail('Error: Test count inconsistent. %s' %
359                                        self.summary)
360                # Keep track of global counts as each continue/retry step below
361                # works on local failures.
362                total_tests = tests
363                total_passed = passed
364            # The DUT has rebooted at this point and is in a clean state.
365        if total_tests == 0:
366            raise error.TestFail('Error: Could not find any tests in package.')
367
368        # If the results were not completed or were failing then continue or
369        # retry them iteratively MAX_RETRY times.
370        while steps < self._max_retry and (notexecuted > 0 or failed > waived):
371            # First retry until there is no test is left that was not executed.
372            while notexecuted > 0 and steps < self._max_retry:
373                steps += 1
374                with self._login_chrome(dont_override_profile=pushed_media):
375                    self._ready_arc()
376                    logging.info('Continuing session %d:', session_id)
377                    # 'Continue' reports as passed all passing results in the
378                    # current session (including all tests passing before
379                    # continue). Hence first subtract the old count before
380                    # adding the new count. (Same for failed.)
381                    previously_passed = passed
382                    previously_failed = failed
383                    previously_notexecuted = notexecuted
384                    # TODO(ihf): For increased robustness pass in datetime_id of
385                    # session we are continuing.
386                    counts = self._tradefed_continue(session_id)
387                    tests, passed, failed, notexecuted, waived = counts
388                    # Unfortunately tradefed sometimes encounters an error
389                    # running the tests for instance timing out on downloading
390                    # the media files. Check for this condition and give it one
391                    # extra chance.
392                    if not (tests == previously_notexecuted and
393                            tests == passed + failed + notexecuted):
394                        logging.warning('Tradefed inconsistency - retrying.')
395                        counts = self._tradefed_continue(session_id)
396                        tests, passed, failed, notexecuted, waived = counts
397                    newly_passed = passed - previously_passed
398                    newly_failed = failed - previously_failed
399                    total_passed += newly_passed
400                    logging.info('RESULT: total_tests=%d, total_passed=%d, step'
401                            '(tests=%d, passed=%d, failed=%d, notexecuted=%d,'
402                            ' waived=%d)', total_tests, total_passed, tests,
403                            newly_passed, newly_failed, notexecuted, waived)
404                    self.summary += ' cont(t=%d, p=%d, f=%d, ne=%d, w=%d)' % (
405                            tests, newly_passed, newly_failed, notexecuted,
406                            waived)
407                    # An internal self-check. We really should never hit this.
408                    if not (tests == previously_notexecuted and
409                            tests == newly_passed + newly_failed + notexecuted):
410                        logging.warning('Test count inconsistent. %s',
411                                self.summary)
412                # The DUT has rebooted at this point and is in a clean state.
413
414            if notexecuted > 0:
415                # This likely means there were too many crashes/reboots to
416                # attempt running all tests. Don't attempt to retry as it is
417                # impossible to pass at this stage (and also inconsistent).
418                raise error.TestFail(
419                    'Failed: Ran out of steps with %d total '
420                    'passed and %d remaining not executed tests. %s' %
421                    (total_passed, notexecuted, self.summary))
422
423            # Managed to reduce notexecuted to zero. Now create a new test plan
424            # to rerun only the failures we did encounter.
425            if failed > waived:
426                with self._login_chrome(dont_override_profile=pushed_media):
427                    steps += 1
428                    self._ready_arc()
429                    logging.info('Retrying failures of %s with session_id %d:',
430                            test_name, session_id)
431                    previously_failed = failed
432                    session_id, counts = self._tradefed_retry(
433                            test_name, session_id)
434                    tests, passed, failed, notexecuted, waived = counts
435                    # Unfortunately tradefed sometimes encounters an error
436                    # running the tests for instance timing out on downloading
437                    # the media files. Check for this condition and give it one
438                    # extra chance.
439                    if not (tests == previously_failed and
440                            tests == passed + failed + notexecuted):
441                        logging.warning('Tradefed inconsistency - retrying.')
442                        session_id, counts = self._tradefed_retry(
443                                test_name, session_id)
444                        tests, passed, failed, notexecuted, waived = counts
445                    total_passed += passed
446                    logging.info('RESULT: total_tests=%d, total_passed=%d, step'
447                            '(tests=%d, passed=%d, failed=%d, notexecuted=%d,'
448                            ' waived=%d)', total_tests, total_passed, *counts)
449                    self.summary += (
450                            ' retry(t=%d, p=%d, f=%d, ne=%d, w=%d)' % counts)
451                    # An internal self-check. We really should never hit this.
452                    if not (previously_failed == tests and
453                            tests == passed + failed + notexecuted):
454                        logging.warning('Test count inconsistent. %s',
455                                self.summary)
456                # The DUT has rebooted at this point and is in a clean state.
457
458        # Final classification of test results.
459        if total_passed + waived == 0 or notexecuted > 0 or failed > waived:
460            raise error.TestFail(
461                'Failed: after %d retries giving up. '
462                'total_passed=%d, failed=%d, notexecuted=%d, waived=%d. %s' %
463                (steps, total_passed, failed, notexecuted, waived,
464                 self.summary))
465        if steps > 0:
466            # TODO(ihf): Make this error.TestPass('...') once available.
467            raise error.TestWarn(
468                'Passed: after %d retries passing %d tests, waived=%d. %s' %
469                (steps, total_passed, waived, self.summary))
470