1# Lint as: python2, python3 2# Copyright 2007 Google Inc. Released under the GPL v2 3#pylint: disable-msg=C0111 4 5from __future__ import absolute_import 6from __future__ import division 7from __future__ import print_function 8 9import glob 10import logging 11import os 12import re 13import sys 14import tempfile 15import time 16import traceback 17 18import common 19from autotest_lib.client.bin.result_tools import runner as result_tools_runner 20from autotest_lib.client.common_lib import autotemp 21from autotest_lib.client.common_lib import base_job 22from autotest_lib.client.common_lib import error 23from autotest_lib.client.common_lib import global_config 24from autotest_lib.client.common_lib import packages 25from autotest_lib.client.common_lib import utils as client_utils 26from autotest_lib.server import installable_object 27from autotest_lib.server import utils 28from autotest_lib.server import utils as server_utils 29from autotest_lib.server.cros.dynamic_suite.constants import JOB_REPO_URL 30import six 31from six.moves import map 32 33 34try: 35 from chromite.lib import metrics 36except ImportError: 37 metrics = client_utils.metrics_mock 38 39 40# This is assumed to be the value by tests, do not change it. 41OFFLOAD_ENVVAR = "SYNCHRONOUS_OFFLOAD_DIR" 42 43AUTOTEST_SVN = 'svn://test.kernel.org/autotest/trunk/client' 44AUTOTEST_HTTP = 'http://test.kernel.org/svn/autotest/trunk/client' 45 46_CONFIG = global_config.global_config 47AUTOSERV_PREBUILD = _CONFIG.get_config_value( 48 'AUTOSERV', 'enable_server_prebuild', type=bool, default=False) 49 50# Match on a line like this: 51# FAIL test_name test_name timestamp=1 localtime=Nov 15 12:43:10 <fail_msg> 52_FAIL_STATUS_RE = re.compile( 53 r'\s*FAIL.*localtime=.*\s*.*\s*[0-9]+:[0-9]+:[0-9]+\s*(?P<fail_msg>.*)') 54 55LOG_BUFFER_SIZE_BYTES = 64 56 57 58class AutodirNotFoundError(Exception): 59 """No Autotest installation could be found.""" 60 61 62class AutotestFailure(Exception): 63 """Gereric exception class for failures during a test run.""" 64 65 66class AutotestAbort(AutotestFailure): 67 """ 68 AutotestAborts are thrown when the DUT seems fine, 69 and the test doesn't give us an explicit reason for 70 failure; In this case we have no choice but to abort. 71 """ 72 73 74class AutotestDeviceError(AutotestFailure): 75 """ 76 Exceptions that inherit from AutotestDeviceError 77 are thrown when we can determine the current 78 state of the DUT and conclude that it probably 79 lead to the test failing; these exceptions lead 80 to failures instead of aborts. 81 """ 82 83 84class AutotestDeviceNotPingable(AutotestDeviceError): 85 """Error for when a DUT becomes unpingable.""" 86 87 88class AutotestDeviceNotSSHable(AutotestDeviceError): 89 """Error for when a DUT is pingable but not SSHable.""" 90 91 92class AutotestDeviceRebooted(AutotestDeviceError): 93 """Error for when a DUT rebooted unexpectedly.""" 94 95 96class Autotest(installable_object.InstallableObject): 97 """ 98 This class represents the Autotest program. 99 100 Autotest is used to run tests automatically and collect the results. 101 It also supports profilers. 102 103 Implementation details: 104 This is a leaf class in an abstract class hierarchy, it must 105 implement the unimplemented methods in parent classes. 106 """ 107 108 def __init__(self, host=None): 109 self.host = host 110 self.got = False 111 self.installed = False 112 self.serverdir = utils.get_server_dir() 113 super(Autotest, self).__init__() 114 115 116 install_in_tmpdir = False 117 @classmethod 118 def set_install_in_tmpdir(cls, flag): 119 """ Sets a flag that controls whether or not Autotest should by 120 default be installed in a "standard" directory (e.g. 121 /home/autotest, /usr/local/autotest) or a temporary directory. """ 122 cls.install_in_tmpdir = flag 123 124 125 @classmethod 126 def get_client_autodir_paths(cls, host): 127 return global_config.global_config.get_config_value( 128 'AUTOSERV', 'client_autodir_paths', type=list) 129 130 131 @classmethod 132 def get_installed_autodir(cls, host): 133 """ 134 Find where the Autotest client is installed on the host. 135 @returns an absolute path to an installed Autotest client root. 136 @raises AutodirNotFoundError if no Autotest installation can be found. 137 """ 138 autodir = host.get_autodir() 139 if autodir: 140 logging.debug('Using existing host autodir: %s', autodir) 141 return autodir 142 143 for path in Autotest.get_client_autodir_paths(host): 144 try: 145 autotest_binary = os.path.join(path, 'bin', 'autotest') 146 host.run('test -x %s' % utils.sh_escape(autotest_binary)) 147 host.run('test -w %s' % utils.sh_escape(path)) 148 logging.debug('Found existing autodir at %s', path) 149 return path 150 except error.GenericHostRunError: 151 logging.debug('%s does not exist on %s', autotest_binary, 152 host.hostname) 153 raise AutodirNotFoundError 154 155 156 @classmethod 157 def get_install_dir(cls, host): 158 """ 159 Determines the location where autotest should be installed on 160 host. If self.install_in_tmpdir is set, it will return a unique 161 temporary directory that autotest can be installed in. Otherwise, looks 162 for an existing installation to use; if none is found, looks for a 163 usable directory in the global config client_autodir_paths. 164 """ 165 try: 166 install_dir = cls.get_installed_autodir(host) 167 except AutodirNotFoundError: 168 install_dir = cls._find_installable_dir(host) 169 170 if cls.install_in_tmpdir: 171 return host.get_tmp_dir(parent=install_dir) 172 return install_dir 173 174 175 @classmethod 176 def _find_installable_dir(cls, host): 177 client_autodir_paths = cls.get_client_autodir_paths(host) 178 for path in client_autodir_paths: 179 try: 180 host.run('mkdir -p %s' % utils.sh_escape(path)) 181 host.run('test -w %s' % utils.sh_escape(path)) 182 return path 183 except error.AutoservRunError: 184 logging.debug('Failed to create %s', path) 185 metrics.Counter( 186 'chromeos/autotest/errors/no_autotest_install_path').increment( 187 fields={'dut_host_name': host.hostname}) 188 raise error.AutoservInstallError( 189 'Unable to find a place to install Autotest; tried %s' % 190 ', '.join(client_autodir_paths)) 191 192 193 def get_fetch_location(self): 194 """Generate list of locations where autotest can look for packages. 195 196 Hosts are tagged with an attribute containing the URL from which 197 to source packages when running a test on that host. 198 199 @returns the list of candidate locations to check for packages. 200 """ 201 c = global_config.global_config 202 repos = c.get_config_value("PACKAGES", 'fetch_location', type=list, 203 default=[]) 204 repos.reverse() 205 206 if not server_utils.is_inside_chroot(): 207 # Only try to get fetch location from host attribute if the 208 # test is not running inside chroot. 209 # 210 # Look for the repo url via the host attribute. If we are 211 # not running with a full AFE autoserv will fall back to 212 # serving packages itself from whatever source version it is 213 # sync'd to rather than using the proper artifacts for the 214 # build on the host. 215 found_repo = self._get_fetch_location_from_host_attribute() 216 if found_repo is not None: 217 # Add our new repo to the end, the package manager will 218 # later reverse the list of repositories resulting in ours 219 # being first 220 repos.append(found_repo) 221 222 return repos 223 224 225 def _get_fetch_location_from_host_attribute(self): 226 """Get repo to use for packages from host attribute, if possible. 227 228 Hosts are tagged with an attribute containing the URL 229 from which to source packages when running a test on that host. 230 If self.host is set, attempt to look this attribute in the host info. 231 232 @returns value of the 'job_repo_url' host attribute, if present. 233 """ 234 if not self.host: 235 return None 236 237 try: 238 info = self.host.host_info_store.get() 239 except Exception as e: 240 # TODO(pprabhu): We really want to catch host_info.StoreError here, 241 # but we can't import host_info from this module. 242 # - autotest_lib.hosts.host_info pulls in (naturally) 243 # autotest_lib.hosts.__init__ 244 # - This pulls in all the host classes ever defined 245 # - That includes abstract_ssh, which depends on autotest 246 logging.warning('Failed to obtain host info: %r', e) 247 logging.warning('Skipping autotest fetch location based on %s', 248 JOB_REPO_URL) 249 return None 250 251 job_repo_url = info.attributes.get(JOB_REPO_URL, '') 252 if not job_repo_url: 253 logging.warning("No %s for %s", JOB_REPO_URL, self.host) 254 return None 255 256 logging.info('Got job repo url from host attributes: %s', 257 job_repo_url) 258 return job_repo_url 259 260 261 def install(self, host=None, autodir=None, use_packaging=True): 262 """Install autotest. If |host| is not None, stores it in |self.host|. 263 264 @param host A Host instance on which autotest will be installed 265 @param autodir Location on the remote host to install to 266 @param use_packaging Enable install modes that use the packaging system. 267 268 """ 269 if host: 270 self.host = host 271 self._install(host=host, autodir=autodir, use_packaging=use_packaging) 272 273 274 def install_full_client(self, host=None, autodir=None): 275 self._install(host=host, autodir=autodir, use_autoserv=False, 276 use_packaging=False) 277 278 279 def install_no_autoserv(self, host=None, autodir=None): 280 self._install(host=host, autodir=autodir, use_autoserv=False) 281 282 283 def _install_using_packaging(self, host, autodir): 284 repos = self.get_fetch_location() 285 if not repos: 286 raise error.PackageInstallError("No repos to install an " 287 "autotest client from") 288 # Make sure devserver has the autotest package staged 289 host.verify_job_repo_url() 290 pkgmgr = packages.PackageManager(autodir, hostname=host.hostname, 291 repo_urls=repos, 292 do_locking=False, 293 run_function=host.run, 294 run_function_dargs=dict(timeout=600)) 295 # The packages dir is used to store all the packages that 296 # are fetched on that client. (for the tests,deps etc. 297 # too apart from the client) 298 pkg_dir = os.path.join(autodir, 'packages') 299 # clean up the autodir except for the packages and result_tools 300 # directory. 301 host.run('cd %s && ls | grep -v "^packages$" | grep -v "^result_tools$"' 302 ' | xargs rm -rf && rm -rf .[!.]*' % autodir) 303 pkgmgr.install_pkg('autotest', 'client', pkg_dir, autodir, 304 preserve_install_dir=True) 305 self.installed = True 306 307 308 def _install_using_send_file(self, host, autodir): 309 dirs_to_exclude = set(["tests", "site_tests", "deps", "profilers", 310 "packages"]) 311 light_files = [os.path.join(self.source_material, f) 312 for f in os.listdir(self.source_material) 313 if f not in dirs_to_exclude] 314 host.send_file(light_files, autodir, delete_dest=True) 315 316 # create empty dirs for all the stuff we excluded 317 commands = [] 318 for path in dirs_to_exclude: 319 abs_path = os.path.join(autodir, path) 320 abs_path = utils.sh_escape(abs_path) 321 commands.append("mkdir -p '%s'" % abs_path) 322 commands.append("touch '%s'/__init__.py" % abs_path) 323 host.run(';'.join(commands)) 324 325 326 def _install(self, host=None, autodir=None, use_autoserv=True, 327 use_packaging=True): 328 """ 329 Install autotest. If get() was not called previously, an 330 attempt will be made to install from the autotest svn 331 repository. 332 333 @param host A Host instance on which autotest will be installed 334 @param autodir Location on the remote host to install to 335 @param use_autoserv Enable install modes that depend on the client 336 running with the autoserv harness 337 @param use_packaging Enable install modes that use the packaging system 338 339 @exception AutoservError if a tarball was not specified and 340 the target host does not have svn installed in its path 341 """ 342 if not host: 343 host = self.host 344 if not self.got: 345 self.get() 346 host.wait_up(timeout=30) 347 host.setup() 348 logging.info("Installing autotest on %s", host.hostname) 349 350 # set up the autotest directory on the remote machine 351 if not autodir: 352 autodir = self.get_install_dir(host) 353 logging.info('Using installation dir %s', autodir) 354 host.set_autodir(autodir) 355 host.run('mkdir -p %s' % utils.sh_escape(autodir)) 356 357 # make sure there are no files in $AUTODIR/results 358 results_path = os.path.join(autodir, 'results') 359 host.run('rm -rf %s/*' % utils.sh_escape(results_path), 360 ignore_status=True) 361 362 # Fetch the autotest client from the nearest repository 363 if use_packaging: 364 try: 365 self._install_using_packaging(host, autodir) 366 logging.info("Installation of autotest completed using the " 367 "packaging system.") 368 return 369 except (error.PackageInstallError, error.AutoservRunError, 370 global_config.ConfigError) as e: 371 logging.info("Could not install autotest using the packaging " 372 "system: %s. Trying other methods", e) 373 else: 374 # Delete the package checksum file to force dut updating local 375 # packages. 376 command = ('rm -f "%s"' % 377 (os.path.join(autodir, packages.CHECKSUM_FILE))) 378 host.run(command) 379 380 # try to install from file or directory 381 if self.source_material: 382 c = global_config.global_config 383 supports_autoserv_packaging = c.get_config_value( 384 "PACKAGES", "serve_packages_from_autoserv", type=bool) 385 # Copy autotest recursively 386 if supports_autoserv_packaging and use_autoserv: 387 self._install_using_send_file(host, autodir) 388 else: 389 host.send_file(self.source_material, autodir, delete_dest=True) 390 logging.info("Installation of autotest completed from %s", 391 self.source_material) 392 self.installed = True 393 else: 394 # if that fails try to install using svn 395 if utils.run('which svn').exit_status: 396 raise error.AutoservError( 397 'svn not found on target machine: %s' % 398 host.hostname) 399 try: 400 host.run('svn checkout %s %s' % (AUTOTEST_SVN, autodir)) 401 except error.AutoservRunError as e: 402 host.run('svn checkout %s %s' % (AUTOTEST_HTTP, autodir)) 403 logging.info("Installation of autotest completed using SVN.") 404 self.installed = True 405 406 # TODO(milleral): http://crbug.com/258161 407 # Send over the most recent global_config.ini after installation if one 408 # is available. 409 # This code is a bit duplicated from 410 # _Run._create_client_config_file, but oh well. 411 if self.installed and self.source_material: 412 self._send_shadow_config() 413 414 # sync the disk, to avoid getting 0-byte files if a test resets the DUT 415 host.run(os.path.join(autodir, 'bin', 'fs_sync.py'), 416 ignore_status=True) 417 418 def _send_shadow_config(self): 419 logging.info('Installing updated global_config.ini.') 420 destination = os.path.join(self.host.get_autodir(), 421 'global_config.ini') 422 with tempfile.NamedTemporaryFile(mode='w') as client_config: 423 config = global_config.global_config 424 client_section = config.get_section_values('CLIENT') 425 client_section.write(client_config) 426 client_config.flush() 427 self.host.send_file(client_config.name, destination) 428 429 430 def uninstall(self, host=None): 431 """ 432 Uninstall (i.e. delete) autotest. Removes the autotest client install 433 from the specified host. 434 435 @params host a Host instance from which the client will be removed 436 """ 437 if not self.installed: 438 return 439 if not host: 440 host = self.host 441 autodir = host.get_autodir() 442 if not autodir: 443 return 444 445 # perform the actual uninstall 446 host.run("rm -rf %s" % utils.sh_escape(autodir), ignore_status=True) 447 host.set_autodir(None) 448 self.installed = False 449 450 451 def get(self, location=None): 452 if not location: 453 location = os.path.join(self.serverdir, '../client') 454 location = os.path.abspath(location) 455 installable_object.InstallableObject.get(self, location) 456 self.got = True 457 458 459 def run(self, control_file, results_dir='.', host=None, timeout=None, 460 tag=None, parallel_flag=False, background=False, 461 client_disconnect_timeout=None, use_packaging=True): 462 """ 463 Run an autotest job on the remote machine. 464 465 @param control_file: An open file-like-obj of the control file. 466 @param results_dir: A str path where the results should be stored 467 on the local filesystem. 468 @param host: A Host instance on which the control file should 469 be run. 470 @param timeout: Maximum number of seconds to wait for the run or None. 471 @param tag: Tag name for the client side instance of autotest. 472 @param parallel_flag: Flag set when multiple jobs are run at the 473 same time. 474 @param background: Indicates that the client should be launched as 475 a background job; the code calling run will be responsible 476 for monitoring the client and collecting the results. 477 @param client_disconnect_timeout: Seconds to wait for the remote host 478 to come back after a reboot. Defaults to the host setting for 479 DEFAULT_REBOOT_TIMEOUT. 480 481 @raises AutotestRunError: If there is a problem executing 482 the control file. 483 """ 484 host = self._get_host_and_setup(host, use_packaging=use_packaging) 485 logging.debug('Autotest job starts on remote host: %s', 486 host.hostname) 487 results_dir = os.path.abspath(results_dir) 488 489 if client_disconnect_timeout is None: 490 client_disconnect_timeout = host.DEFAULT_REBOOT_TIMEOUT 491 492 if tag: 493 results_dir = os.path.join(results_dir, tag) 494 495 atrun = _Run(host, results_dir, tag, parallel_flag, background) 496 self._do_run(control_file, results_dir, host, atrun, timeout, 497 client_disconnect_timeout, use_packaging=use_packaging) 498 499 500 def _get_host_and_setup(self, host, use_packaging=True): 501 if not host: 502 host = self.host 503 if not self.installed: 504 self.install(host, use_packaging=use_packaging) 505 506 host.wait_up(timeout=30) 507 return host 508 509 510 def _do_run(self, control_file, results_dir, host, atrun, timeout, 511 client_disconnect_timeout, use_packaging=True): 512 try: 513 atrun.verify_machine() 514 except: 515 logging.error("Verify failed on %s. Reinstalling autotest", 516 host.hostname) 517 self.install(host) 518 atrun.verify_machine() 519 debug = os.path.join(results_dir, 'debug') 520 try: 521 os.makedirs(debug) 522 except Exception: 523 pass 524 525 delete_file_list = [atrun.remote_control_file, 526 atrun.remote_control_file + '.state', 527 atrun.manual_control_file, 528 atrun.manual_control_file + '.state'] 529 cmd = ';'.join('rm -f ' + control for control in delete_file_list) 530 host.run(cmd, ignore_status=True) 531 532 tmppath = utils.get(control_file, local_copy=True) 533 534 # build up the initialization prologue for the control file 535 prologue_lines = [] 536 537 # Add the additional user arguments 538 prologue_lines.append("args = %r\n" % self.job.args) 539 540 # If the packaging system is being used, add the repository list. 541 repos = None 542 try: 543 if use_packaging: 544 repos = self.get_fetch_location() 545 prologue_lines.append('job.add_repository(%s)\n' % repos) 546 else: 547 logging.debug('use_packaging is set to False, do not add any ' 548 'repository.') 549 except global_config.ConfigError as e: 550 # If repos is defined packaging is enabled so log the error 551 if repos: 552 logging.error(e) 553 554 # on full-size installs, turn on any profilers the server is using 555 if not atrun.background: 556 running_profilers = six.iteritems(host.job.profilers.add_log) 557 for profiler, (args, dargs) in running_profilers: 558 call_args = [repr(profiler)] 559 call_args += [repr(arg) for arg in args] 560 call_args += ["%s=%r" % item for item in six.iteritems(dargs)] 561 prologue_lines.append("job.profilers.add(%s)\n" 562 % ", ".join(call_args)) 563 cfile = "".join(prologue_lines) 564 565 cfile += open(tmppath).read() 566 open(tmppath, "w").write(cfile) 567 568 # Create and copy state file to remote_control_file + '.state' 569 state_file = host.job.preprocess_client_state() 570 host.send_file(state_file, atrun.remote_control_file + '.init.state') 571 os.remove(state_file) 572 573 # Copy control_file to remote_control_file on the host 574 host.send_file(tmppath, atrun.remote_control_file) 575 if os.path.abspath(tmppath) != os.path.abspath(control_file): 576 os.remove(tmppath) 577 578 atrun.execute_control( 579 timeout=timeout, 580 client_disconnect_timeout=client_disconnect_timeout) 581 582 583 @staticmethod 584 def extract_test_failure_msg(failure_status_line): 585 """Extract the test failure message from the status line. 586 587 @param failure_status_line: String of test failure status line, it will 588 look like: 589 FAIL <test name> <test name> timestamp=<ts> localtime=<lt> <reason> 590 591 @returns String of the reason, return empty string if we can't regex out 592 reason. 593 """ 594 fail_msg = '' 595 match = _FAIL_STATUS_RE.match(failure_status_line) 596 if match: 597 fail_msg = match.group('fail_msg') 598 return fail_msg 599 600 601 @classmethod 602 def _check_client_test_result(cls, host, test_name): 603 """ 604 Check result of client test. 605 Autotest will store results in the file name status. 606 We check that second to last line in that file begins with 'END GOOD' 607 608 @raises TestFail: If client test does not pass. 609 """ 610 client_result_dir = '%s/results/default' % host.autodir 611 command = 'tail -2 %s/status | head -1' % client_result_dir 612 status = host.run(command).stdout.strip() 613 logging.info(status) 614 if status[:8] != 'END GOOD': 615 test_fail_status_line_cmd = ( 616 'grep "^\s*FAIL\s*%s" %s/status | tail -n 1' % 617 (test_name, client_result_dir)) 618 test_fail_msg = cls.extract_test_failure_msg( 619 host.run(test_fail_status_line_cmd).stdout.strip()) 620 test_fail_msg_reason = ('' if not test_fail_msg 621 else ' (reason: %s)' % test_fail_msg) 622 test_fail_status = '%s client test did not pass%s.' % ( 623 test_name, test_fail_msg_reason) 624 raise error.TestFail(test_fail_status) 625 626 627 def run_timed_test(self, test_name, results_dir='.', host=None, 628 timeout=None, parallel_flag=False, background=False, 629 client_disconnect_timeout=None, *args, **dargs): 630 """ 631 Assemble a tiny little control file to just run one test, 632 and run it as an autotest client-side test 633 """ 634 if not host: 635 host = self.host 636 if not self.installed: 637 self.install(host) 638 639 opts = ["%s=%s" % (o[0], repr(o[1])) for o in dargs.items()] 640 cmd = ", ".join([repr(test_name)] + list(map(repr, args)) + opts) 641 control = "job.run_test(%s)\n" % cmd 642 self.run(control, results_dir, host, timeout=timeout, 643 parallel_flag=parallel_flag, background=background, 644 client_disconnect_timeout=client_disconnect_timeout) 645 646 if dargs.get('check_client_result', False): 647 self._check_client_test_result(host, test_name) 648 649 650 def run_test(self, test_name, results_dir='.', host=None, 651 parallel_flag=False, background=False, 652 client_disconnect_timeout=None, *args, **dargs): 653 self.run_timed_test(test_name, results_dir, host, timeout=None, 654 parallel_flag=parallel_flag, background=background, 655 client_disconnect_timeout=client_disconnect_timeout, 656 *args, **dargs) 657 658 659 def run_static_method(self, module, method, results_dir='.', host=None, 660 *args): 661 """Runs a non-instance method with |args| from |module| on the client. 662 663 This method runs a static/class/module autotest method on the client. 664 For example: 665 run_static_method("autotest_lib.client.cros.cros_ui", "reboot") 666 667 Will run autotest_lib.client.cros.cros_ui.reboot() on the client. 668 669 @param module: module name as you would refer to it when importing in a 670 control file. e.g. autotest_lib.client.common_lib.module_name. 671 @param method: the method you want to call. 672 @param results_dir: A str path where the results should be stored 673 on the local filesystem. 674 @param host: A Host instance on which the control file should 675 be run. 676 @param args: args to pass to the method. 677 """ 678 control = "\n".join(["import %s" % module, 679 "%s.%s(%s)\n" % (module, method, 680 ','.join(map(repr, args)))]) 681 self.run(control, results_dir=results_dir, host=host) 682 683 684class _Run(object): 685 """ 686 Represents a run of autotest control file. This class maintains 687 all the state necessary as an autotest control file is executed. 688 689 It is not intended to be used directly, rather control files 690 should be run using the run method in Autotest. 691 """ 692 def __init__(self, host, results_dir, tag, parallel_flag, background): 693 self.host = host 694 self.results_dir = results_dir 695 self.tag = tag 696 self.parallel_flag = parallel_flag 697 self.background = background 698 self.autodir = Autotest.get_installed_autodir(self.host) 699 control = os.path.join(self.autodir, 'control') 700 if tag: 701 control += '.' + tag 702 self.manual_control_file = control 703 self.remote_control_file = control + '.autoserv' 704 self.config_file = os.path.join(self.autodir, 'global_config.ini') 705 706 707 def verify_machine(self): 708 binary = os.path.join(self.autodir, 'bin/autotest') 709 at_check = "test -e {} && echo True || echo False".format(binary) 710 if not self.parallel_flag: 711 tmpdir = os.path.join(self.autodir, 'tmp') 712 download = os.path.join(self.autodir, 'tests/download') 713 at_check += "; umount {}; umount {}".format(tmpdir, download) 714 # Check if the test dir is missing. 715 if "False" in str(self.host.run(at_check, ignore_status=True).stdout): 716 raise error.AutoservInstallError( 717 "Autotest does not appear to be installed") 718 719 720 721 def get_base_cmd_args(self, section): 722 args = ['--verbose'] 723 if section > 0: 724 args.append('-c') 725 if self.tag: 726 args.append('-t %s' % self.tag) 727 if self.host.job.use_external_logging(): 728 args.append('-l') 729 if self.host.hostname: 730 args.append('--hostname=%s' % self.host.hostname) 731 args.append('--user=%s' % self.host.job.user) 732 733 args.append(self.remote_control_file) 734 return args 735 736 737 def get_background_cmd(self, section): 738 cmd = ['nohup', os.path.join(self.autodir, 'bin/autotest_client')] 739 cmd += self.get_base_cmd_args(section) 740 cmd += ['>/dev/null', '2>/dev/null', '&'] 741 return ' '.join(cmd) 742 743 744 def get_daemon_cmd(self, section, monitor_dir): 745 cmd = ['nohup', os.path.join(self.autodir, 'bin/autotestd'), 746 monitor_dir, '-H autoserv'] 747 cmd += self.get_base_cmd_args(section) 748 cmd += ['>/dev/null', '2>/dev/null', '&'] 749 return ' '.join(cmd) 750 751 752 def get_monitor_cmd(self, monitor_dir, stdout_read, stderr_read): 753 cmd = [os.path.join(self.autodir, 'bin', 'autotestd_monitor'), 754 monitor_dir, str(stdout_read), str(stderr_read)] 755 return ' '.join(cmd) 756 757 758 def get_client_log(self): 759 """Find what the "next" client.* prefix should be 760 761 @returns A string of the form client.INTEGER that should be prefixed 762 to all client debug log files. 763 """ 764 max_digit = -1 765 debug_dir = os.path.join(self.results_dir, 'debug') 766 client_logs = glob.glob(os.path.join(debug_dir, 'client.*.*')) 767 for log in client_logs: 768 _, number, _ = log.split('.', 2) 769 if number.isdigit(): 770 max_digit = max(max_digit, int(number)) 771 return 'client.%d' % (max_digit + 1) 772 773 774 def copy_client_config_file(self, client_log_prefix=None): 775 """ 776 Create and copy the client config file based on the server config. 777 778 @param client_log_prefix: Optional prefix to prepend to log files. 779 """ 780 client_config_file = self._create_client_config_file(client_log_prefix) 781 self.host.send_file(client_config_file, self.config_file) 782 os.remove(client_config_file) 783 784 785 def _create_client_config_file(self, client_log_prefix=None): 786 """ 787 Create a temporary file with the [CLIENT] section configuration values 788 taken from the server global_config.ini. 789 790 @param client_log_prefix: Optional prefix to prepend to log files. 791 792 @return: Path of the temporary file generated. 793 """ 794 config = global_config.global_config.get_section_values('CLIENT') 795 if client_log_prefix: 796 config.set('CLIENT', 'default_logging_name', client_log_prefix) 797 return self._create_aux_file(config.write) 798 799 800 def _create_aux_file(self, func, *args): 801 """ 802 Creates a temporary file and writes content to it according to a 803 content creation function. The file object is appended to *args, which 804 is then passed to the content creation function 805 806 @param func: Function that will be used to write content to the 807 temporary file. 808 @param *args: List of parameters that func takes. 809 @return: Path to the temporary file that was created. 810 """ 811 fd, path = tempfile.mkstemp(dir=self.host.job.tmpdir) 812 aux_file = os.fdopen(fd, "w") 813 try: 814 list_args = list(args) 815 list_args.append(aux_file) 816 func(*list_args) 817 finally: 818 aux_file.close() 819 return path 820 821 822 @staticmethod 823 def is_client_job_finished(last_line): 824 return bool(re.match(r'^\t*END .*\t[\w.-]+\t[\w.-]+\t.*$', last_line)) 825 826 827 @staticmethod 828 def is_client_job_rebooting(last_line): 829 return bool(re.match(r'^\t*GOOD\t[\w.-]+\treboot\.start.*$', last_line)) 830 831 832 # Roughly ordered list from concrete to less specific reboot causes. 833 _failure_reasons = [ 834 # Try to find possible reasons leading towards failure. 835 ('ethernet recovery methods have failed. Rebooting.', 836 'dead ethernet dongle crbug/1031035'), 837 # GPU hangs are not always recovered from. 838 ('[drm:amdgpu_job_timedout] \*ERROR\* ring gfx timeout', 839 'drm ring gfx timeout'), 840 ('[drm:do_aquire_global_lock] \*ERROR(.*)hw_done or flip_done timed', 841 'drm hw/flip timeout'), 842 ('[drm:i915_hangcheck_hung] \*ERROR\* Hangcheck(.*)GPU hung', 843 'drm GPU hung'), 844 # TODO(ihf): try to get a better magic signature for kernel crashes. 845 ('BUG: unable to handle kernel paging request', 'kernel paging'), 846 ('Kernel panic - not syncing: Out of memory', 'kernel out of memory'), 847 ('Kernel panic - not syncing', 'kernel panic'), 848 # Fish for user mode killing OOM messages. Shows unstable system. 849 ('out_of_memory', 'process out of memory'), 850 # Reboot was bad enough to have truncated the logs. 851 ('crash_reporter(.*)Stored kcrash', 'kcrash'), 852 ('crash_reporter(.*)Last shutdown was not clean', 'not clean'), 853 ] 854 855 def _diagnose_reboot(self): 856 """ 857 Runs diagnostic check on a rebooted DUT. 858 859 TODO(ihf): if this analysis is useful consider moving the code to the 860 DUT into a script and call it from here. This is more 861 powerful and might be cleaner to grow in functionality. But 862 it may also be less robust if stateful is damaged during the 863 reboot. 864 865 @returns msg describing reboot reason. 866 """ 867 reasons = [] 868 for (message, bucket) in self._failure_reasons: 869 # Use -a option for grep to avoid "binary file" warning to stdout. 870 # The grep -v is added to not match itself in the log (across jobs). 871 # Using grep is slightly problematic as it finds any reason, not 872 # just the most recent reason (since 2 boots ago), so it may guess 873 # wrong. Multiple reboots are unusual in the lab setting though and 874 # it is better to have a reasonable guess than no reason at all. 875 found = self.host.run( 876 "grep -aE '" + message + "' /var/log/messages | grep -av grep", 877 ignore_status=True 878 ).stdout 879 if found and found.strip(): 880 reasons.append(bucket) 881 signature = 'reason unknown' 882 if reasons: 883 # Concatenate possible reasons found to obtain a magic signature. 884 signature = ', '.join(reasons) 885 return ('DUT rebooted during the test run. (%s)\n' % signature) 886 887 888 def _diagnose_dut(self, old_boot_id=None): 889 """ 890 Run diagnostic checks on a DUT. 891 892 1. ping: A dead host will not respond to pings. 893 2. ssh (happens with 3.): DUT hangs usually fail in authentication 894 but respond to pings. 895 3. Check if a reboot occured: A healthy but unexpected reboot leaves the 896 host running with a new boot id. 897 898 This method will always raise an exception from the AutotestFailure 899 family and should only get called when the reason for a test failing 900 is ambiguous. 901 902 @raises AutotestDeviceNotPingable: If the DUT doesn't respond to ping. 903 @raises AutotestDeviceNotSSHable: If we cannot SSH into the DUT. 904 @raises AutotestDeviceRebooted: If the boot id changed. 905 @raises AutotestAbort: If none of the above exceptions were raised. 906 Since we have no recourse we must abort at this stage. 907 """ 908 msg = 'Autotest client terminated unexpectedly: ' 909 if utils.ping(self.host.hostname, tries=1, deadline=1) != 0: 910 msg += 'DUT is no longer pingable, it may have rebooted or hung.\n' 911 raise AutotestDeviceNotPingable(msg) 912 913 if old_boot_id: 914 try: 915 new_boot_id = self.host.get_boot_id(timeout=60) 916 except Exception as e: 917 msg += ('DUT is pingable but not SSHable, it most likely' 918 ' sporadically rebooted during testing. %s\n' % str(e)) 919 raise AutotestDeviceNotSSHable(msg) 920 else: 921 if new_boot_id != old_boot_id: 922 msg += self._diagnose_reboot() 923 raise AutotestDeviceRebooted(msg) 924 925 msg += ('DUT is pingable, SSHable and did NOT restart ' 926 'un-expectedly. We probably lost connectivity during the ' 927 'test.') 928 else: 929 msg += ('DUT is pingable, could not determine if an un-expected ' 930 'reboot occured during the test.') 931 932 raise AutotestAbort(msg) 933 934 935 def log_unexpected_abort(self, stderr_redirector, old_boot_id=None): 936 """ 937 Logs that something unexpected happened, then tries to diagnose the 938 failure. The purpose of this function is only to close out the status 939 log with the appropriate error message, not to critically terminate 940 the program. 941 942 @param stderr_redirector: log stream. 943 @param old_boot_id: boot id used to infer if a reboot occured. 944 """ 945 stderr_redirector.flush_all_buffers() 946 try: 947 self._diagnose_dut(old_boot_id) 948 except AutotestFailure as e: 949 self.host.job.record('END ABORT', None, None, str(e)) 950 951 952 def _execute_in_background(self, section, timeout): 953 full_cmd = self.get_background_cmd(section) 954 devnull = open(os.devnull, "w") 955 956 self.copy_client_config_file(self.get_client_log()) 957 958 self.host.job.push_execution_context(self.results_dir) 959 try: 960 result = self.host.run(full_cmd, ignore_status=True, 961 timeout=timeout, 962 stdout_tee=devnull, 963 stderr_tee=devnull) 964 finally: 965 self.host.job.pop_execution_context() 966 967 return result 968 969 970 @staticmethod 971 def _strip_stderr_prologue(stderr): 972 """Strips the 'standard' prologue that get pre-pended to every 973 remote command and returns the text that was actually written to 974 stderr by the remote command.""" 975 stderr_lines = stderr.split("\n")[1:] 976 if not stderr_lines: 977 return "" 978 elif stderr_lines[0].startswith("NOTE: autotestd_monitor"): 979 del stderr_lines[0] 980 return "\n".join(stderr_lines) 981 982 983 def _execute_daemon(self, section, timeout, stderr_redirector, 984 client_disconnect_timeout): 985 monitor_dir = self.host.get_tmp_dir() 986 daemon_cmd = self.get_daemon_cmd(section, monitor_dir) 987 988 # grab the location for the server-side client log file 989 client_log_prefix = self.get_client_log() 990 client_log_path = os.path.join(self.results_dir, 'debug', 991 client_log_prefix + '.log') 992 client_log = open(client_log_path, 'w', LOG_BUFFER_SIZE_BYTES) 993 self.copy_client_config_file(client_log_prefix) 994 995 stdout_read = stderr_read = 0 996 self.host.job.push_execution_context(self.results_dir) 997 try: 998 self.host.run(daemon_cmd, ignore_status=True, timeout=timeout) 999 disconnect_warnings = [] 1000 while True: 1001 monitor_cmd = self.get_monitor_cmd(monitor_dir, stdout_read, 1002 stderr_read) 1003 try: 1004 result = self.host.run(monitor_cmd, ignore_status=True, 1005 timeout=timeout, 1006 stdout_tee=client_log, 1007 stderr_tee=stderr_redirector) 1008 except error.AutoservRunError as e: 1009 result = e.result_obj 1010 result.exit_status = None 1011 disconnect_warnings.append(e.description) 1012 1013 stderr_redirector.log_warning( 1014 "Autotest client was disconnected: %s" % e.description, 1015 "NETWORK") 1016 except error.AutoservSSHTimeout: 1017 result = utils.CmdResult(monitor_cmd, "", "", None, 0) 1018 stderr_redirector.log_warning( 1019 "Attempt to connect to Autotest client timed out", 1020 "NETWORK") 1021 1022 stdout_read += len(result.stdout) 1023 stderr_read += len(self._strip_stderr_prologue(result.stderr)) 1024 1025 if result.exit_status is not None: 1026 # TODO (crosbug.com/38224)- sbasi: Remove extra logging. 1027 logging.debug('Result exit status is %d.', 1028 result.exit_status) 1029 return result 1030 elif not self.host.wait_up(client_disconnect_timeout): 1031 raise error.AutoservSSHTimeout( 1032 "client was disconnected, reconnect timed out") 1033 finally: 1034 client_log.close() 1035 self.host.job.pop_execution_context() 1036 1037 1038 def execute_section(self, section, timeout, stderr_redirector, 1039 client_disconnect_timeout, boot_id=None): 1040 # TODO(crbug.com/684311) The claim is that section is never more than 0 1041 # in pratice. After validating for a week or so, delete all support of 1042 # multiple sections. 1043 metrics.Counter('chromeos/autotest/autotest/sections').increment( 1044 fields={'is_first_section': (section == 0)}) 1045 logging.info("Executing %s/bin/autotest %s/control phase %d", 1046 self.autodir, self.autodir, section) 1047 1048 if self.background: 1049 result = self._execute_in_background(section, timeout) 1050 else: 1051 result = self._execute_daemon(section, timeout, stderr_redirector, 1052 client_disconnect_timeout) 1053 1054 last_line = stderr_redirector.last_line 1055 1056 # check if we failed hard enough to warrant an exception 1057 if result.exit_status == 1: 1058 err = error.AutotestRunError("client job was aborted") 1059 elif not self.background and not result.stderr: 1060 err = error.AutotestRunError( 1061 "execute_section %s failed to return anything\n" 1062 "stdout:%s\n" % (section, result.stdout)) 1063 else: 1064 err = None 1065 1066 # log something if the client failed AND never finished logging 1067 if err and not self.is_client_job_finished(last_line): 1068 self.log_unexpected_abort(stderr_redirector, old_boot_id=boot_id) 1069 1070 if err: 1071 raise err 1072 else: 1073 return stderr_redirector.last_line 1074 1075 1076 def _wait_for_reboot(self, old_boot_id): 1077 logging.info("Client is rebooting") 1078 logging.info("Waiting for client to halt") 1079 if not self.host.wait_down(self.host.WAIT_DOWN_REBOOT_TIMEOUT, 1080 old_boot_id=old_boot_id): 1081 err = "%s failed to shutdown after %d" 1082 err %= (self.host.hostname, self.host.WAIT_DOWN_REBOOT_TIMEOUT) 1083 raise error.AutotestRunError(err) 1084 logging.info("Client down, waiting for restart") 1085 if not self.host.wait_up(self.host.DEFAULT_REBOOT_TIMEOUT): 1086 # since reboot failed 1087 # hardreset the machine once if possible 1088 # before failing this control file 1089 warning = "%s did not come back up, hard resetting" 1090 warning %= self.host.hostname 1091 logging.warning(warning) 1092 try: 1093 self.host.hardreset(wait=False) 1094 except (AttributeError, error.AutoservUnsupportedError): 1095 warning = "Hard reset unsupported on %s" 1096 warning %= self.host.hostname 1097 logging.warning(warning) 1098 raise error.AutotestRunError("%s failed to boot after %ds" % 1099 (self.host.hostname, 1100 self.host.DEFAULT_REBOOT_TIMEOUT)) 1101 self.host.reboot_followup() 1102 1103 1104 def execute_control(self, timeout=None, client_disconnect_timeout=None): 1105 if not self.background: 1106 collector = log_collector(self.host, self.tag, self.results_dir) 1107 hostname = self.host.hostname 1108 remote_results = collector.client_results_dir 1109 local_results = collector.server_results_dir 1110 self.host.job.add_client_log(hostname, remote_results, 1111 local_results) 1112 job_record_context = self.host.job.get_record_context() 1113 1114 section = 0 1115 start_time = time.time() 1116 1117 logger = client_logger(self.host, self.tag, self.results_dir) 1118 try: 1119 while not timeout or time.time() < start_time + timeout: 1120 if timeout: 1121 section_timeout = start_time + timeout - time.time() 1122 else: 1123 section_timeout = None 1124 boot_id = self.host.get_boot_id() 1125 last = self.execute_section(section, section_timeout, 1126 logger, client_disconnect_timeout, 1127 boot_id=boot_id) 1128 if self.background: 1129 return 1130 section += 1 1131 if self.is_client_job_finished(last): 1132 logging.info("Client complete") 1133 return 1134 elif self.is_client_job_rebooting(last): 1135 try: 1136 self._wait_for_reboot(boot_id) 1137 except error.AutotestRunError as e: 1138 self.host.job.record("ABORT", None, "reboot", str(e)) 1139 self.host.job.record("END ABORT", None, None, str(e)) 1140 raise 1141 continue 1142 1143 # If a test fails without probable cause we try to bucket it's 1144 # failure into one of 2 categories. If we can determine the 1145 # current state of the device and it is suspicious, we close the 1146 # status lines indicating a failure. If we either cannot 1147 # determine the state of the device, or it appears totally 1148 # healthy, we give up and abort. 1149 try: 1150 self._diagnose_dut(boot_id) 1151 except AutotestDeviceError as e: 1152 # The status lines of the test are pretty much tailed to 1153 # our log, with indentation, from the client job on the DUT. 1154 # So if the DUT goes down unexpectedly we'll end up with a 1155 # malformed status log unless we manually unwind the status 1156 # stack. Ideally we would want to write a nice wrapper like 1157 # server_job methods run_reboot, run_group but they expect 1158 # reboots and we don't. 1159 self.host.job.record('FAIL', None, None, str(e)) 1160 self.host.job.record('END FAIL', None, None) 1161 self.host.job.record('END GOOD', None, None) 1162 self.host.job.failed_with_device_error = True 1163 return 1164 except AutotestAbort as e: 1165 self.host.job.record('ABORT', None, None, str(e)) 1166 self.host.job.record('END ABORT', None, None) 1167 1168 # give the client machine a chance to recover from a crash 1169 self.host.wait_up( 1170 self.host.HOURS_TO_WAIT_FOR_RECOVERY * 3600) 1171 logging.debug('Unexpected final status message from ' 1172 'client %s: %s', self.host.hostname, last) 1173 # The line 'last' may have sensitive phrases, like 1174 # 'END GOOD', which breaks the tko parser. So the error 1175 # message will exclude it, since it will be recorded to 1176 # status.log. 1177 msg = ("Aborting - unexpected final status message from " 1178 "client on %s\n") % self.host.hostname 1179 raise error.AutotestRunError(msg) 1180 finally: 1181 logging.debug('Autotest job finishes running. Below is the ' 1182 'post-processing operations.') 1183 logger.close() 1184 if not self.background: 1185 collector.collect_client_job_results() 1186 collector.remove_redundant_client_logs() 1187 state_file = os.path.basename(self.remote_control_file 1188 + '.state') 1189 state_path = os.path.join(self.results_dir, state_file) 1190 self.host.job.postprocess_client_state(state_path) 1191 self.host.job.remove_client_log(hostname, remote_results, 1192 local_results) 1193 job_record_context.restore() 1194 1195 logging.debug('Autotest job finishes.') 1196 1197 # should only get here if we timed out 1198 assert timeout 1199 raise error.AutotestTimeoutError() 1200 1201 1202class log_collector(object): 1203 def __init__(self, host, client_tag, results_dir): 1204 self.host = host 1205 if not client_tag: 1206 client_tag = "default" 1207 self.client_results_dir = os.path.join(host.get_autodir(), "results", 1208 client_tag) 1209 self.server_results_dir = results_dir 1210 1211 1212 def collect_client_job_results(self): 1213 """ A method that collects all the current results of a running 1214 client job into the results dir. By default does nothing as no 1215 client job is running, but when running a client job you can override 1216 this with something that will actually do something. """ 1217 # make an effort to wait for the machine to come up 1218 try: 1219 self.host.wait_up(timeout=30) 1220 except error.AutoservError: 1221 # don't worry about any errors, we'll try and 1222 # get the results anyway 1223 pass 1224 1225 # Copy all dirs in default to results_dir 1226 try: 1227 # Build test result directory summary 1228 result_tools_runner.run_on_client( 1229 self.host, self.client_results_dir) 1230 1231 with metrics.SecondsTimer( 1232 'chromeos/autotest/job/log_collection_duration', 1233 fields={'dut_host_name': self.host.hostname}): 1234 self.host.get_file( 1235 self.client_results_dir + '/', 1236 self.server_results_dir, 1237 preserve_symlinks=True) 1238 except Exception: 1239 # well, don't stop running just because we couldn't get logs 1240 e_msg = "Unexpected error copying test result logs, continuing ..." 1241 logging.error(e_msg) 1242 traceback.print_exc(file=sys.stdout) 1243 1244 1245 def remove_redundant_client_logs(self): 1246 """Remove client.*.log files in favour of client.*.DEBUG files.""" 1247 debug_dir = os.path.join(self.server_results_dir, 'debug') 1248 debug_files = [f for f in os.listdir(debug_dir) 1249 if re.search(r'^client\.\d+\.DEBUG$', f)] 1250 for debug_file in debug_files: 1251 log_file = debug_file.replace('DEBUG', 'log') 1252 log_file = os.path.join(debug_dir, log_file) 1253 if os.path.exists(log_file): 1254 os.remove(log_file) 1255 1256 1257# a file-like object for catching stderr from an autotest client and 1258# extracting status logs from it 1259class client_logger(object): 1260 """Partial file object to write to both stdout and 1261 the status log file. We only implement those methods 1262 utils.run() actually calls. 1263 """ 1264 status_parser = re.compile(r"^AUTOTEST_STATUS:([^:]*):(.*)$") 1265 test_complete_parser = re.compile(r"^AUTOTEST_TEST_COMPLETE:(.*)$") 1266 fetch_package_parser = re.compile( 1267 r"^AUTOTEST_FETCH_PACKAGE:([^:]*):([^:]*):(.*)$") 1268 extract_indent = re.compile(r"^(\t*).*$") 1269 extract_timestamp = re.compile(r".*\ttimestamp=(\d+)\t.*$") 1270 1271 def __init__(self, host, tag, server_results_dir): 1272 self.host = host 1273 self.job = host.job 1274 self.log_collector = log_collector(host, tag, server_results_dir) 1275 self.leftover = "" 1276 self.last_line = "" 1277 self.logs = {} 1278 1279 1280 def _process_log_dict(self, log_dict): 1281 log_list = log_dict.pop("logs", []) 1282 for key in sorted(six.iterkeys(log_dict)): 1283 log_list += self._process_log_dict(log_dict.pop(key)) 1284 return log_list 1285 1286 1287 def _process_logs(self): 1288 """Go through the accumulated logs in self.log and print them 1289 out to stdout and the status log. Note that this processes 1290 logs in an ordering where: 1291 1292 1) logs to different tags are never interleaved 1293 2) logs to x.y come before logs to x.y.z for all z 1294 3) logs to x.y come before x.z whenever y < z 1295 1296 Note that this will in general not be the same as the 1297 chronological ordering of the logs. However, if a chronological 1298 ordering is desired that one can be reconstructed from the 1299 status log by looking at timestamp lines.""" 1300 log_list = self._process_log_dict(self.logs) 1301 for entry in log_list: 1302 self.job.record_entry(entry, log_in_subdir=False) 1303 if log_list: 1304 self.last_line = log_list[-1].render() 1305 1306 1307 def _process_quoted_line(self, tag, line): 1308 """Process a line quoted with an AUTOTEST_STATUS flag. If the 1309 tag is blank then we want to push out all the data we've been 1310 building up in self.logs, and then the newest line. If the 1311 tag is not blank, then push the line into the logs for handling 1312 later.""" 1313 entry = base_job.status_log_entry.parse(line) 1314 if entry is None: 1315 return # the line contains no status lines 1316 if tag == "": 1317 self._process_logs() 1318 self.job.record_entry(entry, log_in_subdir=False) 1319 self.last_line = line 1320 else: 1321 tag_parts = [int(x) for x in tag.split(".")] 1322 log_dict = self.logs 1323 for part in tag_parts: 1324 log_dict = log_dict.setdefault(part, {}) 1325 log_list = log_dict.setdefault("logs", []) 1326 log_list.append(entry) 1327 1328 1329 def _process_info_line(self, line): 1330 """Check if line is an INFO line, and if it is, interpret any control 1331 messages (e.g. enabling/disabling warnings) that it may contain.""" 1332 match = re.search(r"^\t*INFO\t----\t----(.*)\t[^\t]*$", line) 1333 if not match: 1334 return # not an INFO line 1335 for field in match.group(1).split('\t'): 1336 if field.startswith("warnings.enable="): 1337 func = self.job.warning_manager.enable_warnings 1338 elif field.startswith("warnings.disable="): 1339 func = self.job.warning_manager.disable_warnings 1340 else: 1341 continue 1342 warning_type = field.split("=", 1)[1] 1343 func(warning_type) 1344 1345 1346 def _process_line(self, line): 1347 """Write out a line of data to the appropriate stream. 1348 1349 Returns the package checksum file if it exists. 1350 1351 Status lines sent by autotest will be prepended with 1352 "AUTOTEST_STATUS", and all other lines are ssh error messages. 1353 """ 1354 logging.debug(line) 1355 fetch_package_match = self.fetch_package_parser.search(line) 1356 if fetch_package_match: 1357 pkg_name, dest_path, fifo_path = fetch_package_match.groups() 1358 serve_packages = _CONFIG.get_config_value( 1359 "PACKAGES", "serve_packages_from_autoserv", type=bool) 1360 if serve_packages and pkg_name == 'packages.checksum': 1361 try: 1362 checksum_file = os.path.join( 1363 self.job.pkgmgr.pkgmgr_dir, 'packages', pkg_name) 1364 if os.path.exists(checksum_file): 1365 self.host.send_file(checksum_file, dest_path) 1366 except error.AutoservRunError: 1367 msg = "Package checksum file not found, continuing anyway" 1368 logging.exception(msg) 1369 1370 try: 1371 # When fetching a package, the client expects to be 1372 # notified when the fetching is complete. Autotest 1373 # does this pushing a B to a fifo queue to the client. 1374 self.host.run("echo B > %s" % fifo_path) 1375 except error.AutoservRunError: 1376 msg = "Checksum installation failed, continuing anyway" 1377 logging.exception(msg) 1378 finally: 1379 return 1380 1381 status_match = self.status_parser.search(line) 1382 test_complete_match = self.test_complete_parser.search(line) 1383 fetch_package_match = self.fetch_package_parser.search(line) 1384 if status_match: 1385 tag, line = status_match.groups() 1386 self._process_info_line(line) 1387 self._process_quoted_line(tag, line) 1388 elif test_complete_match: 1389 self._process_logs() 1390 fifo_path, = test_complete_match.groups() 1391 try: 1392 self.log_collector.collect_client_job_results() 1393 self.host.run("echo A > %s" % fifo_path) 1394 except Exception: 1395 msg = "Post-test log collection failed, continuing anyway" 1396 logging.exception(msg) 1397 elif fetch_package_match: 1398 pkg_name, dest_path, fifo_path = fetch_package_match.groups() 1399 serve_packages = global_config.global_config.get_config_value( 1400 "PACKAGES", "serve_packages_from_autoserv", type=bool) 1401 if serve_packages and pkg_name.endswith(".tar.bz2"): 1402 try: 1403 self._send_tarball(pkg_name, dest_path) 1404 except Exception: 1405 msg = "Package tarball creation failed, continuing anyway" 1406 logging.exception(msg) 1407 try: 1408 self.host.run("echo B > %s" % fifo_path) 1409 except Exception: 1410 msg = "Package tarball installation failed, continuing anyway" 1411 logging.exception(msg) 1412 else: 1413 logging.info(line) 1414 1415 1416 def _send_tarball(self, pkg_name, remote_dest): 1417 """Uses tarballs in package manager by default.""" 1418 try: 1419 server_package = os.path.join(self.job.pkgmgr.pkgmgr_dir, 1420 'packages', pkg_name) 1421 if os.path.exists(server_package): 1422 self.host.send_file(server_package, remote_dest) 1423 return 1424 1425 except error.AutoservRunError: 1426 msg = ("Package %s could not be sent from the package cache." % 1427 pkg_name) 1428 logging.exception(msg) 1429 1430 name, pkg_type = self.job.pkgmgr.parse_tarball_name(pkg_name) 1431 src_dirs = [] 1432 if pkg_type == 'test': 1433 for test_dir in ['site_tests', 'tests']: 1434 src_dir = os.path.join(self.job.clientdir, test_dir, name) 1435 if os.path.exists(src_dir): 1436 src_dirs += [src_dir] 1437 break 1438 elif pkg_type == 'profiler': 1439 src_dirs += [os.path.join(self.job.clientdir, 'profilers', name)] 1440 elif pkg_type == 'dep': 1441 src_dirs += [os.path.join(self.job.clientdir, 'deps', name)] 1442 elif pkg_type == 'client': 1443 return # you must already have a client to hit this anyway 1444 else: 1445 return # no other types are supported 1446 1447 # iterate over src_dirs until we find one that exists, then tar it 1448 for src_dir in src_dirs: 1449 if os.path.exists(src_dir): 1450 try: 1451 logging.info('Bundling %s into %s', src_dir, pkg_name) 1452 temp_dir = autotemp.tempdir(unique_id='autoserv-packager', 1453 dir=self.job.tmpdir) 1454 tarball_path = self.job.pkgmgr.tar_package( 1455 pkg_name, src_dir, temp_dir.name, " .") 1456 self.host.send_file(tarball_path, remote_dest) 1457 finally: 1458 temp_dir.clean() 1459 return 1460 1461 1462 def log_warning(self, msg, warning_type): 1463 """Injects a WARN message into the current status logging stream.""" 1464 timestamp = int(time.time()) 1465 if self.job.warning_manager.is_valid(timestamp, warning_type): 1466 self.job.record('WARN', None, None, msg) 1467 1468 1469 def write(self, data): 1470 # now start processing the existing buffer and the new data 1471 data = self.leftover + data 1472 lines = data.split('\n') 1473 processed_lines = 0 1474 try: 1475 # process all the buffered data except the last line 1476 # ignore the last line since we may not have all of it yet 1477 for line in lines[:-1]: 1478 self._process_line(line) 1479 processed_lines += 1 1480 finally: 1481 # save any unprocessed lines for future processing 1482 self.leftover = '\n'.join(lines[processed_lines:]) 1483 1484 1485 def flush(self): 1486 sys.stdout.flush() 1487 1488 1489 def flush_all_buffers(self): 1490 if self.leftover: 1491 self._process_line(self.leftover) 1492 self.leftover = "" 1493 self._process_logs() 1494 self.flush() 1495 1496 1497 def close(self): 1498 self.flush_all_buffers() 1499