[PATCH v5 18/24] tests/avocado: reverse_debugging reverse-step at the end of the trace

[Nicholas Piggin]

The longer a trace is played for, the more chance there is for bugs
to cause it to go out of synch with the initial recording. Stepping
backward from the end of a trace can be a good way to find problems.

This extends the runtime of the record phase to 1 second, to build a
bigger trace, and it adds a replay test that runs to the end of the
trace, steps back then forward and verifies the pc.

x86_64 and aarch64 have problems with verifying the pc at the end of
the trace after reverse-stepping, so add a workaround to skip that
check for them.

Signed-off-by: Nicholas Piggin <npiggin@gmail.com>
---
 tests/avocado/reverse_debugging.py | 65 +++++++++++++++++++++++++++++-
 1 file changed, 63 insertions(+), 2 deletions(-)

diff --git a/tests/avocado/reverse_debugging.py 
b/tests/avocado/reverse_debugging.py
index bdc9082c85..c0cf580d5c 100644
--- a/tests/avocado/reverse_debugging.py
+++ b/tests/avocado/reverse_debugging.py
@@ -9,6 +9,7 @@
 # later.  See the COPYING file in the top-level directory.
 import os
 import logging
+import time
 
 from avocado import skipUnless
 from avocado_qemu import BUILD_DIR
@@ -31,10 +32,15 @@ class ReverseDebugging(LinuxKernelTest):
     that the execution is stopped at the last of them.
     """
 
-    timeout = 10
+    timeout = 30
     STEPS = 10
     endian_is_le = True
 
+    # If long_trace is true, record execution for some time, and verify
+    # reverse-stepping from the end of the trace as well. If false, only the
+    # first 10 instructions are stepped.
+    verify_end = True
+
     # If first_step_workaround is true, check whether the first step moved
     # icount, and if not then step again.
     first_step_workaround = False
@@ -91,6 +97,19 @@ def check_pc(self, g, addr):
         if pc != addr:
             self.fail('Invalid PC (read %x instead of %x)' % (pc, addr))
 
+    @staticmethod
+    def gdb_break(g):
+        # The avocado GDBRemote does not have a good way to send this break
+        # packet, which is different from others.
+        g._socket.send(b'\x03')
+        transmission_result = g._socket.recv(1)
+        if transmission_result == '-':
+            raise Exception("Bad ack")
+        result = g._socket.recv(1024)
+        response_payload = g.decode(result)
+        if response_payload != b'T02thread:01;':
+            raise Exception("Unexpected response" + response_payload.decode())
+
     @staticmethod
     def gdb_cont(g):
         g.cmd(b'c')
@@ -162,9 +181,15 @@ def reverse_debugging(self, shift=7, args=None):
 
         logger.info('continue running')
         self.gdb_cont_nowait(g)
-
+        logger.info('running for 1s...')
+        time.sleep(1)
         logger.info('stopping to read final icount')
         vm.qmp('stop')
+        self.gdb_break(g)
+
+        last_pc = self.get_pc(g)
+        logger.info('saving position %x' % last_pc)
+        self.gdb_step(g)
         last_icount = self.vm_get_icount(vm)
         logger.info('shutdown...')
         vm.shutdown()
@@ -200,6 +225,34 @@ def reverse_debugging(self, shift=7, args=None):
             self.check_pc(g, addr)
             logger.info('found position %x' % addr)
 
+        # Run to the end of the trace, reverse-step, and then reverse-continue
+        # back to the start, with no breakpoints. This allows us to get to the
+        # end of the trace and reverse step from there, without possibly
+        # hitting a breakpoint that prevents reaching the end, as can happen
+        # with the later breakpoint tests.
+        logger.info('running to the end of the trace')
+        vm.qmp('replay-break', icount=last_icount - 1)
+        # This should stop at the end and get a T02 return.
+        self.gdb_cont(g)
+        if self.vm_get_icount(vm) != last_icount - 1:
+            self.fail('failed to reach the end (icount %s, reached %s)' % 
((last_icount - 1), self.vm_get_icount(vm)))
+        logger.info('reached end of trace')
+
+        if self.verify_end:
+            self.check_pc(g, last_pc)
+            logger.info('found position %x' % last_pc)
+
+            logger.info('stepping backward')
+            self.gdb_bstep(g)
+
+            logger.info('stepping forward')
+            self.gdb_step(g)
+            self.check_pc(g, last_pc)
+            logger.info('found position %x' % last_pc)
+
+        logger.info('reversing to the start of the trace')
+        g.cmd(b'bc', b'T05thread:01;')
+
         # Step forward again
         logger.info('stepping forward')
         for addr in steps:
@@ -250,6 +303,10 @@ class ReverseDebugging_X86_64(ReverseDebugging):
     # The initial step does not change pc on x86 for some reason.
     first_step_workaround = True
 
+    # Reverse stepping from a long-running trace does not reliably replay
+    # the trace precisely on x86.
+    verify_end = False
+
     def get_pc(self, g):
         return self.get_reg_le(g, self.REG_PC) \
             + self.get_reg_le(g, self.REG_CS) * 0x10
@@ -279,6 +336,10 @@ class ReverseDebugging_AArch64(ReverseDebugging):
 
     REG_PC = 32
 
+    # Reverse stepping from a long-running trace does not reliably replay
+    # the trace precisely on aarch64.
+    verify_end = False
+
     def test_aarch64_virt(self):
         """
         :avocado: tags=arch:aarch64
-- 
2.42.0