[PATCH v2 0/3] rteval: Fix issues with cyclictest.py module

[PATCH v2 0/3] rteval: Fix issues with cyclictest.py module

[Punit Agrawal]

Hi,

Here's an updated version of the cyclictest fixes previously posted at
[0]. The changes in this version are to address feedback received on
the previous version.

v1 -> v2:
* Patch 1: Add an option (default off) to save cyclictest output
* Patch 3: Sort cpus returned by online_cpus() in cyclictest.py module

All feedback welcome.

Thanks,
Punit

[0] https://lore.kernel.org/all/20210902092452.726905-1-punitagrawal@gmail.com/

Punit Agrawal (3):
  rteval: cyclictest.py Enable logging cyclictest output
  rteval: cyclictest.py Parse max latencies from cyclictest output
  rteval: cyclictest.py: Sort the list of cpus

 rteval/modules/measurement/cyclictest.py | 44 ++++++++++++++++++++----
 1 file changed, 37 insertions(+), 7 deletions(-)

-- 
2.32.0

[PATCH v2 1/3] rteval: cyclictest.py Enable logging cyclictest output

[Punit Agrawal]

From: Punit Agrawal <punit1.agrawal@toshiba.co.jp>

The cyclictest.py module uses a temporary file to store the output
from "cyclictest" which is deleted at the end of the run. As the
collected log contains information that can be useful for development
or debugging, having the ability to persist the logs is useful.

With this goal, introduce a configuration option for the cyclictest.py
module, "savelogs", that can be used to enable persisting the
cyclictest output to a logfile. As the logs an be quite large, the
default is to not save them.

Signed-off-by: Punit Agrawal <punit1.agrawal@toshiba.co.jp>
---
 rteval/modules/measurement/cyclictest.py | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/rteval/modules/measurement/cyclictest.py b/rteval/modules/measurement/cyclictest.py
index b1755d4f4421..ee1de883d844 100644
--- a/rteval/modules/measurement/cyclictest.py
+++ b/rteval/modules/measurement/cyclictest.py
@@ -197,6 +197,8 @@ class Cyclictest(rtevalModulePrototype):
         self.__numanodes = int(self.__cfg.setdefault('numanodes', 0))
         self.__priority = int(self.__cfg.setdefault('priority', 95))
         self.__buckets = int(self.__cfg.setdefault('buckets', 2000))
+        self.__reportdir = self.__cfg.setdefault('reportdir', os.getcwd())
+        self.__save_logs = self.__cfg.setdefault('savelogs', False)
         self.__numcores = 0
         self.__cpus = []
         self.__cyclicdata = {}
@@ -255,6 +257,8 @@ class Cyclictest(rtevalModulePrototype):
         mounts.close()
         return ret
 
+    def _open_logfile(self, name):
+        return open(os.path.join(self.__reportdir, "logs", name), 'w+b')
 
     def _WorkloadSetup(self):
         self.__cyclicprocess = None
@@ -288,7 +292,10 @@ class Cyclictest(rtevalModulePrototype):
             self.__cmd.append("--tracemark")
 
         # Buffer for cyclictest data written to stdout
-        self.__cyclicoutput = tempfile.SpooledTemporaryFile(mode='w+b')
+        if self.__save_logs:
+            self.__cyclicoutput = self._open_logfile('cyclictest.stdout')
+        else:
+            self.__cyclicoutput = tempfile.SpooledTemporaryFile(mode='w+b')
 
 
     def _WorkloadTask(self):
-- 
2.32.0

Re: [PATCH v2 1/3] rteval: cyclictest.py Enable logging cyclictest output

[Punit Agrawal]

Punit Agrawal <punitagrawal@gmail.com> writes:

