rteval: Fix issues with cyclictest.py module

PATCH Superseded Punit Agrawal 2 participants 8 messages Sep 17, 2021 – Nov 9, 2021

lore

Share & tools

lore

Punit Agrawal

author

2021-09-17 08:53 UTC #0 lore raw

v2 cover rteval: Fix issues with cyclictest.py module

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/[email protected]/

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(-)

Signature · 1 line

2.32.0

Punit Agrawal

author

2021-09-17 08:54 UTC #1 lore raw

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

From: Punit Agrawal <[email protected]>

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 <[email protected]>

---
 rteval/modules/measurement/cyclictest.py | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)

rteval/modules/measurement/cyclictest.py +8 -1

index b1755d4f4421..ee1de883d844 100644
@@ -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):

Signature · 1 line

2.32.0

Punit Agrawal

author

2021-11-09 06:59 UTC #2 lore raw

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

Quoted 41 lines · Punit Agrawal

From: Punit Agrawal <[email protected]>
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 <[email protected]>
---
 rteval/modules/measurement/cyclictest.py | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)
rteval/modules/measurement/cyclictest.py +4 -0
index b1755d4f4421..ee1de883d844 100644
@@ -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")

rteval/modules/measurement/cyclictest.py class Cyclictest(rtevalModulePrototype): · line 301

Quoted 10 lines

rteval/modules/measurement/cyclictest.py +4 -1

 
         # 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.

Punit Agrawal

author

2021-11-09 07:00 UTC #3 lore raw

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

Quoted 52 lines · Punit Agrawal

Quoted 50 lines · Punit Agrawal

From: Punit Agrawal <[email protected]>

Signed-off-by Punit Agrawal <[email protected]>

---
 rteval/modules/measurement/cyclictest.py | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)

rteval/modules/measurement/cyclictest.py +8 -1

index b1755d4f4421..ee1de883d844 100644
@@ -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')

Quoted 6 lines

rteval/modules/measurement/cyclictest.py class Cyclictest(rtevalModulePrototype): · line 301
Quoted 1 line
rteval/modules/measurement/cyclictest.py +0 -0
     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.

Punit Agrawal

author

2021-09-17 08:54 UTC #4 lore raw

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

In reply to Punit Agrawal

From: Punit Agrawal <[email protected]>

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 <[email protected]>

---
 rteval/modules/measurement/cyclictest.py | 31 +++++++++++++++++++-----
 1 file changed, 25 insertions(+), 6 deletions(-)

rteval/modules/measurement/cyclictest.py +25 -6

index ee1de883d844..d3a0b045b9dd 100644
@@ -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

Signature · 1 line

2.32.0

Punit Agrawal

author

2021-09-17 08:54 UTC #5 lore raw

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

In reply to Punit Agrawal

From: Punit Agrawal <[email protected]>

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 <[email protected]>

---
 rteval/modules/measurement/cyclictest.py | 4 ++++
 1 file changed, 4 insertions(+)

rteval/modules/measurement/cyclictest.py +4 -0

index d3a0b045b9dd..50a734c75047 100644
@@ -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)

Signature · 1 line

2.32.0

Punit Agrawal

author

2021-09-28 01:36 UTC #6 lore raw

In reply to Punit Agrawal

Hi John,

Quoted 11 lines · 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.

Ping!

Perhaps this set slipped through the cracks.

Quoted 12 lines

Thanks,
Punit
[0] https://lore.kernel.org/all/[email protected]/
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(-)

John Kacur

2021-09-28 01:47 UTC #7 lore raw

Quoted 14 lines · Punit Agrawal

Hi John,
Quoted 10 lines · 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

Quoted 19 lines

Quoted 1 line
All feedback welcome.
Ping!
Perhaps this set slipped through the cracks.
Quoted 12 lines
Thanks,
Punit
[0] https://lore.kernel.org/all/[email protected]/
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