1# Copyright 2018 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 5from __future__ import absolute_import, division, print_function 6 7import datetime 8import json 9import logging 10import os 11import shutil 12import socket 13import tempfile 14from collections import OrderedDict 15 16import dateutil.parser 17import six 18import yaml 19from autotest_lib.client.common_lib import (base_job, config_vars, error) 20from autotest_lib.client.common_lib.cros import dev_server, tpm_utils 21from autotest_lib.server import test, utils 22from autotest_lib.server.cros.network import wifi_test_context_manager 23from autotest_lib.server.hosts import cros_host, servo_constants, servo_host 24from autotest_lib.site_utils.rpm_control_system import rpm_constants 25from autotest_lib.utils import labellib 26from six.moves import urllib 27 28# A datetime.DateTime representing the Unix epoch in UTC. 29_UNIX_EPOCH = dateutil.parser.parse('1970-01-01T00:00:00Z') 30 31# Keywords that are used in result json file. 32_KEY_NAME = 'name' 33_KEY_START = 'start' 34_KEY_END = 'end' 35_KEY_ERRORS = 'errors' 36_KEY_SKIP_REASON = 'skipReason' 37_KEY_REASON = 'reason' 38_KEY_TIME = 'time' 39_KEY_MISSING_REASON = 'missingReason' 40 41 42def split_arguments(args): 43 """Splits arguments into the autotest and tast variable assignments. 44 Use the results as command_args and varslist respectively. 45 46 @param args: List of strings passed to test_that --args 47 48 @returns Array of Tauto args, Array of TAST variable assignments. 49 """ 50 51 auto_args = [] 52 tast_vars = [] 53 for a in args: 54 if a.startswith("tast."): 55 tast_vars.append(a[5:]) 56 else: 57 auto_args.append(a) 58 return auto_args, tast_vars 59 60 61def _encode_text(text): 62 """Takes an unicode string into utf-8 string 63 (bytes for python 2 and text for python 3). 64 """ 65 if six.PY2: 66 return text.encode('utf-8') 67 return text 68 69 70def _encode_json(j): 71 """Takes JSON object parsed by json.load() family, and encode each unicode 72 strings into str. 73 """ 74 if isinstance(j, six.text_type): 75 return _encode_text(j) 76 if isinstance(j, list): 77 return [_encode_json(x) for x in j] 78 if isinstance(j, dict): 79 return dict((_encode_json(k), _encode_json(v)) 80 for k, v in six.iteritems(j)) 81 return j 82 83 84def _dut_server_arg(command_args): 85 """Return dut_server arg out of command_args if found.""" 86 dut_server_arg = None 87 dut_server = None 88 for arg in command_args: 89 if 'dut_servers=' in arg: 90 dut_server_arg = arg 91 break 92 if not dut_server_arg: 93 return 94 dut_server = dut_server_arg.split('=')[1] 95 96 # In case multiple dutservers are passed... 97 # e.g.: "dut_servers=localhost:1343,localhost:5678" 98 if ',' in dut_server: 99 # Currently only support the first, until we map dut:dut_server 100 dut_server = dut_server.split(',')[0] 101 102 return dut_server 103 104 105class TastConfigError(error.AutotestError): 106 """Indicates a problem with configuration files.""" 107 108 109class tast(test.test): 110 """Autotest server test that runs a Tast test suite. 111 112 Tast is an integration-testing framework analagous to the test-running 113 portion of Autotest. See 114 https://chromium.googlesource.com/chromiumos/platform/tast/ for more 115 information. 116 117 This class runs the "tast" command locally to execute a Tast test suite on a 118 remote DUT. 119 """ 120 version = 1 121 122 # Maximum time to wait for various tast commands to complete, in seconds. 123 _VERSION_TIMEOUT_SEC = 10 124 _DOWNLOAD_TIMEOUT_SEC = 120 125 _LIST_TIMEOUT_SEC = 30 126 _LIST_TRIES = 2 127 128 # Additional time to add to the run timeout (e.g. for collecting crashes and 129 # logs). 130 _RUN_OVERHEAD_SEC = 20 131 # Additional time given to the run command to exit before it's killed. 132 _RUN_EXIT_SEC = 5 133 134 # Number of times to retry SSH connection attempts to the DUT. 135 _SSH_CONNECT_RETRIES = 2 136 137 # File written by the tast command containing test results, as 138 # newline-terminated JSON TestResult objects. 139 _STREAMED_RESULTS_FILENAME = 'streamed_results.jsonl' 140 141 # Text file written by the tast command if a global error caused the test 142 # run to fail (e.g. SSH connection to DUT was lost). 143 _RUN_ERROR_FILENAME = 'run_error.txt' 144 145 # Maximum number of failing and missing tests to include in error messages. 146 _MAX_TEST_NAMES_IN_ERROR = 3 147 148 # Default paths where Tast files are installed by Portage packages. 149 _PORTAGE_TAST_PATH = '/usr/bin/tast' 150 151 # Alternate locations for Tast files when using Server-Side Packaging. 152 # These files are installed from autotest_server_package.tar.bz2. 153 _SSP_ROOT = '/usr/local/tast' 154 _SSP_TAST_PATH = os.path.join(_SSP_ROOT, 'tast') 155 _SSP_REMOTE_BUNDLE_DIR = os.path.join(_SSP_ROOT, 'bundles/remote') 156 _SSP_REMOTE_DATA_DIR = os.path.join(_SSP_ROOT, 'data') 157 _SSP_REMOTE_TEST_RUNNER_PATH = os.path.join(_SSP_ROOT, 'remote_test_runner') 158 _SSP_DEFAULT_VARS_DIR_PATH = os.path.join(_SSP_ROOT, 'vars') 159 160 _F20_CONTAINER_BREADCRUMB = '/usr/local/f20container' 161 # Prefix added to Tast test names when writing their results to TKO 162 # status.log files. 163 _TEST_NAME_PREFIX = 'tast.' 164 165 # Prefixes of keyval keys recorded for missing tests. 166 _MISSING_TEST_KEYVAL_PREFIX = 'tast_missing_test.' 167 168 # Job start/end TKO event status codes from base_client_job._rungroup in 169 # client/bin/job.py. 170 _JOB_STATUS_START = 'START' 171 _JOB_STATUS_END_GOOD = 'END GOOD' 172 _JOB_STATUS_END_FAIL = 'END FAIL' 173 _JOB_STATUS_END_NOSTATUS = 'END NOSTATUS' 174 _JOB_STATUS_END_SKIP = 'END TEST_NA' 175 176 # In-job TKO event status codes from base_client_job._run_test_base in 177 # client/bin/job.py and client/common_lib/error.py. 178 _JOB_STATUS_GOOD = 'GOOD' 179 _JOB_STATUS_FAIL = 'FAIL' 180 _JOB_STATUS_NOSTATUS = 'NOSTATUS' 181 _JOB_STATUS_SKIP = 'TEST_NA' 182 183 # Status reason used when an individual Tast test doesn't finish running. 184 _TEST_DID_NOT_FINISH_MSG = 'Test did not finish' 185 # Status reason used when an individual Tast test doesn't start running. 186 _TEST_DID_NOT_RUN_MSG = 'Test did not run' 187 188 def initialize(self, 189 host, 190 test_exprs, 191 ignore_test_failures=False, 192 max_run_sec=3600, 193 command_args=[], 194 install_root='/', 195 ssp=None, 196 build=None, 197 build_bundle='cros', 198 run_private_tests=True, 199 varsfiles=[], 200 download_data_lazily=True, 201 clear_tpm=True, 202 totalshards=1, 203 shardindex=0, 204 companion_duts={}, 205 varslist=[], 206 maybemissingvars='', 207 use_camera_box=False, 208 vars_gs_path='', 209 retries=0, 210 ephemeraldevserver=None, 211 is_cft=False, 212 exclude_missing=False, 213 test_filter_files=[], 214 report_skipped=False): 215 """ 216 @param host: remote.RemoteHost instance representing DUT. 217 @param test_exprs: Array of strings describing tests to run. 218 @param ignore_test_failures: If False, this test will fail if individual 219 Tast tests report failure. If True, this test will only fail in 220 response to the tast command failing to run successfully. This 221 should generally be False when the test is running inline and True 222 when it's running asynchronously. 223 @param max_run_sec: Integer maximum running time for the "tast run" 224 command in seconds. 225 @param command_args: List of arguments passed on the command line via 226 test_that's --args flag, i.e. |args| in control file. 227 @param install_root: Root directory under which Tast binaries are 228 installed. Alternate values may be passed by unit tests. 229 @param ssp: Whether to use SSP files. Default is to auto-detect. 230 @param build: Whether to build test runners and test bundles. 231 Default is to build if and only if SSP is unavailable 232 (i.e. build = not ssp). 233 @param build_bundle: Test bundle name to build. Effective only when 234 build=True. 235 @param run_private_tests: Download and run private tests. Effective 236 only when build=False. When build=True, build_bundle can be 237 specified to build and run a private bundle. 238 @param varsfiles: list of names of yaml files containing variables set 239 in |-varsfile| arguments. 240 @param download_data_lazily: If True, external data files are downloaded 241 lazily between tests. If false, external data files are downloaded 242 in a batch before running tests. 243 @param clear_tpm: clear the TPM first before running the tast tests. 244 @param totalshards: Total number of shards. 245 @param shardindex: The shard index to be run. 246 @param companion_duts: A map of role to DUT name to tast run command as 247 |-companiondut| arguments. Each entry in the map will be formatted 248 as "role:dut" for each -companiondut argument. 249 @param varslist: list of strings to pass to tast run command as |-vars| 250 arguments. Each string should be formatted as "name=value". 251 @param maybemissingvars: a regex to pass to tast run command as 252 |-maybemissingvars| arguments. 253 @param vars_gs_path: gs path to load vars from. The vars are loaded 254 from gs in json format (key = value), then stored in a local 255 yaml file. The local file name is then appended to |-varsfiles|. 256 @param use_camera_box: Bring the IP address of chart device in CameraBox 257 to tast tests. 258 @param ephemeraldevserver: A value to pass to -ephemeraldevserver 259 @param exclude_missing: This option will exclude tests that are requested, but not found in 260 `tast list` command 261 @param test_filter_files: This option includes a list of files containing names 262 of test to be disabled. 263 @param report_skipped: If true then skipped tests will be reported in 264 the status.log 265 266 When the F20 breadcrumb is detected, it is assumed we are running in 267 the F20 container, meaning we will force disable SSP (though the 268 SSP flag should be false in this case). The F20 container is fully 269 build versioned and matches the chroot paths, so we do not want to 270 take the SSP logic. 271 272 @raises error.TestFail if the Tast installation couldn't be found. 273 """ 274 f20_container = False 275 if os.path.exists(self._F20_CONTAINER_BREADCRUMB): 276 ssp = False 277 f20_container = True 278 if ssp is None: 279 ssp = os.path.exists(self._SSP_TAST_PATH) 280 if build is None: 281 build = not ssp 282 283 self._host = host 284 self._test_exprs = test_exprs 285 self._ignore_test_failures = ignore_test_failures 286 self._max_run_sec = max_run_sec 287 self._command_args = command_args 288 self._install_root = install_root 289 self._ssp = ssp 290 self._build = build 291 self._build_bundle = build_bundle 292 self._run_private_tests = run_private_tests 293 self._fake_now = None 294 self._varsfiles = varsfiles 295 self._varslist = varslist 296 self._download_data_lazily = download_data_lazily 297 self._clear_tpm = clear_tpm 298 self._totalshards = totalshards 299 self._shardindex = shardindex 300 self._companion_duts = companion_duts 301 self._maybemissingvars = maybemissingvars 302 self._vars_gs_path = vars_gs_path 303 self._use_camera_box = use_camera_box 304 self._retries = retries 305 self._f20_container = f20_container or is_cft 306 self._ephemeraldevserver = ephemeraldevserver 307 self._exclude_missing = exclude_missing 308 self._test_filter_files = test_filter_files 309 self._report_skipped = report_skipped 310 311 # Need to pass in dut_servers for every test in CFT. 312 # But only add it if not already in varslist. 313 if not any( 314 [True if 'dut.servers' in arg else False for arg in varslist]): 315 dut_server = _dut_server_arg(command_args) 316 if dut_server: 317 self._varslist.append('servers.dut=:%s' % dut_server) 318 319 # List of JSON objects describing tests that will be run. See Test in 320 # src/platform/tast/src/chromiumos/tast/testing/test.go for details. 321 self._tests_to_run = [] 322 323 # List of JSON objects corresponding to tests from 324 # _STREAMED_RESULTS_FILENAME. See TestResult in 325 # src/platform/tast/src/chromiumos/cmd/tast/run/results.go for details. 326 self._test_results = [] 327 328 # Error message read from _RUN_ERROR_FILENAME, if any. 329 self._run_error = None 330 331 self._tast_path = self._get_path( 332 self._SSP_TAST_PATH if ssp else self._PORTAGE_TAST_PATH) 333 334 # Register a hook to write the results of individual Tast tests as 335 # top-level entries in the TKO status.log file. 336 self.job.add_post_run_hook(self._log_all_unique_tests) 337 338 def run_once(self): 339 """Runs a single iteration of the test.""" 340 341 if self._clear_tpm: 342 tpm_utils.ClearTPMOwnerRequest(self._host, wait_for_ready=True) 343 344 self._log_version() 345 if not self._f20_container: 346 self._find_devservers() 347 348 self._ensure_bundles() 349 350 # Shortcut if no test belongs to the specified test_exprs. 351 list_test_exception = None 352 has_tests_to_run = False 353 for i in range(self._LIST_TRIES): 354 try: 355 if i > 0: 356 logging.info('Retrying to get which tests to run') 357 has_tests_to_run = bool(self._get_tests_to_run()) 358 list_test_exception = None 359 break 360 except Exception as e: 361 list_test_exception = e 362 if list_test_exception: 363 raise error.TestFail('Failed to get list of tests to run: %s' % 364 str(list_test_exception)) 365 if not has_tests_to_run: 366 return 367 368 # TODO(b/221333999): There are no devservers in CFT (F20), so this 369 # would likely error. Once full CFT is done tast.py will be deprecated 370 # and this won't be needed. 371 if not self._f20_container: 372 self._pull_varsfile_from_gs() 373 374 run_failed = False 375 run_failed_msg = None 376 try: 377 self._run_tests() 378 except Exception as e: 379 run_failed = True 380 run_failed_msg = str(e).split('\n', 1)[0] 381 raise 382 finally: 383 self._read_run_error() 384 # Parse partial results even if the tast command didn't finish. 385 self._parse_results(run_failed, run_failed_msg) 386 387 def set_fake_now_for_testing(self, now): 388 """Sets a fake timestamp to use in place of time.time() for unit tests. 389 390 @param now Numeric timestamp as would be returned by time.time(). 391 """ 392 self._fake_now = now 393 394 def _pull_varsfile_from_gs(self): 395 """Pulls varsfiles from GS, does dynamic values transformation, stores 396 it as a local file and appends the file name to varsfiles. 397 398 Has to be called after _get_tests_to_run since it's using _tests_to_run. 399 400 @param varsgspath Path to varsfiles in GS e.g. 401 'config/perf_cuj/perf_cuj.config'. 402 403 @raises TastConfigError for config errors. 404 """ 405 if not self._vars_gs_path: 406 return 407 408 devservers = dev_server.ImageServer.get_available_devservers() 409 devserver_url = devservers[0][0] 410 if not devserver_url: 411 raise TastConfigError('No devserver_url') 412 413 logging.info('Using devserver: %s', devserver_url) 414 labels = self._host.host_info_store.get().labels 415 build = labellib.LabelsMapping(labels).get(labellib.Key.CROS_VERSION) 416 if not build: 417 raise TastConfigError( 418 'Not able to detect build, means not running on Moblab.') 419 420 ds = dev_server.ImageServer(devserver_url) 421 gs_bucket = dev_server._get_image_storage_server() 422 if not gs_bucket: 423 raise TastConfigError('No image storage server gs bucket') 424 425 config_path, config_file = os.path.split(self._vars_gs_path) 426 archive_url = os.path.join(gs_bucket, config_path.strip('/')) 427 logging.info('Staging configuration from %s.', gs_bucket) 428 try: 429 ds.stage_artifacts(build, 430 archive_url=archive_url, 431 files=[config_file]) 432 except Exception as e: 433 raise TastConfigError('Staging artifacts failed: %s', str(e)) 434 435 logging.info('Parsing configuration from %s.', archive_url) 436 config_url = os.path.join(devserver_url, 'static', 437 self._vars_gs_path.strip('/')) 438 response = urllib.request.urlopen(config_url) 439 vars = json.loads(response.read()) 440 test_args = dict() 441 for key in vars: 442 test_args[key] = vars[key] 443 logging.info('Read %d values from remote configuration.', len(vars)) 444 445 extvars = self._fill_config_extvars() 446 test_args = config_vars.TransformConfig(test_args, extvars) 447 448 with tempfile.NamedTemporaryFile(suffix='.yaml', 449 delete=False) as temp_file: 450 yaml.dump(test_args, stream=temp_file, default_flow_style=False) 451 self._varsfiles.append(temp_file.name) 452 453 def _fill_config_extvars(self): 454 """Fill in external variables map for conditional config processing. 455 456 The sources used (in order of precedence low to high): 457 * --varsfiles. 458 * --varslist. 459 * list of tests to run. 460 * command_args: List of arguments passed on the command line via 461 test_that's --args flag, i.e. |args| in control file. 462 * DUT labels (with and without a value). 463 464 @returns external variables map. 465 """ 466 # The latter overwrites the former. 467 extvars = {} 468 469 # Load varsfiles 470 for varsfile in self._varsfiles: 471 with open(varsfile, 'r') as f: 472 for key, val in yaml.safe_load(f).items(): 473 if 'var:' + key in extvars: 474 logging.info('var:%s overwritten', key) 475 extvars['var:' + key] = val 476 477 # Load vars 478 for var in self._varslist: 479 key, val = var.split('=', 1) 480 if 'var:' + key in extvars: 481 logging.info('var:%s overwritten', key) 482 extvars['var:' + key] = val 483 484 # Load tests_to_run 485 extvars['tests:'] = '\n'.join(self._tests_to_run) 486 for test_to_run in self._tests_to_run: 487 extvars['test:' + test_to_run] = '' 488 489 # Load command_args 490 extvars['args:'] = '\n'.join(self._command_args) 491 for key, val in utils.args_to_dict(self._command_args).items(): 492 extvars['arg:' + key] = val 493 for command_arg in self._command_args: 494 if '=' not in command_arg and ':' not in command_arg: 495 extvars['arg:' + command_arg] = '' 496 497 # Load labels 498 labels = self._host.host_info_store.get().labels 499 extvars['labels:'] = '\n'.join(labels) 500 for label in labels: 501 key, val = (label.split(':', 1) + [''])[0:2] 502 extvars['label:' + key] = val 503 504 return extvars 505 506 def _get_path(self, path): 507 """Returns the path to an installed Tast-related file or directory. 508 509 @param path: Absolute paths in root filesystem, e.g. "/usr/bin/tast". 510 511 @returns Absolute path within install root, e.g. 512 "/usr/local/tast/usr/bin/tast". 513 """ 514 return os.path.join(self._install_root, os.path.relpath(path, '/')) 515 516 def _get_camerabox_args(self): 517 """Gets camerabox-related arguments to pass to "tast run". 518 519 @returns List of command-line flag strings that should be inserted in 520 the command line after "tast run". 521 """ 522 args = [] 523 if self._use_camera_box: 524 host_name = self._host.hostname 525 526 # If host name is "FOO.BAR.BAR2", the chart host name should be 527 # "FOO-tablet.BAR.BAR2" 528 domains = host_name.split('.', 1) 529 domains[0] += '-tablet' 530 chart_host_name = '.'.join(domains) 531 try: 532 chart_ip = socket.gethostbyname(chart_host_name) 533 534 # Check if the IP is pingable. 535 if os.system("ping -c 1 " + chart_ip) != 0: 536 logging.error('Failed to ping IP: %s.', chart_ip) 537 538 args += ['-var=chart=' + chart_ip] 539 except socket.gaierror: 540 logging.exception('Failed to get IP: %s.', chart_host_name) 541 logging.info('Camerabox args: %s', args) 542 return args 543 544 def _get_servo_args(self): 545 """Gets servo-related arguments to pass to "tast run". 546 547 @returns List of command-line flag strings that should be inserted in 548 the command line after "tast run". 549 """ 550 # Start with information provided by the Autotest database. 551 merged_args = {} 552 host_args = servo_host.get_servo_args_for_host(self._host) 553 if host_args: 554 merged_args.update(host_args) 555 556 # Incorporate information that was passed manually. 557 args_dict = utils.args_to_dict(self._command_args) 558 merged_args.update(cros_host.CrosHost.get_servo_arguments(args_dict)) 559 560 logging.info('Autotest servo-related args: %s', merged_args) 561 host_arg = merged_args.get(servo_constants.SERVO_HOST_ATTR) 562 port_arg = merged_args.get(servo_constants.SERVO_PORT_ATTR) 563 if not host_arg or not port_arg: 564 return [] 565 return ['-var=servo=%s:%s' % (host_arg, port_arg)] 566 567 def _get_firmware_args(self): 568 """Gets firmware-related arguments to pass to "tast run". 569 570 @returns List of command-line flag strings that should be inserted in 571 the command line after "tast run". 572 """ 573 # Incorporate information that was passed manually. 574 args_dict = utils.args_to_dict(self._command_args) 575 576 args = [] 577 no_ec_sync = args_dict.get("no_ec_sync") 578 if no_ec_sync: 579 args += ['-var=firmware.no_ec_sync=' + no_ec_sync] 580 logging.info('Firmware args: %s', args) 581 return args 582 583 def _get_rpm_args(self): 584 """Gets rpm-related arguments to pass to "tast run". 585 586 @returns List of command-line flag strings that should be inserted in 587 the command line after "tast run". 588 """ 589 info = self._host.host_info_store.get() 590 args = [] 591 forward_args = [ 592 (rpm_constants.POWERUNIT_HOSTNAME_KEY, 'powerunitHostname=%s'), 593 (rpm_constants.POWERUNIT_OUTLET_KEY, 'powerunitOutlet=%s'), 594 (rpm_constants.HYDRA_HOSTNAME_KEY, 'hydraHostname=%s'), 595 ] 596 for key, var_arg in forward_args: 597 if key in info.attributes: 598 args += ['-var=' + var_arg % info.attributes[key]] 599 logging.info('RPM args: %s', args) 600 return args 601 602 def _get_wificell_args(self): 603 """Gets wificell-related (router, pcap) arguments to pass to "tast run". 604 605 @returns List of command-line flag strings that should be inserted in 606 the command line after "tast run". 607 """ 608 # Incorporate information that was passed manually. 609 args_dict = utils.args_to_dict(self._command_args) 610 args = [] 611 # Alias of WiFiTestContextManager. 612 WiFiManager = wifi_test_context_manager.WiFiTestContextManager 613 # TODO(crbug.com/1065601): plumb other WiFi test specific arguments, 614 # e.g. pcap address. See: WiFiTestContextManager's constants. 615 forward_args = [ 616 (WiFiManager.CMDLINE_ROUTER_ADDR, 'router=%s'), 617 (WiFiManager.CMDLINE_PCAP_ADDR, 'pcap=%s'), 618 ] 619 for key, var_arg in forward_args: 620 if key in args_dict: 621 args += ['-var=' + var_arg % args_dict[key]] 622 # Append "routers" var for supporting multi-router tests with current 623 # two-AP fixture setup (with specified router_addr and pcap_addr args). 624 # TODO(b/171949862): remove this when a new multi-router fixture is 625 # defined and rolled out to the lab. 626 if (WiFiManager.CMDLINE_ROUTER_ADDR in args_dict 627 and WiFiManager.CMDLINE_PCAP_ADDR in args_dict): 628 args += [ 629 '-var=routers=%s,%s' % 630 (args_dict[WiFiManager.CMDLINE_ROUTER_ADDR], 631 args_dict[WiFiManager.CMDLINE_PCAP_ADDR]) 632 ] 633 logging.info('Autotest wificell-related args: %s', args) 634 return args 635 636 def _get_cloud_storage_info(self): 637 """Gets the cloud storage bucket URL to pass to tast. 638 639 @returns Cloud storage bucket URL that should be inserted in 640 the command line after "tast run". 641 """ 642 gs_bucket = dev_server._get_image_storage_server() 643 args_dict = utils.args_to_dict(self._command_args) 644 build = args_dict.get('build') 645 if not build: 646 labels = self._host.host_info_store.get().labels 647 build = labellib.LabelsMapping(labels).get( 648 labellib.Key.CROS_VERSION) 649 650 if not gs_bucket or not build: 651 return [] 652 gs_path = os.path.join(gs_bucket, build) 653 if not gs_path.endswith('/'): 654 gs_path += '/' 655 logging.info('Cloud storage bucket: %s', gs_path) 656 return ['-buildartifactsurl=%s' % gs_path] 657 658 def _find_devservers(self): 659 """Finds available devservers. 660 661 The result is saved as self._devserver_args. 662 """ 663 logging.info('All devservers: %s', 664 ', '.join(dev_server.ImageServer.servers())) 665 devservers, can_retry = dev_server.ImageServer.get_available_devservers( 666 self._host.hostname, prefer_local_devserver=True) 667 if not devservers and can_retry and (self._host.is_satlab() 668 or 'MOBLAB' in os.environ): 669 devservers, can_retry = dev_server.ImageServer.get_available_devservers( 670 self._host.hostname, prefer_local_devserver=False) 671 logging.info('Using devservers: %s', ', '.join(devservers)) 672 self._devserver_args = ['-devservers=%s' % ','.join(devservers)] 673 if self._ephemeraldevserver is not None: 674 self._devserver_args.append('-ephemeraldevserver=%s' % 675 self._ephemeraldevserver) 676 677 def _log_version(self): 678 """Runs the tast command locally to log its version.""" 679 try: 680 utils.run([self._tast_path, '-version'], 681 timeout=self._VERSION_TIMEOUT_SEC, 682 stdout_tee=utils.TEE_TO_LOGS, 683 stderr_tee=utils.TEE_TO_LOGS, 684 stderr_is_expected=True, 685 stdout_level=logging.INFO, 686 stderr_level=logging.ERROR) 687 except error.CmdError as e: 688 logging.error('Failed to log tast version: %s', str(e)) 689 690 def _run_tast(self, 691 subcommand, 692 extra_subcommand_args, 693 test_exprs, 694 timeout_sec, 695 log_stdout=False, 696 ignore_status=False): 697 """Runs the tast command locally to e.g. list available tests or perform 698 testing against the DUT. 699 700 @param subcommand: Subcommand to pass to the tast executable, e.g. 'run' 701 or 'list'. 702 @param extra_subcommand_args: List of additional subcommand arguments. 703 @param test_exprs: Array of strings describing tests to run. 704 @param timeout_sec: Integer timeout for the command in seconds. 705 @param log_stdout: If true, write stdout to log. 706 @param ignore_status: If true, command execution errors are ignored. 707 708 @returns client.common_lib.utils.CmdResult object describing the result. 709 710 @raises error.TestFail if the tast command fails or times out. 711 """ 712 cmd = [ 713 self._tast_path, 714 '-verbose=true', 715 '-logtime=false', 716 subcommand, 717 '-sshretries=%d' % self._SSH_CONNECT_RETRIES, 718 '-downloaddata=%s' % ( 719 'lazy' if self._download_data_lazily else 'batch'), 720 '-totalshards=%s' % self._totalshards, 721 '-shardindex=%s' % self._shardindex, 722 ] 723 if self._f20_container: 724 cmd.extend(['-build=false']) 725 if self._run_private_tests: 726 cmd.append('-downloadprivatebundles=true') 727 elif self._build: 728 cmd.extend([ 729 '-build=true', 730 '-buildbundle=%s' % self._build_bundle, 731 '-checkbuilddeps=false', 732 ]) 733 else: 734 cmd.append('-build=false') 735 if self._ssp: 736 remote_test_runner_path = self._get_path( 737 self._SSP_REMOTE_TEST_RUNNER_PATH) 738 if not os.path.exists(remote_test_runner_path): 739 raise error.TestFail( 740 '%s does not exist (broken SSP?)' % 741 remote_test_runner_path) 742 cmd.extend([ 743 '-remotebundledir=%s' % self._get_path( 744 self._SSP_REMOTE_BUNDLE_DIR), 745 '-remotedatadir=%s' % self._get_path( 746 self._SSP_REMOTE_DATA_DIR), 747 '-remoterunner=%s' % remote_test_runner_path, 748 ]) 749 if subcommand == 'run': 750 cmd.append('-defaultvarsdir=%s' % 751 self._get_path(self._SSP_DEFAULT_VARS_DIR_PATH)) 752 if self._run_private_tests: 753 cmd.append('-downloadprivatebundles=true') 754 if not self._f20_container: 755 cmd.extend(self._devserver_args) 756 cmd.extend(extra_subcommand_args) 757 cmd.append('%s%s' % (self._host.hostname, ':%d' % 758 self._host.port if self._host.port else '')) 759 cmd.extend(test_exprs) 760 761 logging.info('Running %s', 762 ' '.join([utils.sh_quote_word(a) for a in cmd])) 763 try: 764 return utils.run( 765 cmd, 766 ignore_status=ignore_status, 767 timeout=timeout_sec, 768 stdout_tee=(utils.TEE_TO_LOGS if log_stdout else None), 769 stderr_tee=utils.TEE_TO_LOGS, 770 stderr_is_expected=True, 771 stdout_level=logging.INFO, 772 stderr_level=logging.ERROR) 773 except error.CmdError as e: 774 # Run several commands to debug possible network issues. 775 # TODO(b/189332919): Remove this logic once we finish debugging. 776 logging.info('Tast exited abnormally. Running several commands to ' 777 'diagnose possible network issues...') 778 utils.run('time getent ahosts %s' % self._host.hostname, 779 timeout=60, 780 ignore_status=True, 781 stdout_tee=utils.TEE_TO_LOGS, 782 stderr_tee=utils.TEE_TO_LOGS, 783 stderr_is_expected=True, 784 stdout_level=logging.INFO, 785 stderr_level=logging.ERROR) 786 utils.run( 787 'ssh ' 788 # Enable maximum debug logging. 789 '-vvv ' 790 # Disable connection sharing to debug connection issues. 791 '-o ControlPath=none ' 792 # Following arguments were copied from Autotest logs. 793 '-a -x ' 794 '-o StrictHostKeyChecking=no ' 795 '-o UserKnownHostsFile=/dev/null ' 796 '-o BatchMode=yes ' 797 '-o ConnectTimeout=10 ' 798 '-o ConnectionAttempts=3 ' 799 '-l root %s%s true' % 800 ('-p %d ' % self._host.port if self._host.port else '', 801 self._host.hostname), 802 timeout=60, 803 ignore_status=True, 804 stdout_tee=utils.TEE_TO_LOGS, 805 stderr_tee=utils.TEE_TO_LOGS, 806 stderr_is_expected=True, 807 stdout_level=logging.INFO, 808 stderr_level=logging.ERROR) 809 # The tast command's output generally ends with a line describing 810 # the error that was encountered; include it in the first line of 811 # the TestFail exception. Fall back to stderr if stdout is empty (as 812 # is the case with the "list" subcommand, which uses stdout to print 813 # test data). 814 get_last_line = lambda s: s.strip().split('\n')[-1].strip() 815 last_line = (get_last_line(e.result_obj.stdout) or 816 get_last_line(e.result_obj.stderr)) 817 msg = (' (last line: %s)' % last_line) if last_line else '' 818 raise error.TestFail('Failed to run tast%s: %s' % (msg, str(e))) 819 except error.CmdTimeoutError as e: 820 raise error.TestFail('Got timeout while running tast: %s' % str(e)) 821 822 def _ensure_bundles(self): 823 """Runs the tast command to ensure all test bundles are available. 824 825 If private test bundles are available, they are downloaded from cloud 826 storage and installed to the DUT. Otherwise it is no-nop. 827 828 Note that "tast list" also downloads private test bundles if they are 829 missing. Nevertheless we attempt to download them in advance because 830 "tast list" cannot emit detailed logs due to technical limitations and 831 often make it difficult to debug issues related to private test bundle 832 installation. 833 """ 834 logging.info('Downloading private test bundles (if any)') 835 temp_dir = tempfile.mkdtemp() 836 try: 837 args = ['-resultsdir=' + temp_dir] + self._get_cloud_storage_info() 838 for role, dut in sorted(self._companion_duts.items()): 839 args.append('-companiondut=%s:%s' % (role, dut)) 840 841 for var in self._varslist: 842 args.append('-var=%s' % var) 843 844 for file_name in self._test_filter_files: 845 args.append('-testfilterfile=%s' % file_name) 846 847 # Start "tast run" with an attribute expression matching no test 848 # to trigger a private test bundle download. 849 # Note that Tast CLI will exit abnormally when no test matches, 850 # so we set ignore_status=True to avoid throwing TestFail. 851 self._run_tast('run', 852 args, ['("group:none")'], 853 tast._DOWNLOAD_TIMEOUT_SEC, 854 log_stdout=True, 855 ignore_status=True) 856 finally: 857 shutil.rmtree(temp_dir, ignore_errors=True) 858 859 def _get_tests_to_run(self): 860 """Runs the tast command to update the list of tests that will be run. 861 862 @returns False if no tests matched by test_exprs; True otherwise 863 864 @raises error.TestFail if the tast command fails or times out. 865 """ 866 logging.info('Getting list of tests that will be run') 867 args = ['-json=true'] + self._get_cloud_storage_info() 868 result = self._run_tast('list', args, self._test_exprs, 869 self._LIST_TIMEOUT_SEC) 870 try: 871 self._tests_to_run = _encode_json(json.loads( 872 result.stdout.strip())) 873 except ValueError as e: 874 raise error.TestFail('Failed to parse tests: %s' % str(e)) 875 if len(self._tests_to_run) == 0: 876 expr = ' '.join([utils.sh_quote_word(a) for a in self._test_exprs]) 877 logging.warning('No tests matched by %s', expr) 878 return False 879 880 logging.info('Expect to run %d test(s)', len(self._tests_to_run)) 881 882 logging.info('Tests in scope:') 883 for test in self._tests_to_run: 884 logging.info('Test: %s', test['name']) 885 886 return True 887 888 def _run_tests(self): 889 """Runs the tast command to perform testing. 890 891 @raises error.TestFail if the tast command fails or times out (but not 892 if individual tests fail). 893 """ 894 args = [ 895 '-resultsdir=' + self.resultsdir, 896 '-waituntilready=true', 897 '-timeout=' + str(self._max_run_sec), 898 '-continueafterfailure=true', 899 ] 900 args.extend(self._get_servo_args()) 901 args.extend(self._get_rpm_args()) 902 args.extend(self._get_wificell_args()) 903 args.extend(self._get_cloud_storage_info()) 904 args.extend(self._get_firmware_args()) 905 args.extend(self._get_camerabox_args()) 906 if self._retries: 907 args.append('-retries=%d' % self._retries) 908 909 for varsfile in self._varsfiles: 910 args.append('-varsfile=%s' % varsfile) 911 912 for var in self._varslist: 913 args.append('-var=%s' % var) 914 915 if self._maybemissingvars: 916 args.append('-maybemissingvars=%s' % self._maybemissingvars) 917 918 for role, dut in sorted(self._companion_duts.items()): 919 args.append( 920 '-companiondut=%s:%s%s' % 921 (role, dut.hostname, ':%d' % dut.port if dut.port else '')) 922 923 for file in self._test_filter_files: 924 args.append('-testfilterfile=%s' % file) 925 926 logging.info('Running tests with timeout of %d sec', self._max_run_sec) 927 # This option will exclude tests that are requested, but not found in 928 # `tast list` command 929 if self._exclude_missing: 930 tests_to_run_list = [test["name"] for test in self._tests_to_run] 931 self._run_tast('run', 932 args, 933 tests_to_run_list, 934 self._max_run_sec + tast._RUN_EXIT_SEC, 935 log_stdout=True) 936 else: 937 self._run_tast('run', 938 args, 939 self._test_exprs, 940 self._max_run_sec + tast._RUN_EXIT_SEC, 941 log_stdout=True) 942 943 def _read_run_error(self): 944 """Reads a global run error message written by the tast command.""" 945 # The file is only written if a run error occurred. 946 path = os.path.join(self.resultsdir, self._RUN_ERROR_FILENAME) 947 if os.path.exists(path): 948 with open(path, 'r') as f: 949 self._run_error = f.read().strip() 950 951 def maybe_replace(self, test, failed): 952 """ Removes a test from the list of failed results 953 954 @param test: Name of test to remove from failed list 955 @param failed: List of failed tests 956 """ 957 # Remove the result, will take & only count the second result. 958 if test[_KEY_NAME] in failed: 959 failed.remove(test[_KEY_NAME]) 960 961 def _parse_results(self, ignore_missing_file, run_error_msg): 962 """Parses results written by the tast command. 963 964 @param ignore_missing_file: If True, return without raising an exception 965 if the Tast results file is missing. This is used to avoid raising a 966 new error if there was already an earlier error while running the 967 tast process. 968 @param run_error_msg: The error message from Tast when there is an 969 error. It will be None if Tast encounters no errors. 970 971 @raises error.TestFail if results file is missing and 972 ignore_missing_file is False, or one or more tests failed and 973 _ignore_test_failures is false. 974 """ 975 # The file may not exist if "tast run" failed to run. Tests that were 976 # seen from the earlier "tast list" command will be reported as having 977 # missing results. 978 path = os.path.join(self.resultsdir, self._STREAMED_RESULTS_FILENAME) 979 if not os.path.exists(path): 980 if ignore_missing_file: 981 return 982 raise error.TestFail('Results file %s not found' % path) 983 984 failed = set() 985 seen_test_names = set() 986 with open(path, 'r') as f: 987 for line in f: 988 line = line.strip() 989 if not line: 990 continue 991 try: 992 test = _encode_json(json.loads(line)) 993 except ValueError as e: 994 raise error.TestFail('Failed to parse %s: %s' % (path, e)) 995 self._test_results.append(test) 996 if test[_KEY_NAME] in seen_test_names: 997 self.maybe_replace(test, failed) 998 999 name = test[_KEY_NAME] 1000 seen_test_names.add(name) 1001 1002 if test.get(_KEY_ERRORS): 1003 for err in test[_KEY_ERRORS]: 1004 logging.warning('%s: %s', name, err[_KEY_REASON]) 1005 failed.add(name) 1006 else: 1007 # The test will have a zero (i.e. 0001-01-01 00:00:00 UTC) 1008 # end time (preceding the Unix epoch) if it didn't report 1009 # completion. 1010 if _rfc3339_time_to_timestamp(test[_KEY_END]) <= 0: 1011 failed.add(name) 1012 1013 missing = [ 1014 t[_KEY_NAME] for t in self._tests_to_run 1015 if t[_KEY_NAME] not in seen_test_names 1016 ] 1017 1018 if missing: 1019 self._record_missing_tests(missing) 1020 time_str = '%sZ' % datetime.datetime.utcnow().isoformat() 1021 for name in missing: 1022 t = {} 1023 t[_KEY_NAME] = name 1024 t[_KEY_START] = time_str 1025 t[_KEY_END] = time_str 1026 if self._run_error: 1027 t[_KEY_MISSING_REASON] = '%s due to global error: %s' % ( 1028 self._TEST_DID_NOT_RUN_MSG, self._run_error) 1029 elif run_error_msg: 1030 t[_KEY_MISSING_REASON] = run_error_msg 1031 else: 1032 t[_KEY_MISSING_REASON] = self._TEST_DID_NOT_RUN_MSG 1033 self._test_results.append(t) 1034 1035 failure_msg = self._get_failure_message(failed, missing) 1036 if failure_msg: 1037 raise error.TestFail(failure_msg) 1038 1039 def _get_failure_message(self, failed, missing): 1040 """Returns an error message describing failed and/or missing tests. 1041 1042 @param failed: List of string names of Tast tests that failed. 1043 @param missing: List of string names of Tast tests with missing results. 1044 1045 @returns String to be used as error.TestFail message. 1046 """ 1047 def list_tests(names): 1048 """Returns a string listing tests. 1049 1050 @param names: List of string test names. 1051 1052 @returns String listing tests. 1053 """ 1054 s = ' '.join(sorted(names)[:self._MAX_TEST_NAMES_IN_ERROR]) 1055 if len(names) > self._MAX_TEST_NAMES_IN_ERROR: 1056 s += ' ...' 1057 return s 1058 1059 msg = '' 1060 if failed and not self._ignore_test_failures: 1061 msg = '%d failed: %s' % (len(failed), list_tests(failed)) 1062 if missing: 1063 if msg: 1064 msg += '; ' 1065 msg += '%d missing: %s' % (len(missing), list_tests(missing)) 1066 return msg 1067 1068 def _log_all_unique_tests(self): 1069 """Writes entries to the TKO status.log file describing the results of 1070 all tests. 1071 1072 If there are 2 tests with the same name, AND it has an error (failure) 1073 replace the result. 1074 Because: if it has an err AND a second result, its either: 1075 The first attempt is logged and failed and we want to use the 1076 retry result 1077 Or the attempts are out of order, and the already logged attempt is 1078 the second attempt which failed, meaning the first ALSO failed. 1079 So in this case, its still safe to override because we just 1080 need to mark the failure. 1081 The benefit of this is, if the first result is logged and failed, the 1082 retry might have passed, so we want to log that. 1083 1084 """ 1085 seen_test_names = set() 1086 tests_to_log = OrderedDict() 1087 for test_res in self._test_results: 1088 test_name = test_res[_KEY_NAME] 1089 1090 dup_res = tests_to_log.get(test_name) 1091 if not dup_res or dup_res.get(_KEY_ERRORS): 1092 tests_to_log[test_name] = test_res 1093 for test in tests_to_log.values(): 1094 self._log_test(test) 1095 seen_test_names.add(test[_KEY_NAME]) 1096 1097 def _log_test(self, test): 1098 """Writes events to the TKO status.log file describing the results from 1099 a Tast test. 1100 1101 @param test: A JSON object corresponding to a single test from a Tast 1102 results.json file. See TestResult in 1103 src/platform/tast/src/chromiumos/cmd/tast/run/results.go for 1104 details. 1105 """ 1106 name = test[_KEY_NAME] 1107 start_time = _rfc3339_time_to_timestamp(test[_KEY_START]) 1108 end_time = _rfc3339_time_to_timestamp(test[_KEY_END]) 1109 1110 test_reported_errors = bool(test.get(_KEY_ERRORS)) 1111 test_skipped = bool(test.get(_KEY_SKIP_REASON)) 1112 test_not_run = bool(test.get(_KEY_MISSING_REASON)) 1113 # The test will have a zero (i.e. 0001-01-01 00:00:00 UTC) end time 1114 # (preceding the Unix epoch) if it didn't report completion. 1115 test_finished = end_time > 0 1116 1117 # Avoid reporting tests that were skipped. 1118 if test_skipped and not test_reported_errors and not self._report_skipped: 1119 return 1120 1121 # Look for magic error _TEST_DID_NOT_RUN_MSG and mark test as not run. 1122 for err in test.get(_KEY_ERRORS) or []: 1123 if err[_KEY_REASON] == self._TEST_DID_NOT_RUN_MSG: 1124 test_not_run = True 1125 test[_KEY_MISSING_REASON] = self._TEST_DID_NOT_RUN_MSG 1126 1127 self._log_test_event(self._JOB_STATUS_START, name, start_time) 1128 1129 if test_not_run: 1130 self._log_test_event(self._JOB_STATUS_NOSTATUS, name, end_time, 1131 test[_KEY_MISSING_REASON]) 1132 end_status = self._JOB_STATUS_END_NOSTATUS 1133 elif test_skipped and not test_reported_errors and self._report_skipped: 1134 self._log_test_event(self._JOB_STATUS_SKIP, name, end_time, 1135 test.get(_KEY_SKIP_REASON)) 1136 end_status = self._JOB_STATUS_END_SKIP 1137 elif test_finished and not test_reported_errors: 1138 self._log_test_event(self._JOB_STATUS_GOOD, name, end_time) 1139 end_status = self._JOB_STATUS_END_GOOD 1140 else: 1141 # The previous START event automatically increases the log 1142 # indentation level until the following END event. 1143 if test_reported_errors: 1144 for err in test[_KEY_ERRORS]: 1145 error_time = _rfc3339_time_to_timestamp(err[_KEY_TIME]) 1146 self._log_test_event(self._JOB_STATUS_FAIL, name, 1147 error_time, err[_KEY_REASON]) 1148 if not test_finished: 1149 # If a run-level error was encountered (e.g. the SSH connection 1150 # to the DUT was lost), report it here to make it easier to see 1151 # the reason why the test didn't finish. 1152 if self._run_error: 1153 self._log_test_event(self._JOB_STATUS_FAIL, name, 1154 start_time, self._run_error) 1155 self._log_test_event(self._JOB_STATUS_FAIL, name, start_time, 1156 self._TEST_DID_NOT_FINISH_MSG) 1157 end_time = start_time 1158 1159 end_status = self._JOB_STATUS_END_FAIL 1160 1161 self._log_test_event(end_status, name, end_time) 1162 1163 def _log_test_event(self, status_code, test_name, timestamp, message=''): 1164 """Logs a single event to the TKO status.log file. 1165 1166 @param status_code: Event status code, e.g. 'END GOOD'. See 1167 client/common_lib/log.py for accepted values. 1168 @param test_name: Tast test name, e.g. 'ui.ChromeLogin'. 1169 @param timestamp: Event timestamp (as seconds since Unix epoch). 1170 @param message: Optional human-readable message. 1171 """ 1172 full_name = self._TEST_NAME_PREFIX + test_name 1173 # The TKO parser code chokes on floating-point timestamps. 1174 entry = base_job.status_log_entry(status_code, 1175 None, 1176 full_name, 1177 message, 1178 None, 1179 timestamp=int(timestamp)) 1180 self.job.record_entry(entry, False) 1181 1182 def _record_missing_tests(self, missing): 1183 """Records tests with missing results in job keyval file. 1184 1185 @param missing: List of string names of Tast tests with missing results. 1186 """ 1187 keyvals = {} 1188 for i, name in enumerate(sorted(missing)): 1189 keyvals['%s%d' % (self._MISSING_TEST_KEYVAL_PREFIX, i)] = name 1190 utils.write_keyval(self.job.resultdir, keyvals) 1191 1192 1193class _LessBrokenParserInfo(dateutil.parser.parserinfo): 1194 """dateutil.parser.parserinfo that interprets years before 100 correctly. 1195 1196 Our version of dateutil.parser.parse misinteprets an unambiguous string like 1197 '0001-01-01T00:00:00Z' as having a two-digit year, which it then converts to 1198 2001. This appears to have been fixed by 1199 https://github.com/dateutil/dateutil/commit/fc696254. This parserinfo 1200 implementation always honors the provided year to prevent this from 1201 happening. 1202 """ 1203 def convertyear(self, year, century_specified=False): 1204 """Overrides convertyear in dateutil.parser.parserinfo.""" 1205 return int(year) 1206 1207 1208def _rfc3339_time_to_timestamp(time_str): 1209 """Converts an RFC3339 time into a Unix timestamp. 1210 1211 @param time_str: RFC3339-compatible time, e.g. 1212 '2018-02-25T07:45:35.916929332-07:00'. 1213 1214 @returns Float number of seconds since the Unix epoch. Negative if the time 1215 precedes the epoch. 1216 """ 1217 dt = dateutil.parser.parse(time_str, parserinfo=_LessBrokenParserInfo()) 1218 return (dt - _UNIX_EPOCH).total_seconds() 1219