> From: Punit Agrawal <punit1.agrawal@toshiba.co.jp>
>
> The cyclictest.py module uses a temporary file to store the output
> from "cyclictest" which is deleted at the end of the run. As the
> collected log contains information that can be useful for development
> or debugging, having the ability to persist the logs is useful.
>
> With this goal, introduce a configuration option for the cyclictest.py
> module, "savelogs", that can be used to enable persisting the
> cyclictest output to a logfile. As the logs an be quite large, the
> default is to not save them.
>
> Signed-off-by: Punit Agrawal <punit1.agrawal@toshiba.co.jp>
> ---
>  rteval/modules/measurement/cyclictest.py | 9 ++++++++-
>  1 file changed, 8 insertions(+), 1 deletion(-)
>
> diff --git a/rteval/modules/measurement/cyclictest.py b/rteval/modules/measurement/cyclictest.py
> index b1755d4f4421..ee1de883d844 100644
> --- a/rteval/modules/measurement/cyclictest.py
> +++ b/rteval/modules/measurement/cyclictest.py
> @@ -197,6 +197,8 @@ class Cyclictest(rtevalModulePrototype):
>          self.__numanodes = int(self.__cfg.setdefault('numanodes', 0))
>          self.__priority = int(self.__cfg.setdefault('priority', 95))
>          self.__buckets = int(self.__cfg.setdefault('buckets', 2000))
> +        self.__reportdir = self.__cfg.setdefault('reportdir', os.getcwd())
> +        self.__save_logs = self.__cfg.setdefault('savelogs', False)
>          self.__numcores = 0
>          self.__cpus = []
>          self.__cyclicdata = {}
> @@ -255,6 +257,8 @@ class Cyclictest(rtevalModulePrototype):
>          mounts.close()
>          return ret
>  
> +    def _open_logfile(self, name):
> +        return open(os.path.join(self.__reportdir, "logs", name), 'w+b')
>  
>      def _WorkloadSetup(self):
>          self.__cyclicprocess = None
> @@ -288,7 +292,10 @@ class Cyclictest(rtevalModulePrototype):
>              self.__cmd.append("--tracemark")
>  
>          # Buffer for cyclictest data written to stdout
> -        self.__cyclicoutput = tempfile.SpooledTemporaryFile(mode='w+b')
> +        if self.__save_logs:
> +            self.__cyclicoutput = self._open_logfile('cyclictest.stdout')
> +        else:
> +            self.__cyclicoutput = tempfile.SpooledTemporaryFile(mode='w+b')
>  
>  
>      def _WorkloadTask(self):

Ping!

This patch was missed when reviewing / merging the other patches in the
series.

Re: [PATCH v2 1/3] rteval: cyclictest.py Enable logging cyclictest output

[Punit Agrawal]

Punit Agrawal <punitagrawal@gmail.com> writes:

> Punit Agrawal <punitagrawal@gmail.com> writes:
>
>> From: Punit Agrawal <punit1.agrawal@toshiba.co.jp>
>>
>> The cyclictest.py module uses a temporary file to store the output
>> from "cyclictest" which is deleted at the end of the run. As the
>> collected log contains information that can be useful for development
>> or debugging, having the ability to persist the logs is useful.
>>
>> With this goal, introduce a configuration option for the cyclictest.py
>> module, "savelogs", that can be used to enable persisting the
>> cyclictest output to a logfile. As the logs an be quite large, the
>> default is to not save them.
>>
>> Signed-off-by: Punit Agrawal <punit1.agrawal@toshiba.co.jp>
>> ---
>>  rteval/modules/measurement/cyclictest.py | 9 ++++++++-
>>  1 file changed, 8 insertions(+), 1 deletion(-)
>>
>> diff --git a/rteval/modules/measurement/cyclictest.py b/rteval/modules/measurement/cyclictest.py
>> index b1755d4f4421..ee1de883d844 100644
>> --- a/rteval/modules/measurement/cyclictest.py
>> +++ b/rteval/modules/measurement/cyclictest.py
>> @@ -197,6 +197,8 @@ class Cyclictest(rtevalModulePrototype):
>>          self.__numanodes = int(self.__cfg.setdefault('numanodes', 0))
>>          self.__priority = int(self.__cfg.setdefault('priority', 95))
>>          self.__buckets = int(self.__cfg.setdefault('buckets', 2000))
>> +        self.__reportdir = self.__cfg.setdefault('reportdir', os.getcwd())
>> +        self.__save_logs = self.__cfg.setdefault('savelogs', False)
>>          self.__numcores = 0
>>          self.__cpus = []
>>          self.__cyclicdata = {}
>> @@ -255,6 +257,8 @@ class Cyclictest(rtevalModulePrototype):
>>          mounts.close()
>>          return ret
>>  
>> +    def _open_logfile(self, name):
>> +        return open(os.path.join(self.__reportdir, "logs", name), 'w+b')
>>  
>>      def _WorkloadSetup(self):
>>          self.__cyclicprocess = None
>> @@ -288,7 +292,10 @@ class Cyclictest(rtevalModulePrototype):
>>              self.__cmd.append("--tracemark")
>>  
>>          # Buffer for cyclictest data written to stdout
>> -        self.__cyclicoutput = tempfile.SpooledTemporaryFile(mode='w+b')
>> +        if self.__save_logs:
>> +            self.__cyclicoutput = self._open_logfile('cyclictest.stdout')
>> +        else:
>> +            self.__cyclicoutput = tempfile.SpooledTemporaryFile(mode='w+b')
>>  
>>  
>>      def _WorkloadTask(self):
>
> Ping!
>
> This patch was missed when reviewing / merging the other patches in the
> series.

