tko/parsers/version_1.py

   1 import os, re, time
   2
   3 from autotest_lib.tko import models, status_lib, utils as tko_utils
   4 from autotest_lib.tko.parsers import base, version_0
   5
   6
   7 class job(version_0.job):
   8     def exit_status(self):
   9         # find the .autoserv_execute path
  10         top_dir = tko_utils.find_toplevel_job_dir(self.dir)
  11         if not top_dir:
  12             return "ABORT"
  13         execute_path = os.path.join(top_dir, ".autoserv_execute")
  14
  15         # if for some reason we can't read the status code, assume disaster
  16         if not os.path.exists(execute_path):
  17             return "ABORT"
  18         lines = open(execute_path).readlines()
  19         if len(lines) < 2:
  20             return "ABORT"
  21         try:
  22             status_code = int(lines[1])
  23         except ValueError:
  24             return "ABORT"
  25
  26         if not os.WIFEXITED(status_code):
  27             # looks like a signal - an ABORT
  28             return "ABORT"
  29         elif os.WEXITSTATUS(status_code) != 0:
  30             # looks like a non-zero exit - a failure
  31             return "FAIL"
  32         else:
  33             # looks like exit code == 0
  34             return "GOOD"
  35
  36
  37 class kernel(models.kernel):
  38     def __init__(self, base, patches):
  39         if base:
  40             patches = [patch(*p.split()) for p in patches]
  41             hashes = [p.hash for p in patches]
  42             kernel_hash = self.compute_hash(base, hashes)
  43         else:
  44             base = "UNKNOWN"
  45             patches = []
  46             kernel_hash = "UNKNOWN"
  47         super(kernel, self).__init__(base, patches, kernel_hash)
  48
  49
  50 class test(models.test):
  51     @staticmethod
  52     def load_iterations(keyval_path):
  53         return iteration.load_from_keyval(keyval_path)
  54
  55
  56 class iteration(models.iteration):
  57     @staticmethod
  58     def parse_line_into_dicts(line, attr_dict, perf_dict):
  59         key, val_type, value = "", "", ""
  60
  61         # figure out what the key, value and keyval type are
  62         typed_match = re.search("^([^=]*)\{(\w*)\}=(.*)$", line)
  63         if typed_match:
  64             key, val_type, value = typed_match.groups()
  65         else:
  66             # old-fashioned untyped match, assume perf
  67             untyped_match = re.search("^([^=]*)=(.*)$", line)
  68             if untyped_match:
  69                 key, value = untyped_match.groups()
  70                 val_type = "perf"
  71
  72         # parse the actual value into a dict
  73         try:
  74             if val_type == "attr":
  75                 attr_dict[key] = value
  76             elif val_type == "perf":
  77                 perf_dict[key] = float(value)
  78             else:
  79                 raise ValueError
  80         except ValueError:
  81             msg = ("WARNING: line '%s' found in test "
  82                    "iteration keyval could not be parsed")
  83             msg %= line
  84             tko_utils.dprint(msg)
  85
  86
  87 class status_line(version_0.status_line):
  88     def __init__(self, indent, status, subdir, testname, reason,
  89                  optional_fields):
  90         # handle INFO fields
  91         if status == "INFO":
  92             self.type = "INFO"
  93             self.indent = indent
  94             self.status = self.subdir = self.testname = self.reason = None
  95             self.optional_fields = optional_fields
  96         else:
  97             # everything else is backwards compatible
  98             super(status_line, self).__init__(indent, status, subdir,
  99                                               testname, reason,
 100                                               optional_fields)
 101
 102
 103     def is_successful_reboot(self, current_status):
 104         # make sure this is a reboot line
 105         if self.testname != "reboot":
 106             return False
 107
 108         # make sure this was not a failure
 109         if status_lib.is_worse_than_or_equal_to(current_status, "FAIL"):
 110             return False
 111
 112         # it must have been a successful reboot
 113         return True
 114
 115
 116     def get_kernel(self):
 117         # get the base kernel version
 118         fields = self.optional_fields
 119         base = re.sub("-autotest$", "", fields.get("kernel", ""))
 120         # get a list of patches
 121         patches = []
 122         patch_index = 0
 123         while ("patch%d" % patch_index) in fields:
 124             patches.append(fields["patch%d" % patch_index])
 125             patch_index += 1
 126         # create a new kernel instance
 127         return kernel(base, patches)
 128
 129
 130     def get_timestamp(self):
 131         return tko_utils.get_timestamp(self.optional_fields,
 132                                        "timestamp")
 133
 134
 135 # the default implementations from version 0 will do for now
 136 patch = version_0.patch
 137
 138
 139 class parser(base.parser):
 140     @staticmethod
 141     def make_job(dir):
 142         return job(dir)
 143
 144
 145     @staticmethod
 146     def make_dummy_abort(indent, subdir, testname, timestamp, reason):
 147         indent = "\t" * indent
 148         if not subdir:
 149             subdir = "----"
 150         if not testname:
 151             testname = "----"
 152
 153         # There is no guarantee that this will be set.
 154         timestamp_field = ''
 155         if timestamp:
 156             timestamp_field = '\ttimestamp=%s' % timestamp
 157
 158         msg = indent + "END ABORT\t%s\t%s%s\t%s"
 159         return msg % (subdir, testname, timestamp_field, reason)
 160
 161
 162     @staticmethod
 163     def put_back_line_and_abort(
 164         line_buffer, line, indent, subdir, timestamp, reason):
 165         tko_utils.dprint("Unexpected indent regression, aborting")
 166         line_buffer.put_back(line)
 167         abort = parser.make_dummy_abort(
 168             indent, subdir, subdir, timestamp, reason)
 169         line_buffer.put_back(abort)
 170
 171
 172     def state_iterator(self, buffer):
 173         line = None
 174         new_tests = []
 175         job_count, boot_count = 0, 0
 176         min_stack_size = 0
 177         stack = status_lib.status_stack()
 178         current_kernel = kernel("", [])  # UNKNOWN
 179         current_status = status_lib.statuses[-1]
 180         current_reason = None
 181         started_time_stack = [None]
 182         subdir_stack = [None]
 183         running_test = None
 184         running_reasons = set()
 185         yield []   # we're ready to start running
 186
 187         # create a RUNNING SERVER_JOB entry to represent the entire test
 188         running_job = test.parse_partial_test(self.job, "----", "SERVER_JOB",
 189                                               "", current_kernel,
 190                                               self.job.started_time)
 191         new_tests.append(running_job)
 192
 193         while True:
 194             # are we finished with parsing?
 195             if buffer.size() == 0 and self.finished:
 196                 if stack.size() == 0:
 197                     break
 198                 # we have status lines left on the stack,
 199                 # we need to implicitly abort them first
 200                 tko_utils.dprint('\nUnexpected end of job, aborting')
 201                 abort_subdir_stack = list(subdir_stack)
 202                 if self.job.aborted_by:
 203                     reason = "Job aborted by %s" % self.job.aborted_by
 204                     reason += self.job.aborted_on.strftime(
 205                         " at %b %d %H:%M:%S")
 206                 else:
 207                     reason = "Job aborted unexpectedly"
 208
 209                 timestamp = line.optional_fields.get('timestamp')
 210                 for i in reversed(xrange(stack.size())):
 211                     if abort_subdir_stack:
 212                         subdir = abort_subdir_stack.pop()
 213                     else:
 214                         subdir = None
 215                     abort = self.make_dummy_abort(
 216                         i, subdir, subdir, timestamp, reason)
 217                     buffer.put(abort)
 218
 219             # stop processing once the buffer is empty
 220             if buffer.size() == 0:
 221                 yield new_tests
 222                 new_tests = []
 223                 continue
 224
 225             # reinitialize the per-iteration state
 226             started_time = None
 227             finished_time = None
 228
 229             # get the next line
 230             raw_line = status_lib.clean_raw_line(buffer.get())
 231             tko_utils.dprint('\nSTATUS: ' + raw_line.strip())
 232             line = status_line.parse_line(raw_line)
 233             if line is None:
 234                 tko_utils.dprint('non-status line, ignoring')
 235                 continue
 236
 237             # do an initial sanity check of the indentation
 238             expected_indent = stack.size()
 239             if line.type == "END":
 240                 expected_indent -= 1
 241             if line.indent < expected_indent:
 242                 # ABORT the current level if indentation was unexpectedly low
 243                 self.put_back_line_and_abort(
 244                     buffer, raw_line, stack.size() - 1, subdir_stack[-1],
 245                     line.optional_fields.get("timestamp"), line.reason)
 246                 continue
 247             elif line.indent > expected_indent:
 248                 # ignore the log if the indent was unexpectedly high
 249                 tko_utils.dprint("unexpected extra indentation, ignoring")
 250                 continue
 251
 252
 253             # initial line processing
 254             if line.type == "START":
 255                 stack.start()
 256                 started_time = line.get_timestamp()
 257                 if (line.testname is None and line.subdir is None
 258                     and not running_test):
 259                     # we just started a client, all tests are relative to here
 260                     min_stack_size = stack.size()
 261                     # start a "RUNNING" CLIENT_JOB entry
 262                     job_name = "CLIENT_JOB.%d" % job_count
 263                     running_client = test.parse_partial_test(self.job, None,
 264                                                              job_name,
 265                                                              "", current_kernel,
 266                                                              started_time)
 267                     msg = "RUNNING: %s\n%s\n"
 268                     msg %= (running_client.status, running_client.testname)
 269                     tko_utils.dprint(msg)
 270                     new_tests.append(running_client)
 271                 elif stack.size() == min_stack_size + 1 and not running_test:
 272                     # we just started a new test, insert a running record
 273                     running_reasons = set()
 274                     if line.reason:
 275                         running_reasons.add(line.reason)
 276                     running_test = test.parse_partial_test(self.job,
 277                                                            line.subdir,
 278                                                            line.testname,
 279                                                            line.reason,
 280                                                            current_kernel,
 281                                                            started_time)
 282                     msg = "RUNNING: %s\nSubdir: %s\nTestname: %s\n%s"
 283                     msg %= (running_test.status, running_test.subdir,
 284                             running_test.testname, running_test.reason)
 285                     tko_utils.dprint(msg)
 286                     new_tests.append(running_test)
 287                 started_time_stack.append(started_time)
 288                 subdir_stack.append(line.subdir)
 289                 continue
 290             elif line.type == "INFO":
 291                 fields = line.optional_fields
 292                 # update the current kernel if one is defined in the info
 293                 if "kernel" in fields:
 294                     current_kernel = line.get_kernel()
 295                 # update the SERVER_JOB reason if one was logged for an abort
 296                 if "job_abort_reason" in fields:
 297                     running_job.reason = fields["job_abort_reason"]
 298                     new_tests.append(running_job)
 299                 continue
 300             elif line.type == "STATUS":
 301                 # update the stacks
 302                 if line.subdir and stack.size() > min_stack_size:
 303                     subdir_stack[-1] = line.subdir
 304                 # update the status, start and finished times
 305                 stack.update(line.status)
 306                 if status_lib.is_worse_than_or_equal_to(line.status,
 307                                                         current_status):
 308                     if line.reason:
 309                         # update the status of a currently running test
 310                         if running_test:
 311                             running_reasons.add(line.reason)
 312                             running_reasons = tko_utils.drop_redundant_messages(
 313                                     running_reasons)
 314                             sorted_reasons = sorted(running_reasons)
 315                             running_test.reason = ", ".join(sorted_reasons)
 316                             current_reason = running_test.reason
 317                             new_tests.append(running_test)
 318                             msg = "update RUNNING reason: %s" % line.reason
 319                             tko_utils.dprint(msg)
 320                         else:
 321                             current_reason = line.reason
 322                     current_status = stack.current_status()
 323                 started_time = None
 324                 finished_time = line.get_timestamp()
 325                 # if this is a non-test entry there's nothing else to do
 326                 if line.testname is None and line.subdir is None:
 327                     continue
 328             elif line.type == "END":
 329                 # grab the current subdir off of the subdir stack, or, if this
 330                 # is the end of a job, just pop it off
 331                 if (line.testname is None and line.subdir is None
 332                     and not running_test):
 333                     min_stack_size = stack.size() - 1
 334                     subdir_stack.pop()
 335                 else:
 336                     line.subdir = subdir_stack.pop()
 337                     if not subdir_stack[-1] and stack.size() > min_stack_size:
 338                         subdir_stack[-1] = line.subdir
 339                 # update the status, start and finished times
 340                 stack.update(line.status)
 341                 current_status = stack.end()
 342                 if stack.size() > min_stack_size:
 343                     stack.update(current_status)
 344                     current_status = stack.current_status()
 345                 started_time = started_time_stack.pop()
 346                 finished_time = line.get_timestamp()
 347                 # update the current kernel
 348                 if line.is_successful_reboot(current_status):
 349                     current_kernel = line.get_kernel()
 350                 # adjust the testname if this is a reboot
 351                 if line.testname == "reboot" and line.subdir is None:
 352                     line.testname = "boot.%d" % boot_count
 353             else:
 354                 assert False
 355
 356             # have we just finished a test?
 357             if stack.size() <= min_stack_size:
 358                 # if there was no testname, just use the subdir
 359                 if line.testname is None:
 360                     line.testname = line.subdir
 361                 # if there was no testname or subdir, use 'CLIENT_JOB'
 362                 if line.testname is None:
 363                     line.testname = "CLIENT_JOB.%d" % job_count
 364                     running_test = running_client
 365                     job_count += 1
 366                     if not status_lib.is_worse_than_or_equal_to(
 367                         current_status, "ABORT"):
 368                         # a job hasn't really failed just because some of the
 369                         # tests it ran have
 370                         current_status = "GOOD"
 371
 372                 if not current_reason:
 373                     current_reason = line.reason
 374                 new_test = test.parse_test(self.job,
 375                                            line.subdir,
 376                                            line.testname,
 377                                            current_status,
 378                                            current_reason,
 379                                            current_kernel,
 380                                            started_time,
 381                                            finished_time,
 382                                            running_test)
 383                 running_test = None
 384                 current_status = status_lib.statuses[-1]
 385                 current_reason = None
 386                 if new_test.testname == ("boot.%d" % boot_count):
 387                     boot_count += 1
 388                 msg = "ADD: %s\nSubdir: %s\nTestname: %s\n%s"
 389                 msg %= (new_test.status, new_test.subdir,
 390                         new_test.testname, new_test.reason)
 391                 tko_utils.dprint(msg)
 392                 new_tests.append(new_test)
 393
 394         # the job is finished, produce the final SERVER_JOB entry and exit
 395         final_job = test.parse_test(self.job, "----", "SERVER_JOB",
 396                                     self.job.exit_status(), running_job.reason,
 397                                     current_kernel,
 398                                     self.job.started_time,
 399                                     self.job.finished_time,
 400                                     running_job)
 401         new_tests.append(final_job)
 402         yield new_tests