Skip to content

[feat] Update report schema, add more loggable fields and update JUnit report #3722

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
vkarak wants to merge 2 commits into
base: develop
Choose a base branch
from
Open

[feat] Update report schema, add more loggable fields and update JUnit report #3722

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
8e98874
Update report schema
vkarak Jun 4, 2026
9394829
Remove unused imports
vkarak Sep 5, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
65 changes: 61 additions & 4 deletions docs/config_reference.rst
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1308,6 +1308,7 @@ All logging handlers share the following set of common attributes:

.. csv-table::

``%(check_basename)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.name` attribute without any parameter suffixes; essentially the test's class name.
``%(check_build_locally)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.build_locally` attribute.
``%(check_build_time_limit)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.build_time_limit` attribute.
``%(check_descr)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.descr` attribute.
Expand All @@ -1320,14 +1321,18 @@ All logging handlers share the following set of common attributes:
``%(check_extra_resources)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.extra_resources` attribute.
``%(check_fail_phase)s``, The phase where the test has failed.
``%(check_fail_reason)s``, The failure reason if the test has failed.
``%(check_filename)s``, The file where this test is defined.
``%(check_fixture)s``, Whether this test is a fixture.
``%(check_hashcode)s``, The unique hash associated with this test.
``%(check_info)s``, Various information about this test; essentially the return value of the test's :func:`~reframe.core.pipeline.RegressionTest.info` function.
``%(check_job_completion_time)s``, Same as the ``(check_job_completion_time_unix)s`` but formatted according to ``datefmt``.
``%(check_job_completion_time)s``, Same as the ``%(check_job_completion_time_unix)s`` but formatted according to ``datefmt``.
``%(check_job_completion_time_unix)s``, The completion time of the associated run job (see :attr:`~reframe.core.schedulers.Job.completion_time`).
``%(check_job_exitcode)s``, The exit code of the associated run job.
``%(check_job_id)s``, The ID of the associated run job.
``%(check_job_nodelist)s``, The list of nodes that the associated run job has run on.
``%(check_job_submit_time)s``, The submission time of the associated run job (see :attr:`~reframe.core.schedulers.Job.submit_time`).
``%(check_jobid)s``, The ID of the associated run job.
``%(check_job_stderr)s``, The name of the file containing the standard error of the associated run job.
``%(check_job_stdout)s``, The name of the file containing the standard output of the associated run job.
``%(check_job_submit_time_us)s``, The submission time of the associated run job, in microseconds since the Epoch (see :attr:`~reframe.core.schedulers.Job.submit_time`).
``%(check_keep_files)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.keep_files` attribute.
``%(check_local)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.local` attribute.
``%(check_maintainers)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.maintainers` attribute.
Expand Down Expand Up @@ -1356,6 +1361,7 @@ All logging handlers share the following set of common attributes:
``%(check_stagedir)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.stagedir` attribute.
``%(check_strict_check)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.strict_check` attribute.
``%(check_system)s``, The name of the test's :attr:`~reframe.core.pipeline.RegressionTest.current_system`.
``%(check_sysenv)s``, The combination of the test's current system, partition and programming environment, in the form ``<system>:<partition>+<environ>``.
``%(check_tags)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.tags` attribute.
``%(check_time_limit)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.time_limit` attribute.
``%(check_unique_name)s``, The value of the :attr:`~reframe.core.pipeline.RegressionTest.unique_name` attribute.
Expand All @@ -1371,6 +1377,8 @@ All logging handlers share the following set of common attributes:
ReFrame allows you to log any test variable, parameter or property if they are marked as "loggable".
The log record placeholder will have the form ``%(check_NAME)s`` where ``NAME`` is the variable name, the parameter name or the property name that is marked as loggable.

The loggable attributes of the test's run job and, if present, its build job are also exposed, using the ``%(check_job_NAME)s`` and ``%(check_build_job_NAME)s`` placeholder forms respectively, where ``NAME`` is a loggable attribute of :class:`~reframe.core.schedulers.Job`, such as ``stdout``, ``stderr``, ``jobid``, ``exitcode``, ``state``, ``nodelist``, ``nodelist_folded``, ``scheduler``, ``script_filename``, ``script_contents``, or the ``submit_time_us``/``submit_timestamp``, ``start_time_us``/``start_timestamp`` and ``completion_time_us``/``completion_timestamp`` pairs.