*Argh* - this is an older version. Please ignore.
I'll highlight the correct version in a separate message.

[PATCH v2 2/3] rteval: cyclictest.py Parse max latencies from cyclictest output

[Punit Agrawal]

From: Punit Agrawal <punit1.agrawal@toshiba.co.jp>

When collecting a histogram of latencies, "cyclictest" reports the
maximum latency encountered on each core even if they fall outside the
configured no. of buckets. This can be useful to understand the worst
case latencies for the run as well as right sizing the number of
buckets for the histogram.

While processing the output of cyclictest, rteval skips the reported
max latencies and calculates them by capping to the no. of buckets.

Fix rteval by parsing the maximum latencies reported by cyclictest.

Signed-off-by: Punit Agrawal <punit1.agrawal@toshiba.co.jp>
---
 rteval/modules/measurement/cyclictest.py | 31 +++++++++++++++++++-----
 1 file changed, 25 insertions(+), 6 deletions(-)

diff --git a/rteval/modules/measurement/cyclictest.py b/rteval/modules/measurement/cyclictest.py
index ee1de883d844..d3a0b045b9dd 100644
--- a/rteval/modules/measurement/cyclictest.py
+++ b/rteval/modules/measurement/cyclictest.py
@@ -67,20 +67,25 @@ class RunData:
         retval += "mean:       %f\n" % self.__mean
         return retval
 
-    def sample(self, value):
-        self.__samples[value] += self.__samples.setdefault(value, 0) + 1
+    def update_max(self, value):
         if value > self.__max:
             self.__max = value
+
+    def update_min(self, value):
         if value < self.__min:
             self.__min = value
+
+    def sample(self, value):
+        self.__samples[value] += self.__samples.setdefault(value, 0) + 1
+        self.update_max(value)
+        self.update_min(value)
         self.__numsamples += 1
 
     def bucket(self, index, value):
         self.__samples[index] = self.__samples.setdefault(index, 0) + value
-        if value and index > self.__max:
-            self.__max = index
-        if value and index < self.__min:
-            self.__min = index
+        if value:
+            self.update_max(index)
+            self.update_min(index)
         self.__numsamples += value
 
     def reduce(self):
@@ -332,6 +337,18 @@ class Cyclictest(rtevalModulePrototype):
         return False
 
 
+    def _parse_max_latencies(self, line):
+        if not line.startswith('# Max Latencies: '):
+            return
+
+        line = line.split(':')[1]
+        vals = [int(x) for x in line.split()]
+
+        for i, core in enumerate(self.__cpus):
+            self.__cyclicdata[core].update_max(vals[i])
+            self.__cyclicdata['system'].update_max(vals[i])
+
+
     def _WorkloadCleanup(self):
         if not self.__started:
             return
@@ -348,6 +365,8 @@ class Cyclictest(rtevalModulePrototype):
                 # Catch if cyclictest stopped due to a breaktrace
                 if line.startswith('# Break value: '):
                     self.__breaktraceval = int(line.split(':')[1])
+                elif line.startswith('# Max Latencies: '):
+                    self._parse_max_latencies(line)
                 continue
 
             # Skipping blank lines
-- 
2.32.0

[PATCH v2 3/3] rteval: cyclictest.py: Sort the list of cpus

