base_sysinfo.py revision a82dc35ef721720e73db887d895bbd5cb835291c
1import os, shutil, re, glob, subprocess, logging 2 3from autotest_lib.client.common_lib import log 4from 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 28class 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 43class 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 81class 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 133class 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 377