def log_after_each_test(self, test):
""" Logging hook called after a test finishs. """
test_sysinfodir = self._get_sysinfodir(test.outputdir)
# create a symlink in the test sysinfo dir to the current boot
reboot_dir = self._get_boot_subdir()
assert os.path.exists(reboot_dir)
symlink_dest = os.path.join(test_sysinfodir, "reboot_current")
os.symlink(
# create a relative symlink
utils.get_relative_path(reboot_dir, os.path.dirname(symlink_dest)),
symlink_dest)
# run all the standard logging commands
for log in self.test_loggables:
log.run(test_sysinfodir)
# grab any new data from /var/log/messages
self._log_messages(test_sysinfodir)
# log some sysinfo data into the test keyval file
keyval = self.log_test_keyvals(test_sysinfodir)
test.write_test_keyval(keyval)
# log any changes to installed packages
old_packages = set(self._installed_packages)
new_packages = set(package.list_all())
added_path = os.path.join(test_sysinfodir, "added_packages")
added_packages = "\n".join(new_packages - old_packages) + "\n"
utils.open_write_close(added_path, added_packages)
removed_path = os.path.join(test_sysinfodir, "removed_packages")
removed_packages = "\n".join(old_packages - new_packages) + "\n"
utils.open_write_close(removed_path, removed_packages)
def log_after_each_iteration(self, test, iteration=None):
""" Logging hook called after a test iteration."""
if not iteration:
iteration = test.iteration
logdir = self._get_iteration_subdir(test, iteration)
for log in self.after_iteration_loggables:
log.run(logdir)
def log_after_each_iteration(self, test, iteration=None):
""" Logging hook called after a test iteration."""
if not iteration:
iteration = test.iteration
logdir = self._get_iteration_subdir(test, iteration)
for log in self.after_iteration_loggables:
log.run(logdir)
def log_before_each_test(self, test):
"""Logging hook called before a test starts.
@param test: A test object.
"""
super(site_sysinfo, self).log_before_each_test(test)
for log in self.diffable_loggables:
log.run(log_dir=None, collect_init_status=True)
def log_after_each_test(self, test):
"""Logging hook called after a test finishs.
@param test: A test object.
"""
super(site_sysinfo, self).log_after_each_test(test)
test_sysinfodir = self._get_sysinfodir(test.outputdir)
for log in self.diffable_loggables:
log.run(log_dir=test_sysinfodir, collect_init_status=False,
collect_all=not test.success)
def log_before_each_iteration(self, test, iteration=None):
"""Logging hook called before a test iteration.
@param test: A test object.
@param iteration: A test iteration.
"""
if not iteration:
iteration = test.iteration
logdir = self._get_iteration_subdir(test, iteration)
for log in self.before_iteration_loggables:
log.run(logdir)
def log_per_reboot_data(self):
"""Logging hook called when a job starts, and again after any reboot."""
logdir = self._get_boot_subdir(next=True)
if not os.path.exists(logdir):
os.mkdir(logdir)
for log in (self.test_loggables | self.boot_loggables):
log.run(logdir)
# also log any installed packages
installed_path = os.path.join(logdir, "installed_packages")
installed_packages = "\n".join(package.list_all()) + "\n"
utils.open_write_close(installed_path, installed_packages)
def log_before_each_test(self, test):
"""Logging hook called before a test starts.
@param test: A test object.
"""
super(site_sysinfo, self).log_before_each_test(test)
for log in self.diffable_loggables:
log.run(log_dir=None, collect_init_status=True)
# Start each log with the board name for orientation.
logging.info("ChromeOS BOARD = %s",
utils.get_board_with_frequency_and_memory())
def log_per_reboot_data(self):
""" Logging hook called whenever a job starts, and again after
any reboot. """
logdir = self._get_boot_subdir(next=True)
if not os.path.exists(logdir):
os.mkdir(logdir)
for log in (self.test_loggables | self.boot_loggables):
log.run(logdir)
# also log any installed packages
installed_path = os.path.join(logdir, "installed_packages")
installed_packages = "\n".join(package.list_all()) + "\n"
utils.open_write_close(installed_path, installed_packages)
def log_after_each_iteration(self, test, iteration=None):
"""Logging hook called after a test iteration.
@param test: A test object.
@param iteration: A test iteration.
"""
if not iteration:
iteration = test.iteration
logdir = self._get_iteration_subdir(test, iteration)
for log in self.after_iteration_loggables:
log.run(logdir)
utils.system('logger "autotest finished iteration %s"' % logdir,
ignore_status=True)
def _run_loggables_ignoring_errors(loggables, output_dir):
"""Runs the given loggables robustly.
In the event of any one of the loggables raising an exception, we print a
traceback and continue on.
@param loggables: An iterable of base_sysinfo.loggable objects.
@param output_dir: Path to the output directory.
"""
for log in loggables:
try:
log.run(output_dir)
except Exception:
logging.exception(
'Failed to collect loggable %r to %s. Continuing...', log,
output_dir)
def log_before_each_iteration(self, test, iteration=None):
"""Logging hook called before a test iteration.
@param test: A test object.
@param iteration: A test iteration.
"""
if not iteration:
iteration = test.iteration
logdir = self._get_iteration_subdir(test, iteration)
for log in self.before_iteration_loggables:
log.run(logdir)
# Start each log with the board name for orientation.
board = utils.get_board_with_frequency_and_memory()
logging.info('ChromeOS BOARD = %s', board)
# Leave some autotest bread crumbs in the system logs.
utils.system('logger "autotest starting iteration %s on %s"' %
(logdir, board),
ignore_status=True)
class base_sysinfo(object):
def __init__(self, job_resultsdir):
self.sysinfodir = self._get_sysinfodir(job_resultsdir)
# pull in the post-test logs to collect
self.test_loggables = set()
for cmd in _DEFAULT_COMMANDS_TO_LOG_PER_TEST:
self.test_loggables.add(command(cmd))
for filename in _DEFAULT_FILES_TO_LOG_PER_TEST:
self.test_loggables.add(logfile(filename))
# pull in the EXTRA post-boot logs to collect
self.boot_loggables = set()
for cmd in _DEFAULT_COMMANDS_TO_LOG_PER_BOOT:
self.boot_loggables.add(command(cmd))
for filename in _DEFAULT_FILES_TO_LOG_PER_BOOT:
self.boot_loggables.add(logfile(filename))
# pull in the pre test iteration logs to collect
self.before_iteration_loggables = set()
for cmd in _DEFAULT_COMMANDS_TO_LOG_BEFORE_ITERATION:
self.before_iteration_loggables.add(
command(cmd, logf=cmd.replace(" ", "_") + '.before'))
for fname in _DEFAULT_FILES_TO_LOG_BEFORE_ITERATION:
self.before_iteration_loggables.add(
logfile(fname, logf=os.path.basename(fname) + '.before'))
# pull in the post test iteration logs to collect
self.after_iteration_loggables = set()
for cmd in _DEFAULT_COMMANDS_TO_LOG_AFTER_ITERATION:
self.after_iteration_loggables.add(
command(cmd, logf=cmd.replace(" ", "_") + '.after'))
for fname in _DEFAULT_FILES_TO_LOG_AFTER_ITERATION:
self.after_iteration_loggables.add(
logfile(fname, logf=os.path.basename(fname) + '.after'))
# add in a couple of extra files and commands we want to grab
self.test_loggables.add(command("df -mP", logf="df"))
# We compress the dmesg because it can get large when kernels are
# configured with a large buffer and some tests trigger OOMs or
# other large "spam" that fill it up...
self.test_loggables.add(
command("dmesg -c", logf="dmesg", compress_log=True))
self.boot_loggables.add(logfile("/proc/cmdline", log_in_keyval=True))
# log /proc/mounts but with custom filename since we already
# log the output of the "mount" command as the filename "mount"
self.boot_loggables.add(logfile('/proc/mounts', logf='proc_mounts'))
self.boot_loggables.add(
command("uname -a", logf="uname", log_in_keyval=True))
def serialize(self):
return {"boot": self.boot_loggables, "test": self.test_loggables}
def deserialize(self, serialized):
self.boot_loggables = serialized["boot"]
self.test_loggables = serialized["test"]
@staticmethod
def _get_sysinfodir(resultsdir):
sysinfodir = os.path.join(resultsdir, "sysinfo")
if not os.path.exists(sysinfodir):
os.makedirs(sysinfodir)
return sysinfodir
def _get_reboot_count(self):
if not glob.glob(os.path.join(self.sysinfodir, "*")):
return -1
else:
return len(glob.glob(os.path.join(self.sysinfodir, "boot.*")))
def _get_boot_subdir(self, next=False):
reboot_count = self._get_reboot_count()
if next:
reboot_count += 1
if reboot_count < 1:
return self.sysinfodir
else:
boot_dir = "boot.%d" % (reboot_count - 1)
return os.path.join(self.sysinfodir, boot_dir)
def _get_iteration_subdir(self, test, iteration):
iter_dir = "iteration.%d" % iteration
logdir = os.path.join(self._get_sysinfodir(test.outputdir), iter_dir)
if not os.path.exists(logdir):
os.mkdir(logdir)
return logdir
@log.log_and_ignore_errors("post-reboot sysinfo error:")
def log_per_reboot_data(self):
""" Logging hook called whenever a job starts, and again after
any reboot. """
logdir = self._get_boot_subdir(next=True)
if not os.path.exists(logdir):
os.mkdir(logdir)
for log in (self.test_loggables | self.boot_loggables):
log.run(logdir)
# also log any installed packages
installed_path = os.path.join(logdir, "installed_packages")
installed_packages = "\n".join(package.list_all()) + "\n"
utils.open_write_close(installed_path, installed_packages)
@log.log_and_ignore_errors("pre-test sysinfo error:")
def log_before_each_test(self, test):
""" Logging hook called before a test starts. """
self._installed_packages = package.list_all()
if os.path.exists("/var/log/messages"):
stat = os.stat("/var/log/messages")
self._messages_size = stat.st_size
self._messages_inode = stat.st_ino
@log.log_and_ignore_errors("post-test sysinfo error:")
def log_after_each_test(self, test):
""" Logging hook called after a test finishs. """
test_sysinfodir = self._get_sysinfodir(test.outputdir)
# create a symlink in the test sysinfo dir to the current boot
reboot_dir = self._get_boot_subdir()
assert os.path.exists(reboot_dir)
symlink_dest = os.path.join(test_sysinfodir, "reboot_current")
symlink_src = utils.get_relative_path(reboot_dir,
os.path.dirname(symlink_dest))
try:
os.symlink(symlink_src, symlink_dest)
except Exception, e:
raise Exception, '%s: whilst linking %s to %s' % (e, symlink_src,
symlink_dest)
# run all the standard logging commands
for log in self.test_loggables:
log.run(test_sysinfodir)
# grab any new data from /var/log/messages
self._log_messages(test_sysinfodir)
# log some sysinfo data into the test keyval file
keyval = self.log_test_keyvals(test_sysinfodir)
test.write_test_keyval(keyval)
# log any changes to installed packages
old_packages = set(self._installed_packages)
new_packages = set(package.list_all())
added_path = os.path.join(test_sysinfodir, "added_packages")
added_packages = "\n".join(new_packages - old_packages) + "\n"
utils.open_write_close(added_path, added_packages)
removed_path = os.path.join(test_sysinfodir, "removed_packages")
removed_packages = "\n".join(old_packages - new_packages) + "\n"
utils.open_write_close(removed_path, removed_packages)
# create a symlink in the test sysinfo dir to the current boot
reboot_dir = self._get_boot_subdir()
assert os.path.exists(reboot_dir)
symlink_dest = os.path.join(test_sysinfodir, "reboot_current")
symlink_src = utils.get_relative_path(reboot_dir,
os.path.dirname(symlink_dest))
try:
os.symlink(symlink_src, symlink_dest)
except Exception, e:
raise Exception, '%s: whilst linking %s to %s' % (e, symlink_src,
symlink_dest)
# run all the standard logging commands
for log in self.test_loggables:
log.run(test_sysinfodir)
# grab any new data from /var/log/messages
self._log_messages(test_sysinfodir)
# grab any new data from systemd journal
self._log_journal(test_sysinfodir)
# log some sysinfo data into the test keyval file
keyval = self.log_test_keyvals(test_sysinfodir)
test.write_test_keyval(keyval)
# log any changes to installed packages
old_packages = set(self._installed_packages)
new_packages = set(package.list_all())
added_path = os.path.join(test_sysinfodir, "added_packages")