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 variables _host and _install_paths are 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 # 15 # _parse_result() and _dir_size() don't access self and could be functions. 16 # pylint: disable=no-self-use 17 18 import errno 19 import glob 20 import hashlib 21 import logging 22 import os 23 import pipes 24 import re 25 import shutil 26 import stat 27 import tempfile 28 import urlparse 29 30 from autotest_lib.client.bin import utils as client_utils 31 from autotest_lib.client.common_lib import error 32 from autotest_lib.client.common_lib.cros import dev_server 33 from autotest_lib.server import test 34 from autotest_lib.server import utils 35 from autotest_lib.server.cros import cts_expected_failure_parser 36 from autotest_lib.server.cros import tradefed_chromelogin as login 37 from autotest_lib.server.cros import tradefed_constants as constants 38 from autotest_lib.server.cros import tradefed_utils 39 40 # TODO(ihf): If akeshet doesn't fix crbug.com/691046 delete metrics again. 41 try: 42 from chromite.lib import metrics 43 except ImportError: 44 metrics = utils.metrics_mock 45 46 # For convenience, add to our scope. 47 parse_tradefed_result = tradefed_utils.parse_tradefed_result 48 adb_keepalive = tradefed_utils.adb_keepalive 49 50 51 class TradefedTest(test.test): 52 """Base class to prepare DUT to run tests via tradefed.""" 53 version = 1 54 55 # Default max_retry based on board and channel. 56 _BOARD_RETRY = {} 57 _CHANNEL_RETRY = {'dev': 5} 58 59 def _log_java_version(self): 60 """Quick sanity and spew of java version installed on the server.""" 61 utils.run( 62 'java', 63 args=('-version',), 64 ignore_status=False, 65 verbose=True, 66 stdout_tee=utils.TEE_TO_LOGS, 67 stderr_tee=utils.TEE_TO_LOGS) 68 69 def initialize(self, 70 bundle=None, 71 uri=None, 72 host=None, 73 max_retry=None, 74 retry_manual_tests=False, 75 warn_on_test_retry=True): 76 """Sets up the tools and binary bundles for the test.""" 77 logging.info('Hostname: %s', host.hostname) 78 self._host = host 79 self._max_retry = self._get_max_retry(max_retry, self._host) 80 self._install_paths = [] 81 self._warn_on_test_retry = warn_on_test_retry 82 # Tests in the lab run within individual lxc container instances. 83 if utils.is_in_container(): 84 cache_root = constants.TRADEFED_CACHE_CONTAINER 85 else: 86 cache_root = constants.TRADEFED_CACHE_LOCAL 87 88 # TODO(ihf): reevaluate this again when we run out of memory. We could 89 # for example use 32 bit java on the first run but not during retries. 90 # b/62895114. If select_32bit_java gets deleted for good also remove it 91 # from the base image. 92 # Try to save server memory (crbug.com/717413). 93 # select_32bit_java() 94 95 # The content of the cache survives across jobs. 96 self._safe_makedirs(cache_root) 97 self._tradefed_cache = os.path.join(cache_root, 'cache') 98 self._tradefed_cache_lock = os.path.join(cache_root, 'lock') 99 self._tradefed_cache_dirty = os.path.join(cache_root, 'dirty') 100 # The content of the install location does not survive across jobs and 101 # is isolated (by using a unique path)_against other autotest instances. 102 # This is not needed for the lab, but if somebody wants to run multiple 103 # TradedefTest instance. 104 self._tradefed_install = tempfile.mkdtemp( 105 prefix=constants.TRADEFED_PREFIX) 106 # Under lxc the cache is shared between multiple autotest/tradefed 107 # instances. We need to synchronize access to it. All binaries are 108 # installed through the (shared) cache into the local (unshared) 109 # lxc/autotest instance storage. 110 # If clearing the cache it must happen before all downloads. 111 self._clean_download_cache_if_needed() 112 # Set permissions (rwxr-xr-x) to the executable binaries. 113 permission = ( 114 stat.S_IRWXU | stat.S_IRGRP | stat.S_IXGRP | stat.S_IROTH 115 | stat.S_IXOTH) 116 self._install_files(constants.ADB_DIR, constants.ADB_FILES, permission) 117 self._install_files(constants.SDK_TOOLS_DIR, constants.SDK_TOOLS_FILES, 118 permission) 119 120 # Install the tradefed bundle. 121 bundle_install_path = self._install_bundle( 122 uri or self._get_default_bundle_url(bundle)) 123 self._repository = os.path.join(bundle_install_path, 124 self._get_tradefed_base_dir()) 125 126 # Load expected test failures to exclude them from re-runs. 127 self._waivers = self._get_expected_failures('expectations') 128 if not retry_manual_tests: 129 self._waivers.update(self._get_expected_failures('manual_tests')) 130 131 # Load modules with no tests. 132 self._notest_modules = self._get_expected_failures('notest_modules') 133 134 def cleanup(self): 135 """Cleans up any dirtied state.""" 136 # Kill any lingering adb servers. 137 self._run('adb', verbose=True, args=('kill-server',)) 138 logging.info('Cleaning up %s.', self._tradefed_install) 139 shutil.rmtree(self._tradefed_install) 140 141 def _login_chrome(self, **cts_helper_kwargs): 142 """Returns Chrome log-in context manager. 143 144 Please see also cheets_StartAndroid for details about how this works. 145 """ 146 return login.ChromeLogin(self._host, cts_helper_kwargs) 147 148 def _get_adb_target(self): 149 return '{}:{}'.format(self._host.hostname, self._host.port) 150 151 def _try_adb_connect(self): 152 """Attempts to connect to adb on the DUT. 153 154 @return boolean indicating if adb connected successfully. 155 """ 156 # This may fail return failure due to a race condition in adb connect 157 # (b/29370989). If adb is already connected, this command will 158 # immediately return success. 159 hostport = self._get_adb_target() 160 result = self._run( 161 'adb', args=('connect', hostport), verbose=True, ignore_status=True) 162 logging.info('adb connect {}:\n{}'.format(hostport, result.stdout)) 163 if result.exit_status != 0: 164 return False 165 166 result = self._run('adb', args=('devices',)) 167 logging.info('adb devices:\n' + result.stdout) 168 if not re.search(r'{}\s+(device|unauthorized)'.format( 169 re.escape(hostport)), result.stdout): 170 return False 171 172 # Actually test the connection with an adb command as there can be 173 # a race between detecting the connected device and actually being 174 # able to run a commmand with authenticated adb. 175 result = self._run('adb', args=('shell', 'exit'), ignore_status=True) 176 return result.exit_status == 0 177 178 def _android_shell(self, command): 179 """Run a command remotely on the device in an android shell 180 181 This function is strictly for internal use only, as commands do not run 182 in a fully consistent Android environment. Prefer adb shell instead. 183 """ 184 self._host.run('android-sh -c ' + pipes.quote(command)) 185 186 def _write_android_file(self, filename, data): 187 """Writes a file to a location relative to the android container. 188 189 This is an internal function used to bootstrap adb. 190 Tests should use adb push to write files. 191 """ 192 android_cmd = 'echo %s > %s' % (pipes.quote(data), 193 pipes.quote(filename)) 194 self._android_shell(android_cmd) 195 196 def _connect_adb(self): 197 """Sets up ADB connection to the ARC container.""" 198 logging.info('Setting up adb connection.') 199 # Generate and push keys for adb. 200 # TODO(elijahtaylor): Extract this code to arc_common and de-duplicate 201 # code in arc.py on the client side tests. 202 key_path = os.path.join(self.tmpdir, 'test_key') 203 pubkey_path = key_path + '.pub' 204 self._run('adb', verbose=True, args=('keygen', pipes.quote(key_path))) 205 with open(pubkey_path, 'r') as f: 206 self._write_android_file(constants.ANDROID_ADB_KEYS_PATH, f.read()) 207 self._android_shell( 208 'restorecon ' + pipes.quote(constants.ANDROID_ADB_KEYS_PATH)) 209 os.environ['ADB_VENDOR_KEYS'] = key_path 210 211 # Kill existing adb server to ensure that the env var is picked up. 212 self._run('adb', verbose=True, args=('kill-server',)) 213 214 # This starts adbd. 215 self._android_shell('setprop sys.usb.config mtp,adb') 216 217 # Also let it be automatically started upon reboot. 218 self._android_shell('setprop persist.sys.usb.config mtp,adb') 219 220 # adbd may take some time to come up. Repeatedly try to connect to adb. 221 utils.poll_for_condition( 222 lambda: self._try_adb_connect(), 223 exception=error.TestFail('Error: Failed to set up adb connection'), 224 timeout=constants.ADB_READY_TIMEOUT_SECONDS, 225 sleep_interval=constants.ADB_POLLING_INTERVAL_SECONDS) 226 227 logging.info('Successfully setup adb connection.') 228 229 def _wait_for_arc_boot(self): 230 """Wait until ARC is fully booted. 231 232 Tests for the presence of the intent helper app to determine whether ARC 233 has finished booting. 234 """ 235 236 def _intent_helper_running(): 237 result = self._run( 238 'adb', 239 args=('shell', 'pgrep', '-f', 'org.chromium.arc.intent_helper'), 240 ignore_status=True) 241 return bool(result.stdout) 242 243 utils.poll_for_condition( 244 _intent_helper_running, 245 exception=error.TestFail( 246 'Error: Timed out waiting for intent helper.'), 247 timeout=constants.ARC_READY_TIMEOUT_SECONDS, 248 sleep_interval=constants.ARC_POLLING_INTERVAL_SECONDS) 249 250 def _disable_adb_install_dialog(self): 251 """Disables a dialog shown on adb install execution. 252 253 By default, on adb install execution, "Allow Google to regularly check 254 device activity ... " dialog is shown. It requires manual user action 255 so that tests are blocked at the point. 256 This method disables it. 257 """ 258 logging.info('Disabling the adb install dialog.') 259 result = self._run( 260 'adb', 261 verbose=True, 262 args=('shell', 'settings', 'put', 'global', 263 'verifier_verify_adb_installs', '0')) 264 logging.info('Disable adb dialog: %s', result.stdout) 265 266 def _ready_arc(self): 267 """Ready ARC and adb for running tests via tradefed.""" 268 self._connect_adb() 269 self._disable_adb_install_dialog() 270 self._wait_for_arc_boot() 271 272 def _safe_makedirs(self, path): 273 """Creates a directory at |path| and its ancestors. 274 275 Unlike os.makedirs(), ignore errors even if directories exist. 276 """ 277 try: 278 os.makedirs(path) 279 except OSError as e: 280 if not (e.errno == errno.EEXIST and os.path.isdir(path)): 281 raise 282 283 def _unzip(self, filename): 284 """Unzip the file. 285 286 The destination directory name will be the stem of filename. 287 E.g., _unzip('foo/bar/baz.zip') will create directory at 288 'foo/bar/baz', and then will inflate zip's content under the directory. 289 If here is already a directory at the stem, that directory will be used. 290 291 @param filename: Path to the zip archive. 292 @return Path to the inflated directory. 293 """ 294 destination = os.path.splitext(filename)[0] 295 if os.path.isdir(destination): 296 logging.info('Skipping unzip %s, reusing content of %s', filename, 297 destination) 298 return destination 299 tmp = tempfile.mkdtemp(dir=os.path.dirname(filename)) 300 logging.info('Begin unzip %s', filename) 301 try: 302 utils.run('unzip', args=('-d', tmp, filename)) 303 except: 304 logging.error('Failed unzip, cleaning up.') 305 # Clean up just created files. 306 shutil.rmtree(tmp, ignore_errors=True) 307 raise 308 logging.info('End unzip %s', filename) 309 try: 310 os.renames(tmp, destination) 311 except: 312 logging.error('Failed rename, cleaning up.') 313 shutil.rmtree(destination, ignore_errors=True) 314 shutil.rmtree(tmp, ignore_errors=True) 315 raise 316 return destination 317 318 def _dir_size(self, directory): 319 """Compute recursive size in bytes of directory.""" 320 size = 0 321 for root, _, files in os.walk(directory): 322 for name in files: 323 try: 324 size += os.path.getsize(os.path.join(root, name)) 325 except OSError: 326 logging.error('Inaccessible path (crbug/793696): %s/%s', 327 root, name) 328 return size 329 330 def _invalidate_download_cache(self): 331 """Marks the download cache for deferred deletion. 332 333 Used to make cache file operations atomic across failures and reboots. 334 The caller is responsible to hold the lock to the cache. 335 """ 336 if not os.path.exists(self._tradefed_cache_dirty): 337 os.mkdir(self._tradefed_cache_dirty) 338 339 def _validate_download_cache(self): 340 """Validates and unmarks the download cache from deletion. 341 342 Used to make cache file operations atomic across failures and reboots. 343 The caller is responsible to hold the lock to the cache. 344 """ 345 shutil.rmtree(self._tradefed_cache_dirty, ignore_errors=True) 346 347 def _clean_download_cache_if_needed(self, force=False): 348 """Invalidates cache to prevent it from growing too large.""" 349 # If the cache is large enough to hold a working set, we can simply 350 # delete everything without thrashing. 351 # TODO(ihf): Investigate strategies like LRU. 352 clean = force 353 with tradefed_utils.lock(self._tradefed_cache_lock): 354 size = self._dir_size(self._tradefed_cache) 355 if size > constants.TRADEFED_CACHE_MAX_SIZE: 356 logging.info( 357 'Current cache size=%d got too large. Clearing %s.', size, 358 self._tradefed_cache) 359 clean = True 360 else: 361 logging.info('Current cache size=%d of %s.', size, 362 self._tradefed_cache) 363 if os.path.exists(self._tradefed_cache_dirty): 364 logging.info('Found dirty cache.') 365 clean = True 366 if clean: 367 logging.warning('Cleaning download cache.') 368 shutil.rmtree(self._tradefed_cache, ignore_errors=True) 369 self._safe_makedirs(self._tradefed_cache) 370 shutil.rmtree(self._tradefed_cache_dirty, ignore_errors=True) 371 372 def _download_to_cache(self, uri): 373 """Downloads the uri from the storage server. 374 375 It always checks the cache for available binaries first and skips 376 download if binaries are already in cache. 377 378 The caller of this function is responsible for holding the cache lock. 379 380 @param uri: The Google Storage or dl.google.com uri. 381 @return Path to the downloaded object, name. 382 """ 383 # Split uri into 3 pieces for use by gsutil and also by wget. 384 parsed = urlparse.urlparse(uri) 385 filename = os.path.basename(parsed.path) 386 # We are hashing the uri instead of the binary. This is acceptable, as 387 # the uris are supposed to contain version information and an object is 388 # not supposed to be changed once created. 389 output_dir = os.path.join(self._tradefed_cache, 390 hashlib.md5(uri).hexdigest()) 391 output = os.path.join(output_dir, filename) 392 # Check for existence of cache entry. We check for directory existence 393 # instead of file existence, so that _install_bundle can delete original 394 # zip files to save disk space. 395 if os.path.exists(output_dir): 396 # TODO(crbug.com/800657): Mitigation for the invalid state. Normally 397 # this should not happen, but when a lock is force borken due to 398 # high IO load, multiple processes may enter the critical section 399 # and leave a bad state permanently. 400 if os.listdir(output_dir): 401 logging.info('Skipping download of %s, reusing content of %s.', 402 uri, output_dir) 403 return output 404 logging.error('Empty cache entry detected %s', output_dir) 405 406 self._safe_makedirs(output_dir) 407 if parsed.scheme not in ['gs', 'http', 'https']: 408 raise error.TestFail( 409 'Error: Unknown download scheme %s' % parsed.scheme) 410 if parsed.scheme in ['http', 'https']: 411 logging.info('Using wget to download %s to %s.', uri, output_dir) 412 # We are downloading 1 file at a time, hence using -O over -P. 413 utils.run( 414 'wget', 415 args=('--report-speed=bits', '-O', output, uri), 416 verbose=True) 417 return output 418 419 if not client_utils.is_moblab(): 420 # If the machine can access to the storage server directly, 421 # defer to "gsutil" for downloading. 422 logging.info('Host %s not in lab. Downloading %s directly to %s.', 423 self._host.hostname, uri, output) 424 # b/17445576: gsutil rsync of individual files is not implemented. 425 utils.run('gsutil', args=('cp', uri, output), verbose=True) 426 return output 427 428 # We are in the moblab. Because the machine cannot access the storage 429 # server directly, use dev server to proxy. 430 logging.info('Host %s is in lab. Downloading %s by staging to %s.', 431 self._host.hostname, uri, output) 432 433 dirname = os.path.dirname(parsed.path) 434 archive_url = '%s://%s%s' % (parsed.scheme, parsed.netloc, dirname) 435 436 # First, request the devserver to download files into the lab network. 437 # TODO(ihf): Switch stage_artifacts to honor rsync. Then we don't have 438 # to shuffle files inside of tarballs. 439 info = self._host.host_info_store.get() 440 ds = dev_server.ImageServer.resolve(info.build) 441 ds.stage_artifacts( 442 info.build, files=[filename], archive_url=archive_url) 443 444 # Then download files from the dev server. 445 # TODO(ihf): use rsync instead of wget. Are there 3 machines involved? 446 # Itself, dev_server plus DUT? Or is there just no rsync in moblab? 447 ds_src = '/'.join([ds.url(), 'static', dirname, filename]) 448 logging.info('dev_server URL: %s', ds_src) 449 # Calls into DUT to pull uri from dev_server. 450 utils.run( 451 'wget', 452 args=('--report-speed=bits', '-O', output, ds_src), 453 verbose=True) 454 return output 455 456 def _instance_copyfile(self, cache_path): 457 """Makes a copy of a file from the (shared) cache to a wholy owned 458 local instance. Also copies one level of cache directoy (MD5 named). 459 """ 460 filename = os.path.basename(cache_path) 461 dirname = os.path.basename(os.path.dirname(cache_path)) 462 instance_dir = os.path.join(self._tradefed_install, dirname) 463 # Make sure destination directory is named the same. 464 self._safe_makedirs(instance_dir) 465 instance_path = os.path.join(instance_dir, filename) 466 shutil.copyfile(cache_path, instance_path) 467 return instance_path 468 469 def _instance_copytree(self, cache_path): 470 """Makes a copy of a directory from the (shared and writable) cache to 471 a wholy owned local instance. 472 473 TODO(ihf): Consider using cp -al to only copy links. Not sure if this 474 is really a benefit across the container boundary, but it is risky due 475 to the possibility of corrupting the original files by an lxc instance. 476 """ 477 # We keep the top 2 names from the cache_path = .../dir1/dir2. 478 dir2 = os.path.basename(cache_path) 479 dir1 = os.path.basename(os.path.dirname(cache_path)) 480 instance_path = os.path.join(self._tradefed_install, dir1, dir2) 481 logging.info('Copying %s to instance %s', cache_path, instance_path) 482 shutil.copytree(cache_path, instance_path) 483 return instance_path 484 485 def _install_bundle(self, gs_uri): 486 """Downloads a zip file, installs it and returns the local path.""" 487 if not gs_uri.endswith('.zip'): 488 raise error.TestFail('Error: Not a .zip file %s.', gs_uri) 489 # Atomic write through of file. 490 with tradefed_utils.lock(self._tradefed_cache_lock): 491 # Atomic operations. 492 self._invalidate_download_cache() 493 # Download is lazy (cache_path may not actually exist if 494 # cache_unzipped does). 495 cache_path = self._download_to_cache(gs_uri) 496 # Unzip is lazy as well (but cache_unzipped guaranteed to 497 # exist). 498 cache_unzipped = self._unzip(cache_path) 499 # To save space we delete the original zip file. This works as 500 # _download only checks existence of the cache directory for 501 # lazily skipping download, and unzip itself will bail if the 502 # unzipped destination exists. Hence we don't need the original 503 # anymore. 504 if os.path.exists(cache_path): 505 logging.info('Deleting original %s', cache_path) 506 os.remove(cache_path) 507 # Erase dirty marker from disk. 508 self._validate_download_cache() 509 # We always copy files to give tradefed a clean copy of the 510 # bundle. 511 unzipped_local = self._instance_copytree(cache_unzipped) 512 self._abi = 'x86' if 'x86-x86' in gs_uri else 'arm' 513 return unzipped_local 514 515 def _install_files(self, gs_dir, files, permission): 516 """Installs binary tools.""" 517 for filename in files: 518 gs_uri = os.path.join(gs_dir, filename) 519 # Atomic write through of file. 520 with tradefed_utils.lock(self._tradefed_cache_lock): 521 # We don't want to leave a corrupt cache for other jobs. 522 self._invalidate_download_cache() 523 cache_path = self._download_to_cache(gs_uri) 524 # Mark cache as clean again. 525 self._validate_download_cache() 526 # This only affects the current job, so not part of cache 527 # validation. 528 local = self._instance_copyfile(cache_path) 529 os.chmod(local, permission) 530 # Keep track of PATH. 531 self._install_paths.append(os.path.dirname(local)) 532 533 def _copy_media(self, media): 534 """Calls copy_media to push media files to DUT via adb.""" 535 logging.info('Copying media to device. This can take a few minutes.') 536 copy_media = os.path.join(media, 'copy_media.sh') 537 with tradefed_utils.pushd(media): 538 try: 539 self._run( 540 'file', 541 args=('/bin/sh',), 542 verbose=True, 543 ignore_status=True, 544 timeout=60, 545 stdout_tee=utils.TEE_TO_LOGS, 546 stderr_tee=utils.TEE_TO_LOGS) 547 self._run( 548 'sh', 549 args=('--version',), 550 verbose=True, 551 ignore_status=True, 552 timeout=60, 553 stdout_tee=utils.TEE_TO_LOGS, 554 stderr_tee=utils.TEE_TO_LOGS) 555 except: 556 logging.warning('Could not obtain sh version.') 557 self._run( 558 'sh', 559 args=('-e', copy_media, 'all'), 560 timeout=7200, # Wait at most 2h for download of media files. 561 verbose=True, 562 ignore_status=False, 563 stdout_tee=utils.TEE_TO_LOGS, 564 stderr_tee=utils.TEE_TO_LOGS) 565 566 def _verify_media(self, media): 567 """Verify that the local media directory matches the DUT. 568 Used for debugging b/32978387 where we may see file corruption.""" 569 # TODO(ihf): Remove function once b/32978387 is resolved. 570 # Find all files in the bbb_short and bbb_full directories, md5sum these 571 # files and sort by filename, both on the DUT and on the local tree. 572 logging.info('Computing md5 of remote media files.') 573 remote = self._run( 574 'adb', 575 args=('shell', 'cd /sdcard/test; ' 576 'find ./bbb_short ./bbb_full -type f -print0 | ' 577 'xargs -0 md5sum | grep -v "\.DS_Store" | sort -k 2')) 578 logging.info('Computing md5 of local media files.') 579 local = self._run( 580 '/bin/sh', 581 args=('-c', ( 582 'cd %s; find ./bbb_short ./bbb_full -type f -print0 | ' 583 'xargs -0 md5sum | grep -v "\.DS_Store" | sort -k 2') % media)) 584 585 # 'adb shell' terminates lines with CRLF. Normalize before comparing. 586 if remote.stdout.replace('\r\n', '\n') != local.stdout: 587 logging.error( 588 'Some media files differ on DUT /sdcard/test vs. local.') 589 logging.info('media=%s', media) 590 logging.error('remote=%s', remote) 591 logging.error('local=%s', local) 592 # TODO(ihf): Return False. 593 return True 594 logging.info('Media files identical on DUT /sdcard/test vs. local.') 595 return True 596 597 def _push_media(self, CTS_URI): 598 """Downloads, caches and pushes media files to DUT.""" 599 media = self._install_bundle(CTS_URI['media']) 600 base = os.path.splitext(os.path.basename(CTS_URI['media']))[0] 601 cts_media = os.path.join(media, base) 602 # TODO(ihf): this really should measure throughput in Bytes/s. 603 m = 'chromeos/autotest/infra_benchmark/cheets/push_media/duration' 604 fields = {'success': False, 'dut_host_name': self._host.hostname} 605 with metrics.SecondsTimer(m, fields=fields) as c: 606 self._copy_media(cts_media) 607 c['success'] = True 608 if not self._verify_media(cts_media): 609 raise error.TestFail('Error: saw corruption pushing media files.') 610 611 def _run(self, *args, **kwargs): 612 """Executes the given command line. 613 614 To support SDK tools, such as adb or aapt, this adds _install_paths 615 to the extra_paths. Before invoking this, ensure _install_files() has 616 been called. 617 """ 618 kwargs['extra_paths'] = ( 619 kwargs.get('extra_paths', []) + self._install_paths) 620 return utils.run(*args, **kwargs) 621 622 def _collect_tradefed_global_log(self, result, destination): 623 """Collects the tradefed global log. 624 625 @param result: The result object from utils.run. 626 @param destination: Autotest result directory (destination of logs). 627 """ 628 match = re.search(r'Saved log to /tmp/(tradefed_global_log_.*\.txt)', 629 result.stdout) 630 if not match: 631 logging.error('no tradefed_global_log file is found') 632 return 633 634 name = match.group(1) 635 dest = os.path.join(destination, 'logs', 'tmp') 636 self._safe_makedirs(dest) 637 shutil.copy(os.path.join('/tmp', name), os.path.join(dest, name)) 638 639 def _parse_result(self, result, waivers=None): 640 """Check the result from the tradefed output. 641 642 This extracts the test pass/fail/executed list from the output of 643 tradefed. It is up to the caller to handle inconsistencies. 644 645 @param result: The result object from utils.run. 646 @param waivers: a set[] of tests which are permitted to fail. 647 """ 648 return parse_tradefed_result(result.stdout, waivers) 649 650 def _get_expected_failures(self, *directories): 651 """Return a list of expected failures or no test module. 652 653 @param directories: A list of directories with expected no tests 654 or failures files. 655 @return: A list of expected failures or no test modules for the current 656 testing device. 657 """ 658 # Load waivers and manual tests so TF doesn't re-run them. 659 expected_fail_files = [] 660 test_board = self._get_board_name(self._host) 661 test_arch = self._get_board_arch(self._host) 662 for directory in directories: 663 expected_fail_dir = os.path.join(self.bindir, directory) 664 if os.path.exists(expected_fail_dir): 665 expected_fail_files += glob.glob(expected_fail_dir + '/*.yaml') 666 667 waivers = cts_expected_failure_parser.ParseKnownCTSFailures( 668 expected_fail_files) 669 return waivers.find_waivers(test_board, test_arch) 670 671 def _get_release_channel(self, host): 672 """Returns the DUT channel of the image ('dev', 'beta', 'stable').""" 673 channel = host.get_channel() 674 return channel or 'dev' 675 676 def _get_board_arch(self, host): 677 """ Return target DUT arch name.""" 678 return 'arm' if host.get_cpu_arch() == 'arm' else 'x86' 679 680 def _get_board_name(self, host): 681 """Return target DUT board name.""" 682 return host.get_board().split(':')[1] 683 684 def _get_max_retry(self, max_retry, host): 685 """Return the maximum number of retries. 686 687 @param max_retry: max_retry specified in the control file. 688 @param host: target DUT for retry adjustment. 689 @return: number of retries for this specific host. 690 """ 691 candidate = [max_retry] 692 candidate.append(self._get_board_retry(host)) 693 candidate.append(self._get_channel_retry(host)) 694 return min(x for x in candidate if x is not None) 695 696 def _get_board_retry(self, host): 697 """Return the maximum number of retries for DUT board name. 698 699 @param host: target DUT for retry adjustment. 700 @return: number of max_retry for this specific board or None. 701 """ 702 board = self._get_board_name(host) 703 if board in self._BOARD_RETRY: 704 return self._BOARD_RETRY[board] 705 logging.debug('No board retry specified for board: %s', board) 706 return None 707 708 def _get_channel_retry(self, host): 709 """Returns the maximum number of retries for DUT image channel.""" 710 channel = self._get_release_channel(host) 711 if channel in self._CHANNEL_RETRY: 712 return self._CHANNEL_RETRY[channel] 713 retry = self._CHANNEL_RETRY['dev'] 714 logging.warning('Could not establish channel. Using retry=%d.', retry) 715 return retry 716 717 def _run_precondition_scripts(self, host, commands, steps): 718 for command in commands: 719 # Replace {0} (if any) with the retry count. 720 formatted_command = command.format(steps) 721 logging.info('RUN: %s\n', formatted_command) 722 output = host.run(formatted_command, ignore_status=True) 723 logging.info('END: %s\n', output) 724 725 def _run_and_parse_tradefed(self, commands): 726 """Kick off the tradefed command. 727 728 Assumes that only last entry of |commands| actually runs tests and has 729 interesting output (results, logs) for collection. Ignores all other 730 commands for this purpose. 731 732 @param commands: List of lists of command tokens. 733 @raise TestFail: when a test failure is detected. 734 @return: tuple of (tests, pass, fail, notexecuted) counts. 735 """ 736 try: 737 output = self._run_tradefed(commands) 738 except Exception as e: 739 self._log_java_version() 740 if not isinstance(e, error.CmdTimeoutError): 741 # In case this happened due to file corruptions, try to force to 742 # recreate the cache. 743 logging.error('Failed to run tradefed! Cleaning up now.') 744 self._clean_download_cache_if_needed(force=True) 745 raise 746 747 result_destination = os.path.join(self.resultsdir, 748 self._get_tradefed_base_dir()) 749 # Gather the global log first. Datetime parsing below can abort the test 750 # if tradefed startup had failed. Even then the global log is useful. 751 self._collect_tradefed_global_log(output, result_destination) 752 # Result parsing must come after all other essential operations as test 753 # warnings, errors and failures can be raised here. 754 return self._parse_result(output, waivers=self._waivers) 755 756 def _setup_result_directories(self): 757 """Sets up the results and logs directories for tradefed. 758 759 Tradefed saves the logs and results at: 760 self._repository/results/$datetime/ 761 self._repository/results/$datetime.zip 762 self._repository/logs/$datetime/ 763 Because other tools rely on the currently chosen Google storage paths 764 we need to keep destination_results in: 765 self.resultdir/android-cts/results/$datetime/ 766 self.resultdir/android-cts/results/$datetime.zip 767 self.resultdir/android-cts/results/logs/$datetime/ 768 To bridge between them, create symlinks from the former to the latter. 769 """ 770 logging.info('Setting up tradefed results and logs directories.') 771 772 results_destination = os.path.join(self.resultsdir, 773 self._get_tradefed_base_dir()) 774 logs_destination = os.path.join(results_destination, 'logs') 775 directory_mapping = [ 776 (os.path.join(self._repository, 'results'), results_destination), 777 (os.path.join(self._repository, 'logs'), logs_destination), 778 ] 779 780 for (tradefed_path, final_path) in directory_mapping: 781 if os.path.exists(tradefed_path): 782 shutil.rmtree(tradefed_path) 783 self._safe_makedirs(final_path) 784 os.symlink(final_path, tradefed_path) 785 786 def _install_plan(self, subplan): 787 """Copy test subplan to CTS-TF. 788 789 @param subplan: CTS subplan to be copied into TF. 790 """ 791 logging.info('Install subplan: %s', subplan) 792 subplans_tf_dir = os.path.join(self._repository, 'subplans') 793 if not os.path.exists(subplans_tf_dir): 794 os.makedirs(subplans_tf_dir) 795 test_subplan_file = os.path.join(self.bindir, 'subplans', 796 '%s.xml' % subplan) 797 try: 798 shutil.copy(test_subplan_file, subplans_tf_dir) 799 except (shutil.Error, OSError, IOError) as e: 800 raise error.TestFail( 801 'Error: failed to copy test subplan %s to CTS bundle. %s' % 802 test_subplan_file, e) 803 804 def _should_skip_test(self): 805 """Some tests are expected to fail and are skipped. 806 807 Subclasses should override with specific details. 808 """ 809 return False 810 811 def _should_reboot(self, steps): 812 """Oracle to decide if DUT should reboot or just restart Chrome. 813 814 For now we will not reboot after the first two iterations, but on all 815 iterations afterward as before. In particular this means that most CTS 816 tests will now not get a "clean" machine, but one on which tests ran 817 before. But we will still reboot after persistent failures, hopefully 818 not causing too many flakes down the line. 819 """ 820 if steps < 3: 821 return False 822 return True 823 824 def _run_tradefed_list_results(self): 825 """Run the `tradefed list results` command. 826 827 @return: tuple of the last (session_id, pass, fail, all_done?). 828 """ 829 output = self._run_tradefed([['list', 'results']]) 830 831 # Parses the last session from the output that looks like: 832 # 833 # Session Pass Fail Modules Complete ... 834 # 0 90 10 1 of 2 835 # 1 199 1 2 of 2 836 # ... 837 lastmatch = None 838 for m in re.finditer(r'^(\d+)\s+(\d+)\s+(\d+)\s+(\d+) of (\d+)', 839 output.stdout, re.MULTILINE): 840 session, passed, failed, done, total = map(int, 841 m.group(1, 2, 3, 4, 5)) 842 lastmatch = (session, passed, failed, done == total) 843 return lastmatch 844 845 def _run_tradefed_with_retries(self, 846 target_module, 847 test_command, 848 test_name, 849 target_plan=None, 850 needs_push_media=False, 851 cts_uri=None, 852 login_precondition_commands=[], 853 precondition_commands=[]): 854 """Run CTS/GTS with retry logic. 855 856 We first kick off the specified module. Then rerun just the failures 857 on the next MAX_RETRY iterations. 858 """ 859 if self._should_skip_test(): 860 logging.warning('Skipped test %s', ' '.join(test_command)) 861 return 862 863 steps = -1 # For historic reasons the first iteration is not counted. 864 pushed_media = False 865 self.summary = '' 866 board = self._get_board_name(self._host) 867 session_id = None 868 869 self._setup_result_directories() 870 871 while steps < self._max_retry: 872 steps += 1 873 self._run_precondition_scripts(self._host, 874 login_precondition_commands, steps) 875 with self._login_chrome( 876 board=board, 877 reboot=self._should_reboot(steps), 878 dont_override_profile=pushed_media) as current_login: 879 self._ready_arc() 880 self._run_precondition_scripts(self._host, 881 precondition_commands, steps) 882 883 # Only push media for tests that need it. b/29371037 884 if needs_push_media and not pushed_media: 885 self._push_media(cts_uri) 886 # copy_media.sh is not lazy, but we try to be. 887 pushed_media = True 888 889 # Run tradefed. 890 if session_id == None: 891 if target_plan is not None: 892 self._install_plan(target_plan) 893 894 logging.info('Running %s:', test_name) 895 commands = [test_command] 896 else: 897 logging.info('Retrying failures of %s with session_id %d:', 898 test_name, session_id) 899 commands = [test_command + ['--retry', '%d' % session_id]] 900 901 legacy_counts = self._run_and_parse_tradefed(commands) 902 result = self._run_tradefed_list_results() 903 if not result: 904 logging.error('Did not find any test results. Retry.') 905 current_login.need_reboot() 906 continue 907 908 # TODO(kinaba): stop parsing |legacy_counts| except for waivers, 909 # and rely more on |result| for generating the message. 910 ltests, lpassed, lfailed, lnotexecuted, lwaived = legacy_counts 911 last_session_id, passed, failed, all_done = result 912 913 msg = 'run' if session_id == None else ' retry' 914 msg += '(t=%d, p=%d, f=%d, ne=%d, w=%d)' % legacy_counts 915 self.summary += msg 916 logging.info('RESULT: %s %s', msg, result) 917 918 # Check for no-test modules 919 notest = (passed + failed == 0 and all_done) 920 if target_module in self._notest_modules: 921 if notest: 922 logging.info('Package has no tests as expected.') 923 return 924 else: 925 # We expected no tests, but the new bundle drop must 926 # have added some for us. Alert us to the situation. 927 raise error.TestFail( 928 'Failed: Remove module %s from ' 929 'notest_modules directory!' % target_module) 930 elif notest: 931 logging.error('Did not find any tests in module. Hoping ' 932 'this is transient. Retry after reboot.') 933 current_login.need_reboot() 934 continue 935 936 session_id = last_session_id 937 938 # Check if all the tests passed. 939 if failed <= lwaived and all_done: 940 # TODO(ihf): Make this error.TestPass('...') once available. 941 if steps > 0 and self._warn_on_test_retry: 942 raise error.TestWarn( 943 'Passed: after %d retries passing %d tests, waived=' 944 '%d. %s' % (steps, passed, lwaived, self.summary)) 945 return 946 947 if session_id == None: 948 raise error.TestFail('Error: Could not find any tests in module.') 949 raise error.TestFail( 950 'Failed: after %d retries giving up. ' 951 'passed=%d, failed=%d, notexecuted=%d, waived=%d. %s' % 952 (steps, passed, failed, lnotexecuted, lwaived, self.summary)) 953
