You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

575 lines
23 KiB

import json
import math
import os
import re
import common
from autotest_lib.tko import models
from autotest_lib.tko import status_lib
from autotest_lib.tko import utils as tko_utils
from autotest_lib.tko.parsers import base
from autotest_lib.tko.parsers import version_0
class job(version_0.job):
"""Represents a job."""
def exit_status(self):
"""Returns the string exit status of this job."""
# Find the .autoserv_execute path.
top_dir = tko_utils.find_toplevel_job_dir(self.dir)
if not top_dir:
return 'ABORT'
execute_path = os.path.join(top_dir, '.autoserv_execute')
# If for some reason we can't read the status code, assume disaster.
if not os.path.exists(execute_path):
return 'ABORT'
lines = open(execute_path).readlines()
if len(lines) < 2:
return 'ABORT'
try:
status_code = int(lines[1])
except ValueError:
return 'ABORT'
if not os.WIFEXITED(status_code):
# Looks like a signal - an ABORT.
return 'ABORT'
elif os.WEXITSTATUS(status_code) != 0:
# Looks like a non-zero exit - a failure.
return 'FAIL'
else:
# Looks like exit code == 0.
return 'GOOD'
class kernel(models.kernel):
"""Represents a kernel."""
def __init__(self, base, patches):
if base:
patches = [patch(*p.split()) for p in patches]
hashes = [p.hash for p in patches]
kernel_hash = self.compute_hash(base, hashes)
else:
base = 'UNKNOWN'
patches = []
kernel_hash = 'UNKNOWN'
super(kernel, self).__init__(base, patches, kernel_hash)
class test(models.test):
"""Represents a test."""
@staticmethod
def load_iterations(keyval_path):
return iteration.load_from_keyval(keyval_path)
class iteration(models.iteration):
"""Represents an iteration."""
@staticmethod
def parse_line_into_dicts(line, attr_dict, perf_dict):
key, val_type, value = "", "", ""
# Figure out what the key, value and keyval type are.
typed_match = re.search('^([^=]*)\{(\w*)\}=(.*)$', line)
if typed_match:
key, val_type, value = typed_match.groups()
else:
# Old-fashioned untyped match, assume perf.
untyped_match = re.search('^([^=]*)=(.*)$', line)
if untyped_match:
key, value = untyped_match.groups()
val_type = 'perf'
# Parse the actual value into a dict.
try:
if val_type == 'attr':
attr_dict[key] = value
elif val_type == 'perf':
# first check if value is in the form of 'mean+-deviation'
if isinstance(value, str):
r = re.compile('(\d+.?\d*)\+-(\d+.?\d*)')
match = r.match(value)
if match:
perf_dict[key] = float(match.group(1))
perf_dict['%s_dev' % key] = float(match.group(2))
return
# otherwise try to interpret as a regular float
perf_dict[key] = float(value)
else:
raise ValueError
except ValueError:
msg = ('WARNING: line "%s" found in test '
'iteration keyval could not be parsed')
msg %= line
tko_utils.dprint(msg)
class perf_value_iteration(models.perf_value_iteration):
"""Represents a perf value iteration."""
@staticmethod
def parse_line_into_dict(line):
"""
Parse a perf measurement text line into a dictionary.
The line is assumed to be a JSON-formatted string containing key/value
pairs, where each pair represents a piece of information associated
with a measured perf metric:
'description': a string description for the perf metric.
'value': a numeric value, or list of numeric values.
'units': the string units associated with the perf metric.
'higher_is_better': a boolean whether a higher value is considered
better. If False, a lower value is considered better.
'graph': a string indicating the name of the perf dashboard graph
on which the perf data will be displayed.
The resulting dictionary will also have a standard deviation key/value
pair, 'stddev'. If the perf measurement value is a list of values
instead of a single value, then the average and standard deviation of
the list of values is computed and stored. If a single value, the
value itself is used, and is associated with a standard deviation of 0.
@param line: A string line of JSON text from a perf measurements output
file.
@return A dictionary containing the parsed perf measurement information
along with a computed standard deviation value (key 'stddev'), or
an empty dictionary if the inputted line cannot be parsed.
"""
try:
perf_dict = json.loads(line)
except ValueError:
msg = 'Could not parse perf measurements line as json: "%s"' % line
tko_utils.dprint(msg)
return {}
def mean_and_standard_deviation(data):
"""
Computes the mean and standard deviation of a list of numbers.
@param data: A list of numbers.
@return A 2-tuple (mean, standard_deviation) computed from the list
of numbers.
"""
n = len(data)
if n == 0:
return 0.0, 0.0
if n == 1:
return data[0], 0.0
mean = float(sum(data)) / n
# Divide by n-1 to compute "sample standard deviation".
variance = sum([(elem - mean) ** 2 for elem in data]) / (n - 1)
return mean, math.sqrt(variance)
value = perf_dict['value']
perf_dict['stddev'] = 0.0
if isinstance(value, list):
value, stddev = mean_and_standard_deviation(map(float, value))
perf_dict['value'] = value
perf_dict['stddev'] = stddev
return perf_dict
class status_line(version_0.status_line):
"""Represents a status line."""
def __init__(self, indent, status, subdir, testname, reason,
optional_fields):
# Handle INFO fields.
if status == 'INFO':
self.type = 'INFO'
self.indent = indent
self.status = self.subdir = self.testname = self.reason = None
self.optional_fields = optional_fields
else:
# Everything else is backwards compatible.
super(status_line, self).__init__(indent, status, subdir,
testname, reason,
optional_fields)
def is_successful_reboot(self, current_status):
"""
Checks whether the status represents a successful reboot.
@param current_status: A string representing the current status.
@return True, if the status represents a successful reboot, or False
if not.
"""
# Make sure this is a reboot line.
if self.testname != 'reboot':
return False
# Make sure this was not a failure.
if status_lib.is_worse_than_or_equal_to(current_status, 'FAIL'):
return False
# It must have been a successful reboot.
return True
def get_kernel(self):
# Get the base kernel version.
fields = self.optional_fields
base = re.sub('-autotest$', '', fields.get('kernel', ''))
# Get a list of patches.
patches = []
patch_index = 0
while ('patch%d' % patch_index) in fields:
patches.append(fields['patch%d' % patch_index])
patch_index += 1
# Create a new kernel instance.
return kernel(base, patches)
def get_timestamp(self):
return tko_utils.get_timestamp(self.optional_fields, 'timestamp')
# The default implementations from version 0 will do for now.
patch = version_0.patch
class parser(base.parser):
"""Represents a parser."""
@staticmethod
def make_job(dir):
return job(dir)
@staticmethod
def make_dummy_abort(indent, subdir, testname, timestamp, reason):
"""
Creates an abort string.
@param indent: The number of indentation levels for the string.
@param subdir: The subdirectory name.
@param testname: The test name.
@param timestamp: The timestamp value.
@param reason: The reason string.
@return A string describing the abort.
"""
indent = '\t' * indent
if not subdir:
subdir = '----'
if not testname:
testname = '----'
# There is no guarantee that this will be set.
timestamp_field = ''
if timestamp:
timestamp_field = '\ttimestamp=%s' % timestamp
msg = indent + 'END ABORT\t%s\t%s%s\t%s'
return msg % (subdir, testname, timestamp_field, reason)
@staticmethod
def put_back_line_and_abort(
line_buffer, line, indent, subdir, testname, timestamp, reason):
"""
Appends a line to the line buffer and aborts.
@param line_buffer: A line_buffer object.
@param line: A line to append to the line buffer.
@param indent: The number of indentation levels.
@param subdir: The subdirectory name.
@param testname: The test name.
@param timestamp: The timestamp value.
@param reason: The reason string.
"""
tko_utils.dprint('Unexpected indent: aborting log parse')
line_buffer.put_back(line)
abort = parser.make_dummy_abort(
indent, subdir, testname, timestamp, reason)
line_buffer.put_back(abort)
def state_iterator(self, buffer):
"""
Yields a list of tests out of the buffer.
@param buffer: a buffer object
"""
line = None
new_tests = []
job_count, boot_count = 0, 0
min_stack_size = 0
stack = status_lib.status_stack()
current_kernel = kernel("", []) # UNKNOWN
current_status = status_lib.statuses[-1]
current_reason = None
started_time_stack = [None]
subdir_stack = [None]
testname_stack = [None]
running_test = None
running_reasons = set()
ignored_lines = []
yield [] # We're ready to start running.
def print_ignored_lines():
"""
Prints the ignored_lines using tko_utils.dprint method.
"""
num_lines = len(ignored_lines)
if num_lines > 2:
tko_utils.dprint('The following %s lines were ignored:' %
num_lines)
tko_utils.dprint('%r' % ignored_lines[0])
tko_utils.dprint('...')
tko_utils.dprint('%r' % ignored_lines[-1])
elif num_lines == 2:
tko_utils.dprint('The following %s lines were ignored:' %
num_lines)
tko_utils.dprint('%r' % ignored_lines[0])
tko_utils.dprint('%r' % ignored_lines[-1])
elif num_lines == 1:
tko_utils.dprint('The following line was ignored:')
tko_utils.dprint('%r' % ignored_lines[0])
# Create a RUNNING SERVER_JOB entry to represent the entire test.
running_job = test.parse_partial_test(self.job, '----', 'SERVER_JOB',
'', current_kernel,
self.job.started_time)
new_tests.append(running_job)
while True:
# Are we finished with parsing?
if buffer.size() == 0 and self.finished:
if ignored_lines:
print_ignored_lines()
ignored_lines = []
if stack.size() == 0:
break
# We have status lines left on the stack;
# we need to implicitly abort them first.
tko_utils.dprint('\nUnexpected end of job, aborting')
abort_subdir_stack = list(subdir_stack)
if self.job.aborted_by:
reason = 'Job aborted by %s' % self.job.aborted_by
reason += self.job.aborted_on.strftime(
' at %b %d %H:%M:%S')
else:
reason = 'Job aborted unexpectedly'
timestamp = line.optional_fields.get('timestamp')
for i in reversed(xrange(stack.size())):
if abort_subdir_stack:
subdir = abort_subdir_stack.pop()
else:
subdir = None
abort = self.make_dummy_abort(
i, subdir, subdir, timestamp, reason)
buffer.put(abort)
# Stop processing once the buffer is empty.
if buffer.size() == 0:
yield new_tests
new_tests = []
continue
# Reinitialize the per-iteration state.
started_time = None
finished_time = None
# Get the next line.
raw_line = status_lib.clean_raw_line(buffer.get())
line = status_line.parse_line(raw_line)
if line is None:
ignored_lines.append(raw_line)
continue
elif ignored_lines:
print_ignored_lines()
ignored_lines = []
# Do an initial sanity check of the indentation.
expected_indent = stack.size()
if line.type == 'END':
expected_indent -= 1
if line.indent < expected_indent:
# ABORT the current level if indentation was unexpectedly low.
self.put_back_line_and_abort(
buffer, raw_line, stack.size() - 1, subdir_stack[-1],
testname_stack[-1], line.optional_fields.get('timestamp'),
line.reason)
continue
elif line.indent > expected_indent:
# Ignore the log if the indent was unexpectedly high.
tko_utils.dprint('ignoring line because of extra indentation')
continue
# Initial line processing.
if line.type == 'START':
stack.start()
started_time = line.get_timestamp()
testname = None
if (line.testname is None and line.subdir is None
and not running_test):
# We just started a client; all tests are relative to here.
min_stack_size = stack.size()
# Start a "RUNNING" CLIENT_JOB entry.
job_name = 'CLIENT_JOB.%d' % job_count
running_client = test.parse_partial_test(self.job, None,
job_name,
'', current_kernel,
started_time)
msg = 'RUNNING: %s\n%s\n'
msg %= (running_client.status, running_client.testname)
tko_utils.dprint(msg)
new_tests.append(running_client)
testname = running_client.testname
elif stack.size() == min_stack_size + 1 and not running_test:
# We just started a new test; insert a running record.
running_reasons = set()
if line.reason:
running_reasons.add(line.reason)
running_test = test.parse_partial_test(self.job,
line.subdir,
line.testname,
line.reason,
current_kernel,
started_time)
msg = 'RUNNING: %s\nSubdir: %s\nTestname: %s\n%s'
msg %= (running_test.status, running_test.subdir,
running_test.testname, running_test.reason)
tko_utils.dprint(msg)
new_tests.append(running_test)
testname = running_test.testname
started_time_stack.append(started_time)
subdir_stack.append(line.subdir)
testname_stack.append(testname)
continue
elif line.type == 'INFO':
fields = line.optional_fields
# Update the current kernel if one is defined in the info.
if 'kernel' in fields:
current_kernel = line.get_kernel()
# Update the SERVER_JOB reason if one was logged for an abort.
if 'job_abort_reason' in fields:
running_job.reason = fields['job_abort_reason']
new_tests.append(running_job)
continue
elif line.type == 'STATUS':
# Update the stacks.
if line.subdir and stack.size() > min_stack_size:
subdir_stack[-1] = line.subdir
testname_stack[-1] = line.testname
# Update the status, start and finished times.
stack.update(line.status)
if status_lib.is_worse_than_or_equal_to(line.status,
current_status):
if line.reason:
# Update the status of a currently running test.
if running_test:
running_reasons.add(line.reason)
running_reasons = tko_utils.drop_redundant_messages(
running_reasons)
sorted_reasons = sorted(running_reasons)
running_test.reason = ', '.join(sorted_reasons)
current_reason = running_test.reason
new_tests.append(running_test)
msg = 'update RUNNING reason: %s' % line.reason
tko_utils.dprint(msg)
else:
current_reason = line.reason
current_status = stack.current_status()
started_time = None
finished_time = line.get_timestamp()
# If this is a non-test entry there's nothing else to do.
if line.testname is None and line.subdir is None:
continue
elif line.type == 'END':
# Grab the current subdir off of the subdir stack, or, if this
# is the end of a job, just pop it off.
if (line.testname is None and line.subdir is None
and not running_test):
min_stack_size = stack.size() - 1
subdir_stack.pop()
testname_stack.pop()
else:
line.subdir = subdir_stack.pop()
testname_stack.pop()
if not subdir_stack[-1] and stack.size() > min_stack_size:
subdir_stack[-1] = line.subdir
# Update the status, start and finished times.
stack.update(line.status)
current_status = stack.end()
if stack.size() > min_stack_size:
stack.update(current_status)
current_status = stack.current_status()
started_time = started_time_stack.pop()
finished_time = line.get_timestamp()
# Update the current kernel.
if line.is_successful_reboot(current_status):
current_kernel = line.get_kernel()
# Adjust the testname if this is a reboot.
if line.testname == 'reboot' and line.subdir is None:
line.testname = 'boot.%d' % boot_count
else:
assert False
# Have we just finished a test?
if stack.size() <= min_stack_size:
# If there was no testname, just use the subdir.
if line.testname is None:
line.testname = line.subdir
# If there was no testname or subdir, use 'CLIENT_JOB'.
if line.testname is None:
line.testname = 'CLIENT_JOB.%d' % job_count
running_test = running_client
job_count += 1
if not status_lib.is_worse_than_or_equal_to(
current_status, 'ABORT'):
# A job hasn't really failed just because some of the
# tests it ran have.
current_status = 'GOOD'
if not current_reason:
current_reason = line.reason
new_test = test.parse_test(self.job,
line.subdir,
line.testname,
current_status,
current_reason,
current_kernel,
started_time,
finished_time,
running_test)
running_test = None
current_status = status_lib.statuses[-1]
current_reason = None
if new_test.testname == ('boot.%d' % boot_count):
boot_count += 1
msg = 'ADD: %s\nSubdir: %s\nTestname: %s\n%s'
msg %= (new_test.status, new_test.subdir,
new_test.testname, new_test.reason)
tko_utils.dprint(msg)
new_tests.append(new_test)
# The job is finished; produce the final SERVER_JOB entry and exit.
final_job = test.parse_test(self.job, '----', 'SERVER_JOB',
self.job.exit_status(), running_job.reason,
current_kernel,
self.job.started_time,
self.job.finished_time,
running_job)
new_tests.append(final_job)
yield new_tests