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