| # Copyright 2007 Google Inc. Released under the GPL v2 |
| |
| import re, os, sys, traceback, subprocess, tempfile, time, pickle, glob, logging |
| from autotest_lib.server import installable_object, utils |
| from autotest_lib.client.common_lib import log, error |
| from autotest_lib.client.common_lib import global_config, packages |
| from autotest_lib.client.common_lib import utils as client_utils |
| |
| AUTOTEST_SVN = 'svn://test.kernel.org/autotest/trunk/client' |
| AUTOTEST_HTTP = 'http://test.kernel.org/svn/autotest/trunk/client' |
| |
| # Timeouts for powering down and up respectively |
| HALT_TIME = 300 |
| BOOT_TIME = 1800 |
| CRASH_RECOVERY_TIME = 9000 |
| |
| |
| class BaseAutotest(installable_object.InstallableObject): |
| """ |
| This class represents the Autotest program. |
| |
| Autotest is used to run tests automatically and collect the results. |
| It also supports profilers. |
| |
| Implementation details: |
| This is a leaf class in an abstract class hierarchy, it must |
| implement the unimplemented methods in parent classes. |
| """ |
| |
| def __init__(self, host = None): |
| self.host = host |
| self.got = False |
| self.installed = False |
| self.lightweight = False |
| self.serverdir = utils.get_server_dir() |
| super(BaseAutotest, self).__init__() |
| |
| |
| install_in_tmpdir = False |
| @classmethod |
| def set_install_in_tmpdir(cls, flag): |
| """ Sets a flag that controls whether or not Autotest should by |
| default be installed in a "standard" directory (e.g. |
| /home/autotest, /usr/local/autotest) or a temporary directory. """ |
| cls.install_in_tmpdir = flag |
| |
| |
| def _get_install_dir(self, host): |
| """ Determines the location where autotest should be installed on |
| host. If self.install_in_tmpdir is set, it will return a unique |
| temporary directory that autotest can be installed in. """ |
| try: |
| autodir = _get_autodir(host) |
| except error.AutotestRunError: |
| autodir = '/usr/local/autotest' |
| if self.install_in_tmpdir: |
| autodir = host.get_tmp_dir(parent=autodir) |
| return autodir |
| |
| |
| @log.record |
| def install(self, host=None, autodir=None): |
| self._install(host=host, autodir=autodir) |
| |
| |
| def install_base(self, host=None, autodir=None): |
| """ Performs a lightweight autotest install. Useful for when you |
| want to run some client-side code but don't want to pay the cost |
| of a full installation. """ |
| self._install(host=host, autodir=autodir, lightweight=True) |
| |
| |
| def _install(self, host=None, autodir=None, lightweight=False): |
| """ |
| Install autotest. If get() was not called previously, an |
| attempt will be made to install from the autotest svn |
| repository. |
| |
| Args: |
| host: a Host instance on which autotest will be installed |
| autodir: location on the remote host to install to |
| lightweight: exclude tests, deps and profilers, if possible |
| |
| Raises: |
| AutoservError: if a tarball was not specified and |
| the target host does not have svn installed in its path""" |
| if not host: |
| host = self.host |
| if not self.got: |
| self.get() |
| host.wait_up(timeout=30) |
| host.setup() |
| logging.info("Installing autotest on %s", host.hostname) |
| |
| # set up the autotest directory on the remote machine |
| if not autodir: |
| autodir = self._get_install_dir(host) |
| host.set_autodir(autodir) |
| host.run('mkdir -p %s' % utils.sh_escape(autodir)) |
| |
| # make sure there are no files in $AUTODIR/results |
| results_path = os.path.join(autodir, 'results') |
| host.run('rm -rf %s/*' % utils.sh_escape(results_path), |
| ignore_status=True) |
| |
| # Fetch the autotest client from the nearest repository |
| try: |
| c = global_config.global_config |
| repos = c.get_config_value("PACKAGES", 'fetch_location', type=list) |
| pkgmgr = packages.PackageManager(autodir, hostname=host.hostname, |
| repo_urls=repos, |
| do_locking=False, |
| run_function=host.run, |
| run_function_dargs=dict(timeout=600)) |
| # The packages dir is used to store all the packages that |
| # are fetched on that client. (for the tests,deps etc. |
| # too apart from the client) |
| pkg_dir = os.path.join(autodir, 'packages') |
| # clean up the autodir except for the packages directory |
| host.run('cd %s && ls | grep -v "^packages$"' |
| ' | xargs rm -rf && rm -rf .[^.]*' % autodir) |
| pkgmgr.install_pkg('autotest', 'client', pkg_dir, autodir, |
| preserve_install_dir=True) |
| self.installed = True |
| self.lightweight = lightweight |
| return |
| except global_config.ConfigError, e: |
| logging.error("Could not install autotest using the packaging" |
| "system: %s", e) |
| except (packages.PackageInstallError, error.AutoservRunError), e: |
| logging.error("Could not install autotest from %s", repos) |
| |
| # try to install from file or directory |
| if self.source_material: |
| if os.path.isdir(self.source_material): |
| # Copy autotest recursively |
| if lightweight: |
| dirs_to_exclude = set(["tests", "site_tests", "deps", |
| "tools", "profilers"]) |
| light_files = [os.path.join(self.source_material, f) |
| for f in os.listdir(self.source_material) |
| if f not in dirs_to_exclude] |
| host.send_file(light_files, autodir, delete_dest=True) |
| |
| # create empty dirs for all the stuff we excluded |
| commands = [] |
| for path in dirs_to_exclude: |
| abs_path = os.path.join(autodir, path) |
| abs_path = utils.sh_escape(abs_path) |
| commands.append("mkdir -p '%s'" % abs_path) |
| host.run(';'.join(commands)) |
| else: |
| host.send_file(self.source_material, autodir, |
| delete_dest=True) |
| else: |
| # Copy autotest via tarball |
| e_msg = 'Installation method not yet implemented!' |
| raise NotImplementedError(e_msg) |
| logging.info("Installation of autotest completed") |
| self.installed = True |
| self.lightweight = lightweight |
| return |
| |
| # if that fails try to install using svn |
| if utils.run('which svn').exit_status: |
| raise error.AutoservError('svn not found on target machine: %s' |
| % host.name) |
| try: |
| host.run('svn checkout %s %s' % (AUTOTEST_SVN, autodir)) |
| except error.AutoservRunError, e: |
| host.run('svn checkout %s %s' % (AUTOTEST_HTTP, autodir)) |
| logging.info("Installation of autotest completed") |
| self.installed = True |
| self.lightweight = lightweight |
| |
| |
| def uninstall(self, host=None): |
| """ |
| Uninstall (i.e. delete) autotest. Removes the autotest client install |
| from the specified host. |
| |
| @params host a Host instance from which the client will be removed |
| """ |
| if not self.installed: |
| return |
| if not host: |
| host = self.host |
| autodir = host.get_autodir() |
| if not autodir: |
| return |
| |
| # perform the actual uninstall |
| host.run("rm -rf %s" % utils.sh_escape(autodir), ignore_status=True) |
| host.set_autodir(None) |
| self.installed = False |
| |
| |
| def get(self, location = None): |
| if not location: |
| location = os.path.join(self.serverdir, '../client') |
| location = os.path.abspath(location) |
| # If there's stuff run on our client directory already, it |
| # can cause problems. Try giving it a quick clean first. |
| cwd = os.getcwd() |
| os.chdir(location) |
| os.system('tools/make_clean') |
| os.chdir(cwd) |
| super(BaseAutotest, self).get(location) |
| self.got = True |
| |
| |
| def run(self, control_file, results_dir = '.', host = None, |
| timeout=None, tag=None, parallel_flag=False, background=False, |
| client_disconnect_timeout=1800): |
| """ |
| Run an autotest job on the remote machine. |
| |
| Args: |
| control_file: an open file-like-obj of the control file |
| results_dir: a str path where the results should be stored |
| on the local filesystem |
| host: a Host instance on which the control file should |
| be run |
| tag: tag name for the client side instance of autotest |
| parallel_flag: flag set when multiple jobs are run at the |
| same time |
| background: indicates that the client should be launched as |
| a background job; the code calling run will be |
| responsible for monitoring the client and |
| collecting the results |
| Raises: |
| AutotestRunError: if there is a problem executing |
| the control file |
| """ |
| host = self._get_host_and_setup(host) |
| results_dir = os.path.abspath(results_dir) |
| |
| if tag: |
| results_dir = os.path.join(results_dir, tag) |
| |
| atrun = _Run(host, results_dir, tag, parallel_flag, background) |
| self._do_run(control_file, results_dir, host, atrun, timeout, |
| client_disconnect_timeout) |
| |
| |
| def _get_host_and_setup(self, host): |
| if not host: |
| host = self.host |
| if not self.installed: |
| self.install(host) |
| |
| host.wait_up(timeout=30) |
| return host |
| |
| |
| def _do_run(self, control_file, results_dir, host, atrun, timeout, |
| client_disconnect_timeout): |
| try: |
| atrun.verify_machine() |
| except: |
| logging.error("Verify failed on %s. Reinstalling autotest", |
| host.hostname) |
| self.install(host) |
| atrun.verify_machine() |
| debug = os.path.join(results_dir, 'debug') |
| try: |
| os.makedirs(debug) |
| except Exception: |
| pass |
| |
| delete_file_list = [atrun.remote_control_file, |
| atrun.remote_control_file + '.state', |
| atrun.manual_control_file, |
| atrun.manual_control_file + '.state'] |
| cmd = ';'.join('rm -f ' + control for control in delete_file_list) |
| host.run(cmd, ignore_status=True) |
| |
| tmppath = utils.get(control_file) |
| |
| # build up the initialization prologue for the control file |
| prologue_lines = [] |
| prologue_lines.append("job.default_boot_tag(%r)\n" |
| % host.job.last_boot_tag) |
| prologue_lines.append("job.default_test_cleanup(%r)\n" |
| % host.job.run_test_cleanup) |
| |
| # If the packaging system is being used, add the repository list. |
| try: |
| c = global_config.global_config |
| repos = c.get_config_value("PACKAGES", 'fetch_location', type=list) |
| pkgmgr = packages.PackageManager('autotest', hostname=host.hostname, |
| repo_urls=repos) |
| prologue_lines.append('job.add_repository(%s)\n' |
| % pkgmgr.repo_urls) |
| except global_config.ConfigError, e: |
| pass |
| |
| # on full-size installs, turn on any profilers the server is using |
| if not self.lightweight and not atrun.background: |
| running_profilers = host.job.profilers.add_log.iteritems() |
| for profiler, (args, dargs) in running_profilers: |
| call_args = [repr(profiler)] |
| call_args += [repr(arg) for arg in args] |
| call_args += ["%s=%r" % item for item in dargs.iteritems()] |
| prologue_lines.append("job.profilers.add(%s)\n" |
| % ", ".join(call_args)) |
| cfile = "".join(prologue_lines) |
| |
| cfile += open(tmppath).read() |
| open(tmppath, "w").write(cfile) |
| |
| # Create and copy state file to remote_control_file + '.state' |
| sysinfo_state = {"__sysinfo": host.job.sysinfo.serialize()} |
| state_file = self._create_state_file(host.job, sysinfo_state) |
| host.send_file(state_file, atrun.remote_control_file + '.state') |
| os.remove(state_file) |
| |
| # Copy control_file to remote_control_file on the host |
| host.send_file(tmppath, atrun.remote_control_file) |
| if os.path.abspath(tmppath) != os.path.abspath(control_file): |
| os.remove(tmppath) |
| |
| atrun.execute_control( |
| timeout=timeout, |
| client_disconnect_timeout=client_disconnect_timeout) |
| |
| |
| def _create_state_file(self, job, state_dict): |
| """ Create a state file from a dictionary. Returns the path of the |
| state file. """ |
| fd, path = tempfile.mkstemp(dir=job.tmpdir) |
| state_file = os.fdopen(fd, "w") |
| pickle.dump(state_dict, state_file) |
| state_file.close() |
| return path |
| |
| |
| def run_timed_test(self, test_name, results_dir='.', host=None, |
| timeout=None, *args, **dargs): |
| """ |
| Assemble a tiny little control file to just run one test, |
| and run it as an autotest client-side test |
| """ |
| if not host: |
| host = self.host |
| if not self.installed: |
| self.install(host) |
| opts = ["%s=%s" % (o[0], repr(o[1])) for o in dargs.items()] |
| cmd = ", ".join([repr(test_name)] + map(repr, args) + opts) |
| control = "job.run_test(%s)\n" % cmd |
| self.run(control, results_dir, host, timeout=timeout) |
| |
| |
| def run_test(self, test_name, results_dir='.', host=None, *args, **dargs): |
| self.run_timed_test(test_name, results_dir, host, timeout=None, |
| *args, **dargs) |
| |
| |
| class _Run(object): |
| """ |
| Represents a run of autotest control file. This class maintains |
| all the state necessary as an autotest control file is executed. |
| |
| It is not intended to be used directly, rather control files |
| should be run using the run method in Autotest. |
| """ |
| def __init__(self, host, results_dir, tag, parallel_flag, background): |
| self.host = host |
| self.results_dir = results_dir |
| self.env = host.env |
| self.tag = tag |
| self.parallel_flag = parallel_flag |
| self.background = background |
| self.autodir = _get_autodir(self.host) |
| control = os.path.join(self.autodir, 'control') |
| if tag: |
| control += '.' + tag |
| self.manual_control_file = control |
| self.remote_control_file = control + '.autoserv' |
| |
| |
| def verify_machine(self): |
| binary = os.path.join(self.autodir, 'bin/autotest') |
| try: |
| self.host.run('ls %s > /dev/null 2>&1' % binary) |
| except: |
| raise "Autotest does not appear to be installed" |
| |
| if not self.parallel_flag: |
| tmpdir = os.path.join(self.autodir, 'tmp') |
| download = os.path.join(self.autodir, 'tests/download') |
| self.host.run('umount %s' % tmpdir, ignore_status=True) |
| self.host.run('umount %s' % download, ignore_status=True) |
| |
| |
| def get_base_cmd_args(self, section): |
| args = [] |
| if section > 0: |
| args.append('-c') |
| if self.tag: |
| args.append('-t %s' % self.tag) |
| if self.host.job.use_external_logging(): |
| args.append('-l') |
| args.append(self.remote_control_file) |
| return args |
| |
| |
| def get_background_cmd(self, section): |
| cmd = ['nohup', os.path.join(self.autodir, 'bin/autotest_client')] |
| cmd += self.get_base_cmd_args(section) |
| cmd.append('>/dev/null 2>/dev/null &') |
| return ' '.join(cmd) |
| |
| |
| def get_daemon_cmd(self, section, monitor_dir): |
| cmd = ['nohup', os.path.join(self.autodir, 'bin/autotestd'), |
| monitor_dir, '-H autoserv'] |
| cmd += self.get_base_cmd_args(section) |
| cmd.append('>/dev/null 2>/dev/null </dev/null &') |
| return ' '.join(cmd) |
| |
| |
| def get_monitor_cmd(self, monitor_dir, stdout_read, stderr_read): |
| cmd = [os.path.join(self.autodir, 'bin', 'autotestd_monitor'), |
| monitor_dir, str(stdout_read), str(stderr_read)] |
| return ' '.join(cmd) |
| |
| |
| def get_client_log(self, section): |
| """ Find what the "next" client.log.* file should be and open it. """ |
| debug_dir = os.path.join(self.results_dir, "debug") |
| client_logs = glob.glob(os.path.join(debug_dir, "client.log.*")) |
| next_log = os.path.join(debug_dir, "client.log.%d" % len(client_logs)) |
| return open(next_log, "w", 0) |
| |
| |
| @staticmethod |
| def is_client_job_finished(last_line): |
| return bool(re.match(r'^END .*\t----\t----\t.*$', last_line)) |
| |
| |
| @staticmethod |
| def is_client_job_rebooting(last_line): |
| return bool(re.match(r'^\t*GOOD\t----\treboot\.start.*$', last_line)) |
| |
| |
| def log_unexpected_abort(self, stderr_redirector): |
| stderr_redirector.flush_all_buffers() |
| msg = "Autotest client terminated unexpectedly" |
| self.host.job.record("END ABORT", None, None, msg) |
| |
| |
| def _execute_in_background(self, section, timeout): |
| full_cmd = self.get_background_cmd(section) |
| devnull = open(os.devnull, "w") |
| |
| old_resultdir = self.host.job.resultdir |
| try: |
| self.host.job.resultdir = self.results_dir |
| result = self.host.run(full_cmd, ignore_status=True, |
| timeout=timeout, |
| stdout_tee=devnull, |
| stderr_tee=devnull) |
| finally: |
| self.host.job.resultdir = old_resultdir |
| |
| return result |
| |
| |
| @staticmethod |
| def _strip_stderr_prologue(stderr): |
| """Strips the 'standard' prologue that get pre-pended to every |
| remote command and returns the text that was actually written to |
| stderr by the remote command.""" |
| stderr_lines = stderr.split("\n")[1:] |
| if not stderr_lines: |
| return "" |
| elif stderr_lines[0].startswith("NOTE: autotestd_monitor"): |
| del stderr_lines[0] |
| return "\n".join(stderr_lines) |
| |
| |
| def _execute_daemon(self, section, timeout, stderr_redirector, |
| client_disconnect_timeout): |
| monitor_dir = self.host.get_tmp_dir() |
| daemon_cmd = self.get_daemon_cmd(section, monitor_dir) |
| client_log = self.get_client_log(section) |
| |
| stdout_read = stderr_read = 0 |
| old_resultdir = self.host.job.resultdir |
| try: |
| self.host.job.resultdir = self.results_dir |
| self.host.run(daemon_cmd, ignore_status=True, timeout=timeout) |
| disconnect_warnings = [] |
| while True: |
| monitor_cmd = self.get_monitor_cmd(monitor_dir, stdout_read, |
| stderr_read) |
| try: |
| result = self.host.run(monitor_cmd, ignore_status=True, |
| timeout=timeout, |
| stdout_tee=client_log, |
| stderr_tee=stderr_redirector) |
| except error.AutoservRunError, e: |
| result = e.result_obj |
| result.exit_status = None |
| disconnect_warnings.append(e.description) |
| |
| stderr_redirector.log_warning( |
| "Autotest client was disconnected: %s" % e.description, |
| "NETWORK") |
| except error.AutoservSSHTimeout: |
| result = utils.CmdResult(monitor_cmd, "", "", None, 0) |
| stderr_redirector.log_warning( |
| "Attempt to connect to Autotest client timed out", |
| "NETWORK") |
| |
| stdout_read += len(result.stdout) |
| stderr_read += len(self._strip_stderr_prologue(result.stderr)) |
| |
| if result.exit_status is not None: |
| return result |
| elif not self.host.wait_up(client_disconnect_timeout): |
| raise error.AutoservSSHTimeout( |
| "client was disconnected, reconnect timed out") |
| finally: |
| self.host.job.resultdir = old_resultdir |
| |
| |
| def execute_section(self, section, timeout, stderr_redirector, |
| client_disconnect_timeout): |
| logging.info("Executing %s/bin/autotest %s/control phase %d", |
| self.autodir, self.autodir, section) |
| |
| if self.background: |
| result = self._execute_in_background(section, timeout) |
| else: |
| result = self._execute_daemon(section, timeout, stderr_redirector, |
| client_disconnect_timeout) |
| |
| last_line = stderr_redirector.last_line |
| |
| # check if we failed hard enough to warrant an exception |
| if result.exit_status == 1: |
| err = error.AutotestRunError("client job was aborted") |
| elif not self.background and not result.stderr: |
| err = error.AutotestRunError( |
| "execute_section %s failed to return anything\n" |
| "stdout:%s\n" % (section, result.stdout)) |
| else: |
| err = None |
| |
| # log something if the client failed AND never finished logging |
| if err and not self.is_client_job_finished(last_line): |
| self.log_unexpected_abort(stderr_redirector) |
| |
| if err: |
| raise err |
| else: |
| return stderr_redirector.last_line |
| |
| |
| def _wait_for_reboot(self): |
| logging.info("Client is rebooting") |
| logging.info("Waiting for client to halt") |
| if not self.host.wait_down(HALT_TIME): |
| err = "%s failed to shutdown after %d" |
| err %= (self.host.hostname, HALT_TIME) |
| raise error.AutotestRunError(err) |
| logging.info("Client down, waiting for restart") |
| if not self.host.wait_up(BOOT_TIME): |
| # since reboot failed |
| # hardreset the machine once if possible |
| # before failing this control file |
| warning = "%s did not come back up, hard resetting" |
| warning %= self.host.hostname |
| logging.warning(warning) |
| try: |
| self.host.hardreset(wait=False) |
| except (AttributeError, error.AutoservUnsupportedError): |
| warning = "Hard reset unsupported on %s" |
| warning %= self.host.hostname |
| logging.warning(warning) |
| raise error.AutotestRunError("%s failed to boot after %ds" % |
| (self.host.hostname, BOOT_TIME)) |
| self.host.reboot_followup() |
| |
| |
| def _process_client_state_file(self): |
| state_file = os.path.basename(self.remote_control_file) + ".state" |
| state_path = os.path.join(self.results_dir, state_file) |
| try: |
| state_dict = pickle.load(open(state_path)) |
| except Exception, e: |
| msg = "Ignoring error while loading client job state file: %s" % e |
| logging.warning(msg) |
| state_dict = {} |
| |
| # clear out the state file |
| # TODO: stash the file away somewhere useful instead |
| try: |
| os.remove(state_path) |
| except Exception: |
| pass |
| |
| msg = "Persistent state variables pulled back from %s: %s" |
| msg %= (self.host.hostname, state_dict) |
| print msg |
| |
| if "__run_test_cleanup" in state_dict: |
| if state_dict["__run_test_cleanup"]: |
| self.host.job.enable_test_cleanup() |
| else: |
| self.host.job.disable_test_cleanup() |
| |
| if "__last_boot_tag" in state_dict: |
| self.host.job.last_boot_tag = state_dict["__last_boot_tag"] |
| |
| if "__sysinfo" in state_dict: |
| self.host.job.sysinfo.deserialize(state_dict["__sysinfo"]) |
| |
| |
| def execute_control(self, timeout=None, client_disconnect_timeout=None): |
| if not self.background: |
| collector = log_collector(self.host, self.tag, self.results_dir) |
| hostname = self.host.hostname |
| remote_results = collector.client_results_dir |
| local_results = collector.server_results_dir |
| self.host.job.add_client_log(hostname, remote_results, |
| local_results) |
| |
| section = 0 |
| start_time = time.time() |
| |
| logger = client_logger(self.host, self.tag, self.results_dir) |
| try: |
| while not timeout or time.time() < start_time + timeout: |
| if timeout: |
| section_timeout = start_time + timeout - time.time() |
| else: |
| section_timeout = None |
| last = self.execute_section(section, section_timeout, |
| logger, client_disconnect_timeout) |
| if self.background: |
| return |
| section += 1 |
| if self.is_client_job_finished(last): |
| logging.info("Client complete") |
| return |
| elif self.is_client_job_rebooting(last): |
| try: |
| self._wait_for_reboot() |
| except error.AutotestRunError, e: |
| self.host.job.record("ABORT", None, "reboot", str(e)) |
| self.host.job.record("END ABORT", None, None, str(e)) |
| raise |
| continue |
| |
| # if we reach here, something unexpected happened |
| self.log_unexpected_abort(logger) |
| |
| # give the client machine a chance to recover from a crash |
| self.host.wait_up(CRASH_RECOVERY_TIME) |
| msg = ("Aborting - unexpected final status message from " |
| "client: %s\n") % last |
| raise error.AutotestRunError(msg) |
| finally: |
| logger.close() |
| if not self.background: |
| collector.collect_client_job_results() |
| self._process_client_state_file() |
| self.host.job.remove_client_log(hostname, remote_results, |
| local_results) |
| |
| # should only get here if we timed out |
| assert timeout |
| raise error.AutotestTimeoutError() |
| |
| |
| def _get_autodir(host): |
| autodir = host.get_autodir() |
| if autodir: |
| logging.debug('Using existing host autodir: %s', autodir) |
| return autodir |
| try: |
| # There's no clean way to do this. readlink may not exist |
| cmd = ("python -c '%s' /etc/autotest.conf 2> /dev/null" |
| % "import os,sys; print os.readlink(sys.argv[1])") |
| autodir = os.path.dirname(host.run(cmd).stdout) |
| if autodir: |
| logging.debug('Using autodir from /etc/autotest.conf: %s', autodir) |
| return autodir |
| except error.AutoservRunError: |
| pass |
| for path in ['/usr/local/autotest', '/home/autotest']: |
| try: |
| host.run('ls %s > /dev/null 2>&1' % path) |
| logging.debug('Found autodir at %s', path) |
| return path |
| except error.AutoservRunError: |
| logging.debug('%s does not exist', path) |
| raise error.AutotestRunError('Cannot figure out autotest directory') |
| |
| |
| class log_collector(object): |
| def __init__(self, host, client_tag, results_dir): |
| self.host = host |
| if not client_tag: |
| client_tag = "default" |
| self.client_results_dir = os.path.join(host.get_autodir(), "results", |
| client_tag) |
| self.server_results_dir = results_dir |
| |
| |
| def collect_client_job_results(self): |
| """ A method that collects all the current results of a running |
| client job into the results dir. By default does nothing as no |
| client job is running, but when running a client job you can override |
| this with something that will actually do something. """ |
| |
| # make an effort to wait for the machine to come up |
| try: |
| self.host.wait_up(timeout=30) |
| except error.AutoservError: |
| # don't worry about any errors, we'll try and |
| # get the results anyway |
| pass |
| |
| # Copy all dirs in default to results_dir |
| try: |
| self.host.get_file(self.client_results_dir + '/', |
| self.server_results_dir, preserve_symlinks=True) |
| except Exception: |
| # well, don't stop running just because we couldn't get logs |
| e_msg = "Unexpected error copying test result logs, continuing ..." |
| logging.error(e_msg) |
| traceback.print_exc(file=sys.stdout) |
| |
| |
| # a file-like object for catching stderr from an autotest client and |
| # extracting status logs from it |
| class client_logger(object): |
| """Partial file object to write to both stdout and |
| the status log file. We only implement those methods |
| utils.run() actually calls. |
| |
| Note that this class is fairly closely coupled with server_job, as it |
| uses special job._ methods to actually carry out the loggging. |
| """ |
| status_parser = re.compile(r"^AUTOTEST_STATUS:([^:]*):(.*)$") |
| test_complete_parser = re.compile(r"^AUTOTEST_TEST_COMPLETE:(.*)$") |
| extract_indent = re.compile(r"^(\t*).*$") |
| extract_timestamp = re.compile(r".*\ttimestamp=(\d+)\t.*$") |
| |
| def __init__(self, host, tag, server_results_dir): |
| self.host = host |
| self.job = host.job |
| self.log_collector = log_collector(host, tag, server_results_dir) |
| self.leftover = "" |
| self.last_line = "" |
| self.newest_timestamp = float("-inf") |
| self.logs = {} |
| self.server_warnings = [] |
| |
| |
| def _update_timestamp(self, line): |
| match = self.extract_timestamp.search(line) |
| if match: |
| self.newest_timestamp = max(self.newest_timestamp, |
| int(match.group(1))) |
| |
| |
| def _process_log_dict(self, log_dict): |
| log_list = log_dict.pop("logs", []) |
| for key in sorted(log_dict.iterkeys()): |
| log_list += self._process_log_dict(log_dict.pop(key)) |
| return log_list |
| |
| |
| def _process_logs(self): |
| """Go through the accumulated logs in self.log and print them |
| out to stdout and the status log. Note that this processes |
| logs in an ordering where: |
| |
| 1) logs to different tags are never interleaved |
| 2) logs to x.y come before logs to x.y.z for all z |
| 3) logs to x.y come before x.z whenever y < z |
| |
| Note that this will in general not be the same as the |
| chronological ordering of the logs. However, if a chronological |
| ordering is desired that one can be reconstructed from the |
| status log by looking at timestamp lines.""" |
| log_list = self._process_log_dict(self.logs) |
| for line in log_list: |
| self.job._record_prerendered(line + '\n') |
| if log_list: |
| self.last_line = log_list[-1] |
| |
| |
| def _process_quoted_line(self, tag, line): |
| """Process a line quoted with an AUTOTEST_STATUS flag. If the |
| tag is blank then we want to push out all the data we've been |
| building up in self.logs, and then the newest line. If the |
| tag is not blank, then push the line into the logs for handling |
| later.""" |
| logging.info(line) |
| if tag == "": |
| self._process_logs() |
| self.job._record_prerendered(line + '\n') |
| self.last_line = line |
| else: |
| tag_parts = [int(x) for x in tag.split(".")] |
| log_dict = self.logs |
| for part in tag_parts: |
| log_dict = log_dict.setdefault(part, {}) |
| log_list = log_dict.setdefault("logs", []) |
| log_list.append(line) |
| |
| |
| def _process_info_line(self, line): |
| """Check if line is an INFO line, and if it is, interpret any control |
| messages (e.g. enabling/disabling warnings) that it may contain.""" |
| match = re.search(r"^\t*INFO\t----\t----(.*)\t[^\t]*$", line) |
| if not match: |
| return # not an INFO line |
| for field in match.group(1).split('\t'): |
| if field.startswith("warnings.enable="): |
| func = self.job.warning_manager.enable_warnings |
| elif field.startswith("warnings.disable="): |
| func = self.job.warning_manager.disable_warnings |
| else: |
| continue |
| warning_type = field.split("=", 1)[1] |
| func(warning_type) |
| |
| |
| def _process_line(self, line): |
| """Write out a line of data to the appropriate stream. Status |
| lines sent by autotest will be prepended with |
| "AUTOTEST_STATUS", and all other lines are ssh error |
| messages.""" |
| status_match = self.status_parser.search(line) |
| test_complete_match = self.test_complete_parser.search(line) |
| if status_match: |
| tag, line = status_match.groups() |
| self._process_info_line(line) |
| self._process_quoted_line(tag, line) |
| elif test_complete_match: |
| self._process_logs() |
| fifo_path, = test_complete_match.groups() |
| self.log_collector.collect_client_job_results() |
| self.host.run("echo A > %s" % fifo_path) |
| else: |
| logging.info(line) |
| |
| |
| def _format_warnings(self, last_line, warnings): |
| # use the indentation of whatever the last log line was |
| indent = self.extract_indent.match(last_line).group(1) |
| # if the last line starts a new group, add an extra indent |
| if last_line.lstrip('\t').startswith("START\t"): |
| indent += '\t' |
| return [self.job._render_record("WARN", None, None, msg, |
| timestamp, indent).rstrip('\n') |
| for timestamp, msg in warnings] |
| |
| |
| def _process_warnings(self, last_line, log_dict, warnings): |
| if log_dict.keys() in ([], ["logs"]): |
| # there are no sub-jobs, just append the warnings here |
| warnings = self._format_warnings(last_line, warnings) |
| log_list = log_dict.setdefault("logs", []) |
| log_list += warnings |
| for warning in warnings: |
| sys.stdout.write(warning + '\n') |
| else: |
| # there are sub-jobs, so put the warnings in there |
| log_list = log_dict.get("logs", []) |
| if log_list: |
| last_line = log_list[-1] |
| for key in sorted(log_dict.iterkeys()): |
| if key != "logs": |
| self._process_warnings(last_line, |
| log_dict[key], |
| warnings) |
| |
| |
| def log_warning(self, msg, warning_type): |
| """Injects a WARN message into the current status logging stream.""" |
| timestamp = int(time.time()) |
| if self.job.warning_manager.is_valid(timestamp, warning_type): |
| self.server_warnings.append((timestamp, msg)) |
| |
| |
| def write(self, data): |
| # first check for any new console warnings |
| warnings = self.job._read_warnings() + self.server_warnings |
| warnings.sort() # sort into timestamp order |
| # now process the newest data written out |
| data = self.leftover + data |
| lines = data.split("\n") |
| # process every line but the last one |
| for line in lines[:-1]: |
| self._update_timestamp(line) |
| # output any warnings between now and the next status line |
| old_warnings = [(timestamp, msg) for timestamp, msg in warnings |
| if timestamp < self.newest_timestamp] |
| self._process_warnings(self.last_line, self.logs, warnings) |
| del warnings[:len(old_warnings)] |
| self._process_line(line) |
| # save off any warnings not yet logged for later processing |
| self.server_warnings = warnings |
| # save the last line for later processing |
| # since we may not have the whole line yet |
| self.leftover = lines[-1] |
| |
| |
| def flush(self): |
| sys.stdout.flush() |
| |
| |
| def flush_all_buffers(self): |
| if self.leftover: |
| self._process_line(self.leftover) |
| self.leftover = "" |
| self._process_warnings(self.last_line, self.logs, self.server_warnings) |
| self._process_logs() |
| self.flush() |
| |
| |
| def close(self): |
| self.flush_all_buffers() |
| |
| |
| SiteAutotest = client_utils.import_site_class( |
| __file__, "autotest_lib.server.site_autotest", "SiteAutotest", |
| BaseAutotest) |
| |
| class Autotest(SiteAutotest): |
| pass |