| from __future__ import print_function |
| |
| import collections |
| import logging |
| import os |
| import pipes |
| import random |
| import shutil |
| import time |
| |
| import common |
| from autotest_lib.client.bin.result_tools import runner as result_tools_runner |
| from autotest_lib.client.common_lib import error |
| from autotest_lib.client.common_lib import global_config |
| from autotest_lib.client.cros import constants |
| from autotest_lib.server import utils |
| |
| try: |
| from chromite.lib import metrics |
| except ImportError: |
| metrics = utils.metrics_mock |
| |
| |
| # The amortized max filesize to collect. For example, if _MAX_FILESIZE is 10 |
| # then we would collect a file with size 20 half the time, and a file with size |
| # 40 a quarter of the time, so that in the long run we are collecting files |
| # with this max size. |
| _MAX_FILESIZE = 64 * (2 ** 20) # 64 MiB |
| |
| class _RemoteTempDir(object): |
| |
| """Context manager for temporary directory on remote host.""" |
| |
| def __init__(self, host): |
| self.host = host |
| self.tmpdir = None |
| |
| def __repr__(self): |
| return '<{cls} host={this.host!r}, tmpdir={this.tmpdir!r}>'.format( |
| cls=type(self).__name__, this=self) |
| |
| def __enter__(self): |
| self.tmpdir = (self.host |
| .run('mktemp -d', stdout_tee=None) |
| .stdout.strip()) |
| return self.tmpdir |
| |
| def __exit__(self, exc_type, exc_value, exc_tb): |
| self.host.run('rm -rf %s' % (pipes.quote(self.tmpdir),)) |
| |
| |
| def _collect_log_file_with_summary(host, source_path, dest_path): |
| """Collects a log file from the remote machine with directory summary. |
| |
| @param host: The RemoteHost to collect logs from. |
| @param source_path: The remote path to collect the log file from. |
| @param dest_path: A path (file or directory) to write the copies logs into. |
| """ |
| # Build test result directory summary |
| summary_created = result_tools_runner.run_on_client(host, source_path) |
| |
| skip_summary_collection = True |
| try: |
| host.get_file(source_path, dest_path, preserve_perm=False) |
| skip_summary_collection = False |
| finally: |
| if summary_created: |
| # If dest_path is a file, use its parent folder to store the |
| # directory summary file. |
| if os.path.isfile(dest_path): |
| dest_path = os.path.dirname(dest_path) |
| # If dest_path doesn't exist, that means get_file failed, there is |
| # no need to collect directory summary file. |
| skip_summary_collection |= not os.path.exists(dest_path) |
| result_tools_runner.collect_last_summary( |
| host, source_path, dest_path, |
| skip_summary_collection=skip_summary_collection) |
| |
| |
| def collect_log_file(host, log_path, dest_path, use_tmp=False, clean=False, |
| clean_content=False): |
| """Collects a log file from the remote machine. |
| |
| Log files are collected from the remote machine and written into the |
| destination path. If dest_path is a directory, the log file will be named |
| using the basename of the remote log path. |
| |
| Very large files will randomly not be collected, to alleviate network |
| traffic in the case of widespread crashes dumping large core files. Note |
| that this check only applies to the exact file passed as log_path. For |
| example, if this is a directory, the size of the contents will not be |
| checked. |
| |
| @param host: The RemoteHost to collect logs from |
| @param log_path: The remote path to collect the log file from |
| @param dest_path: A path (file or directory) to write the copies logs into |
| @param use_tmp: If True, will first copy the logs to a temporary directory |
| on the host and download logs from there. |
| @param clean: If True, remove dest_path after upload attempt even if it |
| failed. |
| @param clean_content: If True, remove files and directories in dest_path |
| after upload attempt even if it failed. |
| |
| """ |
| logging.info('Collecting %s...', log_path) |
| if not host.check_cached_up_status(): |
| logging.warning('Host %s did not answer to ping, skip collecting log ' |
| 'file %s.', host.hostname, log_path) |
| return |
| try: |
| file_stats = _get_file_stats(host, log_path) |
| if not file_stats: |
| # Failed to get file stat, the file may not exist. |
| return |
| |
| if (not result_tools_runner.ENABLE_RESULT_THROTTLING and |
| random.random() > file_stats.collection_probability): |
| logging.warning('Collection of %s skipped:' |
| 'size=%s, collection_probability=%s', |
| log_path, file_stats.size, |
| file_stats.collection_probability) |
| elif use_tmp: |
| _collect_log_file_with_tmpdir(host, log_path, dest_path) |
| else: |
| _collect_log_file_with_summary(host, log_path, dest_path) |
| except Exception as e: |
| logging.exception('Non-critical failure: collection of %s failed: %s', |
| log_path, e) |
| finally: |
| if clean_content: |
| path_to_delete = os.path.join(pipes.quote(log_path), '*') |
| elif clean: |
| path_to_delete = pipes.quote(log_path) |
| if clean or clean_content: |
| host.run('rm -rf %s' % path_to_delete, ignore_status=True) |
| |
| |
| _FileStats = collections.namedtuple('_FileStats', |
| 'size collection_probability') |
| |
| |
| def _collect_log_file_with_tmpdir(host, log_path, dest_path): |
| """Collect log file from host through a temp directory on the host. |
| |
| @param host: The RemoteHost to collect logs from. |
| @param log_path: The remote path to collect the log file from. |
| @param dest_path: A path (file or directory) to write the copies logs into. |
| |
| """ |
| with _RemoteTempDir(host) as tmpdir: |
| host.run('cp -rp %s %s' % (pipes.quote(log_path), pipes.quote(tmpdir))) |
| source_path = os.path.join(tmpdir, os.path.basename(log_path)) |
| |
| _collect_log_file_with_summary(host, source_path, dest_path) |
| |
| |
| def _get_file_stats(host, path): |
| """Get the stats of a file from host. |
| |
| @param host: Instance of Host subclass with run(). |
| @param path: Path of file to check. |
| @returns: _FileStats namedtuple with file size and collection probability. |
| """ |
| cmd = 'ls -ld %s | cut -d" " -f5' % (pipes.quote(path),) |
| output = None |
| file_size = 0 |
| try: |
| output = host.run(cmd).stdout |
| except error.CmdError as e: |
| logging.warning('Getting size of file %r on host %r failed: %s. ' |
| 'Default its size to 0', path, host, e) |
| try: |
| if output is not None: |
| file_size = int(output) |
| except ValueError: |
| logging.warning('Failed to convert size string "%s" for %s on host %r. ' |
| 'File may not exist.', output, path, host) |
| return |
| |
| if file_size == 0: |
| return _FileStats(0, 1.0) |
| else: |
| collection_probability = _MAX_FILESIZE / float(file_size) |
| return _FileStats(file_size, collection_probability) |
| |
| |
| # import any site hooks for the crashdump and crashinfo collection |
| get_site_crashdumps = utils.import_site_function( |
| __file__, "autotest_lib.server.site_crashcollect", "get_site_crashdumps", |
| lambda host, test_start_time: None) |
| get_site_crashinfo = utils.import_site_function( |
| __file__, "autotest_lib.server.site_crashcollect", "get_site_crashinfo", |
| lambda host, test_start_time: None) |
| report_crashdumps = utils.import_site_function( |
| __file__, "autotest_lib.server.site_crashcollect", "report_crashdumps", |
| lambda host: None) |
| fetch_orphaned_crashdumps = utils.import_site_function( |
| __file__, "autotest_lib.server.site_crashcollect", "fetch_orphaned_crashdumps", |
| lambda host, host_resultdir: None) |
| get_host_infodir = utils.import_site_function( |
| __file__, "autotest_lib.server.site_crashcollect", "get_host_infodir", |
| lambda host: None) |
| |
| |
| @metrics.SecondsTimerDecorator( |
| 'chromeos/autotest/autoserv/get_crashdumps_duration') |
| def get_crashdumps(host, test_start_time): |
| get_site_crashdumps(host, test_start_time) |
| |
| |
| @metrics.SecondsTimerDecorator( |
| 'chromeos/autotest/autoserv/get_crashinfo_duration') |
| def get_crashinfo(host, test_start_time): |
| logging.info("Collecting crash information...") |
| |
| # get_crashdumps collects orphaned crashdumps and symbolicates all |
| # collected crashdumps. Symbolicating could happen |
| # during a postjob task as well, at which time some crashdumps could have |
| # already been pulled back from machine. So it doesn't necessarily need |
| # to wait for the machine to come up. |
| get_crashdumps(host, test_start_time) |
| |
| if wait_for_machine_to_recover(host): |
| # run any site-specific collection |
| get_site_crashinfo(host, test_start_time) |
| |
| crashinfo_dir = get_crashinfo_dir(host, 'crashinfo') |
| collect_messages(host) |
| collect_command(host, "dmesg", os.path.join(crashinfo_dir, "dmesg")) |
| collect_uncollected_logs(host) |
| |
| # Collect everything in /var/log. |
| log_path = os.path.join(crashinfo_dir, 'var') |
| os.makedirs(log_path) |
| collect_log_file(host, constants.LOG_DIR, log_path) |
| |
| # Collect console-ramoops. The filename has changed in linux-3.19, |
| # so collect all the files in the pstore dirs. |
| log_path = os.path.join(crashinfo_dir, 'pstore') |
| for pstore_dir in constants.LOG_PSTORE_DIRS: |
| collect_log_file(host, pstore_dir, log_path, use_tmp=True, |
| clean_content=True) |
| # Collect i915_error_state, only available on intel systems. |
| # i915 contains the Intel graphics state. It might contain useful data |
| # when a DUT hangs, times out or crashes. |
| log_path = os.path.join( |
| crashinfo_dir, os.path.basename(constants.LOG_I915_ERROR_STATE)) |
| collect_log_file(host, constants.LOG_I915_ERROR_STATE, |
| log_path, use_tmp=True) |
| |
| |
| # Load default for number of hours to wait before giving up on crash collection. |
| HOURS_TO_WAIT = global_config.global_config.get_config_value( |
| 'SERVER', 'crash_collection_hours_to_wait', type=float, default=4.0) |
| |
| |
| def wait_for_machine_to_recover(host, hours_to_wait=HOURS_TO_WAIT): |
| """Wait for a machine (possibly down) to become accessible again. |
| |
| @param host: A RemoteHost instance to wait on |
| @param hours_to_wait: Number of hours to wait before giving up |
| |
| @returns: True if the machine comes back up, False otherwise |
| """ |
| current_time = time.strftime("%b %d %H:%M:%S", time.localtime()) |
| if host.is_up(): |
| logging.info("%s already up, collecting crash info", host.hostname) |
| return True |
| |
| logging.info("Waiting %s hours for %s to come up (%s)", |
| hours_to_wait, host.hostname, current_time) |
| if not host.wait_up(timeout=hours_to_wait * 3600): |
| (metrics.Counter('chromeos/autotest/errors/collect_crashinfo_timeout') |
| .increment()) |
| logging.warning("%s down, unable to collect crash info", |
| host.hostname) |
| return False |
| else: |
| logging.info("%s is back up, collecting crash info", host.hostname) |
| return True |
| |
| |
| def get_crashinfo_dir(host, dir_prefix): |
| """Find and if necessary create a directory to store crashinfo in. |
| |
| @param host: The RemoteHost object that crashinfo will be collected from |
| @param dir_prefix: Prefix of directory name. |
| |
| @returns: The path to an existing directory for writing crashinfo into |
| """ |
| host_resultdir = getattr(getattr(host, "job", None), "resultdir", None) |
| if host_resultdir: |
| infodir = host_resultdir |
| else: |
| infodir = os.path.abspath(os.getcwd()) |
| infodir = os.path.join(infodir, "%s.%s" % (dir_prefix, host.hostname)) |
| if not os.path.exists(infodir): |
| os.mkdir(infodir) |
| return infodir |
| |
| |
| def collect_command(host, command, dest_path): |
| """Collects the result of a command on the remote machine. |
| |
| The standard output of the command will be collected and written into the |
| desitionation path. The destination path is assumed to be filename and |
| not a directory. |
| |
| @param host: The RemoteHost to collect from |
| @param command: A shell command to run on the remote machine and capture |
| the output from. |
| @param dest_path: A file path to write the results of the log into |
| """ |
| logging.info("Collecting '%s' ...", command) |
| try: |
| result = host.run(command, stdout_tee=None).stdout |
| utils.open_write_close(dest_path, result) |
| except Exception as e: |
| logging.warning("Collection of '%s' failed:\n%s", command, e) |
| |
| |
| def collect_uncollected_logs(host): |
| """Collects any leftover uncollected logs from the client. |
| |
| @param host: The RemoteHost to collect from |
| """ |
| if host.job: |
| try: |
| logs = host.job.get_client_logs() |
| for hostname, remote_path, local_path in logs: |
| if hostname == host.hostname: |
| logging.info('Retrieving logs from %s:%s into %s', |
| hostname, remote_path, local_path) |
| collect_log_file(host, remote_path + '/', local_path + '/') |
| except Exception as e: |
| logging.warning('Error while trying to collect stranded ' |
| 'Autotest client logs: %s', e) |
| |
| |
| def collect_messages(host): |
| """Collects the 'new' contents of /var/log/messages. |
| |
| If host.VAR_LOG_MESSAGE_COPY_PATH is on the remote machine, collects |
| the contents of /var/log/messages excluding whatever initial contents |
| are already present in host.VAR_LOG_MESSAGE_COPY_PATH. If it is not |
| present, simply collects the entire contents of /var/log/messages. |
| |
| @param host: The RemoteHost to collect from |
| """ |
| crashinfo_dir = get_crashinfo_dir(host, 'crashinfo') |
| |
| try: |
| # paths to the messages files |
| messages = os.path.join(crashinfo_dir, "messages") |
| messages_raw = os.path.join(crashinfo_dir, "messages.raw") |
| messages_at_start = os.path.join(crashinfo_dir, "messages.at_start") |
| |
| # grab the files from the remote host |
| collect_log_file(host, host.VAR_LOG_MESSAGES_COPY_PATH, |
| messages_at_start) |
| collect_log_file(host, "/var/log/messages", messages_raw) |
| |
| # figure out how much of messages.raw to skip |
| if os.path.exists(messages_at_start): |
| # if the first lines of the messages at start should match the |
| # first lines of the current messages; if they don't then messages |
| # has been erase or rotated and we just grab all of it |
| first_line_at_start = utils.read_one_line(messages_at_start) |
| first_line_now = utils.read_one_line(messages_raw) |
| if first_line_at_start != first_line_now: |
| size_at_start = 0 |
| else: |
| size_at_start = os.path.getsize(messages_at_start) |
| else: |
| size_at_start = 0 |
| raw_messages_file = open(messages_raw) |
| messages_file = open(messages, "w") |
| raw_messages_file.seek(size_at_start) |
| shutil.copyfileobj(raw_messages_file, messages_file) |
| raw_messages_file.close() |
| messages_file.close() |
| |
| # get rid of the "raw" versions of messages |
| os.remove(messages_raw) |
| if os.path.exists(messages_at_start): |
| os.remove(messages_at_start) |
| except Exception as e: |
| logging.warning("Error while collecting /var/log/messages: %s", e) |
