[PATCH 0/2] Fix a few "make check-perf" problems

[PATCH 0/2] Fix a few "make check-perf" problems

[Pedro Alves]

These patches make "make check-perf" work with Python 3.8, and fix a
couple other issues:

 - Python errors should be detected and issue FAIL.
 - We currently run against a bunch of expect buffer overflows.

Pedro Alves (2):
  gdb.perf/: FAIL on Python errors, avoid "ERROR: internal buffer is
    full"
  Update gdb performance testsuite to be compatible with Python 3.8

 gdb/testsuite/gdb.perf/backtrace.exp          |  2 +-
 gdb/testsuite/gdb.perf/disassemble.exp        |  2 +-
 .../gdb.perf/lib/perftest/measure.py          | 50 +++++++++++++------
 .../gdb.perf/lib/perftest/perftest.py         |  6 ++-
 gdb/testsuite/gdb.perf/single-step.exp        |  2 +-
 gdb/testsuite/gdb.perf/skip-command.exp       |  2 +-
 gdb/testsuite/gdb.perf/skip-prologue.exp      | 12 +----
 gdb/testsuite/gdb.perf/solib.exp              |  2 +-
 .../gdb.perf/template-breakpoints.exp         |  2 +-
 gdb/testsuite/lib/perftest.exp                | 25 ++++++++++
 10 files changed, 72 insertions(+), 33 deletions(-)


base-commit: ff5404f5b37484567a19603769a2c0e56f108272
-- 
2.26.2

[PATCH 1/2] gdb.perf/: FAIL on Python errors, avoid "ERROR: internal buffer is full"

[Pedro Alves]

Currently, if you run make check-perf on a system with Python 3.8,
tests seen to PASS, but they actually test a lot less than intended,
due to:

 PerfTest::assemble, run ...
 python BackTrace(64).run()
 Traceback (most recent call last):
   File "<string>", line 1, in <module>
   File "/home/pedro/rocm/gdb/src/gdb/testsuite/gdb.perf/lib/perftest/perftest.py", line 65, in run
     self.execute_test()
   File "<string>", line 49, in execute_test
   File "/home/pedro/rocm/gdb/src/gdb/testsuite/gdb.perf/lib/perftest/measure.py", line 45, in measure
     m.start(id)
   File "/home/pedro/rocm/gdb/src/gdb/testsuite/gdb.perf/lib/perftest/measure.py", line 102, in start
     self.start_time = time.clock()
 AttributeError: module 'time' has no attribute 'clock'
 Error while executing Python code.
 (gdb) PASS: gdb.perf/backtrace.exp: python BackTrace(64).run()

And then, after fixing the above Python compatibility issues (which
will be a separate patch), I get 86 instances of overflowing expect's
buffer, like:

  ERROR: internal buffer is full.
  UNRESOLVED: gdb.perf/single-step.exp: python SingleStep(1000).run()

This patch fixes both problems by adding & using a gdb_test_python_run
routine that:

 - checks for Python errors
 - consumes output line by line

gdb/testsuite/ChangeLog:
yyyy-mm-dd  Pedro Alves  <pedro@palves.net>

	* gdb.perf/backtrace.exp: Use gdb_test_python_run.
	* gdb.perf/disassemble.exp: Use gdb_test_python_run.
	* gdb.perf/single-step.exp: Use gdb_test_python_run.
	* gdb.perf/skip-command.exp: Use gdb_test_python_run.
	* gdb.perf/skip-prologue.exp: Use gdb_test_python_run.
	* gdb.perf/solib.exp: Use gdb_test_python_run.
	* gdb.perf/template-breakpoints.exp: Use gdb_test_python_run.
	* lib/perftest.exp (gdb_test_python_run): New.

Change-Id: I007af36f164b3f4cda41033616eaaa4e268dfd2f
---
 gdb/testsuite/gdb.perf/backtrace.exp          |  2 +-
 gdb/testsuite/gdb.perf/disassemble.exp        |  2 +-
 gdb/testsuite/gdb.perf/single-step.exp        |  2 +-
 gdb/testsuite/gdb.perf/skip-command.exp       |  2 +-
 gdb/testsuite/gdb.perf/skip-prologue.exp      | 12 +--------
 gdb/testsuite/gdb.perf/solib.exp              |  2 +-
 .../gdb.perf/template-breakpoints.exp         |  2 +-
 gdb/testsuite/lib/perftest.exp                | 25 +++++++++++++++++++
 8 files changed, 32 insertions(+), 17 deletions(-)

