From 29786a74b9c8888dfe88b39a604a80218b6e5090 Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Tue, 20 Dec 2022 14:28:35 +0100 Subject: [PATCH 1/2] Fix multiline perflog bug --- reframe/core/logging.py | 19 ++++++++++--------- unittests/test_policies.py | 18 ++++++++++++++++-- 2 files changed, 26 insertions(+), 11 deletions(-) diff --git a/reframe/core/logging.py b/reframe/core/logging.py index ed05763ccf..c868a0021c 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -735,15 +735,16 @@ def log_performance(self, level, task, msg=None, multiline=False): if multiline: # Log one record for each performance variable check = self.extra['__rfm_check__'] - for var, info in check.perfvalues.items(): - val, ref, lower, upper, unit = info - self.extra['check_perf_var'] = var.split(':')[-1] - self.extra['check_perf_value'] = val - self.extra['check_perf_ref'] = ref - self.extra['check_perf_lower_thres'] = lower - self.extra['check_perf_upper_thres'] = upper - self.extra['check_perf_unit'] = unit - self.log(level, msg) + if check: + for var, info in check.perfvalues.items(): + val, ref, lower, upper, unit = info + self.extra['check_perf_var'] = var.split(':')[-1] + self.extra['check_perf_value'] = val + self.extra['check_perf_ref'] = ref + self.extra['check_perf_lower_thres'] = lower + self.extra['check_perf_upper_thres'] = upper + self.extra['check_perf_unit'] = unit + self.log(level, msg) else: self.log(level, msg) diff --git a/unittests/test_policies.py b/unittests/test_policies.py index cbaf0f4da8..84fbe62b04 100644 --- a/unittests/test_policies.py +++ b/unittests/test_policies.py @@ -989,6 +989,20 @@ def perf1(self): return _MyTest() +@pytest.fixture +def simple_test(): + class _MySimpleTest(rfm.RunOnlyRegressionTest): + valid_systems = ['*'] + valid_prog_environs = ['*'] + executable = 'echo hello' + + @sanity_function + def validate(self): + return sn.assert_found(r'hello', self.stdout) + + return _MySimpleTest() + + @pytest.fixture def config_perflog(make_config_file): def _config_perflog(fmt, perffmt=None, logging_opts=None): @@ -1178,7 +1192,7 @@ def test_perf_logging_no_perfvars(make_runner, make_exec_ctx, perf_test, def test_perf_logging_multiline(make_runner, make_exec_ctx, perf_test, - config_perflog, tmp_path): + simple_test, config_perflog, tmp_path): make_exec_ctx( config_perflog( fmt=( @@ -1193,7 +1207,7 @@ def test_perf_logging_multiline(make_runner, make_exec_ctx, perf_test, ) logging.configure_logging(rt.runtime().site_config) runner = make_runner() - testcases = executors.generate_testcases([perf_test]) + testcases = executors.generate_testcases([perf_test, simple_test]) runner.runall(testcases) logfile = tmp_path / 'perflogs' / 'generic' / 'default' / '_MyTest.log' From 5820c42199844b9f5cb45b1ddc4833a58bc7b2b6 Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Tue, 20 Dec 2022 16:43:56 +0100 Subject: [PATCH 2/2] Fix multiline perflog bug --- reframe/core/logging.py | 19 +++++++++---------- reframe/frontend/executors/__init__.py | 10 ++++++---- 2 files changed, 15 insertions(+), 14 deletions(-) diff --git a/reframe/core/logging.py b/reframe/core/logging.py index c868a0021c..ed05763ccf 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -735,16 +735,15 @@ def log_performance(self, level, task, msg=None, multiline=False): if multiline: # Log one record for each performance variable check = self.extra['__rfm_check__'] - if check: - for var, info in check.perfvalues.items(): - val, ref, lower, upper, unit = info - self.extra['check_perf_var'] = var.split(':')[-1] - self.extra['check_perf_value'] = val - self.extra['check_perf_ref'] = ref - self.extra['check_perf_lower_thres'] = lower - self.extra['check_perf_upper_thres'] = upper - self.extra['check_perf_unit'] = unit - self.log(level, msg) + for var, info in check.perfvalues.items(): + val, ref, lower, upper, unit = info + self.extra['check_perf_var'] = var.split(':')[-1] + self.extra['check_perf_value'] = val + self.extra['check_perf_ref'] = ref + self.extra['check_perf_lower_thres'] = lower + self.extra['check_perf_upper_thres'] = upper + self.extra['check_perf_unit'] = unit + self.log(level, msg) else: self.log(level, msg) diff --git a/reframe/frontend/executors/__init__.py b/reframe/frontend/executors/__init__.py index 19631c2a58..957ea58689 100644 --- a/reframe/frontend/executors/__init__.py +++ b/reframe/frontend/executors/__init__.py @@ -386,8 +386,9 @@ def finalize(self): self._current_stage = 'finalize' self._notify_listeners('on_task_success') - self._perflogger.log_performance(logging.INFO, self, - multiline=self._perflog_compat) + if self.check.is_performance_check(): + self._perflogger.log_performance(logging.INFO, self, + multiline=self._perflog_compat) @logging.time_function def cleanup(self, *args, **kwargs): @@ -397,8 +398,9 @@ def fail(self, exc_info=None): self._failed_stage = self._current_stage self._exc_info = exc_info or sys.exc_info() self._notify_listeners('on_task_failure') - self._perflogger.log_performance(logging.INFO, self, - multiline=self._perflog_compat) + if self.check.is_performance_check(): + self._perflogger.log_performance(logging.INFO, self, + multiline=self._perflog_compat) def skip(self, exc_info=None): self._skipped = True