rteval: Fix issues with cyclictest module

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

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

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

From: Punit Agrawal <[email protected]>

The cyclictest.py module recently gained the capability to parse max latency values as reported by cyclictest.

When the max latency exceeds the range of the latency histogram (or in other words, the number of configured buckets), statistics such as mean and standard deviation can not be calculated correctly due to lost samples during measurement.

In the case of lost samples, skip statistics generation and report the max latency warning the user to rerun the measurement.

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

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

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

index 50a734c75047..7a619dd1c852 100644
@@ -67,6 +67,9 @@ class RunData:
         retval += "mean:       %f\n" % self.__mean
         return retval
 
+    def get_max(self):
+        return self.__max
+
     def update_max(self, value):
         if value > self.__max:
             self.__max = value

@@ -423,6 +426,13 @@ class Cyclictest(rtevalModulePrototype):
         if abrt:
             rep_n.addChild(abrt_n)
 
+        # Let the user know if max latency overshot the number of buckets
+        if self.__cyclicdata["system"].get_max() > self.__buckets:
+            self._log(Log.ERR, "Max latency(%dus) exceeded histogram range(%dus). Skipping statistics" %
+                      (self.__cyclicdata["system"].get_max(), self.__buckets))
+            self._log(Log.ERR, "Increase number of buckets to avoid lost samples")
+            return rep_n
+
         rep_n.addChild(self.__cyclicdata["system"].MakeReport())
         for thr in self.__cpus:
             if str(thr) not in self.__cyclicdata:

Signature · 1 line

2.33.0

Quoted 36 lines · Punit Agrawal

From: Punit Agrawal <[email protected]>

The cyclictest.py module recently gained the capability to parse max latency values as reported by cyclictest.

When the max latency exceeds the range of the latency histogram (or in other words, the number of configured buckets), statistics such as mean and standard deviation can not be calculated correctly due to lost samples during measurement.

In the case of lost samples, skip statistics generation and report the max latency warning the user to rerun the measurement.

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

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

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

index 50a734c75047..7a619dd1c852 100644
@@ -67,6 +67,9 @@ class RunData:
         retval += "mean:       %f\n" % self.__mean
         return retval
 
+    def get_max(self):
+        return self.__max
+
     def update_max(self, value):
         if value > self.__max:
             self.__max = value

@@ -423,6 +426,13 @@ class Cyclictest(rtevalModulePrototype):
         if abrt:
             rep_n.addChild(abrt_n)
 

Quoted 14 lines

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

+        # Let the user know if max latency overshot the number of buckets
+        if self.__cyclicdata["system"].get_max() > self.__buckets:
+            self._log(Log.ERR, "Max latency(%dus) exceeded histogram range(%dus). Skipping statistics" %
+                      (self.__cyclicdata["system"].get_max(), self.__buckets))
+            self._log(Log.ERR, "Increase number of buckets to avoid lost samples")
+            return rep_n
+
         rep_n.addChild(self.__cyclicdata["system"].MakeReport())
         for thr in self.__cpus:
             if str(thr) not in self.__cyclicdata:

Signature · 1 line

2.33.0

Signed-off-by John Kacur <[email protected]>