maxjhandsome
/
llvm-project
forked from OSchip/llvm-project
1
0
Fork 0
Code Issues Pull Requests Packages Releases Wiki Activity

wire timeouts and exceptional inferior process exits through the test event system 

The results formatter system is now fed timeouts and exceptional process
exits (i.e. inferior dotest.py process that exited by signal on POSIX
systems).

If a timeout or exceptional exit happens while a test method is running
on the worker queue, the timeout or exceptional exit is charged and
reported against that test method.  Otherwise, if no test method was
running at the time of the timeout or exceptional exit, only the test
filename will be reported as the TIMEOUT or ERROR.

Implements:
https://llvm.org/bugs/show_bug.cgi?id=24830
https://llvm.org/bugs/show_bug.cgi?id=25703

In support of:
https://llvm.org/bugs/show_bug.cgi?id=25450

llvm-svn: 255097
This commit is contained in:
Todd Fiala 2015-12-09 06:45:43 +00:00
parent 0876d2d5cf
commit 5183147e2d
5 changed files with 420 additions and 54 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

59
lldb/packages/Python/lldbsuite/test/basic_results_formatter.py
View File

@ -14,6 +14,7 @@ import os
# Our imports
from . import result_formatter
from .result_formatter import EventBuilder
import lldbsuite
@ -96,12 +97,27 @@ class BasicResultsFormatter(result_formatter.ResultsFormatter):
self.result_events[test_key],
test_event)
self.result_events[test_key] = test_event
elif event_type == "job_result":
# Build the job key.
test_key = test_event.get("test_filename", None)
if test_key is None:
raise Exception(
"failed to find test filename for job event {}".format(
test_event))
self.result_events[test_key] = test_event
else:
# This is an unknown event.
if self.options.assert_on_unknown_events:
raise Exception("unknown event type {} from {}\n".format(
event_type, test_event))
@classmethod
def _event_sort_key(cls, event):
if "test_name" in event:
return event["test_name"]
else:
return event.get("test_filename", None)
def _partition_results_by_status(self, categories):
"""Partitions the captured test results by event status.
@ -123,7 +139,7 @@ class BasicResultsFormatter(result_formatter.ResultsFormatter):
if event.get("status", "") == result_status_id]
partitioned_events[result_status_id] = sorted(
matching_events,
key=lambda x: x[1]["test_name"])
key=lambda x: self._event_sort_key(x[1]))
return partitioned_events
def _print_summary_counts(
@ -223,13 +239,29 @@ class BasicResultsFormatter(result_formatter.ResultsFormatter):
if print_matching_tests:
# Sort by test name
for (_, event) in result_events_by_status[result_status_id]:
test_relative_path = os.path.relpath(
os.path.realpath(event["test_filename"]),
lldbsuite.lldb_test_root)
self.out_file.write("{}: {} ({})\n".format(
detail_label,
event["test_name"],
test_relative_path))
extra_info = ""
if result_status_id == EventBuilder.STATUS_EXCEPTIONAL_EXIT:
extra_info = "{} ({}) ".format(
event["exception_code"],
event["exception_description"])
if event["event"] == EventBuilder.TYPE_JOB_RESULT:
# Jobs status that couldn't be mapped to a test method
# doesn't have as much detail.
self.out_file.write("{}: {}{} (no test method running)\n".format(
detail_label,
extra_info,
event["test_filename"]))
else:
# Test-method events have richer detail, use that here.
test_relative_path = os.path.relpath(
os.path.realpath(event["test_filename"]),
lldbsuite.lldb_test_root)
self.out_file.write("{}: {}{} ({})\n".format(
detail_label,
extra_info,
event["test_name"],
test_relative_path))
def _finish_output_no_lock(self):
"""Writes the test result report to the output file."""
@ -247,10 +279,16 @@ class BasicResultsFormatter(result_formatter.ResultsFormatter):
"Expected Failure", False, None],
[result_formatter.EventBuilder.STATUS_FAILURE,
"Failure", True, "FAIL"],
[result_formatter.EventBuilder.STATUS_ERROR, "Error", True, "ERROR"],
[result_formatter.EventBuilder.STATUS_ERROR,
"Error", True, "ERROR"],
[result_formatter.EventBuilder.STATUS_EXCEPTIONAL_EXIT,
"Exceptional Exit", True, "ERROR"],
[result_formatter.EventBuilder.STATUS_UNEXPECTED_SUCCESS,
"Unexpected Success", True, "UNEXPECTED SUCCESS"],
[result_formatter.EventBuilder.STATUS_SKIP, "Skip", False, None]]
[result_formatter.EventBuilder.STATUS_SKIP, "Skip", False, None],
[result_formatter.EventBuilder.STATUS_TIMEOUT,
"Timeout", True, "TIMEOUT"],
]
# Partition all the events by test result status
result_events_by_status = self._partition_results_by_status(
@ -269,7 +307,6 @@ class BasicResultsFormatter(result_formatter.ResultsFormatter):
self._print_summary_counts(
categories, result_events_by_status, extra_results)
def _finish_output(self):
"""Prepare and write the results report as all incoming events have
arrived.

