• 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# likely hang unit the TIMEOUT hits and no RETRY steps will happen.
24_CTS_MAX_RETRY = {'dev': 5, 'beta': 5, 'stable': 5}
25# Maximum default time allowed for each individual CTS module.
26_CTS_TIMEOUT_SECONDS = 3600
27
28# Public download locations for android cts bundles.
29_DL_CTS = 'https://dl.google.com/dl/android/cts/'
30_CTS_URI = {
31    'arm': _DL_CTS + 'android-cts-7.1_r7-linux_x86-arm.zip',
32    'x86': _DL_CTS + 'android-cts-7.1_r7-linux_x86-x86.zip',
33    'media': _DL_CTS + 'android-cts-media-1.3.zip',
34}
35
36_SDK_TOOLS_DIR_N = 'gs://chromeos-arc-images/builds/git_nyc-mr1-arc-linux-static_sdk_tools/3544738'
37_ADB_DIR_N = 'gs://chromeos-arc-images/builds/git_nyc-mr1-arc-linux-cheets_arm-user/3544738'
38
39
40class cheets_CTS_N(tradefed_test.TradefedTest):
41    """Sets up tradefed to run CTS tests."""
42    version = 1
43
44    def initialize(self, host=None):
45        super(cheets_CTS_N, self).initialize(host=host, adb_dir=_ADB_DIR_N,
46                                             sdk_tools_dir=_SDK_TOOLS_DIR_N)
47
48    def setup(self, bundle=None, uri=None):
49        """Download and install a zipfile bundle from Google Storage.
50
51        @param bundle: bundle name, which needs to be key of the _CTS_URI
52                       dictionary. Can be 'arm', 'x86' and undefined.
53        @param uri: URI of CTS bundle. Required if |abi| is undefined.
54        """
55        if bundle in _CTS_URI:
56            self._android_cts = self._install_bundle(_CTS_URI[bundle])
57        else:
58            self._android_cts = self._install_bundle(uri)
59
60        self._cts_tradefed = os.path.join(self._android_cts, 'android-cts',
61                                          'tools', 'cts-tradefed')
62        logging.info('CTS-tradefed path: %s', self._cts_tradefed)
63
64        # Load waivers and manual tests so TF doesn't re-run them.
65        self.waivers_and_manual_tests = self._get_expected_failures(
66            'expectations')
67        # Load modules with no tests.
68        self.notest_modules = self._get_expected_failures('notest_modules')
69
70    def _clean_repository(self):
71        """Ensures all old logs, results and plans are deleted.
72
73        This function should be called at the start of each autotest iteration.
74        """
75        logging.info('Cleaning up repository.')
76        repository = os.path.join(self._android_cts, 'android-cts')
77        for directory in ['logs', 'subplans', 'results']:
78            path = os.path.join(repository, directory)
79            if os.path.exists(path):
80                shutil.rmtree(path)
81            self._safe_makedirs(path)
82
83    def _install_plan(self, plan):
84        logging.info('Install plan: %s', plan)
85        plans_dir = os.path.join(self._android_cts, 'android-cts', 'repository',
86                                 'plans')
87        src_plan_file = os.path.join(self.bindir, 'plans', '%s.xml' % plan)
88        shutil.copy(src_plan_file, plans_dir)
89
90    def _tradefed_run_command(self,
91                              module=None,
92                              plan=None,
93                              session_id=None,
94                              test_class=None,
95                              test_method=None):
96        """Builds the CTS tradefed 'run' command line.
97
98        There are five different usages:
99
100        1. Test a module: assign the module name via |module|.
101        2. Test a plan: assign the plan name via |plan|.
102        3. Continue a session: assign the session ID via |session_id|.
103        4. Run all test cases of a class: assign the class name via
104           |test_class|.
105        5. Run a specific test case: assign the class name and method name in
106           |test_class| and |test_method|.
107
108        @param module: the name of test module to be run.
109        @param plan: name of the plan to be run.
110        @param session_id: tradefed session id to continue.
111        @param test_class: the name of the class of which all test cases will
112                           be run.
113        @param test_name: the name of the method of |test_class| to be run.
114                          Must be used with |test_class|.
115        @return: list of command tokens for the 'run' command.
116        """
117        if module is not None:
118            # Run a particular module (used to be called package in M).
119            cmd = ['run', 'commandAndExit', 'cts', '--module', module]
120        elif plan is not None and session_id is not None:
121            # In 7.1 R2 we can only retry session_id with the original plan.
122            cmd = ['run', 'commandAndExit', 'cts', '--plan', plan,
123                   '--retry', '%d' % session_id]
124        elif plan is not None:
125            # TODO(ihf): This needs testing to support media team.
126            cmd = ['run', 'commandAndExit', 'cts', '--plan', plan]
127        elif test_class is not None:
128            # TODO(ihf): This needs testing to support media team.
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']
135        # We handle media download ourselves in the lab, as lazy as possible.
136        cmd.append('--precondition-arg')
137        cmd.append('skip-media-download')
138        # If we are running outside of the lab we can collect more data.
139        if not utils.is_in_container():
140            logging.info('Running outside of lab, adding extra debug options.')
141            cmd.append('--log-level-display=DEBUG')
142            cmd.append('--screenshot-on-failure')
143            # TODO(ihf): Add log collection once b/28333587 fixed.
144            #cmd.append('--collect-deqp-logs')
145        # TODO(ihf): Add tradefed_test.adb_keepalive() and remove
146        # --disable-reboot. This might be more efficient.
147        # At early stage, cts-tradefed tries to reboot the device by
148        # "adb reboot" command. In a real Android device case, when the
149        # rebooting is completed, adb connection is re-established
150        # automatically, and cts-tradefed expects that behavior.
151        # However, in ARC, it doesn't work, so the whole test process
152        # is just stuck. Here, disable the feature.
153        cmd.append('--disable-reboot')
154        # Create a logcat file for each individual failure.
155        cmd.append('--logcat-on-failure')
156        return cmd
157
158    def _run_cts_tradefed(self,
159                          commands,
160                          datetime_id=None,
161                          collect_results=True):
162        """Runs tradefed, collects logs and returns the result counts.
163
164        Assumes that only last entry of |commands| actually runs tests and has
165        interesting output (results, logs) for collection. Ignores all other
166        commands for this purpose.
167
168        @param commands: List of lists of command tokens.
169        @param datetime_id: For 'continue' datetime of previous run is known.
170                            Knowing it makes collecting logs more robust.
171        @param collect: Skip result collection if False.
172        @return: tuple of (tests, pass, fail, notexecuted) counts.
173        """
174        for command in commands:
175            # Assume only last command actually runs tests and has interesting
176            # output (results, logs) for collection.
177            logging.info('RUN: ./cts-tradefed %s', ' '.join(command))
178            output = self._run(
179                self._cts_tradefed,
180                args=tuple(command),
181                timeout=self._timeout,
182                verbose=True,
183                ignore_status=False,
184                # Make sure to tee tradefed stdout/stderr to autotest logs
185                # continuously during the test run.
186                stdout_tee=utils.TEE_TO_LOGS,
187                stderr_tee=utils.TEE_TO_LOGS)
188            logging.info('END: ./cts-tradefed %s\n', ' '.join(command))
189        if not collect_results:
190            return None
191        result_destination = os.path.join(self.resultsdir, 'android-cts')
192        # Gather the global log first. Datetime parsing below can abort the test
193        # if tradefed startup had failed. Even then the global log is useful.
194        self._collect_tradefed_global_log(output, result_destination)
195        if not datetime_id:
196            # Parse stdout to obtain datetime of the session. This is needed to
197            # locate result xml files and logs.
198            datetime_id = self._parse_tradefed_datetime_v2(output, self.summary)
199        # Collect tradefed logs for autotest.
200        tradefed = os.path.join(self._android_cts, 'android-cts')
201        self._collect_logs(tradefed, datetime_id, result_destination)
202        return self._parse_result_v2(output,
203                                     waivers=self.waivers_and_manual_tests)
204
205    def _tradefed_retry(self, test_name, session_id):
206        """Retries failing tests in session.
207
208        It is assumed that there are no notexecuted tests of session_id,
209        otherwise some tests will be missed and never run.
210
211        @param test_name: the name of test to be retried.
212        @param session_id: tradefed session id to retry.
213        @param result_type: [N only] either 'failed' or 'not_executed'
214        @return: tuple of (new session_id, tests, pass, fail, notexecuted).
215        """
216        # Creating new test plan for retry.
217        derivedplan = 'retry.%s.%s' % (test_name, session_id)
218        logging.info('Retrying failures using derived plan %s.', derivedplan)
219        # The list commands are not required. It allows the reader to inspect
220        # the tradefed state when examining the autotest logs.
221        commands = [
222                ['add', 'subplan', '--name', derivedplan,
223                 '--session', '%d' % session_id,
224                 '--result-type', 'failed', '--result-type', 'not_executed'],
225                ['list', 'subplans'],
226                ['list', 'results'],
227                self._tradefed_run_command(plan=derivedplan,
228                                           session_id=session_id)]
229        # TODO(ihf): Consider if diffing/parsing output of "list results" for
230        # new session_id might be more reliable. For now just assume simple
231        # increment. This works if only one tradefed instance is active and
232        # only a single run command is executing at any moment.
233        return session_id + 1, self._run_cts_tradefed(commands)
234
235    def _get_release_channel(self):
236        """Returns the DUT channel of the image ('dev', 'beta', 'stable')."""
237        # TODO(ihf): check CHROMEOS_RELEASE_DESCRIPTION and return channel.
238        return 'dev'
239
240    def _get_channel_retry(self):
241        """Returns the maximum number of retries for DUT image channel."""
242        channel = self._get_release_channel()
243        if channel in _CTS_MAX_RETRY:
244            return _CTS_MAX_RETRY[channel]
245        retry = _CTS_MAX_RETRY['dev']
246        logging.warning('Could not establish channel. Using retry=%d.', retry)
247        return retry
248
249    def _consistent(self, tests, passed, failed, notexecuted):
250        """Verifies that the given counts are plausible.
251
252        Used for finding bad logfile parsing using accounting identities.
253
254        TODO(ihf): change to tests != passed + failed + notexecuted
255        only once b/35530394 fixed."""
256        return ((tests == passed + failed) or
257                (tests == passed + failed + notexecuted))
258
259    def _run_precondition_scripts(self, host, commands):
260        for command in commands:
261            logging.info('RUN: %s\n', command)
262            output = host.run(command, ignore_status=True)
263            logging.info('END: %s\n', output)
264
265
266    def run_once(self,
267                 target_module=None,
268                 target_plan=None,
269                 target_class=None,
270                 target_method=None,
271                 needs_push_media=False,
272                 max_retry=None,
273                 cts_tradefed_args=None,
274                 pre_condition_commands=[],
275                 warn_on_test_retry=True,
276                 timeout=_CTS_TIMEOUT_SECONDS):
277        """Runs the specified CTS once, but with several retries.
278
279        There are four usages:
280        1. Test the whole module named |target_module|.
281        2. Test with a plan named |target_plan|.
282        3. Run all the test cases of class named |target_class|.
283        4. Run a specific test method named |target_method| of class
284           |target_class|.
285        5. Run an arbitrary tradefed command.
286
287        @param target_module: the name of test module to run.
288        @param target_plan: the name of the test plan to run.
289        @param target_class: the name of the class to be tested.
290        @param target_method: the name of the method to be tested.
291        @param needs_push_media: need to push test media streams.
292        @param max_retry: number of retry steps before reporting results.
293        @param timeout: time after which tradefed can be interrupted.
294        @param pre_condition_command: a list of scripts to be run on the
295        dut before the test is run, the scripts must already be installed.
296        @param warn_on_test_retry: False if you want to skip warning message
297        about tradefed retries.
298        @param cts_tradefed_args: a list of args to pass to tradefed.
299        """
300
301        # On dev and beta channels timeouts are sharp, lenient on stable.
302        self._timeout = timeout
303        if self._get_release_channel == 'stable':
304            self._timeout += 3600
305        # Retries depend on channel.
306        self._max_retry = (
307            max_retry if max_retry is not None else self._get_channel_retry())
308        logging.info('Maximum number of retry steps %d.', self._max_retry)
309        session_id = 0
310
311        self.result_history = {}
312        steps = -1  # For historic reasons the first iteration is not counted.
313        pushed_media = False
314        total_tests = 0
315        total_passed = 0
316        self.summary = ''
317        if target_module is not None:
318            test_name = 'module.%s' % target_module
319            test_command = self._tradefed_run_command(
320                module=target_module, session_id=session_id)
321        elif target_plan is not None:
322            test_name = 'plan.%s' % target_plan
323            test_command = self._tradefed_run_command(
324                plan=target_plan, session_id=session_id)
325        elif target_class is not None:
326            test_name = 'testcase.%s' % target_class
327            if target_method is not None:
328                test_name += '.' + target_method
329            test_command = self._tradefed_run_command(
330                test_class=target_class,
331                test_method=target_method,
332                session_id=session_id)
333        elif cts_tradefed_args is not None:
334            test_name = 'run tradefed %s' % ' '.join(cts_tradefed_args)
335            test_command = cts_tradefed_args
336
337        else:
338            test_command = self._tradefed_run_command()
339            test_name = 'all_CTS'
340
341        # Unconditionally run CTS module until we see some tests executed.
342        while total_tests == 0 and steps < self._max_retry:
343            steps += 1
344            with self._login_chrome(dont_override_profile=pushed_media):
345                self._ready_arc()
346                self._run_precondition_scripts(
347                    self._host,
348                    pre_condition_commands)
349
350                # Only push media for tests that need it. b/29371037
351                if needs_push_media and not pushed_media:
352                    self._push_media(_CTS_URI)
353                    # copy_media.sh is not lazy, but we try to be.
354                    pushed_media = True
355
356                # Start each valid iteration with a clean repository. This
357                # allows us to track session_id blindly.
358                self._clean_repository()
359                if target_plan is not None:
360                    self._install_plan(target_plan)
361                logging.info('Running %s:', test_name)
362
363                # The list command is not required. It allows the reader to
364                # inspect the tradefed state when examining the autotest logs.
365                commands = [['list', 'results'], test_command]
366                counts = self._run_cts_tradefed(commands)
367                tests, passed, failed, notexecuted, waived = counts
368                self.result_history[steps] = counts
369                msg = 'run(t=%d, p=%d, f=%d, ne=%d, w=%d)' % counts
370                logging.info('RESULT: %s', msg)
371                self.summary += msg
372                if tests == 0 and target_module in self.notest_modules:
373                    logging.info('Package has no tests as expected.')
374                    return
375                if tests > 0 and target_module in self.notest_modules:
376                    # We expected no tests, but the new bundle drop must have
377                    # added some for us. Alert us to the situation.
378                    raise error.TestFail('Failed: Remove module %s from '
379                                         'notest_modules directory!' %
380                                         target_module)
381                if tests == 0 and target_module not in self.notest_modules:
382                    logging.error('Did not find any tests in module. Hoping '
383                                  'this is transient. Retry after reboot.')
384                if not self._consistent(tests, passed, failed, notexecuted):
385                    # Try to figure out what happened. Example: b/35605415.
386                    self._run_cts_tradefed([['list', 'results']],
387                                           collect_results=False)
388                    logging.warning('Test count inconsistent. %s',
389                                    self.summary)
390                # Keep track of global count, we can't trust continue/retry.
391                if total_tests == 0:
392                    total_tests = tests
393                total_passed += passed
394            # The DUT has rebooted at this point and is in a clean state.
395        if total_tests == 0:
396            raise error.TestFail('Error: Could not find any tests in module.')
397
398        retry_inconsistency_error = None
399        # If the results were not completed or were failing then continue or
400        # retry them iteratively MAX_RETRY times.
401        while steps < self._max_retry and failed > waived:
402            steps += 1
403            with self._login_chrome(dont_override_profile=pushed_media):
404                self._ready_arc()
405                self._run_precondition_scripts(
406                    self._host,
407                    pre_condition_commands)
408                logging.info('Retrying failures of %s with session_id %d:',
409                             test_name, session_id)
410                expected_tests = failed + notexecuted
411                session_id, counts = self._tradefed_retry(test_name,
412                                                          session_id)
413                tests, passed, failed, notexecuted, waived = counts
414                self.result_history[steps] = counts
415                # Consistency check, did we really run as many as we thought
416                # initially?
417                if expected_tests != tests:
418                    msg = ('Retry inconsistency - '
419                           'initially saw %d failed+notexecuted, ran %d tests. '
420                           'passed=%d, failed=%d, notexecuted=%d, waived=%d.' %
421                           (expected_tests, tests, passed, failed, notexecuted,
422                            waived))
423                    logging.warning(msg)
424                    if expected_tests > tests:
425                        # See b/36523200#comment8. Due to the existence of the
426                        # multiple tests having the same ID, more cases may be
427                        # run than previous fail count. As a workaround, making
428                        # it an error only when the tests run were less than
429                        # expected.
430                        # TODO(kinaba): Find a way to handle this dup.
431                        retry_inconsistency_error = msg
432                if not self._consistent(tests, passed, failed, notexecuted):
433                    logging.warning('Tradefed inconsistency - retrying.')
434                    session_id, counts = self._tradefed_retry(test_name,
435                                                              session_id)
436                    tests, passed, failed, notexecuted, waived = counts
437                    self.result_history[steps] = counts
438                msg = 'retry(t=%d, p=%d, f=%d, ne=%d, w=%d)' % counts
439                logging.info('RESULT: %s', msg)
440                self.summary += ' ' + msg
441                if not self._consistent(tests, passed, failed, notexecuted):
442                    logging.warning('Test count inconsistent. %s', self.summary)
443                total_passed += passed
444                if tests > expected_tests:
445                    total_tests += tests - expected_tests
446            # The DUT has rebooted at this point and is in a clean state.
447
448        # Final classification of test results.
449        if total_passed + waived == 0 or failed > waived:
450            raise error.TestFail(
451                'Failed: after %d retries giving up. '
452                'passed=%d, failed=%d, notexecuted=%d, waived=%d. %s' %
453                (steps, total_passed, failed, notexecuted, waived,
454                 self.summary))
455        if not self._consistent(total_tests, total_passed, failed, notexecuted):
456            raise error.TestFail('Error: Test count inconsistent. %s' %
457                                 self.summary)
458        if retry_inconsistency_error:
459            raise error.TestFail('Error: %s %s' % (retry_inconsistency_error,
460                                                   self.summary))
461        if steps > 0 and warn_on_test_retry:
462            # TODO(ihf): Make this error.TestPass('...') once available.
463            raise error.TestWarn(
464                'Passed: after %d retries passing %d tests, waived=%d. %s' %
465                (steps, total_passed, waived, self.summary))
466