[Punit Agrawal]

From: Punit Agrawal <punit1.agrawal@toshiba.co.jp>

online_cpus() returns a list of online cpus in arbitrary order. e.g.,
on a hexacore system it returns -

    ['5', '3', '1', '4', '2', '0']

Generally this wouldn't be a problem but the cyclictest.py module
matches the unsorted list with the latencies output by "cyclictest"
which are ordered by core number. This leads to incorrect reporting of
per-core latencies in the final report generated by rteval. The issue
was noticed when comparing the rteval report with cyclictest logs
(enabled by a recent change).

Fix the inconsistency in core numbering by sorting the list of cpus
used by cyclictest.py module. As the cpus are represented as a string,
sort with the integer key to avoid issues on systems with large number
of cores.

Signed-off-by: Punit Agrawal <punit1.agrawal@toshiba.co.jp>
---
 rteval/modules/measurement/cyclictest.py | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/rteval/modules/measurement/cyclictest.py b/rteval/modules/measurement/cyclictest.py
index d3a0b045b9dd..50a734c75047 100644
--- a/rteval/modules/measurement/cyclictest.py
+++ b/rteval/modules/measurement/cyclictest.py
@@ -216,6 +216,10 @@ class Cyclictest(rtevalModulePrototype):
         else:
             self.__cpus = online_cpus()
 
+        # Sort the list of cpus to align with the order reported by
+        # cyclictest
+        self.__cpus.sort(key=int)
+
         # Get the cpuset from the environment
         cpuset = os.sched_getaffinity(0)
 
-- 
2.32.0

Re: [PATCH v2 0/3] rteval: Fix issues with cyclictest.py module

[Punit Agrawal]

Hi John,

Punit Agrawal <punitagrawal@gmail.com> writes:

> Hi,
>
> Here's an updated version of the cyclictest fixes previously posted at
> [0]. The changes in this version are to address feedback received on
> the previous version.
>
> v1 -> v2:
> * Patch 1: Add an option (default off) to save cyclictest output
> * Patch 3: Sort cpus returned by online_cpus() in cyclictest.py module
>
> All feedback welcome.

Ping!

Perhaps this set slipped through the cracks.

> Thanks,
> Punit
>
> [0] https://lore.kernel.org/all/20210902092452.726905-1-punitagrawal@gmail.com/
>
> Punit Agrawal (3):
>   rteval: cyclictest.py Enable logging cyclictest output
>   rteval: cyclictest.py Parse max latencies from cyclictest output
>   rteval: cyclictest.py: Sort the list of cpus
>
>  rteval/modules/measurement/cyclictest.py | 44 ++++++++++++++++++++----
>  1 file changed, 37 insertions(+), 7 deletions(-)

Re: [PATCH v2 0/3] rteval: Fix issues with cyclictest.py module

[John Kacur]

On Tue, 28 Sep 2021, Punit Agrawal wrote:

> Hi John,
> 
> Punit Agrawal <punitagrawal@gmail.com> writes:
> 
> > Hi,
> >
> > Here's an updated version of the cyclictest fixes previously posted at
> > [0]. The changes in this version are to address feedback received on
> > the previous version.
> >
> > v1 -> v2:
> > * Patch 1: Add an option (default off) to save cyclictest output
> > * Patch 3: Sort cpus returned by online_cpus() in cyclictest.py module
> >
> > All feedback welcome.
> 
> Ping!
> 
> Perhaps this set slipped through the cracks.
> 
> > Thanks,
> > Punit
> >
> > [0] https://lore.kernel.org/all/20210902092452.726905-1-punitagrawal@gmail.com/
> >
> > Punit Agrawal (3):
> >   rteval: cyclictest.py Enable logging cyclictest output
> >   rteval: cyclictest.py Parse max latencies from cyclictest output
> >   rteval: cyclictest.py: Sort the list of cpus
> >
> >  rteval/modules/measurement/cyclictest.py | 44 ++++++++++++++++++++----
> >  1 file changed, 37 insertions(+), 7 deletions(-)
> 

Thanks for the ping, but I haven't forgotten this, I just haven't had time 
to go through it properly yet. It's on my TODO list.

Thanks

John