167
lldb/packages/Python/lldbsuite/test/dosep.py
View File

@ -55,8 +55,11 @@ from . import dotest_channels
from . import dotest_args
from . import result_formatter
# Todo: Convert this folder layout to be relative-import friendly and don't hack up
# sys.path like this
from .result_formatter import EventBuilder
# Todo: Convert this folder layout to be relative-import friendly and
# don't hack up sys.path like this
sys.path.append(os.path.join(os.path.dirname(__file__), "test_runner", "lib"))
import lldb_utils
import process_control
@ -105,7 +108,6 @@ def setup_global_variables(
global GET_WORKER_INDEX
GET_WORKER_INDEX = get_worker_index_use_pid
def report_test_failure(name, command, output):
global output_lock
with output_lock:
@ -223,6 +225,32 @@ class DoTestProcessDriver(process_control.ProcessDriver):
failures,
unexpected_successes)
def is_exceptional_exit(self):
"""Returns whether the process returned a timeout.
Not valid to call until after on_process_exited() completes.
@return True if the exit is an exceptional exit (e.g. signal on
POSIX); False otherwise.
"""
if self.results is None:
raise Exception(
"exit status checked before results are available")
return self.process_helper.is_exceptional_exit(
self.results[1])
def exceptional_exit_details(self):
if self.results is None:
raise Exception(
"exit status checked before results are available")
return self.process_helper.exceptional_exit_details(self.results[1])
def is_timeout(self):
if self.results is None:
raise Exception(
"exit status checked before results are available")
return self.results[1] == eTimedOut
def get_soft_terminate_timeout():
# Defaults to 10 seconds, but can set
@ -244,9 +272,109 @@ def want_core_on_soft_terminate():
return False
def send_events_to_collector(events, command):
"""Sends the given events to the collector described in the command line.
@param events the list of events to send to the test event collector.
@param command the inferior command line which contains the details on
how to connect to the test event collector.
"""
if events is None or len(events) == 0:
# Nothing to do.
return
# Find the port we need to connect to from the --results-port option.
try:
arg_index = command.index("--results-port") + 1
except ValueError:
# There is no results port, so no way to communicate back to
# the event collector. This is not a problem if we're not
# using event aggregation.
# TODO flag as error once we always use the event system
print(
"INFO: no event collector, skipping post-inferior test "
"event reporting")
return
if arg_index >= len(command):
raise Exception(
"expected collector port at index {} in {}".format(
arg_index, command))
event_port = int(command[arg_index])
# Create results formatter connected back to collector via socket.
config = result_formatter.FormatterConfig()
config.port = event_port
formatter_spec = result_formatter.create_results_formatter(config)
if formatter_spec is None or formatter_spec.formatter is None:
raise Exception(
"Failed to create socket-based ResultsFormatter "
"back to test event collector")
# Send the events: the port-based event just pickles the content
# and sends over to the server side of the socket.
for event in events:
formatter_spec.formatter.handle_event(event)
# Cleanup
if formatter_spec.cleanup_func is not None:
formatter_spec.cleanup_func()
def send_inferior_post_run_events(command, worker_index, process_driver):
"""Sends any test events that should be generated after the inferior runs.
These events would include timeouts and exceptional (i.e. signal-returning)
process completion results.
@param command the list of command parameters passed to subprocess.Popen().
@param worker_index the worker index (possibly None) used to run
this process
@param process_driver the ProcessDriver-derived instance that was used
to run the inferior process.
"""
if process_driver is None:
raise Exception("process_driver must not be None")
if process_driver.results is None:
# Invalid condition - the results should have been set one way or
# another, even in a timeout.
raise Exception("process_driver.results were not set")
# The code below fills in the post events struct. If there are any post
# events to fire up, we'll try to make a connection to the socket and
# provide the results.
post_events = []
# Handle signal/exceptional exits.
if process_driver.is_exceptional_exit():
(code, desc) = process_driver.exceptional_exit_details()
test_filename = process_driver.results[0]
post_events.append(
EventBuilder.event_for_job_exceptional_exit(
process_driver.pid,
worker_index,
code,
desc,
test_filename,
command))
# Handle timeouts.
if process_driver.is_timeout():
test_filename = process_driver.results[0]
post_events.append(EventBuilder.event_for_job_timeout(
process_driver.pid,
worker_index,
test_filename,
command))
if len(post_events) > 0:
send_events_to_collector(post_events, command)
def call_with_timeout(command, timeout, name, inferior_pid_events):
# Add our worker index (if we have one) to all test events
# from this inferior.
worker_index = None
if GET_WORKER_INDEX is not None:
try:
worker_index = GET_WORKER_INDEX()
@ -277,6 +405,15 @@ def call_with_timeout(command, timeout, name, inferior_pid_events):
# This is truly exceptional. Even a failing or timed out
# binary should have called the results-generation code.
raise Exception("no test results were generated whatsoever")
# Handle cases where the test inferior cannot adequately provide
# meaningful results to the test event system.
send_inferior_post_run_events(
command,
worker_index,
process_driver)
return process_driver.results
@ -487,7 +624,7 @@ def find_test_files_in_dir_tree(dir_root, found_func):
def initialize_global_vars_common(num_threads, test_work_items):
global total_tests, test_counter, test_name_len
total_tests = sum([len(item[1]) for item in test_work_items])
test_counter = multiprocessing.Value('i', 0)
test_name_len = multiprocessing.Value('i', 0)
@ -1413,26 +1550,16 @@ def main(print_details_on_success, num_threads, test_subdir,
print_legacy_summary = False
if not print_legacy_summary:
# Remove this timeout handling once
# https://llvm.org/bugs/show_bug.cgi?id=25703
# is addressed.
#
# Use non-event-based structures to count timeouts.
timeout_count = len(timed_out)
if timeout_count > 0:
failed.sort()
print("Timed out test files: {}".format(len(timed_out)))
for f in failed:
if f in timed_out:
print("TIMEOUT: %s (%s)" % (f, system_info))
# Figure out exit code by count of test result types.
issue_count = (
results_formatter.counts_by_test_result_status(
result_formatter.EventBuilder.STATUS_ERROR) +
EventBuilder.STATUS_ERROR) +
results_formatter.counts_by_test_result_status(
result_formatter.EventBuilder.STATUS_FAILURE) +
timeout_count)
EventBuilder.STATUS_FAILURE) +
results_formatter.counts_by_test_result_status(
EventBuilder.STATUS_TIMEOUT)
)
# Return with appropriate result code
if issue_count > 0:
sys.exit(1)