There is also the special ``%(check_#ALL)s`` format placeholder which expands to all the loggable test attributes.
These include all the above placeholders and any additional loggable variables or parameters defined by the test.
On expanding this placeholder, ReFrame will try to guess the delimiter to use for separating the different attributes based on the existing format.
Expand Down Expand Up @@ -1399,6 +1407,13 @@ All logging handlers share the following set of common attributes:
.. versionadded:: 4.8
The ``%(hostname)s`` placeholder is added.

.. versionchanged:: 4.11
The ``%(check_basename)s``, ``%(check_sysenv)s``, ``%(check_filename)s`` and ``%(check_fixture)s`` placeholders, as well as the ``%(check_build_job_NAME)s`` placeholder family, are added.

.. deprecated:: 4.11
The ``%(check_jobid)s`` and ``%(check_job_submit_time)s`` placeholders are deprecated in favor of ``%(check_job_id)s`` and ``%(check_job_submit_time_us)s`` respectively, for consistency with the rest of the ``%(check_job_NAME)s`` placeholders.
The old placeholders keep working but emit a deprecation warning; they will be removed in a future release.


.. py:attribute:: logging.handlers.format_perfvars
.. py:attribute:: logging.handlers_perflog.format_perfvars
Expand Down Expand Up @@ -1512,6 +1527,18 @@ The ``filelog`` log handler
This handler is meant for performance logging only and logs the performance of a test in one or more files.
The additional properties for the ``filelog`` handler are the following:

Unlike the other handlers, the ``filelog`` handler's :attr:`~config.logging.handlers_perflog.format` and :attr:`~config.logging.handlers_perflog.format_perfvars` default to values geared towards performance logging rather than to the generic, handler-wide defaults:

.. code-block:: python

'format': '%(check_result)s|%(check_job_completion_time)s|%(check_#ALL)s',
'format_perfvars': ('%(check_perf_value)s|%(check_perf_unit)s|'
'%(check_perf_ref)s|%(check_perf_lower_thres)s|'
'%(check_perf_upper_thres)s|')

.. versionchanged:: 4.11
The ``filelog``-specific defaults for :attr:`~config.logging.handlers_perflog.format` and :attr:`~config.logging.handlers_perflog.format_perfvars` are added; previously, a ``filelog`` handler without an explicit ``format`` would fall back to the generic ``"%(message)s"`` default, which produced empty performance log records.


.. py:attribute:: logging.handlers_perflog..filelog..basedir

Expand All @@ -1523,14 +1550,37 @@ The additional properties for the ``filelog`` handler are the following:

.. py:attribute:: logging.handlers_perflog..filelog..ignore_keys

:required: No
:default: See below.

A list of log record `format placeholders <#config.logging.handlers.format>`__ that will be ignored by the special ``%(check_#ALL)s`` placeholder.

By default, the following keys are ignored, since they tend to be either bulky (e.g., script or captured output contents) or not generally useful in a performance log:

.. code-block:: python

['check_build_job_script_contents', 'check_build_job_stderr_contents',
'check_build_job_stdout_contents', 'check_build_locally',
'check_build_time_limit', 'check_display_name', 'check_hashcode',
'check_job_script_contents', 'check_job_stderr_contents',
'check_job_stdout_contents', 'check_keep_files', 'check_local',
'check_maintainers', 'check_max_pending_time', 'check_outputdir',
'check_prefix', 'check_readonly_files', 'check_stagedir',
'check_strict_check', 'check_tags', 'check_time_limit',
'check_variables']

Setting this option explicitly in your configuration replaces this default list entirely; it is not merged with it.

.. versionadded:: 4.3

.. versionchanged:: 4.11
A default value for this option is now provided; previously it defaulted to an empty list and the actual values was derived from the built-in configuration.


.. py:attribute:: logging.handlers_perflog..filelog..prefix

:required: Yes
:required: No
:default: ``"%(check_system)s/%(check_partition)s"``

This is a directory prefix (usually dynamic), appended to the :attr:`~config.logging.handlers_perflog..filelog..basedir`, where the performance logs of a test will be stored.
This attribute accepts any of the check-specific `formatting placeholders <#config.logging.handlers_perflog.format>`__.
Expand All @@ -1550,6 +1600,10 @@ The additional properties for the ``filelog`` handler are the following:
system2/
...

.. versionchanged:: 4.11
This option is no longer required and now defaults to ``"%(check_system)s/%(check_partition)s"``.
Previously, it was being derived by the built-in configuration.


.. py:attribute:: logging.handlers_perflog..filelog..append

Expand Down Expand Up @@ -2036,6 +2090,9 @@ General Configuration

.. versionadded:: 4.7

.. versionchanged:: 4.11
This option now also controls the amount of stdout/stderr content captured in the ``*_stdout_contents``/``*_stderr_contents`` fields of the run report and in the JUnit XML report (see :option:`--report-junit`).


.. py:attribute:: general.flex_alloc_strict

Expand Down
24 changes: 23 additions & 1 deletion docs/manpage.rst
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -554,7 +554,7 @@ Options controlling ReFrame output

Instruct ReFrame to generate a JUnit XML report in ``FILE``.

The generated report adheres to the XSD schema `here <https://github.com/windyroad/JUnit-Schema/blob/master/JUnit.xsd>`__ where each retry is treated as an individual testsuite.
The generated report adheres to the XSD schema in `reframe/schemas/junit.xsd <https://github.com/reframe-hpc/reframe/blob/develop/reframe/schemas/junit.xsd>`__, which is a superset of the original `Apache Ant JUnit XSD <https://github.com/windyroad/JUnit-Schema/blob/master/JUnit.xsd>`__, where each retry is treated as an individual testsuite.

This option can also be set using the :envvar:`RFM_REPORT_JUNIT` environment variable or the :attr:`~config.general.report_junit` general configuration parameter.

Expand All @@ -563,6 +563,15 @@ Options controlling ReFrame output
.. versionchanged:: 3.6.1
Added support for retries in the JUnit XML report.

.. versionchanged:: 4.11
Failed test cases now include ``<system-out>`` / ``<system-err>`` elements with the tail of the captured build or run output, in addition to the ``<failure>`` element.
Each ``<testcase>`` also gets a ``file`` attribute pointing to the file where the test is defined.

.. note::
These additions are not part of the original Apache Ant JUnit XSD linked above, which only allows ``<system-out>``/``<system-err>`` at the ``<testsuite>`` level and does not define a ``file`` attribute on ``<testcase>``.
They match what `GitLab's Test Reports <https://docs.gitlab.com/ci/testing/unit_test_reports/>`__ feature parses, but other JUnit consumers with a stricter or differently-shaped schema (e.g., Jenkins) may reject them.
If you run into such a case, please report it by opening a Github issue.

.. option:: -s, --stage=DIR

Directory prefix for staging test resources.
Expand Down Expand Up @@ -1763,6 +1772,19 @@ The following list summarizes the schema changes (version numbers refer to schem
Since ReFrame 4.9, if a test's dependencies fail, the test is skipped and is put in the ``fail_deps`` state.
Previously, it was treated as a normal failure.

.. admonition:: 5.0

This is a major schema revision that reworks how job information is reported and removes several properties that were never generally useful.

- The following ``.runs[].testcases[]`` properties are removed with no replacement: ``dependencies_actual``, ``dependencies_conceptual``, ``session_uuid``, ``time_compile``, ``time_performance``, ``time_run``, ``time_sanity``, ``time_setup``, ``time_total`` and ``uuid``.
A unique identifier for a test case can still be reconstructed from ``session_info.uuid``, ``run_index`` and the new ``testcase_index`` property.
- ``build_jobid``, ``build_stdout`` and ``build_stderr`` are renamed to ``build_job_id``, ``build_job_stdout`` and ``build_job_stderr`` respectively.
- The loggable attributes of a test's run job and, if present, its build job (see :attr:`~config.logging.handlers_perflog.format`) are now reported in full, under the ``job_*`` and ``build_job_*`` property prefixes respectively (e.g., ``job_state``, ``job_nodelist``, ``build_job_script_contents``).
- New properties ``job_stdout_contents``, ``job_stderr_contents``, ``build_job_stdout_contents`` and ``build_job_stderr_contents`` are added, holding the tail of the captured output for failed tests (see :attr:`~config.general.failure_inspect_lines`).
- New properties ``basename``, ``sysenv`` and ``testcase_index`` are added to ``.runs[].testcases[]``.
- New properties ``start_time_us``, ``start_timestamp``, ``end_time_us`` and ``end_timestamp`` are added to ``session_info``; ``time_start``, ``time_start_unix``, ``time_end`` and ``time_end_unix`` are retained for compatibility with the SQLite results backend only.
- The set of ``required`` properties for both ``session_info`` and testcases is reduced to the minimal identifying fields (``data_version``, ``hostname`` and ``uuid`` for sessions; ``name`` and ``result`` for testcases), since almost everything else may legitimately be absent depending on how far a test got in the pipeline before failing.


Environment
===========
Expand Down
72 changes: 66 additions & 6 deletions reframe/core/logging.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@
import reframe.utility.osext as osext
from reframe.core.exceptions import (ConfigError, LoggingError,
WarningAsError, what)
from reframe.core.warnings import suppress_deprecations
from reframe.core.warnings import suppress_deprecations, user_deprecation_warning
from reframe.utility import is_trivially_callable
from reframe.utility.profile import TimeProfiler

Expand Down Expand Up @@ -172,6 +172,10 @@ def __init__(self, prefix, mode='a', encoding=None, fmt=None,
self.__lockfile_mode = lockfile_mode
self.__locks = {}

# Always ignore the following keys in file logging
# NOTE: Consider setting this as the default configuration parameter
self.__ignore_keys |= {'check_job_script_contents'}

def __generate_header(self, record):
# Generate the header from the record and fmt

Expand Down Expand Up @@ -331,6 +335,14 @@ def _dofmt(v):
return _dofmt(val)


# Log record placeholders that were renamed; kept here so that format
# strings referencing the old names keep working, with a deprecation warning
_DEPRECATED_LOG_ALIASES = {
'check_jobid': 'check_job_id',
'check_job_submit_time': 'check_job_submit_time_us',
}


class CheckFieldFormatter(logging.Formatter):
'''Log formatter that dynamically looks up format specifiers inside a
regression test.'''
Expand All @@ -348,6 +360,25 @@ def __init__(self, fmt=None, datefmt=None, perffmt=None,
self.__expanded_fmt = {}
self.__ignore_keys = set(ignore_keys) if ignore_keys else set()

# Always ignore the following keys in file logging
self.__ignore_keys |= {'check_job_script_contents'}

# Resolve any deprecated placeholders used in the format string once;
# the format string is static, so there is no need to redo this
# on every call to formatMessage()
self.__alias_map = {}
for s in self.__specs:
if (new_name := _DEPRECATED_LOG_ALIASES.get(s)) is None:
continue

msg = (f"the '%({s})s' log record placeholder is deprecated; "
f"please use '%({new_name})s' instead")
if msg not in _WARN_ONCE:
_WARN_ONCE.add(msg)
user_deprecation_warning(msg)

self.__alias_map[s] = new_name

def _expand_fmt(self, record):
if not self.__expand_vars:
return self.__fmt
Expand All @@ -370,7 +401,7 @@ def _format_perf(self, perfvars):
for var, info in perfvars.items():
val, ref, lower, upper, unit, result = info
record = {
'check_perf_var': var.split(':')[-1],
'check_perf_var': var,
'check_perf_value': val,
'check_perf_unit': unit,
'check_perf_ref': ref,
Expand All @@ -389,7 +420,14 @@ def _format_perf(self, perfvars):
def formatMessage(self, record):
fmt = self._expand_fmt(record)
for s in self.__specs:
if s != 'check_#ALL' and not hasattr(record, s):
if s == 'check_#ALL' or hasattr(record, s):
continue

# Check if placeholder has an alias
new_name = self.__alias_map.get(s)
if new_name is not None and hasattr(record, new_name):
setattr(record, s, getattr(record, new_name))
else:
setattr(record, s, None)

record_proxy = dict(record.__dict__)
Expand Down Expand Up @@ -918,6 +956,14 @@ def std_stream_handlers(self):
else:
return []

def _update_job_extras(self, job, prefix):
job_type = type(job)
for attr, alt_name in job_type.loggable_attrs():
extra_name = alt_name or attr
key = f'{prefix}_{extra_name}'
self.extra['__rfm_loggable_attrs__'].append(key)
self.extra[key] = getattr(job, attr, None)

def _update_check_extras(self):
'''Return a dictionary with all the check-specific information.'''

Expand All @@ -941,11 +987,25 @@ def _update_check_extras(self):
self.extra['__rfm_loggable_attrs__'].append(key)
self.extra[key] = val

# Add build job and job attributes
if self.check.build_job:
self._update_job_extras(self.check.build_job, 'check_build_job')

if self.check.job:
self._update_job_extras(self.check.job, 'check_job')

# Add special extras
self.extra['check_info'] = self.check.info()
self.extra['check_job_completion_time'] = _format_time_rfc3339(
self.extra['check_job_completion_time_unix'], r'%FT%T%:z'
)

# Add the legacy entries for the job completion times
job_completion_time_us = self.extra.get('check_job_completion_time_us')
if job_completion_time_us:
self.extra['check_job_completion_time_unix'] = (
job_completion_time_us / 1_000_000
)
self.extra['check_job_completion_time'] = _format_time_rfc3339(
self.extra['check_job_completion_time_unix'], r'%FT%T%:z'
)

def log_result(self, level, task, msg=None, multiline=False):
if self.check is None:
Expand Down
Loading
Loading