From 428f9fb3a62a822b62d2bd3f9c012b90ead4c2eb Mon Sep 17 00:00:00 2001 From: Theofilos Manitaras Date: Mon, 14 Oct 2019 11:07:51 +0200 Subject: [PATCH 1/4] Write the number of tasks in performance report * Change documentation regarding the performance report format. --- docs/running.rst | 10 +++++++--- reframe/frontend/statistics.py | 2 ++ 2 files changed, 9 insertions(+), 3 deletions(-) diff --git a/docs/running.rst b/docs/running.rst index 9744178ecb..e15ea3a6f4 100644 --- a/docs/running.rst +++ b/docs/running.rst @@ -543,27 +543,31 @@ The performance report is printed after the output of the regression tests and h Check1 - system:partition - PrgEnv1 + * num_tasks: * perf_variable1: * perf_variable2: * ... - PrgEnv2 - : perf_variable1: - : perf_variable2: + * num_tasks: + * perf_variable1: + * perf_variable2: * ... ------------------------------------------------------------------------------ Check2 - system:partition - PrgEnv1 + * num_tasks: * perf_variable1: * perf_variable2: * ... - PrgEnv2 + * num_tasks: * perf_variable1: * perf_variable2: * ... ------------------------------------------------------------------------------ -Achieved performance values are listed by system partition and programming environment for each performance test that has run. +The number of tasks and the achieved performance values are listed by system partition and programming environment for each performance test that has run. Performance variables are the variables collected through the :attr:`reframe.core.pipeline.RegressionTest.perf_patterns` attribute. The following command will run the CUDA matrix-vector multiplication example from the `tutorial `__ and will produce a performance report: diff --git a/reframe/frontend/statistics.py b/reframe/frontend/statistics.py index e592247798..6be05d9832 100644 --- a/reframe/frontend/statistics.py +++ b/reframe/frontend/statistics.py @@ -127,6 +127,8 @@ def performance_report(self): report.append(' - %s' % t.check.current_environ) + report.append(' * num_tasks: %s' % t.check.num_tasks) + for key, ref in t.check.perfvalues.items(): var = key.split(':')[-1] val = ref[0] From f48e08ea6f1094e110ae6c2462b48e14d432a06e Mon Sep 17 00:00:00 2001 From: Theofilos Manitaras Date: Tue, 22 Oct 2019 11:38:58 +0200 Subject: [PATCH 2/4] Address PR comments --- config/cscs-ci.py | 1 + config/cscs-pbs.py | 1 + config/cscs.py | 1 + docs/running.rst | 13 +++++++++---- reframe/core/logging.py | 4 +++- reframe/core/pipeline.py | 2 +- 6 files changed, 16 insertions(+), 6 deletions(-) diff --git a/config/cscs-ci.py b/config/cscs-ci.py index 58288775b9..b6cc9e61d4 100644 --- a/config/cscs-ci.py +++ b/config/cscs-ci.py @@ -157,6 +157,7 @@ class ReframeSettings: 'format': ( '%(asctime)s|reframe %(version)s|' '%(check_info)s|jobid=%(check_jobid)s|' + 'num_tasks=%(check_num_tasks)s|' '%(check_perf_var)s=%(check_perf_value)s|' 'ref=%(check_perf_ref)s ' '(l=%(check_perf_lower_thres)s, ' diff --git a/config/cscs-pbs.py b/config/cscs-pbs.py index 8ece85d54e..de7f22a943 100644 --- a/config/cscs-pbs.py +++ b/config/cscs-pbs.py @@ -140,6 +140,7 @@ class ReframeSettings: 'format': ( '%(asctime)s|reframe %(version)s|' '%(check_info)s|jobid=%(check_jobid)s|' + 'num_tasks=%(check_num_tasks)s|' '%(check_perf_var)s=%(check_perf_value)s|' 'ref=%(check_perf_ref)s ' '(l=%(check_perf_lower_thres)s, ' diff --git a/config/cscs.py b/config/cscs.py index 4016a28a7b..2ccfe9026a 100644 --- a/config/cscs.py +++ b/config/cscs.py @@ -557,6 +557,7 @@ class ReframeSettings: 'format': ( '%(asctime)s|reframe %(version)s|' '%(check_info)s|jobid=%(check_jobid)s|' + 'num_tasks=%(check_num_tasks)s|' '%(check_perf_var)s=%(check_perf_value)s|' 'ref=%(check_perf_ref)s ' '(l=%(check_perf_lower_thres)s, ' diff --git a/docs/running.rst b/docs/running.rst index e15ea3a6f4..e0862d13c1 100644 --- a/docs/running.rst +++ b/docs/running.rst @@ -964,6 +964,7 @@ The attributes of this handler are the following: * ``format``: The syntax of this attribute is the same as of the standard logging facility, except that it adds a couple more performance-specific formatting placeholders: + - ``check_perf_num_tasks``: The number of tasks assigned to the test. - ``check_perf_lower_thres``: The lower threshold of the difference from the reference value expressed as a fraction of the reference. - ``check_perf_upper_thres``: The upper threshold of the difference from the reference value expressed as a fraction of the reference. - ``check_perf_ref``: The reference performance value of a certain performance variable. @@ -971,14 +972,17 @@ The attributes of this handler are the following: - ``check_perf_var``: The name of the `performance variable `__, whose value is logged. - ``check_perf_unit``: The unit of measurement for the measured performance variable, if specified in the corresponding tuple of the :attr:`reframe.core.pipeline.RegressionTest.reference` attribute. +.. note:: + .. versionchanged:: 2.20 + Added support for logging the `num_tasks` in performance logs. + Using the default performance log format, the resulting log entries look like the following: .. code-block:: none - 2018-05-30T00:14:53|reframe 2.13-dev0|Example7Test on daint:gpu using PrgEnv-gnu|jobid=749667|perf=49.152408|ref=50.0 (l=-0.1, u=0.1) - 2018-05-30T00:14:53|reframe 2.13-dev0|Example7Test on daint:gpu using PrgEnv-pgi|jobid=749668|perf=48.930356|ref=50.0 (l=-0.1, u=0.1) - 2018-05-30T00:14:53|reframe 2.13-dev0|Example7Test on daint:gpu using PrgEnv-cray|jobid=749666|perf=48.914735|ref=50.0 (l=-0.1, u=0.1) - + 2019-10-17T09:40:54|reframe 2.20-dev2|Example7Test on daint:gpu using PrgEnv-cray|jobid=808493|num_tasks=1|perf=49.440872|ref=50.0 (l=-0.1, u=0.1)|Gflop/s + 2019-10-17T09:41:04|reframe 2.20-dev2|Example7Test on daint:gpu using PrgEnv-gnu|jobid=808494|num_tasks=1|perf=49.842667|ref=50.0 (l=-0.1, u=0.1)|Gflop/s + 2019-10-17T09:41:13|reframe 2.20-dev2|Example7Test on daint:gpu using PrgEnv-pgi|jobid=808495|num_tasks=1|perf=50.421853|ref=50.0 (l=-0.1, u=0.1)|Gflop/s The interpretation of the performance values depends on the individual tests. The above output is from the CUDA performance test we presented in the `tutorial `__, so the value refers to the achieved Gflop/s. @@ -1001,6 +1005,7 @@ An example configuration of such a handler is the following: 'format': ( '%(asctime)s|reframe %(version)s|' '%(check_info)s|jobid=%(check_jobid)s|' + 'num_tasks=%(check_num_tasks)s|' '%(check_perf_var)s=%(check_perf_value)s|' 'ref=%(check_perf_ref)s ' '(l=%(check_perf_lower_thres)s, ' diff --git a/reframe/core/logging.py b/reframe/core/logging.py index 1682bfd726..7bea4926d3 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -373,6 +373,7 @@ def __init__(self, logger=None, check=None): 'check_environ': None, 'check_outputdir': None, 'check_stagedir': None, + 'check_num_tasks': None, 'check_perf_var': None, 'check_perf_value': None, 'check_perf_ref': None, @@ -425,10 +426,11 @@ def _update_check_extras(self): if self.check.job: self.extra['check_jobid'] = self.check.job.jobid - def log_performance(self, level, tag, value, ref, + def log_performance(self, level, num_tasks, tag, value, ref, low_thres, upper_thres, unit=None, *, msg=None): # Update the performance-relevant extras and log the message + self.extra['check_num_tasks'] = num_tasks self.extra['check_perf_var'] = tag self.extra['check_perf_value'] = value self.extra['check_perf_ref'] = ref diff --git a/reframe/core/pipeline.py b/reframe/core/pipeline.py index 18b6e71a6c..9d14cd1d41 100644 --- a/reframe/core/pipeline.py +++ b/reframe/core/pipeline.py @@ -1206,7 +1206,7 @@ def check_performance(self): (tag, self._current_partition.fullname)) self._perfvalues[key] = (value, *self.reference[key]) - self._perf_logger.log_performance(logging.INFO, tag, value, + self._perf_logger.log_performance(logging.INFO, self.num_tasks, tag, value, *self.reference[key]) for key, values in self._perfvalues.items(): From ebe617af66d91d2dd6c40709f67f54162c55c641 Mon Sep 17 00:00:00 2001 From: Theofilos Manitaras Date: Tue, 22 Oct 2019 11:41:48 +0200 Subject: [PATCH 3/4] Fix PEP8 issue --- reframe/core/pipeline.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/reframe/core/pipeline.py b/reframe/core/pipeline.py index 9d14cd1d41..ff481a859e 100644 --- a/reframe/core/pipeline.py +++ b/reframe/core/pipeline.py @@ -1206,8 +1206,9 @@ def check_performance(self): (tag, self._current_partition.fullname)) self._perfvalues[key] = (value, *self.reference[key]) - self._perf_logger.log_performance(logging.INFO, self.num_tasks, tag, value, - *self.reference[key]) + self._perf_logger.log_performance( + logging.INFO, self.num_tasks, tag, value, + *self.reference[key]) for key, values in self._perfvalues.items(): val, ref, low_thres, high_thres, *_ = values From 3f6c00e716d282c60f082284eff850df741ed2a3 Mon Sep 17 00:00:00 2001 From: Theofilos Manitaras Date: Wed, 23 Oct 2019 13:57:31 +0200 Subject: [PATCH 4/4] Address PR comments (version 2) --- docs/running.rst | 10 +++++----- reframe/core/logging.py | 4 ++-- reframe/core/pipeline.py | 5 ++--- 3 files changed, 9 insertions(+), 10 deletions(-) diff --git a/docs/running.rst b/docs/running.rst index e0862d13c1..c63ac11a06 100644 --- a/docs/running.rst +++ b/docs/running.rst @@ -844,6 +844,7 @@ All handlers accept the following set of attributes (keys) in their configuratio If a job or process is not yet created, ``-1`` will be printed. - ``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. - ``check_outputdir``: The output directory associated with the currently executing test. - ``check_partition``: The system partition where this test is currently executing. - ``check_stagedir``: The stage directory associated with the currently executing test. @@ -964,7 +965,6 @@ The attributes of this handler are the following: * ``format``: The syntax of this attribute is the same as of the standard logging facility, except that it adds a couple more performance-specific formatting placeholders: - - ``check_perf_num_tasks``: The number of tasks assigned to the test. - ``check_perf_lower_thres``: The lower threshold of the difference from the reference value expressed as a fraction of the reference. - ``check_perf_upper_thres``: The upper threshold of the difference from the reference value expressed as a fraction of the reference. - ``check_perf_ref``: The reference performance value of a certain performance variable. @@ -974,15 +974,15 @@ The attributes of this handler are the following: .. note:: .. versionchanged:: 2.20 - Added support for logging the `num_tasks` in performance logs. + Support for logging `num_tasks` in performance logs was added. Using the default performance log format, the resulting log entries look like the following: .. code-block:: none - 2019-10-17T09:40:54|reframe 2.20-dev2|Example7Test on daint:gpu using PrgEnv-cray|jobid=808493|num_tasks=1|perf=49.440872|ref=50.0 (l=-0.1, u=0.1)|Gflop/s - 2019-10-17T09:41:04|reframe 2.20-dev2|Example7Test on daint:gpu using PrgEnv-gnu|jobid=808494|num_tasks=1|perf=49.842667|ref=50.0 (l=-0.1, u=0.1)|Gflop/s - 2019-10-17T09:41:13|reframe 2.20-dev2|Example7Test on daint:gpu using PrgEnv-pgi|jobid=808495|num_tasks=1|perf=50.421853|ref=50.0 (l=-0.1, u=0.1)|Gflop/s + 2019-10-23T13:46:05|reframe 2.20-dev2|Example7Test on daint:gpu using PrgEnv-cray|jobid=813559|num_tasks=1|perf=49.681565|ref=50.0 (l=-0.1, u=0.1)|Gflop/s + 2019-10-23T13:46:27|reframe 2.20-dev2|Example7Test on daint:gpu using PrgEnv-gnu|jobid=813560|num_tasks=1|perf=50.737651|ref=50.0 (l=-0.1, u=0.1)|Gflop/s + 2019-10-23T13:46:48|reframe 2.20-dev2|Example7Test on daint:gpu using PrgEnv-pgi|jobid=813561|num_tasks=1|perf=50.720164|ref=50.0 (l=-0.1, u=0.1)|Gflop/s The interpretation of the performance values depends on the individual tests. The above output is from the CUDA performance test we presented in the `tutorial `__, so the value refers to the achieved Gflop/s. diff --git a/reframe/core/logging.py b/reframe/core/logging.py index 7bea4926d3..03ced55af1 100644 --- a/reframe/core/logging.py +++ b/reframe/core/logging.py @@ -413,6 +413,7 @@ def _update_check_extras(self): self.extra['check_info'] = self.check.info() self.extra['check_outputdir'] = self.check.outputdir self.extra['check_stagedir'] = self.check.stagedir + self.extra['check_num_tasks'] = self.check.num_tasks self.extra['check_tags'] = ','.join(self.check.tags) if self.check.current_system: self.extra['check_system'] = self.check.current_system.name @@ -426,11 +427,10 @@ def _update_check_extras(self): if self.check.job: self.extra['check_jobid'] = self.check.job.jobid - def log_performance(self, level, num_tasks, tag, value, ref, + def log_performance(self, level, tag, value, ref, low_thres, upper_thres, unit=None, *, msg=None): # Update the performance-relevant extras and log the message - self.extra['check_num_tasks'] = num_tasks self.extra['check_perf_var'] = tag self.extra['check_perf_value'] = value self.extra['check_perf_ref'] = ref diff --git a/reframe/core/pipeline.py b/reframe/core/pipeline.py index ff481a859e..18b6e71a6c 100644 --- a/reframe/core/pipeline.py +++ b/reframe/core/pipeline.py @@ -1206,9 +1206,8 @@ def check_performance(self): (tag, self._current_partition.fullname)) self._perfvalues[key] = (value, *self.reference[key]) - self._perf_logger.log_performance( - logging.INFO, self.num_tasks, tag, value, - *self.reference[key]) + self._perf_logger.log_performance(logging.INFO, tag, value, + *self.reference[key]) for key, values in self._perfvalues.items(): val, ref, low_thres, high_thres, *_ = values