13
lldb/packages/Python/lldbsuite/test/dotest.py
View File

@ -568,16 +568,25 @@ def createSocketToLocalPort(port):
def setupTestResults():
"""Sets up test results-related objects based on arg settings."""
# Setup the results formatter configuration.
formatter_config = result_formatter.FormatterConfig()
formatter_config.filename = configuration.results_filename
formatter_config.formatter_name = configuration.results_formatter_name
formatter_config.formatter_options = (
configuration.results_formatter_options)
formatter_config.port = configuration.results_port
# Create the results formatter.
formatter_spec = result_formatter.create_results_formatter()
formatter_spec = result_formatter.create_results_formatter(
formatter_config)
if formatter_spec is not None and formatter_spec.formatter is not None:
configuration.results_formatter_object = formatter_spec.formatter
# Send an intialize message to the formatter.
initialize_event = EventBuilder.bare_event("initialize")
if isMultiprocessTestRunner():
if configuration.test_runner_name is not None and configuration.test_runner_name == "serial":
if (configuration.test_runner_name is not None and
configuration.test_runner_name == "serial"):
# Only one worker queue here.
worker_count = 1
else:

190
lldb/packages/Python/lldbsuite/test/result_formatter.py
View File

@ -30,15 +30,29 @@ import six
from six.moves import cPickle
# LLDB modules
from . import configuration
# Ignore method count on DTOs.
# pylint: disable=too-few-public-methods
class FormatterConfig(object):
"""Provides formatter configuration info to create_results_formatter()."""
def __init__(self):
self.filename = None
self.port = None
self.formatter_name = None
self.formatter_options = None
# Ignore method count on DTOs.
# pylint: disable=too-few-public-methods
class CreatedFormatter(object):
"""Provides transfer object for returns from create_results_formatter()."""
def __init__(self, formatter, cleanup_func):
self.formatter = formatter
self.cleanup_func = cleanup_func
def create_results_formatter():
def create_results_formatter(config):
"""Sets up a test results formatter.
@param config an instance of FormatterConfig
@ -67,28 +81,28 @@ def create_results_formatter():
results_file_object = None
cleanup_func = None
if configuration.results_filename:
if config.filename:
# Open the results file for writing.
if configuration.results_filename == 'stdout':
if config.filename == 'stdout':
results_file_object = sys.stdout
cleanup_func = None
elif configuration.results_filename == 'stderr':
elif config.filename == 'stderr':
results_file_object = sys.stderr
cleanup_func = None
else:
results_file_object = open(configuration.results_filename, "w")
results_file_object = open(config.filename, "w")
cleanup_func = results_file_object.close
default_formatter_name = (
"lldbsuite.test.result_formatter.XunitFormatter")
elif configuration.results_port:
elif config.port:
# Connect to the specified localhost port.
results_file_object, cleanup_func = create_socket(configuration.results_port)
results_file_object, cleanup_func = create_socket(config.port)
default_formatter_name = (
"lldbsuite.test.result_formatter.RawPickledFormatter")
# If we have a results formatter name specified and we didn't specify
# a results file, we should use stdout.
if configuration.results_formatter_name is not None and results_file_object is None:
if config.formatter_name is not None and results_file_object is None:
# Use stdout.
results_file_object = sys.stdout
cleanup_func = None
@ -96,8 +110,8 @@ def create_results_formatter():
if results_file_object:
# We care about the formatter. Choose user-specified or, if
# none specified, use the default for the output type.
if configuration.results_formatter_name:
formatter_name = configuration.results_formatter_name
if config.formatter_name:
formatter_name = config.formatter_name
else:
formatter_name = default_formatter_name
@ -111,8 +125,8 @@ def create_results_formatter():
# Handle formatter options for the results formatter class.
formatter_arg_parser = cls.arg_parser()
if configuration.results_formatter_options and len(configuration.results_formatter_options) > 0:
command_line_options = configuration.results_formatter_options
if config.formatter_options and len(config.formatter_options) > 0:
command_line_options = config.formatter_options
else:
command_line_options = []
@ -145,13 +159,20 @@ class EventBuilder(object):
BASE_DICTIONARY = None
# Test Status Tags
# Test Event Types
TYPE_JOB_RESULT = "job_result"
TYPE_TEST_RESULT = "test_result"
TYPE_TEST_START = "test_start"
# Test/Job Status Tags
STATUS_EXCEPTIONAL_EXIT = "exceptional_exit"
STATUS_SUCCESS = "success"
STATUS_FAILURE = "failure"
STATUS_EXPECTED_FAILURE = "expected_failure"
STATUS_UNEXPECTED_SUCCESS = "unexpected_success"
STATUS_SKIP = "skip"
STATUS_ERROR = "error"
STATUS_TIMEOUT = "timeout"
@staticmethod
def _get_test_name_info(test):
@ -256,7 +277,8 @@ class EventBuilder(object):
@return the event dictionary
"""
event = EventBuilder._event_dictionary_common(test, "test_result")
event = EventBuilder._event_dictionary_common(
test, EventBuilder.TYPE_TEST_RESULT)
event["status"] = status
return event
@ -291,7 +313,8 @@ class EventBuilder(object):
@return the event dictionary
"""
return EventBuilder._event_dictionary_common(test, "test_start")
return EventBuilder._event_dictionary_common(
test, EventBuilder.TYPE_TEST_START)
@staticmethod
def event_for_success(test):
@ -405,6 +428,65 @@ class EventBuilder(object):
event["issue_phase"] = "cleanup"
return event
@staticmethod
def event_for_job_exceptional_exit(
pid, worker_index, exception_code, exception_description,
test_filename, command_line):
"""Creates an event for a job (i.e. process) exit due to signal.
@param pid the process id for the job that failed
@param worker_index optional id for the job queue running the process
@param exception_code optional code
(e.g. SIGTERM integer signal number)
@param exception_description optional string containing symbolic
representation of the issue (e.g. "SIGTERM")
@param test_filename the path to the test filename that exited
in some exceptional way.
@param command_line the Popen-style list provided as the command line
for the process that timed out.
@return an event dictionary coding the job completion description.
"""
event = EventBuilder.bare_event(EventBuilder.TYPE_JOB_RESULT)
event["status"] = EventBuilder.STATUS_EXCEPTIONAL_EXIT
if pid is not None:
event["pid"] = pid
if worker_index is not None:
event["worker_index"] = int(worker_index)
if exception_code is not None:
event["exception_code"] = exception_code
if exception_description is not None:
event["exception_description"] = exception_description
if test_filename is not None:
event["test_filename"] = test_filename
if command_line is not None:
event["command_line"] = command_line
return event
@staticmethod
def event_for_job_timeout(pid, worker_index, test_filename, command_line):
"""Creates an event for a job (i.e. process) timeout.
@param pid the process id for the job that timed out
@param worker_index optional id for the job queue running the process
@param test_filename the path to the test filename that timed out.
@param command_line the Popen-style list provided as the command line
for the process that timed out.
@return an event dictionary coding the job completion description.
"""
event = EventBuilder.bare_event(EventBuilder.TYPE_JOB_RESULT)
event["status"] = "timeout"
if pid is not None:
event["pid"] = pid
if worker_index is not None:
event["worker_index"] = int(worker_index)
if test_filename is not None:
event["test_filename"] = test_filename
if command_line is not None:
event["command_line"] = command_line
return event
@staticmethod
def add_entries_to_all_events(entries_dict):
"""Specifies a dictionary of entries to add to all test events.
@ -428,7 +510,6 @@ class EventBuilder(object):
class ResultsFormatter(object):
"""Provides interface to formatting test results out to a file-like object.
This class allows the LLDB test framework's raw test-realted
@ -524,15 +605,59 @@ class ResultsFormatter(object):
EventBuilder.STATUS_SKIP: 0,
EventBuilder.STATUS_UNEXPECTED_SUCCESS: 0,
EventBuilder.STATUS_FAILURE: 0,
EventBuilder.STATUS_ERROR: 0
EventBuilder.STATUS_ERROR: 0,
EventBuilder.STATUS_TIMEOUT: 0,
EventBuilder.STATUS_EXCEPTIONAL_EXIT: 0
}
# Track the most recent test start event by worker index.
# We'll use this to assign TIMEOUT and exceptional
# exits to the most recent test started on a given
# worker index.
self.started_tests_by_worker = {}
# Lock that we use while mutating inner state, like the
# total test count and the elements. We minimize how
# long we hold the lock just to keep inner state safe, not
# entirely consistent from the outside.
self.lock = threading.Lock()
def _maybe_remap_job_result_event(self, test_event):
"""Remaps timeout/exceptional exit job results to last test method running.
@param test_event the job_result test event. This is an in/out
parameter. It will be modified if it can be mapped to a test_result
of the same status, using details from the last-running test method
known to be most recently started on the same worker index.
"""
test_start = None
job_status = test_event["status"]
if job_status in [
EventBuilder.STATUS_TIMEOUT,
EventBuilder.STATUS_EXCEPTIONAL_EXIT]:
worker_index = test_event.get("worker_index", None)
if worker_index is not None:
test_start = self.started_tests_by_worker.get(
worker_index, None)
# If we have a test start to remap, do it here.
if test_start is not None:
test_event["event"] = EventBuilder.TYPE_TEST_RESULT
# Fill in all fields from test start not present in
# job status message.
for (start_key, start_value) in test_start.items():
if start_key not in test_event:
test_event[start_key] = start_value
# Always take the value of test_filename from test_start,
# as it was gathered by class introspections. Job status
# has less refined info available to it, so might be missing
# path info.
if "test_filename" in test_start:
test_event["test_filename"] = test_start["test_filename"]
def handle_event(self, test_event):
"""Handles the test event for collection into the formatter output.
@ -549,12 +674,35 @@ class ResultsFormatter(object):
# called yet".
if test_event is not None:
event_type = test_event.get("event", "")
# We intentionally allow event_type to be checked anew
# after this check below since this check may rewrite
# the event type
if event_type == EventBuilder.TYPE_JOB_RESULT:
# Possibly convert the job status (timeout, exceptional exit)
# to an appropriate test_result event.
self._maybe_remap_job_result_event(test_event)
event_type = test_event.get("event", "")
if event_type == "terminate":
self.terminate_called = True
elif event_type == "test_result":
# Keep track of event counts per test result status type
elif (event_type == EventBuilder.TYPE_TEST_RESULT or
event_type == EventBuilder.TYPE_JOB_RESULT):
# Keep track of event counts per test/job result status type.
# The only job (i.e. inferior process) results that make it
# here are ones that cannot be remapped to the most recently
# started test for the given worker index.
status = test_event["status"]
self.result_status_counts[status] += 1
# Clear the most recently started test for the related worker.
worker_index = test_event.get("worker_index", None)
if worker_index is not None:
self.started_tests_by_worker.pop(worker_index, None)
elif event_type == EventBuilder.TYPE_TEST_START:
# Keep track of the most recent test start event
# for the related worker.
worker_index = test_event.get("worker_index", None)
if worker_index is not None:
self.started_tests_by_worker[worker_index] = test_event
def track_start_time(self, test_class, test_name, start_time):
"""tracks the start time of a test so elapsed time can be computed.
@ -805,7 +953,7 @@ class XunitFormatter(ResultsFormatter):
test_event["test_class"],
test_event["test_name"],
test_event["event_time"])
elif event_type == "test_result":
elif event_type == EventBuilder.TYPE_TEST_RESULT:
self._process_test_result(test_event)
else:
# This is an unknown event.

45
lldb/packages/Python/lldbsuite/test/test_runner/lib/process_control.py
View File

@ -243,6 +243,37 @@ class ProcessHelper(object):
"""
return None
def is_exceptional_exit(self, popen_status):
"""Returns whether the program exit status is exceptional.
Returns whether the return code from a Popen process is exceptional
(e.g. signals on POSIX systems).
Derived classes should override this if they can detect exceptional
program exit.
@return True if the given popen_status represents an exceptional
program exit; False otherwise.
"""
return False
def exceptional_exit_details(self, popen_status):
"""Returns the normalized exceptional exit code and a description.
Given an exceptional exit code, returns the integral value of the
exception (e.g. signal number for POSIX) and a description (e.g.
signal name on POSIX) for the result.
Derived classes should override this if they can detect exceptional
program exit.
It is fine to not implement this so long as is_exceptional_exit()
always returns False.
@return (normalized exception code, symbolic exception description)
"""
raise Exception("exception_exit_details() called on unsupported class")
class UnixProcessHelper(ProcessHelper):
"""Provides a ProcessHelper for Unix-like operating systems.
@ -366,6 +397,20 @@ class UnixProcessHelper(ProcessHelper):
def soft_terminate_signals(self):
return [signal.SIGQUIT, signal.SIGTERM]
def is_exceptional_exit(self, popen_status):
return popen_status < 0
@classmethod
def _signal_names_by_number(cls):
return dict(
(k, v) for v, k in reversed(sorted(signal.__dict__.items()))
if v.startswith('SIG') and not v.startswith('SIG_'))
def exceptional_exit_details(self, popen_status):
signo = -popen_status
signal_names_by_number = self._signal_names_by_number()
signal_name = signal_names_by_number.get(signo, "")
return (signo, signal_name)
class WindowsProcessHelper(ProcessHelper):
"""Provides a Windows implementation of the ProcessHelper class."""