diff --git a/rebench/configurator.py b/rebench/configurator.py index 33ae72c3..b99b43b5 100644 --- a/rebench/configurator.py +++ b/rebench/configurator.py @@ -25,7 +25,7 @@ from .model.exp_variables import ExpVariables from .model.reporting import Reporting from .model.virtual_machine import VirtualMachine -from .ui import UIError +from .ui import UIError, escape_braces class _VMFilter(object): @@ -130,9 +130,10 @@ def load_config(file_name): try: validator.validate(raise_exception=True) except SchemaError as err: + errors = [escape_braces(val_err) for val_err in validator.validation_errors] raise UIError( "Validation of " + file_name + " failed.\n{ind}" + - "{ind}".join(validator.validation_errors) + "\n", err) + "\n{ind}".join(errors) + "\n", err) return data except IOError as err: if err.errno == 2: @@ -156,8 +157,16 @@ def __init__(self, raw_config, data_store, ui, cli_options=None, cli_reporter=No self._data_file = data_file or raw_config.get('standard_data_file', 'rebench.data') self._exp_name = exp_name or raw_config.get('standard_experiment', 'all') + # capture invocation and iteration settings and override when quick is selected + invocations = cli_options.invocations if cli_options else None + iterations = cli_options.iterations if cli_options else None + if cli_options and cli_options.quick: + invocations = 1 + iterations = 1 + self._root_run_details = ExpRunDetails.compile( - raw_config.get('runs', {}), ExpRunDetails.default()) + raw_config.get('runs', {}), ExpRunDetails.default( + invocations, iterations)) self._root_reporting = Reporting.compile( raw_config.get('reporting', {}), Reporting.empty(cli_reporter), cli_options, ui) diff --git a/rebench/executor.py b/rebench/executor.py index 5663509b..ab07ead9 100644 --- a/rebench/executor.py +++ b/rebench/executor.py @@ -416,21 +416,19 @@ def execute_run(self, run_id): if not terminate and self._do_builds: self._build_vm_and_suite(run_id) - stats = StatisticProperties(run_id.get_total_values()) - # now start the actual execution if not terminate: terminate = self._generate_data_point(cmdline, gauge_adapter, run_id, termination_check) - stats = StatisticProperties(run_id.get_total_values()) + stats = StatisticProperties(run_id.get_total_values()) if terminate: run_id.report_run_completed(stats, cmdline) if (not run_id.is_failed() and run_id.min_iteration_time and stats.mean < run_id.min_iteration_time): self._ui.warning( ("{ind}Warning: Low mean run time.\n" - + "{ind}{ind}The mean (%.1f) is lower than min_iteration_time (%d)") + + "{ind}{ind}The mean (%.1f) is lower than min_iteration_time (%d)\n") % (stats.mean, run_id.min_iteration_time), run_id, cmdline) return terminate @@ -456,7 +454,6 @@ def _get_gauge_adapter_instance(self, adapter_name): def _generate_data_point(self, cmdline, gauge_adapter, run_id, termination_check): # execute the external program here - run_id.indicate_invocation_start() try: self._ui.debug_output_info("{ind}Starting run\n", run_id, cmdline) @@ -506,7 +503,7 @@ def _generate_data_point(self, cmdline, gauge_adapter, run_id, def _eval_output(self, output, run_id, gauge_adapter, cmdline): try: - data_points = gauge_adapter.parse_data(output, run_id) + data_points = gauge_adapter.parse_data(output, run_id, run_id.completed_invocations + 1) warmup = run_id.warmup_iterations @@ -542,13 +539,17 @@ def _check_termination_condition(run_id, termination_check): run_id.get_number_of_data_points()) def execute(self): - self._scheduler.execute() - successful = True - for run in self._runs: - run.report_job_completed(self._runs) - if run.is_failed(): - successful = False - return successful + try: + self._scheduler.execute() + successful = True + for run in self._runs: + run.report_job_completed(self._runs) + if run.is_failed(): + successful = False + return successful + finally: + for run in self._runs: + run.close_files() @property def runs(self): diff --git a/rebench/interop/adapter.py b/rebench/interop/adapter.py index e85ff84c..d974d0b0 100644 --- a/rebench/interop/adapter.py +++ b/rebench/interop/adapter.py @@ -38,7 +38,7 @@ def __init__(self, include_faulty): def acquire_command(self, command): return command - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, invocation): raise NotImplementedError() def check_for_error(self, line): diff --git a/rebench/interop/jmh_adapter.py b/rebench/interop/jmh_adapter.py index a1d62235..6408808f 100644 --- a/rebench/interop/jmh_adapter.py +++ b/rebench/interop/jmh_adapter.py @@ -33,7 +33,8 @@ class JMHAdapter(GaugeAdapter): re_result_line = re.compile(r"^Iteration\s+(\d+):\s+(\d+(?:\.\d+)?)\s+(.+)") re_bench = re.compile(r"^# Benchmark: (.+)") - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, invocation): + iteration = 1 data_points = [] for line in data.split("\n"): @@ -60,8 +61,10 @@ def parse_data(self, data, run_id): criterion = "total" point = DataPoint(run_id) - point.add_measurement(Measurement(value, unit, run_id, criterion)) + point.add_measurement(Measurement(invocation, iteration, + value, unit, run_id, criterion)) data_points.append(point) + iteration += 1 if not data_points: raise OutputNotParseable(data) diff --git a/rebench/interop/multivariate_adapter.py b/rebench/interop/multivariate_adapter.py index 5e02bc79..19c81be8 100644 --- a/rebench/interop/multivariate_adapter.py +++ b/rebench/interop/multivariate_adapter.py @@ -37,7 +37,8 @@ def __init__(self, include_faulty): super(MultivariateAdapter, self).__init__(include_faulty) self._other_error_definitions = [re.compile("FAILED")] - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, invocation): + iteration = 1 data_points = [] current = DataPoint(run_id) @@ -63,7 +64,8 @@ def parse_data(self, data, run_id): else: value = float(value_thing) - measure = Measurement(value, unit if unit is not None else 'ms', + measure = Measurement(invocation, iteration, value, + unit if unit is not None else 'ms', run_id, variable) current.add_measurement(measure) @@ -71,6 +73,7 @@ def parse_data(self, data, run_id): # compatibility for TestVMPerformance data_points.append(current) current = DataPoint(run_id) + iteration += 1 if not data_points: raise OutputNotParseable(data) diff --git a/rebench/interop/plain_seconds_log_adapter.py b/rebench/interop/plain_seconds_log_adapter.py index 71150c85..89d0f97d 100644 --- a/rebench/interop/plain_seconds_log_adapter.py +++ b/rebench/interop/plain_seconds_log_adapter.py @@ -41,7 +41,8 @@ def __init__(self, include_faulty): self.re_NPB_invalid, self.re_incorrect, self.re_err] - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, invocation): + iteration = 1 data_points = [] current = DataPoint(run_id) @@ -52,11 +53,12 @@ def parse_data(self, data, run_id): try: time = float(line) * 1000 - measure = Measurement(time, 'ms', run_id, 'total') + measure = Measurement(invocation, iteration, time, 'ms', run_id, 'total') current.add_measurement(measure) data_points.append(current) current = DataPoint(run_id) + iteration += 1 except ValueError: pass # ignore that line diff --git a/rebench/interop/rebench_log_adapter.py b/rebench/interop/rebench_log_adapter.py index e7af48c8..fd4b9119 100644 --- a/rebench/interop/rebench_log_adapter.py +++ b/rebench/interop/rebench_log_adapter.py @@ -45,7 +45,8 @@ def __init__(self, include_faulty): self._other_error_definitions = [self.re_NPB_partial_invalid, self.re_NPB_invalid, self.re_incorrect] - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, invocation): + iteration = 1 data_points = [] current = DataPoint(run_id) @@ -62,7 +63,7 @@ def parse_data(self, data, run_id): time /= 1000 criterion = (match.group(2) or 'total').strip() - measure = Measurement(time, 'ms', run_id, criterion) + measure = Measurement(invocation, iteration, time, 'ms', run_id, criterion) else: match = self.re_extra_criterion_log_line.match(line) @@ -71,7 +72,7 @@ def parse_data(self, data, run_id): criterion = match.group(2) unit = match.group(4) - measure = Measurement(value, unit, run_id, criterion) + measure = Measurement(invocation, iteration, value, unit, run_id, criterion) if measure: current.add_measurement(measure) @@ -79,6 +80,7 @@ def parse_data(self, data, run_id): if measure.is_total(): data_points.append(current) current = DataPoint(run_id) + iteration += 1 if not data_points: raise OutputNotParseable(data) diff --git a/rebench/interop/savina_log_adapter.py b/rebench/interop/savina_log_adapter.py index 079abe15..083865ba 100644 --- a/rebench/interop/savina_log_adapter.py +++ b/rebench/interop/savina_log_adapter.py @@ -30,17 +30,19 @@ class SavinaLogAdapter(GaugeAdapter): re_log_line = re.compile( r"^([\w\.]+)\s+Iteration-(?:\d+):\s+([0-9]+\.[0-9]+) ms") - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, invocation): + iteration = 1 data_points = [] for line in data.split("\n"): match = self.re_log_line.match(line) if match: time = float(match.group(2)) - measure = Measurement(time, 'ms', run_id, 'total') + measure = Measurement(invocation, iteration, time, 'ms', run_id, 'total') current = DataPoint(run_id) current.add_measurement(measure) data_points.append(current) + iteration += 1 if not data_points: raise OutputNotParseable(data) diff --git a/rebench/interop/test_adapter.py b/rebench/interop/test_adapter.py index f070c26e..150584f9 100644 --- a/rebench/interop/test_adapter.py +++ b/rebench/interop/test_adapter.py @@ -32,9 +32,9 @@ class TestAdapter(GaugeAdapter): 45875, 45871, 45869, 45870, 45874] index = 0 - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, _invocation): point = DataPoint(run_id) - point.add_measurement(Measurement(self.test_data[self.index], "ms", + point.add_measurement(Measurement(1, 1, self.test_data[self.index], "ms", run_id)) self.index = (self.index + 1) % len(self.test_data) return [point] diff --git a/rebench/interop/test_vm_adapter.py b/rebench/interop/test_vm_adapter.py index efe30ddd..21e0e884 100644 --- a/rebench/interop/test_vm_adapter.py +++ b/rebench/interop/test_vm_adapter.py @@ -35,7 +35,8 @@ def __init__(self, include_faulty): super(TestVMAdapter, self).__init__(include_faulty) self._other_error_definitions = [re.compile("FAILED")] - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, invocation): + iteration = 1 data_points = [] current = DataPoint(run_id) @@ -46,13 +47,15 @@ def parse_data(self, data, run_id): match = TestVMAdapter.re_time.match(line) if match: - measure = Measurement(float(match.group(2)), 'ms', run_id, + measure = Measurement(invocation, iteration, + float(match.group(2)), 'ms', run_id, match.group(1)) current.add_measurement(measure) if measure.is_total(): data_points.append(current) current = DataPoint(run_id) + iteration += 1 if not data_points: raise OutputNotParseable(data) diff --git a/rebench/interop/time_adapter.py b/rebench/interop/time_adapter.py index 803ad675..352bb78a 100644 --- a/rebench/interop/time_adapter.py +++ b/rebench/interop/time_adapter.py @@ -57,9 +57,11 @@ def acquire_command(self, command): # TODO: add support for reading out memory info on OS X return "/usr/bin/time -p %s" % command - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, invocation): + iteration = 1 data_points = [] current = DataPoint(run_id) + total_measure = None for line in data.split("\n"): if self.check_for_error(line): @@ -70,14 +72,15 @@ def parse_data(self, data, run_id): match2 = self.re_formatted_time.match(line) if match1: mem_kb = float(match1.group(1)) - measure = Measurement(mem_kb, 'kb', run_id, 'MaxRSS') + measure = Measurement(invocation, iteration, mem_kb, 'kb', run_id, 'MaxRSS') current.add_measurement(measure) elif match2: time = float(match2.group(1)) * 1000 - measure = Measurement(time, 'ms', run_id, 'total') + measure = Measurement(invocation, iteration, time, 'ms', run_id, 'total') current.add_measurement(measure) data_points.append(current) current = DataPoint(run_id) + iteration += 1 else: match1 = self.re_time.match(line) match2 = self.re_time2.match(line) @@ -86,8 +89,11 @@ def parse_data(self, data, run_id): criterion = 'total' if match.group(1) == 'real' else match.group(1) time = (float(match.group(2).strip() or 0) * 60 + float(match.group(3))) * 1000 - measure = Measurement(time, 'ms', run_id, criterion) - current.add_measurement(measure) + measure = Measurement(invocation, iteration, time, 'ms', run_id, criterion) + if measure.is_total(): + total_measure = measure + else: + current.add_measurement(measure) else: measure = None @@ -95,6 +101,11 @@ def parse_data(self, data, run_id): current.get_total_value() is not None: data_points.append(current) current = DataPoint(run_id) + iteration += 1 + + if total_measure: + current.add_measurement(total_measure) + data_points.append(current) if not data_points: raise OutputNotParseable(data) diff --git a/rebench/interop/validation_log_adapter.py b/rebench/interop/validation_log_adapter.py index 483e9a47..8c261358 100644 --- a/rebench/interop/validation_log_adapter.py +++ b/rebench/interop/validation_log_adapter.py @@ -47,7 +47,8 @@ def __init__(self, include_faulty): self._other_error_definitions = [self.re_NPB_partial_invalid, self.re_NPB_invalid, self.re_incorrect] - def parse_data(self, data, run_id): + def parse_data(self, data, run_id, invocation): + iteration = 1 data_points = [] current = DataPoint(run_id) @@ -62,27 +63,34 @@ def parse_data(self, data, run_id): if match.group(5) == "u": time /= 1000 criterion = (match.group(2) or 'total').strip() - success_measure = Measurement(match.group(6) == "true", 'bool', run_id, 'Success') - measure = Measurement(time, 'ms', run_id, criterion) + success_measure = Measurement(invocation, iteration, + match.group(6) == "true", 'bool', run_id, 'Success') + measure = Measurement(invocation, iteration, time, 'ms', run_id, criterion) current.add_measurement(success_measure) current.add_measurement(measure) if measure.is_total(): data_points.append(current) current = DataPoint(run_id) + iteration += 1 else: match = self.re_actors.match(line) if match: - measure1 = Measurement(int(match.group(1)), 'count', run_id, 'Actors') - measure2 = Measurement(int(match.group(2)), 'count', run_id, 'Messages') - measure3 = Measurement(int(match.group(3)), 'count', run_id, 'Promises') - measure4 = Measurement(0, 'ms', run_id, 'total') + measure1 = Measurement(invocation, iteration, + int(match.group(1)), 'count', run_id, 'Actors') + measure2 = Measurement(invocation, iteration, + int(match.group(2)), 'count', run_id, 'Messages') + measure3 = Measurement(invocation, iteration, + int(match.group(3)), 'count', run_id, 'Promises') + measure4 = Measurement(invocation, iteration, + 0, 'ms', run_id, 'total') current.add_measurement(measure1) current.add_measurement(measure2) current.add_measurement(measure3) current.add_measurement(measure4) data_points.append(current) current = DataPoint(run_id) + iteration += 1 if not data_points: raise OutputNotParseable(data) diff --git a/rebench/model/data_point.py b/rebench/model/data_point.py index 668ee077..f04ed2f4 100644 --- a/rebench/model/data_point.py +++ b/rebench/model/data_point.py @@ -17,6 +17,7 @@ # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING # FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS # IN THE SOFTWARE. +from ..ui import UIError class DataPoint(object): @@ -24,11 +25,23 @@ def __init__(self, run_id): self._run_id = run_id self._measurements = [] self._total = None + self._invocation = -1 + + @property + def invocation(self): + return self._invocation def number_of_measurements(self): return len(self._measurements) def add_measurement(self, measurement): + if self._invocation == -1: + self._invocation = measurement.invocation + elif self._invocation != measurement.invocation: + raise UIError("A data point is expected to represent a single invocation " + + "but we got invocation " + str(measurement.invocation) + + " and " + str(self._invocation) + "\n", None) + self._measurements.append(measurement) if measurement.is_total(): if self._total is not None: diff --git a/rebench/model/exp_run_details.py b/rebench/model/exp_run_details.py index 529b90ea..073e4718 100644 --- a/rebench/model/exp_run_details.py +++ b/rebench/model/exp_run_details.py @@ -39,18 +39,21 @@ def compile(cls, config, defaults): defaults.execute_exclusively)) return ExpRunDetails(invocations, iterations, warmup, min_iteration_time, - max_invocation_time, parallel_interference_factor, execute_exclusively) + max_invocation_time, parallel_interference_factor, execute_exclusively, + defaults.invocations_override, defaults.iterations_override) @classmethod def empty(cls): - return ExpRunDetails(None, None, None, None, None, None, None) + return ExpRunDetails(None, None, None, None, None, None, None, None, None) @classmethod - def default(cls): - return ExpRunDetails(1, 1, None, 50, -1, None, True) + def default(cls, invocations_override, iterations_override): + return ExpRunDetails(1, 1, None, 50, -1, None, True, + invocations_override, iterations_override) def __init__(self, invocations, iterations, warmup, min_iteration_time, - max_invocation_time, parallel_interference_factor, execute_exclusively): + max_invocation_time, parallel_interference_factor, execute_exclusively, + invocations_override, iterations_override): self._invocations = invocations self._iterations = iterations self._warmup = warmup @@ -60,6 +63,9 @@ def __init__(self, invocations, iterations, warmup, min_iteration_time, self._parallel_interference_factor = parallel_interference_factor self._execute_exclusively = execute_exclusively + self._invocations_override = invocations_override + self._iterations_override = iterations_override + @property def invocations(self): return self._invocations @@ -68,6 +74,14 @@ def invocations(self): def iterations(self): return self._iterations + @property + def invocations_override(self): + return self._invocations_override + + @property + def iterations_override(self): + return self._iterations_override + @property def warmup(self): return self._warmup diff --git a/rebench/model/measurement.py b/rebench/model/measurement.py index 550f6bc5..1e3485a5 100644 --- a/rebench/model/measurement.py +++ b/rebench/model/measurement.py @@ -17,26 +17,33 @@ # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING # FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS # IN THE SOFTWARE. -from datetime import datetime - from .run_id import RunId class Measurement(object): - def __init__(self, value, unit, run_id, criterion='total', - timestamp=None, line_number=None, filename=None): - self._run_id = run_id - self._criterion = criterion + def __init__(self, invocation, iteration, value, unit, + run_id, criterion='total', line_number=None, filename=None): + self._invocation = invocation + self._iteration = iteration self._value = value self._unit = unit + self._run_id = run_id + self._criterion = criterion assert unit is not None - self._timestamp = timestamp or datetime.now() self._line_number = line_number self._filename = filename def is_total(self): return self._criterion == 'total' + @property + def invocation(self): + return self._invocation + + @property + def iteration(self): + return self._iteration + @property def criterion(self): return self._criterion @@ -49,10 +56,6 @@ def value(self): def unit(self): return self._unit - @property - def timestamp(self): - return self._timestamp - @property def run_id(self): return self._run_id @@ -65,28 +68,25 @@ def filename(self): def line_number(self): return self._line_number - TIME_FORMAT = "%Y-%m-%dT%H:%M:%S" - def as_str_list(self): if isinstance(self._value, float): val = "%f" % self.value else: val = "%s" % self.value - return ["[" + self._timestamp.strftime(self.TIME_FORMAT) + "]", + return [str(self._invocation), str(self._iteration), val, self._unit, self._criterion] + self._run_id.as_str_list() @classmethod - def from_str_list(cls, data_store, str_list, line_number=None, - filename=None): - - timestamp = datetime.strptime(str_list[0][1:-1], cls.TIME_FORMAT) - value = float(str_list[1]) - unit = str_list[2] - criterion = str_list[3] - run_id = RunId.from_str_list(data_store, str_list[4:]) - - return Measurement(value, unit, run_id, criterion, timestamp, - line_number, filename) + def from_str_list(cls, data_store, str_list, line_number=None, filename=None): + invocation = int(str_list[0]) + iteration = int(str_list[1]) + value = float(str_list[2]) + unit = str_list[3] + criterion = str_list[4] + run_id = RunId.from_str_list(data_store, str_list[5:]) + + return Measurement(invocation, iteration, value, unit, run_id, + criterion, line_number, filename) diff --git a/rebench/model/run_id.py b/rebench/model/run_id.py index 519643bd..37fa98b8 100644 --- a/rebench/model/run_id.py +++ b/rebench/model/run_id.py @@ -40,6 +40,8 @@ def __init__(self, benchmark, cores, input_size, var_value): self._cmdline = None self._failed = True + self._max_invocation = 0 + @property def warmup_iterations(self): return self._benchmark.run_details.warmup @@ -54,11 +56,21 @@ def max_invocation_time(self): @property def iterations(self): - return self._benchmark.run_details.iterations + run_details = self._benchmark.run_details + if run_details.iterations_override is not None: + return run_details.iterations_override + return run_details.iterations @property def invocations(self): - return self._benchmark.run_details.invocations + run_details = self._benchmark.run_details + if run_details.invocations_override is not None: + return run_details.invocations_override + return run_details.invocations + + @property + def completed_invocations(self): + return self._max_invocation @property def execute_exclusively(self): @@ -104,9 +116,6 @@ def requires_warmup(self): def fail_immediately(self): self._termination_check.fail_immediately() - def indicate_invocation_start(self): - self._termination_check.indicate_invocation_start() - def indicate_failed_execution(self): self._termination_check.indicate_failed_execution() @@ -146,10 +155,17 @@ def report_start_run(self): def add_persistence(self, persistence): self._persistence.add(persistence) + def close_files(self): + for persistence in self._persistence: + persistence.close() + def loaded_data_point(self, data_point): + self._max_invocation = max(self._max_invocation, data_point.invocation) self._data_points.append(data_point) def add_data_point(self, data_point, warmup): + self._max_invocation = max(self._max_invocation, data_point.invocation) + if not warmup: self._data_points.append(data_point) for persistence in self._persistence: @@ -163,6 +179,7 @@ def get_data_points(self): def discard_data_points(self): self._data_points = [] + self._max_invocation = 0 def get_total_values(self): return [dp.get_total_value() for dp in self._data_points] @@ -197,9 +214,10 @@ def as_simple_string(self): def _expand_vars(self, string): try: return string % {'benchmark': self._benchmark.command, + 'cores': self._cores, 'input': self._input_size, + 'iterations': self.iterations, 'variable': self._var_value, - 'cores': self._cores, 'warmup': self._benchmark.run_details.warmup} except ValueError as err: self._report_format_issue_and_exit(string, err) diff --git a/rebench/model/termination_check.py b/rebench/model/termination_check.py index e1e7f0c6..3488f53c 100644 --- a/rebench/model/termination_check.py +++ b/rebench/model/termination_check.py @@ -23,7 +23,6 @@ class TerminationCheck(object): def __init__(self, run_id, ui): self._run_id = run_id self._ui = ui - self._num_invocations = 0 self._consecutive_erroneous_executions = 0 self._failed_execution_count = 0 self._fail_immediately = False @@ -31,9 +30,6 @@ def __init__(self, run_id, ui): def fail_immediately(self): self._fail_immediately = True - def indicate_invocation_start(self): - self._num_invocations += 1 - def indicate_failed_execution(self): self._consecutive_erroneous_executions += 1 self._failed_execution_count += 1 @@ -62,7 +58,7 @@ def should_terminate(self, number_of_data_points): self._ui.verbose_error_info( "{ind}Many runs are failing, benchmark is aborted.\n", self._run_id) return True - elif self._num_invocations >= self._run_id.benchmark.run_details.invocations: + elif self._run_id.completed_invocations >= self._run_id.invocations: return True else: return False diff --git a/rebench/persistence.py b/rebench/persistence.py index eb3d36dc..62d2fff4 100644 --- a/rebench/persistence.py +++ b/rebench/persistence.py @@ -18,11 +18,10 @@ # FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS # IN THE SOFTWARE. import os -import sys import subprocess -import shutil +import sys +from datetime import datetime from threading import Lock -import time from .model.data_point import DataPoint from .model.measurement import Measurement @@ -131,7 +130,7 @@ def __init__(self, data_filename, data_store, discard_old_data, ui): self._file = None if discard_old_data: self._discard_old_data() - self._insert_shebang_line() + self._append_execution_comment() self._lock = Lock() def _discard_old_data(self): @@ -188,19 +187,20 @@ def _process_lines(self, data_file): msg = str(err) if not errors: self._ui.debug_error_info("Failed loading data from data file: " - + data_file + "\n") + + self._data_filename + "\n") if msg not in errors: # Configuration is not available, skip data point self._ui.debug_error_info("{ind}" + msg + "\n") errors.add(msg) - line_number += 1 - def _insert_shebang_line(self): + def _append_execution_comment(self): """ - Insert a shebang (#!/path/to/executable) into the data file. + Append a shebang (#!/path/to/executable) to the data file. This allows it theoretically to be executable. + But more importantly also records execution metadata to reproduce the data. """ shebang_line = "#!%s\n" % (subprocess.list2cmdline(sys.argv)) + shebang_line += "# Execution Start: " + datetime.now().strftime("%Y-%m-%dT%H:%M:%S\n") try: # if file doesn't exist, just create it @@ -211,22 +211,13 @@ def _insert_shebang_line(self): data_file.close() return - # if file exists, the first line might already be the same line - with open(self._data_filename, 'r') as data_file: - if data_file.readline() == shebang_line: - return - - # otherwise, copy the file and insert line at the beginning - renamed_file = "%s-%.0f.tmp" % (self._data_filename, time.time()) - os.rename(self._data_filename, renamed_file) - with open(self._data_filename, 'w') as data_file: + # otherwise, append the lines + with open(self._data_filename, 'a') as data_file: data_file.write(shebang_line) data_file.flush() - shutil.copyfileobj(open(renamed_file, 'r'), data_file) - os.remove(renamed_file) except Exception as err: # pylint: disable=broad-except self._ui.error( - "Error: While inserting a shebang line into the data file.\n{ind}%s\n" % err) + "Error: While appending metadata to the data file.\n{ind}%s\n" % err) _SEP = "\t" # separator between serialized parts of a measurement @@ -247,3 +238,8 @@ def persist_data_point(self, data_point): def _open_file_to_add_new_data(self): if not self._file: self._file = open(self._data_filename, 'a+') + + def close(self): + if self._file: + self._file.close() + self._file = None diff --git a/rebench/rebench.py b/rebench/rebench.py index d2cad9ed..1da90848 100755 --- a/rebench/rebench.py +++ b/rebench/rebench.py @@ -87,10 +87,17 @@ def shell_options(self): execution = parser.add_argument_group( 'Execution Options', 'Adapt how ReBench executes benchmarks') + execution.add_argument( + '-in', '--invocations', action='store', dest='invocations', + help='The number of times a VM is started to execute a run.', + default=None, type=int) + execution.add_argument( + '-it', '--iterations', action='store', dest='iterations', + help='The number of times a benchmark is to be executed within a VM invocation.', + default=None, type=int) execution.add_argument( '-q', '--quick', action='store_true', dest='quick', - help='Do a quick benchmark run instead of a full, ' - 'statistical rigorous experiment.', + help='Execute quickly. Identical with --iterations=1 --invocations=1', default=False) execution.add_argument( '-N', '--without-nice', action='store_false', dest='use_nice', @@ -190,7 +197,6 @@ def run(self, argv=None): self._config = Configurator(config, data_store, self._ui, args, cli_reporter, exp_name, args.data_file, args.build_log, exp_filter) - #TODO how to set ui on codespeed reporter? except ConfigurationError as exc: raise UIError(exc.message + "\n", exc) @@ -225,7 +231,7 @@ def main_func(): rebench = ReBench() return 0 if rebench.run() else -1 except KeyboardInterrupt: - rebench.ui.debug_error_info("Aborted by user request") + rebench.ui.debug_error_info("Aborted by user request\n") return -1 except UIError as err: rebench.ui.error(err.message) diff --git a/rebench/reporter.py b/rebench/reporter.py index ab9c6118..01d07158 100644 --- a/rebench/reporter.py +++ b/rebench/reporter.py @@ -81,10 +81,11 @@ def _generate_all_output(run_ids): for run_id in run_ids: stats = StatisticProperties(run_id.get_total_values()) out = run_id.as_str_list() + out.append(stats.num_samples) if stats.num_samples == 0: out.append("Failed") else: - out.append(stats.mean) + out.append(int(round(stats.mean, 0))) rows.append(out) return rows @@ -112,7 +113,7 @@ def run_completed(self, run_id, statistics, cmdline): def report_job_completed(self, run_ids): self._ui.output("\n\n" + format_pretty_table( self._generate_all_output(run_ids), - ['Benchmark', 'VM', 'Suite', 'Extra', 'Core', 'Size', 'Var', 'Mean'], + ['Benchmark', 'VM', 'Suite', 'Extra', 'Core', 'Size', 'Var', '#Samples', 'Mean (ms)'], vertical_bar=' ')) def set_total_number_of_runs(self, num_runs): diff --git a/rebench/tests/executor_test.py b/rebench/tests/executor_test.py index 1b60a8ec..996065ee 100644 --- a/rebench/tests/executor_test.py +++ b/rebench/tests/executor_test.py @@ -39,15 +39,20 @@ def setUp(self): def test_setup_and_run_benchmark(self): # before executing the benchmark, # we override stuff in subprocess for testing + old_popen = subprocess.Popen subprocess.Popen = Popen_override - options = ReBench().shell_options().parse_args(['dummy']) - cnf = Configurator(load_config(self._path + '/test.conf'), DataStore(self._ui), - self._ui, options, - None, 'Test', data_file=self._tmp_file) + try: + options = ReBench().shell_options().parse_args(['dummy']) - ex = Executor(cnf.get_runs(), cnf.use_nice, cnf.do_builds, TestDummyUI()) - ex.execute() + cnf = Configurator(load_config(self._path + '/test.conf'), DataStore(self._ui), + self._ui, options, + None, 'Test', data_file=self._tmp_file) + + ex = Executor(cnf.get_runs(), cnf.use_nice, cnf.do_builds, TestDummyUI()) + ex.execute() + finally: + subprocess.Popen = old_popen # TODO: should test more details # (mean, sdev, (interval, interval_percentage), @@ -112,6 +117,41 @@ def test_basic_execution_with_magic_all(self): 'all', data_file=self._tmp_file) self._basic_execution(cnf) + def test_execution_with_quick_set(self): + self._set_path(__file__) + option_parser = ReBench().shell_options() + cmd_config = option_parser.parse_args(['-q', 'persistency.conf']) + self.assertTrue(cmd_config.quick) + + cnf = Configurator(load_config(self._path + '/persistency.conf'), DataStore(self._ui), + self._ui, cmd_config, data_file=self._tmp_file) + runs = cnf.get_runs() + self.assertEqual(1, len(runs)) + + ex = Executor(runs, False, False, self._ui) + ex.execute() + run = list(runs)[0] + + self.assertEqual(1, run.get_number_of_data_points()) + + def test_execution_with_invocation_and_iteration_set(self): + self._set_path(__file__) + option_parser = ReBench().shell_options() + cmd_config = option_parser.parse_args(['-in=2', '-it=2', 'persistency.conf']) + self.assertEqual(2, cmd_config.invocations) + self.assertEqual(2, cmd_config.iterations) + + cnf = Configurator(load_config(self._path + '/persistency.conf'), DataStore(self._ui), + self._ui, cmd_config, data_file=self._tmp_file) + runs = cnf.get_runs() + self.assertEqual(1, len(runs)) + + ex = Executor(runs, False, False, self._ui) + ex.execute() + run = list(runs)[0] + + self.assertEqual(2, run.get_number_of_data_points()) + def test_shell_options_without_filters(self): option_parser = ReBench().shell_options() args = option_parser.parse_args(['-d', '-v', 'some.conf']) @@ -158,7 +198,7 @@ def test_determine_exp_name_and_filters_only_others(self): self.assertEqual(exp_filter, ['vm:bar', 's:b']) -def Popen_override(cmdline, stdout, stderr=None, shell=None): # pylint: disable=unused-argument +def Popen_override(cmdline, stdout, stdin=None, stderr=None, cwd=None, shell=None): # pylint: disable=unused-argument class Popen(object): returncode = 0 @@ -174,7 +214,7 @@ def poll(self): def kill(self): pass - def wait(self): + def wait(self, **_kwargs): pass def __enter__(self): diff --git a/rebench/tests/features/issue_32_jmh_support_test.py b/rebench/tests/features/issue_32_jmh_support_test.py index d95da6d5..58768f9e 100644 --- a/rebench/tests/features/issue_32_jmh_support_test.py +++ b/rebench/tests/features/issue_32_jmh_support_test.py @@ -35,7 +35,7 @@ def setUp(self): def test_parsing(self): adapter = JMHAdapter(False) - data_points = adapter.parse_data(self._data, None) + data_points = adapter.parse_data(self._data, None, 1) self.assertEqual(4 * 20, len(data_points)) diff --git a/rebench/tests/interop/plain_seconds_log_adapter_test.py b/rebench/tests/interop/plain_seconds_log_adapter_test.py index da4947fe..d7b48633 100644 --- a/rebench/tests/interop/plain_seconds_log_adapter_test.py +++ b/rebench/tests/interop/plain_seconds_log_adapter_test.py @@ -35,7 +35,7 @@ def test_parse_data(self): 50 1""" adapter = PlainSecondsLogAdapter(False) - data = adapter.parse_data(data, None) + data = adapter.parse_data(data, None, 2) self.assertEqual(3, len(data)) self.assertEqual(1, len(data[0].get_measurements())) @@ -49,4 +49,4 @@ def test_parse_data(self): def test_parse_no_data(self): adapter = PlainSecondsLogAdapter(False) - self.assertRaises(OutputNotParseable, adapter.parse_data, "", None) + self.assertRaises(OutputNotParseable, adapter.parse_data, "", None, 1) diff --git a/rebench/tests/interop/rebench_log_adapter_test.py b/rebench/tests/interop/rebench_log_adapter_test.py index 382c2f97..0ce81b00 100644 --- a/rebench/tests/interop/rebench_log_adapter_test.py +++ b/rebench/tests/interop/rebench_log_adapter_test.py @@ -38,32 +38,32 @@ def _assert_two_measures(self, data, val1, unit1, criterion1, val_t, unit_t): def test_simple_name(self): adapter = RebenchLogAdapter(True) - data = adapter.parse_data("Dispatch: iterations=1 runtime: 557ms", None) + data = adapter.parse_data("Dispatch: iterations=1 runtime: 557ms", None, 1) self._assert_basics(data, 557, 'ms', 'total', True) def test_doted_name(self): adapter = RebenchLogAdapter(True) data = adapter.parse_data( - "LanguageFeatures.Dispatch: iterations=1 runtime: 309557us", None) + "LanguageFeatures.Dispatch: iterations=1 runtime: 309557us", None, 1) self._assert_basics(data, 309.557, 'ms', 'total', True) def test_doted_and_ms(self): adapter = RebenchLogAdapter(True) data = adapter.parse_data( - "LanguageFeatures.Dispatch: iterations=1 runtime: 557ms", None) + "LanguageFeatures.Dispatch: iterations=1 runtime: 557ms", None, 1) self._assert_basics(data, 557, 'ms', 'total', True) def test_high_iter_count(self): adapter = RebenchLogAdapter(True) data = adapter.parse_data( - "LanguageFeatures.Dispatch: iterations=2342 runtime: 557ms", None) + "LanguageFeatures.Dispatch: iterations=2342 runtime: 557ms", None, 1) self._assert_basics(data, 557, 'ms', 'total', True) def test_total_explicit(self): adapter = RebenchLogAdapter(True) data = adapter.parse_data( "LanguageFeatures.Dispatch total: iterations=2342 runtime: 557ms", - None) + None, 1) self._assert_basics(data, 557, 'ms', 'total', True) def test_alloc_criterion(self): @@ -71,7 +71,7 @@ def test_alloc_criterion(self): data = adapter.parse_data( """LanguageFeatures.Dispatch alloc: iterations=2342 runtime: 222ms LanguageFeatures.Dispatch total: iterations=2342 runtime: 557ms""", - None) + None, 3) self._assert_two_measures(data, 222, 'ms', 'alloc', 557, 'ms') def test_foobar_criterion(self): @@ -79,7 +79,7 @@ def test_foobar_criterion(self): data = adapter.parse_data( """LanguageFeatures.Dispatch foobar: iterations=2342 runtime: 550ms LanguageFeatures.Dispatch total: iterations=2342 runtime: 557ms""", - None) + None, 5) self._assert_two_measures(data, 550, 'ms', 'foobar', 557, 'ms') def test_foobar_criterion_no_doted_name(self): @@ -87,21 +87,21 @@ def test_foobar_criterion_no_doted_name(self): data = adapter.parse_data( """Dispatch foobar: iterations=2342 runtime: 550ms LanguageFeatures.Dispatch total: iterations=2342 runtime: 557ms""", - None) + None, 7) self._assert_two_measures(data, 550, 'ms', 'foobar', 557, 'ms') def test_some_prefix_before_data(self): adapter = RebenchLogAdapter(True) data = adapter.parse_data( "some prefix: Dispatch: iterations=2342 runtime: 557ms", - None) + None, 11) self._assert_basics(data, 557, 'ms', 'total', True) def test_path_as_name(self): adapter = RebenchLogAdapter(True) data = adapter.parse_data( "core-lib/Benchmarks/Join/FibSeq.ns: iterations=1 runtime: 129us", - None) + None, 12) self._assert_basics(data, 0.129, 'ms', 'total', True) def test_other_data(self): @@ -111,7 +111,7 @@ def test_other_data(self): Savina.Chameneos: iterations=1 runtime: 64208us Savina.Chameneos: trace size: 3903414byte Savina.Chameneos: external data: 40byte -Savina.Chameneos: iterations=1 runtime: 48581us""", None) +Savina.Chameneos: iterations=1 runtime: 48581us""", None, 13) self.assertEqual(2, len(data)) point = data[0] diff --git a/rebench/tests/interop/time_adapter_test.py b/rebench/tests/interop/time_adapter_test.py index ef23a05a..1efdd248 100644 --- a/rebench/tests/interop/time_adapter_test.py +++ b/rebench/tests/interop/time_adapter_test.py @@ -35,7 +35,7 @@ def test_parse_data(self): user 5.00 sys 1.00""" adapter = TimeAdapter(False) - data = adapter.parse_data(data, None) + data = adapter.parse_data(data, None, 1) self.assertEqual(1, len(data)) measurements = data[0].get_measurements() @@ -44,7 +44,7 @@ def test_parse_data(self): def test_parse_no_data(self): adapter = TimeAdapter(False) - self.assertRaises(OutputNotParseable, adapter.parse_data, "", None) + self.assertRaises(OutputNotParseable, adapter.parse_data, "", None, 1) def test_manual_adapter(self): adapter = TimeManualAdapter(False) diff --git a/rebench/tests/model/runs_config_test.py b/rebench/tests/model/runs_config_test.py index 3766f46b..014e76ea 100644 --- a/rebench/tests/model/runs_config_test.py +++ b/rebench/tests/model/runs_config_test.py @@ -17,6 +17,8 @@ # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING # FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS # IN THE SOFTWARE. +from ...model.data_point import DataPoint +from ...model.measurement import Measurement from ...model.termination_check import TerminationCheck from ...configurator import Configurator, load_config from ...persistence import DataStore @@ -38,11 +40,15 @@ def test_termination_check_basic(self): self.assertFalse(check.should_terminate(0)) # start 9 times, but expect to be done only after 10 - for _ in range(0, 9): - check.indicate_invocation_start() + for i in range(1, 10): + dp = DataPoint(self._run) + dp.add_measurement(Measurement(i, 1, 0, 'ms', self._run)) + self._run.loaded_data_point(dp) self.assertFalse(check.should_terminate(0)) - check.indicate_invocation_start() + dp = DataPoint(self._run) + dp.add_measurement(Measurement(10, 1, 0, 'ms', self._run)) + self._run.loaded_data_point(dp) self.assertTrue(check.should_terminate(0)) def test_terminate_not_determine_by_number_of_data_points(self): diff --git a/rebench/tests/persistency.conf b/rebench/tests/persistency.conf new file mode 100644 index 00000000..1418b77f --- /dev/null +++ b/rebench/tests/persistency.conf @@ -0,0 +1,29 @@ +# Config file for ReBench +# Config format is YAML (see http://yaml.org/ for detailed spec) + +# this run definition will be chosen if no parameters are given to rebench.py +standard_experiment: Test +standard_data_file: 'persistency.data' + + +benchmark_suites: + TestSuite: + invocations: 10 + min_iteration_time: 1 + gauge_adapter: Time + command: 1 FooBar %(benchmark)s 2 3 4 + benchmarks: + - TestBench + +virtual_machines: + TestVM: + path: . + binary: test-vm1.py + cores: [1] + +experiments: + Test: + suites: + - TestSuite + executions: + - TestVM diff --git a/rebench/tests/persistency_test.py b/rebench/tests/persistency_test.py index 63291b6f..dae0cd5e 100644 --- a/rebench/tests/persistency_test.py +++ b/rebench/tests/persistency_test.py @@ -17,12 +17,12 @@ # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING # FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS # IN THE SOFTWARE. -from datetime import datetime - from .rebench_test_case import ReBenchTestCase from ..persistence import DataStore +from ..configurator import Configurator, load_config +from ..executor import Executor from ..model.benchmark import Benchmark from ..model.benchmark_suite import BenchmarkSuite from ..model.exp_run_details import ExpRunDetails @@ -40,12 +40,11 @@ def test_de_serialization(self): suite = BenchmarkSuite("MySuite", vm, '', '', None, None, None, None, None, None) benchmark = Benchmark("Test Bench [>", "Test Bench [>", None, - suite, None, None, ExpRunDetails.default(), None, data_store) + suite, None, None, ExpRunDetails.default(None, None), + None, data_store) run_id = RunId(benchmark, 1000, 44, 'sdf sdf sdf sdfsf') - timestamp = datetime.now().replace(microsecond=0) - measurement = Measurement(2222.2222, 'ms', run_id, 'foobar crit', - timestamp) + measurement = Measurement(43, 45, 2222.2222, 'ms', run_id, 'foobar crit') serialized = measurement.as_str_list() deserialized = Measurement.from_str_list(data_store, serialized) @@ -53,6 +52,43 @@ def test_de_serialization(self): self.assertEqual(deserialized.criterion, measurement.criterion) self.assertEqual(deserialized.value, measurement.value) self.assertEqual(deserialized.unit, measurement.unit) - self.assertAlmostEqual(deserialized.timestamp, measurement.timestamp) + self.assertEqual(deserialized.invocation, measurement.invocation) + self.assertEqual(deserialized.iteration, measurement.iteration) self.assertEqual(deserialized.run_id, measurement.run_id) + + def _assert_runs(self, cnf, num_runs, num_dps, num_invocations): + runs = cnf.get_runs() + self.assertEqual(num_runs, len(runs)) + run = list(runs)[0] + + self.assertEqual(num_dps, run.get_number_of_data_points()) + self.assertEqual(num_invocations, run.completed_invocations) + + def test_iteration_invocation_semantics(self): + ## Executes first time + ds = DataStore(self._ui) + cnf = Configurator(load_config(self._path + '/persistency.conf'), + ds, self._ui, data_file=self._tmp_file) + ds.load_data() + + self._assert_runs(cnf, 1, 0, 0) + + ex = Executor(cnf.get_runs(), False, False, self._ui) + ex.execute() + + self._assert_runs(cnf, 1, 10, 10) + + ## Execute a second time, should not add any data points, + ## because goal is already reached + ds2 = DataStore(self._ui) + cnf2 = Configurator(load_config(self._path + '/persistency.conf'), + ds2, self._ui, data_file=self._tmp_file) + ds2.load_data() + + self._assert_runs(cnf2, 1, 10, 10) + + ex2 = Executor(cnf2.get_runs(), False, False, self._ui) + ex2.execute() + + self._assert_runs(cnf2, 1, 10, 10) diff --git a/rebench/tests/rebench_test_case.py b/rebench/tests/rebench_test_case.py index 9b07c51e..3cb91757 100644 --- a/rebench/tests/rebench_test_case.py +++ b/rebench/tests/rebench_test_case.py @@ -32,7 +32,6 @@ class ReBenchTestCase(TestCase): def _set_path(self, path): self._path = dirname(realpath(path)) os.chdir(self._path) - self._ui = TestDummyUI() def setUp(self): logging.getLogger('pykwalify').addHandler(logging.NullHandler()) @@ -41,6 +40,7 @@ def setUp(self): self._tmp_file = mkstemp()[1] # just use the file name self._sys_exit = sys.exit # make sure that we restore sys.exit + self._ui = TestDummyUI() def tearDown(self): os.remove(self._tmp_file) diff --git a/rebench/ui.py b/rebench/ui.py index b017dfbf..74a17449 100644 --- a/rebench/ui.py +++ b/rebench/ui.py @@ -19,6 +19,8 @@ # IN THE SOFTWARE. import sys +from os import getcwd + from humanfriendly import erase_line_code, Spinner from humanfriendly.compat import coerce_string from humanfriendly.terminal import terminal_supports_colors, ansi_wrap, auto_encode @@ -26,6 +28,11 @@ _DETAIL_INDENT = " " +def escape_braces(string): + string = coerce_string(string) + return string.replace('{', '{{').replace('}', '}}') + + class UI(object): def __init__(self): @@ -77,8 +84,10 @@ def _prepare_details(self, run_id, cmd, cwd): assert text if cwd: text += _DETAIL_INDENT + "cwd: " + cwd + "\n" - elif run_id: + elif run_id and run_id.location: text += _DETAIL_INDENT + "cwd: " + run_id.location + "\n" + else: + text += _DETAIL_INDENT + "cwd: " + getcwd() + "\n" self._prev_run_id = run_id self._prev_cmd = cmd @@ -121,7 +130,7 @@ def verbose_output_info(self, text, run_id=None, cmd=None, cwd=None, **kw): def verbose_error_info(self, text, run_id=None, cmd=None, cwd=None, **kw): if self._verbose: self._output_detail_header(run_id, cmd, cwd) - self._output(text, 'error', faint=True, **kw) + self._output(text, 'red', faint=True, **kw) def debug_output_info(self, text, run_id=None, cmd=None, cwd=None, **kw): if self._debug: @@ -131,7 +140,7 @@ def debug_output_info(self, text, run_id=None, cmd=None, cwd=None, **kw): def debug_error_info(self, text, run_id=None, cmd=None, cwd=None, **kw): if self._debug: self._output_detail_header(run_id, cmd, cwd) - self._output(text, 'error', faint=True, **kw) + self._output(text, 'red', faint=True, **kw) class UIError(Exception):