From 47647d1bf2c34cb298b7de23b157d7ca32b4c3f4 Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Wed, 9 Jul 2025 14:55:22 +0200 Subject: [PATCH 1/8] log sanity results for httpjson handler --- reframe/core/logging.py | 23 ++++++++++++++++++++--- reframe/schemas/config.json | 1 + 2 files changed, 21 insertions(+), 3 deletions(-) diff --git a/reframe/core/logging.py b/reframe/core/logging.py index 5352451a7..3e3a52458 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -558,6 +558,7 @@ def _create_httpjson_handler(site_config, config_prefix): debug = site_config.get(f'{config_prefix}/debug') backoff_intervals = site_config.get(f'{config_prefix}/backoff_intervals') retry_timeout = site_config.get(f'{config_prefix}/retry_timeout') + log_sanity_results = site_config.get(f'{config_prefix}/log_sanity_results') parsed_url = urllib.parse.urlparse(url) if parsed_url.scheme not in {'http', 'https'}: @@ -600,7 +601,7 @@ def _create_httpjson_handler(site_config, config_prefix): return HTTPJSONHandler(url, extras, ignore_keys, json_formatter, extra_headers, debug, backoff_intervals, - retry_timeout) + retry_timeout, log_sanity_results) def _record_to_json(record, extras, ignore_keys): @@ -651,7 +652,8 @@ class HTTPJSONHandler(logging.Handler): def __init__(self, url, extras=None, ignore_keys=None, json_formatter=None, extra_headers=None, - debug=False, backoff_intervals=(1, 2, 3), retry_timeout=0): + debug=False, backoff_intervals=(1, 2, 3), retry_timeout=0, + log_sanity_results=False): super().__init__() self._url = url self._extras = extras @@ -677,6 +679,7 @@ def __init__(self, url, extras=None, ignore_keys=None, self._debug = debug self._timeout = retry_timeout self._backoff_intervals = backoff_intervals + self._log_sanity_results = log_sanity_results def emit(self, record): # Convert tags to a list to make them JSON friendly @@ -882,7 +885,11 @@ def _update_check_extras(self): ) def log_performance(self, level, task, msg=None, multiline=False): - if self.check is None or not self.check.is_performance_check(): + if ( + self.check is None or + not self.check.is_performance_check() and + not self.logger._log_sanity_results + ): return _, part, env = task.testcase @@ -911,6 +918,16 @@ def log_performance(self, level, task, msg=None, multiline=False): self.extra['check_perf_unit'] = unit self.extra['check_perf_result'] = result self.log(level, msg) + + if not self.check.perfvalues: + self.extra['check_perf_var'] = "$sanity_dummy" + self.extra['check_perf_value'] = None + self.extra['check_perf_ref'] = None + self.extra['check_perf_lower_thres'] = None + self.extra['check_perf_upper_thres'] = None + self.extra['check_perf_unit'] = None + self.extra['check_perf_result'] = None + self.log(level, msg) else: self.log(level, msg) diff --git a/reframe/schemas/config.json b/reframe/schemas/config.json index 6fd7c1bb9..fe75984af 100644 --- a/reframe/schemas/config.json +++ b/reframe/schemas/config.json @@ -179,6 +179,7 @@ "type": "array", "items": {"type": "number"} }, + "log_sanity_results": {"type": "boolean"}, "retry_timeout": {"type": "number"} }, "required": ["url"] From df6ff5c920e7defb37b54312275d40e8b1b7edda Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Mon, 14 Jul 2025 06:43:59 +0200 Subject: [PATCH 2/8] Set default `log_sanity_results` to false --- reframe/schemas/config.json | 1 + 1 file changed, 1 insertion(+) diff --git a/reframe/schemas/config.json b/reframe/schemas/config.json index fe75984af..babfa8a0c 100644 --- a/reframe/schemas/config.json +++ b/reframe/schemas/config.json @@ -641,6 +641,7 @@ "logging/handlers_perflog/httpjson_extra_headers": {}, "logging/handlers_perflog/httpjson_debug": false, "logging/handlers_perflog/httpjson_backoff_intervals": [0.1, 0.2, 0.4, 0.8, 1.6, 3.2], + "logging/handlers_perflog/httpjson_log_sanity_results": false, "logging/handlers_perflog/httpjson_retry_timeout": 0, "modes/options": [], "modes/target_systems": ["*"], From b62c18f1147a5bf38ee98ba4c21b7dc6d96fdb93 Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Mon, 14 Jul 2025 06:50:10 +0200 Subject: [PATCH 3/8] Get _log_sanity_results value for all loggers --- reframe/core/logging.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/reframe/core/logging.py b/reframe/core/logging.py index 3e3a52458..14efb07d0 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -888,7 +888,7 @@ def log_performance(self, level, task, msg=None, multiline=False): if ( self.check is None or not self.check.is_performance_check() and - not self.logger._log_sanity_results + not getattr(self.logger, '_log_sanity_results', False) ): return From 3ee83d972f890163191106dd70b1f96043b19015 Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Mon, 14 Jul 2025 07:26:10 +0200 Subject: [PATCH 4/8] Move log_sanity_results to logger instead of handlers --- reframe/core/logging.py | 7 ++----- reframe/frontend/executors/__init__.py | 3 +++ reframe/schemas/config.json | 4 ++-- 3 files changed, 7 insertions(+), 7 deletions(-) diff --git a/reframe/core/logging.py b/reframe/core/logging.py index 14efb07d0..4f880d9ca 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -558,7 +558,6 @@ def _create_httpjson_handler(site_config, config_prefix): debug = site_config.get(f'{config_prefix}/debug') backoff_intervals = site_config.get(f'{config_prefix}/backoff_intervals') retry_timeout = site_config.get(f'{config_prefix}/retry_timeout') - log_sanity_results = site_config.get(f'{config_prefix}/log_sanity_results') parsed_url = urllib.parse.urlparse(url) if parsed_url.scheme not in {'http', 'https'}: @@ -601,7 +600,7 @@ def _create_httpjson_handler(site_config, config_prefix): return HTTPJSONHandler(url, extras, ignore_keys, json_formatter, extra_headers, debug, backoff_intervals, - retry_timeout, log_sanity_results) + retry_timeout) def _record_to_json(record, extras, ignore_keys): @@ -652,8 +651,7 @@ class HTTPJSONHandler(logging.Handler): def __init__(self, url, extras=None, ignore_keys=None, json_formatter=None, extra_headers=None, - debug=False, backoff_intervals=(1, 2, 3), retry_timeout=0, - log_sanity_results=False): + debug=False, backoff_intervals=(1, 2, 3), retry_timeout=0): super().__init__() self._url = url self._extras = extras @@ -679,7 +677,6 @@ def __init__(self, url, extras=None, ignore_keys=None, self._debug = debug self._timeout = retry_timeout self._backoff_intervals = backoff_intervals - self._log_sanity_results = log_sanity_results def emit(self, record): # Convert tags to a list to make them JSON friendly diff --git a/reframe/frontend/executors/__init__.py b/reframe/frontend/executors/__init__.py index 9c7155e5f..07353c18e 100644 --- a/reframe/frontend/executors/__init__.py +++ b/reframe/frontend/executors/__init__.py @@ -235,6 +235,9 @@ def __init__(self, case, listeners=None, timeout=None): self._perflog_compat = runtime.runtime().get_option( 'logging/0/perflog_compat' ) + self._log_sanity_results = runtime.runtime().get_option( + 'logging/0/log_sanity_results' + ) def duration(self, phase): # Treat pseudo-phases first diff --git a/reframe/schemas/config.json b/reframe/schemas/config.json index babfa8a0c..d3f4069fd 100644 --- a/reframe/schemas/config.json +++ b/reframe/schemas/config.json @@ -179,7 +179,6 @@ "type": "array", "items": {"type": "number"} }, - "log_sanity_results": {"type": "boolean"}, "retry_timeout": {"type": "number"} }, "required": ["url"] @@ -439,6 +438,7 @@ "properties": { "level": {"$ref": "#/defs/loglevel"}, "perflog_compat": {"type": "boolean"}, + "log_sanity_results": {"type": "boolean"}, "handlers": { "type": "array", "items": { @@ -618,6 +618,7 @@ "general/verbose": 0, "logging/level": "undefined", "logging/perflog_compat": false, + "logging/log_sanity_results": false, "logging/target_systems": ["*"], "logging/handlers": [], "logging/handlers_perflog": [], @@ -641,7 +642,6 @@ "logging/handlers_perflog/httpjson_extra_headers": {}, "logging/handlers_perflog/httpjson_debug": false, "logging/handlers_perflog/httpjson_backoff_intervals": [0.1, 0.2, 0.4, 0.8, 1.6, 3.2], - "logging/handlers_perflog/httpjson_log_sanity_results": false, "logging/handlers_perflog/httpjson_retry_timeout": 0, "modes/options": [], "modes/target_systems": ["*"], From 11f461a09a7b3beed330ffae0feb108af40899d9 Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Mon, 14 Jul 2025 07:33:35 +0200 Subject: [PATCH 5/8] Refactor log performance function --- reframe/core/logging.py | 6 ++++-- reframe/frontend/executors/__init__.py | 14 ++++++++++---- 2 files changed, 14 insertions(+), 6 deletions(-) diff --git a/reframe/core/logging.py b/reframe/core/logging.py index 4f880d9ca..a292c021a 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -881,11 +881,13 @@ def _update_check_extras(self): '%FT%T%:z' ) - def log_performance(self, level, task, msg=None, multiline=False): + def log_performance( + self, level, task, msg=None, multiline=False, log_sanity=False + ): if ( self.check is None or not self.check.is_performance_check() and - not getattr(self.logger, '_log_sanity_results', False) + not log_sanity ): return diff --git a/reframe/frontend/executors/__init__.py b/reframe/frontend/executors/__init__.py index 07353c18e..ea7889b2f 100644 --- a/reframe/frontend/executors/__init__.py +++ b/reframe/frontend/executors/__init__.py @@ -528,8 +528,11 @@ def finalize(self): self._current_stage = 'finalize' self._notify_listeners('on_task_success') try: - self._perflogger.log_performance(logging.INFO, self, - multiline=self._perflog_compat) + self._perflogger.log_performance( + logging.INFO, self, + multiline=self._perflog_compat, + log_sanity=self._log_sanity_results + ) except LoggingError as e: getlogger().warning( f'could not log performance data for {self.testcase}: {e}' @@ -553,8 +556,11 @@ def _wait_job(job): self._exc_info = exc_info or sys.exc_info() self._notify_listeners(callback) try: - self._perflogger.log_performance(logging.INFO, self, - multiline=self._perflog_compat) + self._perflogger.log_performance( + logging.INFO, self, + multiline=self._perflog_compat, + log_sanity=self._log_sanity_results + ) except LoggingError as e: getlogger().warning( f'could not log performance data for {self.testcase}: {e}' From 1f57cc047b219020daf9c9f709febcf8e311dead Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Mon, 14 Jul 2025 07:45:36 +0200 Subject: [PATCH 6/8] Add documentation for log_sanity_results attribute --- docs/config_reference.rst | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/docs/config_reference.rst b/docs/config_reference.rst index 3ab38af0c..b7205b800 100644 --- a/docs/config_reference.rst +++ b/docs/config_reference.rst @@ -1143,6 +1143,16 @@ You may define different logger objects per system but *not* per partition. Emit a separate log record for each performance variable. Set this option to ``true`` if you want to keep compatibility with the performance logging prior to ReFrame 4.0. +.. py:attribute:: logging.log_sanity_results + + :required: No + :default: ``false`` + + Emit log records of sanity-only tests in the performance handlers. + It is useful when you want to send data to the `httpjson <#the-httpjson-log-handler>`__ or other performance logging backends. + + .. versionadded:: 4.9 + .. py:attribute:: logging.target_systems :required: No From 45a16f0da33a13c474f184c09ec4d00a1c71c62f Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Fri, 18 Jul 2025 16:37:40 +0200 Subject: [PATCH 7/8] Log results for all tests, not only perf tests --- reframe/core/logging.py | 10 +++------- reframe/frontend/executors/__init__.py | 17 ++++------------- reframe/schemas/config.json | 2 -- 3 files changed, 7 insertions(+), 22 deletions(-) diff --git a/reframe/core/logging.py b/reframe/core/logging.py index a292c021a..2de712065 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -881,14 +881,10 @@ def _update_check_extras(self): '%FT%T%:z' ) - def log_performance( - self, level, task, msg=None, multiline=False, log_sanity=False + def log_result( + self, level, task, msg=None, multiline=False ): - if ( - self.check is None or - not self.check.is_performance_check() and - not log_sanity - ): + if self.check is None: return _, part, env = task.testcase diff --git a/reframe/frontend/executors/__init__.py b/reframe/frontend/executors/__init__.py index ea7889b2f..10392240b 100644 --- a/reframe/frontend/executors/__init__.py +++ b/reframe/frontend/executors/__init__.py @@ -235,9 +235,6 @@ def __init__(self, case, listeners=None, timeout=None): self._perflog_compat = runtime.runtime().get_option( 'logging/0/perflog_compat' ) - self._log_sanity_results = runtime.runtime().get_option( - 'logging/0/log_sanity_results' - ) def duration(self, phase): # Treat pseudo-phases first @@ -528,11 +525,8 @@ def finalize(self): self._current_stage = 'finalize' self._notify_listeners('on_task_success') try: - self._perflogger.log_performance( - logging.INFO, self, - multiline=self._perflog_compat, - log_sanity=self._log_sanity_results - ) + self._perflogger.log_result(logging.INFO, self, + multiline=self._perflog_compat) except LoggingError as e: getlogger().warning( f'could not log performance data for {self.testcase}: {e}' @@ -556,11 +550,8 @@ def _wait_job(job): self._exc_info = exc_info or sys.exc_info() self._notify_listeners(callback) try: - self._perflogger.log_performance( - logging.INFO, self, - multiline=self._perflog_compat, - log_sanity=self._log_sanity_results - ) + self._perflogger.log_result(logging.INFO, self, + multiline=self._perflog_compat) except LoggingError as e: getlogger().warning( f'could not log performance data for {self.testcase}: {e}' diff --git a/reframe/schemas/config.json b/reframe/schemas/config.json index d3f4069fd..6fd7c1bb9 100644 --- a/reframe/schemas/config.json +++ b/reframe/schemas/config.json @@ -438,7 +438,6 @@ "properties": { "level": {"$ref": "#/defs/loglevel"}, "perflog_compat": {"type": "boolean"}, - "log_sanity_results": {"type": "boolean"}, "handlers": { "type": "array", "items": { @@ -618,7 +617,6 @@ "general/verbose": 0, "logging/level": "undefined", "logging/perflog_compat": false, - "logging/log_sanity_results": false, "logging/target_systems": ["*"], "logging/handlers": [], "logging/handlers_perflog": [], From 2e7e861b57406904990ccda39db50d2036f38f5f Mon Sep 17 00:00:00 2001 From: Eirini Koutsaniti Date: Fri, 18 Jul 2025 16:43:06 +0200 Subject: [PATCH 8/8] Update docs --- docs/config_reference.rst | 10 ---------- docs/tutorial.rst | 4 ++++ 2 files changed, 4 insertions(+), 10 deletions(-) diff --git a/docs/config_reference.rst b/docs/config_reference.rst index b7205b800..3ab38af0c 100644 --- a/docs/config_reference.rst +++ b/docs/config_reference.rst @@ -1143,16 +1143,6 @@ You may define different logger objects per system but *not* per partition. Emit a separate log record for each performance variable. Set this option to ``true`` if you want to keep compatibility with the performance logging prior to ReFrame 4.0. -.. py:attribute:: logging.log_sanity_results - - :required: No - :default: ``false`` - - Emit log records of sanity-only tests in the performance handlers. - It is useful when you want to send data to the `httpjson <#the-httpjson-log-handler>`__ or other performance logging backends. - - .. versionadded:: 4.9 - .. py:attribute:: logging.target_systems :required: No diff --git a/docs/tutorial.rst b/docs/tutorial.rst index 64f4e090c..9d48ad614 100644 --- a/docs/tutorial.rst +++ b/docs/tutorial.rst @@ -2072,6 +2072,10 @@ Let's walk briefly through the most important parts of its configuration: Let's rerun our STREAM example using the new configuration: +.. note:: + + After Reframe 4.9 ReFrame will add entries in the perflogs for all tests, not only performance tests. + .. code-block:: bash :caption: Run with the Docker compose setup.