diff --git a/docs/running.rst b/docs/running.rst index 03fe08b650..0fe0e3e27c 100644 --- a/docs/running.rst +++ b/docs/running.rst @@ -862,6 +862,9 @@ All handlers accept the following set of attributes (keys) in their configuratio In this case, the accuracy depends on the execution policy used. If tests are executed with the serial execution policy, this is close to the real completion time, but if the asynchronous execution policy is used, it can differ significantly. If the job completion time cannot be retrieved, ``None`` will be printed. + - ``check_job_completion_time_unix``: *[new in 3.0]* The completion time of the job spawned by this regression test expressed as UNIX time. + This is a raw time field and will not be formatted according to ``datefmt``. + If specific formatting is desired, the ``check_job_completion_time`` should be used instead. - ``check_name``: Prints the name of the regression test on behalf of which ReFrame is currently executing. If ReFrame is not in the context of regression test, ``reframe`` will be printed. - ``check_num_tasks``: The number of tasks assigned to the regression test. diff --git a/reframe/core/logging.py b/reframe/core/logging.py index 102549b52e..b8b1aa9fb1 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -175,8 +175,8 @@ def formatTime(self, record, datefmt=None): def format(self, record): datefmt = self.datefmt or self.default_time_format - if record.check_job_completion_time is not None: - ct = self.converter(record.check_job_completion_time) + if record.check_job_completion_time_unix is not None: + ct = self.converter(record.check_job_completion_time_unix) record.check_job_completion_time = _format_time_rfc3339( ct, datefmt ) @@ -419,6 +419,7 @@ def __init__(self, logger=None, check=None): 'check_name': 'reframe', 'check_jobid': '-1', 'check_job_completion_time': None, + 'check_job_completion_time_unix': None, 'check_info': 'reframe', 'check_system': None, 'check_partition': None, @@ -480,7 +481,7 @@ def _update_check_extras(self): self.extra['check_jobid'] = self.check.job.jobid if self.check.job.completion_time: ct = self.check.job.completion_time - self.extra['check_job_completion_time'] = ct + self.extra['check_job_completion_time_unix'] = ct def log_performance(self, level, tag, value, ref, low_thres, upper_thres, unit=None, *, msg=None): diff --git a/unittests/test_cli.py b/unittests/test_cli.py index 96285b4dbb..e700e252e4 100644 --- a/unittests/test_cli.py +++ b/unittests/test_cli.py @@ -473,6 +473,16 @@ def test_verbosity(self): assert 'Traceback' not in stderr assert 0 == returncode + def test_verbosity_with_check(self): + self.more_options = ['-vvvvv'] + self.checkpath = ['unittests/resources/checks/hellocheck.py'] + returncode, stdout, stderr = self._run_reframe() + assert '' != stdout + assert '--- Logging error ---' not in stdout + assert 'Traceback' not in stdout + assert 'Traceback' not in stderr + assert 0 == returncode + @fixtures.switch_to_user_runtime def test_unload_module(self): # This test is mostly for ensuring coverage. `_run_reframe()` restores