diff --git a/gdb/testsuite/gdb.perf/backtrace.exp b/gdb/testsuite/gdb.perf/backtrace.exp
index 1e1243c8900..ced653c4b84 100644
--- a/gdb/testsuite/gdb.perf/backtrace.exp
+++ b/gdb/testsuite/gdb.perf/backtrace.exp
@@ -63,7 +63,7 @@ PerfTest::assemble {
 } {
     global BACKTRACE_DEPTH
 
-    gdb_test "python BackTrace\($BACKTRACE_DEPTH\).run()"
+    gdb_test_python_run "BackTrace\($BACKTRACE_DEPTH\)"
 
     return 0
 }
diff --git a/gdb/testsuite/gdb.perf/disassemble.exp b/gdb/testsuite/gdb.perf/disassemble.exp
index 55261d0d6bf..4a79e298e02 100644
--- a/gdb/testsuite/gdb.perf/disassemble.exp
+++ b/gdb/testsuite/gdb.perf/disassemble.exp
@@ -55,6 +55,6 @@ PerfTest::assemble {
 
     return 0
 } {
-    gdb_test "python Disassemble\(\).run()"
+    gdb_test_python_run "Disassemble\(\)"
     return 0
 }
diff --git a/gdb/testsuite/gdb.perf/single-step.exp b/gdb/testsuite/gdb.perf/single-step.exp
index 4a8eafe5bb5..7a5d068f153 100644
--- a/gdb/testsuite/gdb.perf/single-step.exp
+++ b/gdb/testsuite/gdb.perf/single-step.exp
@@ -51,7 +51,7 @@ PerfTest::assemble {
 } {
     global SINGLE_STEP_COUNT
 
-    gdb_test_no_output "python SingleStep\(${SINGLE_STEP_COUNT}\).run()"
+    gdb_test_python_run "SingleStep\(${SINGLE_STEP_COUNT}\)"
     # Terminate the loop.
     gdb_test "set variable flag = 0"
     return 0
diff --git a/gdb/testsuite/gdb.perf/skip-command.exp b/gdb/testsuite/gdb.perf/skip-command.exp
index dfd84a15820..e396262af06 100644
--- a/gdb/testsuite/gdb.perf/skip-command.exp
+++ b/gdb/testsuite/gdb.perf/skip-command.exp
@@ -103,7 +103,7 @@ proc run_skip_bench { kind text } {
     for { set i 0 } { $i < 5 } { incr i } {
 	set nr_skips [expr $i * $SKIP_DIRECTIVE_COUNT]
 	install_skips $kind $text $nr_skips
-	gdb_test_no_output "python SkipCommand\(\"skip-$kind-$nr_skips\", ${SKIP_STEP_COUNT}\).run()"
+	gdb_test_python_run "SkipCommand\(\"skip-$kind-$nr_skips\", ${SKIP_STEP_COUNT}\)"
     }
 
     gdb_test "set variable flag = 0"
diff --git a/gdb/testsuite/gdb.perf/skip-prologue.exp b/gdb/testsuite/gdb.perf/skip-prologue.exp
index 8ff9238b280..7caff667a0d 100644
--- a/gdb/testsuite/gdb.perf/skip-prologue.exp
+++ b/gdb/testsuite/gdb.perf/skip-prologue.exp
@@ -63,16 +63,6 @@ PerfTest::assemble {
 } {
     global SKIP_PROLOGUE_COUNT
 
-    set test "run"
-    gdb_test_multiple "python SkipPrologue\($SKIP_PROLOGUE_COUNT\).run()" $test {
-	-re "Breakpoint $decimal at \[^\n\]*\n" {
-	    # GDB prints some messages on breakpoint creation.
-	    # Consume the output to avoid internal buffer full.
-	    exp_continue
-	}
-	-re ".*$gdb_prompt $" {
-	    pass $test
-	}
-    }
+    gdb_test_python_run "SkipPrologue\($SKIP_PROLOGUE_COUNT\)" "run"
     return 0
 }
diff --git a/gdb/testsuite/gdb.perf/solib.exp b/gdb/testsuite/gdb.perf/solib.exp
index 61e9a95841d..e0cd341bf31 100644
--- a/gdb/testsuite/gdb.perf/solib.exp
+++ b/gdb/testsuite/gdb.perf/solib.exp
@@ -84,6 +84,6 @@ PerfTest::assemble {
 } {
     global SOLIB_COUNT
 
-    gdb_test_no_output "python SolibLoadUnload\($SOLIB_COUNT\).run()"
+    gdb_test_python_run "SolibLoadUnload\($SOLIB_COUNT\)"
     return 0
 }
diff --git a/gdb/testsuite/gdb.perf/template-breakpoints.exp b/gdb/testsuite/gdb.perf/template-breakpoints.exp
index aa4dc950984..96c1209e96c 100644
--- a/gdb/testsuite/gdb.perf/template-breakpoints.exp
+++ b/gdb/testsuite/gdb.perf/template-breakpoints.exp
@@ -59,7 +59,7 @@ PerfTest::assemble {
 	return 0
 } {
 
-	gdb_test "python TemplateBreakpoints().run()"
+	gdb_test_python_run "TemplateBreakpoints()"
 
 	return 0
 }
diff --git a/gdb/testsuite/lib/perftest.exp b/gdb/testsuite/lib/perftest.exp
index 5549a723a0c..949b33a8955 100644
--- a/gdb/testsuite/lib/perftest.exp
+++ b/gdb/testsuite/lib/perftest.exp
@@ -155,3 +155,28 @@ proc tcl_string_list_to_python_list { l } {
     }
     return "([join $quoted_list {, }])"
 }
+
+# Helper routine for PerfTest::assemble "run" step implementations.
+# Issues the "python ${OBJ}.run()" command, and consumes GDB output
+# line by line.  Issues a FAIL if the command fails with a Python
+# error.  Issues a PASS on success.  MESSAGE is an optional message to
+# be printed.  If this is omitted, then the pass/fail messages use the
+# command string as the message.
+
+proc gdb_test_python_run {obj {message ""}} {
+    global gdb_prompt
+
+    set saw_error 0
+    gdb_test_multiple "python $obj" $message {
+	-re "Error while executing Python code\\." {
+	    set saw_error 1
+	    exp_continue
+	}
+	-re "\[^\r\n\]*\r\n" {
+	    exp_continue
+	}
+	-re "$gdb_prompt $" {
+	    gdb_assert {!$saw_error} $gdb_test_name
+	}
+    }
+}
-- 
2.26.2

[PATCH 2/2] Update gdb performance testsuite to be compatible with Python 3.8

[Pedro Alves]

Running "make check-perf" on a system with Python 3.8 (e.g., Ubuntu
20.04) runs into this Python problem:

  Traceback (most recent call last):
    File "<string>", line 1, in <module>
    File "/home/pedro/rocm/gdb/src/gdb/testsuite/gdb.perf/lib/perftest/perftest.py", line 65, in run
      self.execute_test()
    File "<string>", line 35, in execute_test
    File "/home/pedro/rocm/gdb/src/gdb/testsuite/gdb.perf/lib/perftest/measure.py", line 45, in measure
      m.start(id)
    File "/home/pedro/rocm/gdb/src/gdb/testsuite/gdb.perf/lib/perftest/measure.py", line 102, in start
      self.start_time = time.clock()
  AttributeError: module 'time' has no attribute 'clock'
  Error while executing Python code.
  (gdb) FAIL: gdb.perf/single-step.exp: python SingleStep(1000).run()

... many times over.

The problem is that the testsuite is using time.clock(), deprecated in
Python 3.3 and finaly removed in Python 3.8.  The guidelines say to
use time.perf_counter() or time.process_time() instead depending on
requirements.  Looking at the current description of those functions,
at:

   https://docs.python.org/3.10/library/time.html

we have:

   time.perf_counter() → float

       Return the value (in fractional seconds) of a performance
       counter, i.e. a clock with the highest available resolution to
       measure a short duration. It does include time elapsed during
       sleep and is system-wide. (...)

   time.process_time() → float

       Return the value (in fractional seconds) of the sum of the
       system and user CPU time of the current process. It does not
       include time elapsed during sleep. It is process-wide by
       definition. (...)

I'm thinking that it's just best to record both instead of picking
one.  So this patch replaces the MeasurementCpuTime measurement class
with two new classes -- MeasurementPerfCounter and
MeasurementProcessTime.  Correspondingly, this changes the reports in
testsuite/perftest.log -- we have two new "perf_counter" and
"process_time" measurements and the "cpu_time" measurement is gone.  I
don't suppose breaking backward compatibility here is a big problem.
I suspect no one is really tracking long term performance using the
perf testsuite today.  And if they are, it shouldn't be hard to adjust.

For backward compatility, with Python < 3.3, both perf_counter and
process_time use the old time.clock.

gdb/testsuite/ChangeLog:
yyyy-mm-dd  Qingchuan Shi  <qingchuan.shi@amd.com>
	    Pedro Alves  <pedro@palves.net>

	* gdb.perf/lib/perftest/perftest.py: Import sys.
	(time.perf_counter, time.process_time): Map to time.clock on
	Python < 3.3.
	(MeasurementCpuTime): Delete, replaced by...
	(MeasurementPerfCounter, MeasurementProcessTime): .. these two new
	classes.
	* gdb.perf/lib/perftest/perftest.py: Import MeasurementPerfCounter
	and MeasurementProcessTime instead of MeasurementCpuTime.
	(TestCaseWithBasicMeasurements): Use MeasurementPerfCounter and
	MeasurementProcessTime instead of MeasurementCpuTime.

Co-authored-by: Qingchuan Shi <qingchuan.shi@amd.com>

Change-Id: Ia850c05d5ce57d2dada70ba5b0061f566444aa2b
---
 .../gdb.perf/lib/perftest/measure.py          | 50 +++++++++++++------
 .../gdb.perf/lib/perftest/perftest.py         |  6 ++-
 2 files changed, 40 insertions(+), 16 deletions(-)

diff --git a/gdb/testsuite/gdb.perf/lib/perftest/measure.py b/gdb/testsuite/gdb.perf/lib/perftest/measure.py
index 2a20c5eafb2..9810458fdb6 100644
--- a/gdb/testsuite/gdb.perf/lib/perftest/measure.py
+++ b/gdb/testsuite/gdb.perf/lib/perftest/measure.py
@@ -16,6 +16,13 @@
 import time
 import os
 import gc
+import sys
+
+# time.perf_counter() and time.process_time() were added in Python
+# 3.3, time.clock() was removed in Python 3.8.
+if sys.version_info < (3, 3, 0):
+    time.perf_counter = time.clock
+    time.process_time = time.clock
 
 
 class Measure(object):
@@ -85,28 +92,43 @@ class Measurement(object):
         self.result.report(reporter, name + " " + self.name)
 
 
-class MeasurementCpuTime(Measurement):
-    """Measurement on CPU time."""
+class MeasurementPerfCounter(Measurement):
+    """Measurement on performance counter."""
+
+    # Measures time in fractional seconds, using a performance
+    # counter, i.e. a clock with the highest available resolution to
+    # measure a short duration.  It includes time elapsed during sleep
+    # and is system-wide.
+
+    def __init__(self, result):
+        super(MeasurementPerfCounter, self).__init__("perf_counter", result)
+        self.start_time = 0
+
+    def start(self, id):
+        self.start_time = time.perf_counter()
+
+    def stop(self, id):
+        perf_counter = time.perf_counter() - self.start_time
+        self.result.record(id, perf_counter)
+
+
+class MeasurementProcessTime(Measurement):
+    """Measurement on process time."""
 
-    # On UNIX, time.clock() measures the amount of CPU time that has
-    # been used by the current process.  On Windows it will measure
-    # wall-clock seconds elapsed since the first call to the function.
-    # Something other than time.clock() should be used to measure CPU
-    # time on Windows.
+    # Measures the sum of the system and user CPU time of the current
+    # process.  Does not include time elapsed during sleep.  It is
+    # process-wide by definition.
 
     def __init__(self, result):
-        super(MeasurementCpuTime, self).__init__("cpu_time", result)
+        super(MeasurementProcessTime, self).__init__("process_time", result)
         self.start_time = 0
 
     def start(self, id):
-        self.start_time = time.clock()
+        self.start_time = time.process_time()
 
     def stop(self, id):
-        if os.name == "nt":
-            cpu_time = 0
-        else:
-            cpu_time = time.clock() - self.start_time
-        self.result.record(id, cpu_time)
+        process_time = time.process_time() - self.start_time
+        self.result.record(id, process_time)
 
 
 class MeasurementWallTime(Measurement):
diff --git a/gdb/testsuite/gdb.perf/lib/perftest/perftest.py b/gdb/testsuite/gdb.perf/lib/perftest/perftest.py
index 07266413fb0..202ba3f71bc 100644
--- a/gdb/testsuite/gdb.perf/lib/perftest/perftest.py
+++ b/gdb/testsuite/gdb.perf/lib/perftest/perftest.py
@@ -18,7 +18,8 @@ from __future__ import absolute_import
 import perftest.testresult as testresult
 import perftest.reporter as reporter
 from perftest.measure import Measure
-from perftest.measure import MeasurementCpuTime
+from perftest.measure import MeasurementPerfCounter
+from perftest.measure import MeasurementProcessTime
 from perftest.measure import MeasurementWallTime
 from perftest.measure import MeasurementVmSize
 
@@ -72,7 +73,8 @@ class TestCaseWithBasicMeasurements(TestCase):
     def __init__(self, name):
         result_factory = testresult.SingleStatisticResultFactory()
         measurements = [
-            MeasurementCpuTime(result_factory.create_result()),
+            MeasurementPerfCounter(result_factory.create_result()),
+            MeasurementProcessTime(result_factory.create_result()),
             MeasurementWallTime(result_factory.create_result()),
             MeasurementVmSize(result_factory.create_result()),
         ]
-- 
2.26.2

Re: [PATCH 0/2] Fix a few "make check-perf" problems

[Pedro Alves]

On 2021-06-18 10:12 p.m., Pedro Alves wrote:
> These patches make "make check-perf" work with Python 3.8, and fix a
> couple other issues:
> 
>  - Python errors should be detected and issue FAIL.
>  - We currently run against a bunch of expect buffer overflows.

FYI, I've merged these now.  I have a follow up series to clean up the remainder
of the bit rot.  I'll send it next.