client/bin/base_sysinfo.py

   1 import os, shutil, re, glob, subprocess, logging
   2
   3 from autotest_lib.client.common_lib import log
   4 from autotest_lib.client.bin import utils, package
   5
   6
   7 _DEFAULT_COMMANDS_TO_LOG_PER_TEST = []
   8 _DEFAULT_COMMANDS_TO_LOG_PER_BOOT = [
   9     "lspci -vvn", "gcc --version", "ld --version", "mount", "hostname",
  10     "uptime",
  11     ]
  12 _DEFAULT_COMMANDS_TO_LOG_BEFORE_ITERATION = []
  13 _DEFAULT_COMMANDS_TO_LOG_AFTER_ITERATION = []
  14
  15 _DEFAULT_FILES_TO_LOG_PER_TEST = []
  16 _DEFAULT_FILES_TO_LOG_PER_BOOT = [
  17     "/proc/pci", "/proc/meminfo", "/proc/slabinfo", "/proc/version",
  18     "/proc/cpuinfo", "/proc/modules", "/proc/interrupts", "/proc/partitions",
  19     ]
  20 _DEFAULT_FILES_TO_LOG_BEFORE_ITERATION = [
  21     "/proc/schedstat", "/proc/meminfo", "/proc/slabinfo", "/proc/interrupts"
  22     ]
  23 _DEFAULT_FILES_TO_LOG_AFTER_ITERATION = [
  24     "/proc/schedstat", "/proc/meminfo", "/proc/slabinfo", "/proc/interrupts"
  25     ]
  26
  27
  28 class loggable(object):
  29     """ Abstract class for representing all things "loggable" by sysinfo. """
  30     def __init__(self, logf, log_in_keyval):
  31         self.logf = logf
  32         self.log_in_keyval = log_in_keyval
  33
  34
  35     def readline(self, logdir):
  36         path = os.path.join(logdir, self.logf)
  37         if os.path.exists(path):
  38             return utils.read_one_line(path)
  39         else:
  40             return ""
  41
  42
  43 class logfile(loggable):
  44     def __init__(self, path, logf=None, log_in_keyval=False):
  45         if not logf:
  46             logf = os.path.basename(path)
  47         super(logfile, self).__init__(logf, log_in_keyval)
  48         self.path = path
  49
  50
  51     def __repr__(self):
  52         r = "sysinfo.logfile(%r, %r, %r)"
  53         r %= (self.path, self.logf, self.log_in_keyval)
  54         return r
  55
  56
  57     def __eq__(self, other):
  58         if isinstance(other, logfile):
  59             return (self.path, self.logf) == (other.path, other.logf)
  60         elif isinstance(other, loggable):
  61             return False
  62         return NotImplemented
  63
  64
  65     def __ne__(self, other):
  66         result = self.__eq__(other)
  67         if result is NotImplemented:
  68             return result
  69         return not result
  70
  71
  72     def __hash__(self):
  73         return hash((self.path, self.logf))
  74
  75
  76     def run(self, logdir):
  77         if os.path.exists(self.path):
  78             shutil.copyfile(self.path, os.path.join(logdir, self.logf))
  79
  80
  81 class command(loggable):
  82     def __init__(self, cmd, logf=None, log_in_keyval=False, compress_log=False):
  83         if not logf:
  84             logf = cmd.replace(" ", "_")
  85         super(command, self).__init__(logf, log_in_keyval)
  86         self.cmd = cmd
  87         self._compress_log = compress_log
  88
  89
  90     def __repr__(self):
  91         r = "sysinfo.command(%r, %r, %r)"
  92         r %= (self.cmd, self.logf, self.log_in_keyval)
  93         return r
  94
  95
  96     def __eq__(self, other):
  97         if isinstance(other, command):
  98             return (self.cmd, self.logf) == (other.cmd, other.logf)
  99         elif isinstance(other, loggable):
 100             return False
 101         return NotImplemented
 102
 103
 104     def __ne__(self, other):
 105         result = self.__eq__(other)
 106         if result is NotImplemented:
 107             return result
 108         return not result
 109
 110
 111     def __hash__(self):
 112         return hash((self.cmd, self.logf))
 113
 114
 115     def run(self, logdir):
 116         env = os.environ.copy()
 117         if "PATH" not in env:
 118             env["PATH"] = "/usr/bin:/bin"
 119         logf_path = os.path.join(logdir, self.logf)
 120         stdin = open(os.devnull, "r")
 121         stderr = open(os.devnull, "w")
 122         stdout = open(logf_path, "w")
 123         try:
 124             subprocess.call(self.cmd, stdin=stdin, stdout=stdout, stderr=stderr,
 125                             shell=True, env=env)
 126         finally:
 127             for f in (stdin, stdout, stderr):
 128                 f.close()
 129             if self._compress_log and os.path.exists(logf_path):
 130                 utils.system('gzip -9 "%s"' % logf_path, ignore_status=True)
 131
 132
 133 class base_sysinfo(object):
 134     def __init__(self, job_resultsdir):
 135         self.sysinfodir = self._get_sysinfodir(job_resultsdir)
 136
 137         # pull in the post-test logs to collect
 138         self.test_loggables = set()
 139         for cmd in _DEFAULT_COMMANDS_TO_LOG_PER_TEST:
 140             self.test_loggables.add(command(cmd))
 141         for filename in _DEFAULT_FILES_TO_LOG_PER_TEST:
 142             self.test_loggables.add(logfile(filename))
 143
 144         # pull in the EXTRA post-boot logs to collect
 145         self.boot_loggables = set()
 146         for cmd in _DEFAULT_COMMANDS_TO_LOG_PER_BOOT:
 147             self.boot_loggables.add(command(cmd))
 148         for filename in _DEFAULT_FILES_TO_LOG_PER_BOOT:
 149             self.boot_loggables.add(logfile(filename))
 150
 151         # pull in the pre test iteration logs to collect
 152         self.before_iteration_loggables = set()
 153         for cmd in _DEFAULT_COMMANDS_TO_LOG_BEFORE_ITERATION:
 154             self.before_iteration_loggables.add(
 155                 command(cmd, logf=cmd.replace(" ", "_") + '.before'))
 156         for fname in _DEFAULT_FILES_TO_LOG_BEFORE_ITERATION:
 157             self.before_iteration_loggables.add(
 158                 logfile(fname, logf=os.path.basename(fname) + '.before'))
 159
 160         # pull in the post test iteration logs to collect
 161         self.after_iteration_loggables = set()
 162         for cmd in _DEFAULT_COMMANDS_TO_LOG_AFTER_ITERATION:
 163             self.after_iteration_loggables.add(
 164                 command(cmd, logf=cmd.replace(" ", "_") + '.after'))
 165         for fname in _DEFAULT_FILES_TO_LOG_AFTER_ITERATION:
 166             self.after_iteration_loggables.add(
 167                 logfile(fname, logf=os.path.basename(fname) + '.after'))
 168
 169         # add in a couple of extra files and commands we want to grab
 170         self.test_loggables.add(command("df -mP", logf="df"))
 171         # We compress the dmesg because it can get large when kernels are
 172         # configured with a large buffer and some tests trigger OOMs or
 173         # other large "spam" that fill it up...
 174         self.test_loggables.add(command("dmesg -c", logf="dmesg",
 175                                         compress_log=True))
 176         self.boot_loggables.add(logfile("/proc/cmdline",
 177                                              log_in_keyval=True))
 178         # log /proc/mounts but with custom filename since we already
 179         # log the output of the "mount" command as the filename "mount"
 180         self.boot_loggables.add(logfile('/proc/mounts', logf='proc_mounts'))
 181         self.boot_loggables.add(command("uname -a", logf="uname",
 182                                              log_in_keyval=True))
 183
 184
 185     def serialize(self):
 186         return {"boot": self.boot_loggables, "test": self.test_loggables}
 187
 188
 189     def deserialize(self, serialized):
 190         self.boot_loggables = serialized["boot"]
 191         self.test_loggables = serialized["test"]
 192
 193
 194     @staticmethod
 195     def _get_sysinfodir(resultsdir):
 196         sysinfodir = os.path.join(resultsdir, "sysinfo")
 197         if not os.path.exists(sysinfodir):
 198             os.makedirs(sysinfodir)
 199         return sysinfodir
 200
 201
 202     def _get_reboot_count(self):
 203         if not glob.glob(os.path.join(self.sysinfodir, "*")):
 204             return -1
 205         else:
 206             return len(glob.glob(os.path.join(self.sysinfodir, "boot.*")))
 207
 208
 209     def _get_boot_subdir(self, next=False):
 210         reboot_count = self._get_reboot_count()
 211         if next:
 212             reboot_count += 1
 213         if reboot_count < 1:
 214             return self.sysinfodir
 215         else:
 216             boot_dir = "boot.%d" % (reboot_count - 1)
 217             return os.path.join(self.sysinfodir, boot_dir)
 218
 219
 220     def _get_iteration_subdir(self, test, iteration):
 221         iter_dir = "iteration.%d" % iteration
 222
 223         logdir = os.path.join(self._get_sysinfodir(test.outputdir), iter_dir)
 224         if not os.path.exists(logdir):
 225             os.mkdir(logdir)
 226         return logdir
 227
 228
 229     @log.log_and_ignore_errors("post-reboot sysinfo error:")
 230     def log_per_reboot_data(self):
 231         """ Logging hook called whenever a job starts, and again after
 232         any reboot. """
 233         logdir = self._get_boot_subdir(next=True)
 234         if not os.path.exists(logdir):
 235             os.mkdir(logdir)
 236
 237         for log in (self.test_loggables | self.boot_loggables):
 238             log.run(logdir)
 239
 240         # also log any installed packages
 241         installed_path = os.path.join(logdir, "installed_packages")
 242         installed_packages = "\n".join(package.list_all()) + "\n"
 243         utils.open_write_close(installed_path, installed_packages)
 244
 245
 246     @log.log_and_ignore_errors("pre-test sysinfo error:")
 247     def log_before_each_test(self, test):
 248         """ Logging hook called before a test starts. """
 249         self._installed_packages = package.list_all()
 250         if os.path.exists("/var/log/messages"):
 251             stat = os.stat("/var/log/messages")
 252             self._messages_size = stat.st_size
 253             self._messages_inode = stat.st_ino
 254
 255
 256     @log.log_and_ignore_errors("post-test sysinfo error:")
 257     def log_after_each_test(self, test):
 258         """ Logging hook called after a test finishs. """
 259         test_sysinfodir = self._get_sysinfodir(test.outputdir)
 260
 261         # create a symlink in the test sysinfo dir to the current boot
 262         reboot_dir = self._get_boot_subdir()
 263         assert os.path.exists(reboot_dir)
 264         symlink_dest = os.path.join(test_sysinfodir, "reboot_current")
 265         symlink_src = utils.get_relative_path(reboot_dir,
 266                                               os.path.dirname(symlink_dest))
 267         try:
 268             os.symlink(symlink_src, symlink_dest)
 269         except Exception, e:
 270             raise Exception, '%s: whilst linking %s to %s' % (e, symlink_src,
 271                                                               symlink_dest)
 272
 273         # run all the standard logging commands
 274         for log in self.test_loggables:
 275             log.run(test_sysinfodir)
 276
 277         # grab any new data from /var/log/messages
 278         self._log_messages(test_sysinfodir)
 279
 280         # log some sysinfo data into the test keyval file
 281         keyval = self.log_test_keyvals(test_sysinfodir)
 282         test.write_test_keyval(keyval)
 283
 284         # log any changes to installed packages
 285         old_packages = set(self._installed_packages)
 286         new_packages = set(package.list_all())
 287         added_path = os.path.join(test_sysinfodir, "added_packages")
 288         added_packages = "\n".join(new_packages - old_packages) + "\n"
 289         utils.open_write_close(added_path, added_packages)
 290         removed_path = os.path.join(test_sysinfodir, "removed_packages")
 291         removed_packages = "\n".join(old_packages - new_packages) + "\n"
 292         utils.open_write_close(removed_path, removed_packages)
 293
 294
 295     @log.log_and_ignore_errors("pre-test siteration sysinfo error:")
 296     def log_before_each_iteration(self, test, iteration=None):
 297         """ Logging hook called before a test iteration."""
 298         if not iteration:
 299             iteration = test.iteration
 300         logdir = self._get_iteration_subdir(test, iteration)
 301
 302         for log in self.before_iteration_loggables:
 303             log.run(logdir)
 304
 305
 306     @log.log_and_ignore_errors("post-test siteration sysinfo error:")
 307     def log_after_each_iteration(self, test, iteration=None):
 308         """ Logging hook called after a test iteration."""
 309         if not iteration:
 310             iteration = test.iteration
 311         logdir = self._get_iteration_subdir(test, iteration)
 312
 313         for log in self.after_iteration_loggables:
 314             log.run(logdir)
 315
 316
 317     def _log_messages(self, logdir):
 318         """ Log all of the new data in /var/log/messages. """
 319         try:
 320             # log all of the new data in /var/log/messages
 321             bytes_to_skip = 0
 322             if hasattr(self, "_messages_size"):
 323                 current_inode = os.stat("/var/log/messages").st_ino
 324                 if current_inode == self._messages_inode:
 325                     bytes_to_skip = self._messages_size
 326             in_messages = open("/var/log/messages")
 327             in_messages.seek(bytes_to_skip)
 328             out_messages = open(os.path.join(logdir, "messages"), "w")
 329             out_messages.write(in_messages.read())
 330             in_messages.close()
 331             out_messages.close()
 332         except Exception, e:
 333             logging.error("/var/log/messages collection failed with %s", e)
 334
 335
 336     @staticmethod
 337     def _read_sysinfo_keyvals(loggables, logdir):
 338         keyval = {}
 339         for log in loggables:
 340             if log.log_in_keyval:
 341                 keyval["sysinfo-" + log.logf] = log.readline(logdir)
 342         return keyval
 343
 344
 345     def log_test_keyvals(self, test_sysinfodir):
 346         """ Logging hook called by log_after_each_test to collect keyval
 347         entries to be written in the test keyval. """
 348         keyval = {}
 349
 350         # grab any loggables that should be in the keyval
 351         keyval.update(self._read_sysinfo_keyvals(
 352             self.test_loggables, test_sysinfodir))
 353         keyval.update(self._read_sysinfo_keyvals(
 354             self.boot_loggables,
 355             os.path.join(test_sysinfodir, "reboot_current")))
 356
 357         # remove hostname from uname info
 358         #   Linux lpt36 2.6.18-smp-230.1 #1 [4069269] SMP Fri Oct 24 11:30:...
 359         if "sysinfo-uname" in keyval:
 360             kernel_vers = " ".join(keyval["sysinfo-uname"].split()[2:])
 361             keyval["sysinfo-uname"] = kernel_vers
 362
 363         # grab the total avail memory, not used by sys tables
 364         path = os.path.join(test_sysinfodir, "reboot_current", "meminfo")
 365         if os.path.exists(path):
 366             mem_data = open(path).read()
 367             match = re.search(r"^MemTotal:\s+(\d+) kB$", mem_data,
 368                               re.MULTILINE)
 369             if match:
 370                 keyval["sysinfo-memtotal-in-kb"] = match.group(1)
 371
 372         # guess the system's total physical memory, including sys tables
 373         keyval["sysinfo-phys-mbytes"] = utils.rounded_memtotal()//1024
 374
 375         # return what we collected
 376         return keyval