Record/replay support for arm virt board

panda/include/panda/rr/rr_log.h

@@ -216,7 +216,7 @@ static inline uint64_t rr_num_instr_before_next_interrupt(void) {
 
 uint32_t rr_checksum_memory(void);
 uint32_t rr_checksum_regs(void);
-
+uint32_t rr_checksum_timers(int);
 bool rr_queue_empty(void);
 
 #endif

panda/scripts/diverge.py

@@ -14,6 +14,7 @@
 from multiprocessing.pool import ThreadPool
 from os.path import join
 from subprocess import check_call, CalledProcessError
+from time import sleep
 
 from expect import Expect, TimeoutExpired
 from tempdir import TempDir
@@ -255,19 +256,19 @@ def display_commands(self):
     def ram_ptr(self):
         return self.get_value(
             "memory_region_find(" +
-                "get_system_memory(), 0x2000000, 1).mr->ram_block.host")
+                "get_system_memory(), 0x2000000, 1).mr->ram_block->host")
 
     def crc32_ram(self, low, size):
         step = 1 << 31 if size > (1 << 31) else size
         crc32s = 0
         for start in range(low, low + size, step):
-            crc32s ^= self.get_value("crc32(0, {} + {}, {})".format(
-                            hex(self.ram_ptr), hex(start), hex(step)))
+            crc32s ^= self.get_value("(unsigned long) crc32(0, {} +{}, {})".format(
+                        hex(self.ram_ptr), hex(start), hex(step)))
         return crc32s
 
     @cached_property
     def ram_size(self):
-        return self.get_value('ram_size')
+        return self.get_value('memory_region_find(get_system_memory(), 0x2000000, 1).mr->ram_block.used_length')
 
     @cached_property
     def reg_size(self):
@@ -670,11 +671,12 @@ def cleanup_error():
         self.both.gdb("set pagination off")
 
         check_call(['tmux', 'select-layout', 'even-horizontal'])
-
+        self.both.breakpoint("_start")
+        self.both.gdb("c")
+        sleep(1)
         self.both.breakpoint("rr_do_begin_record")
         self.both.breakpoint("rr_do_begin_replay")
         self.both.breakpoint("cpu_loop_exec_tb")
-
         try:
             self.both.breakpoint("debug_counter")
         except RuntimeError:

panda/src/rr/arm-vrit.md

@@ -0,0 +1,11 @@
+# What works
+A basic busybox system runs with the addition of rring timers.
+This was done by creating .accessfn functions for gvirt_timer ctl values. Then inserting the correct rr macro into that function.
+# What is still broken
+All of virtio. 
+Most importantly virtio-blk and virtio-net.
+virtio-blk causes a MEM_UNMAP skipped call. 
+the skipped calls functions that have a record and replay macro in them. This kind of recursive call is problematic and was fixed with adding a global variable that controls if you are currently in the call stack of skipped calls. Further information is needed to know if (the offending macro)[https://github.com/panda-re/panda/blob/381301411f110b9a4df3335526f52d78f6702413/exec.c#L2908-L2947] is needed though it seems likely it is not.
+
+# Infortmation to continue work
+Most of virt-blk seems to be handle by the existing memrw skipped calls. A core funtionality breaks upon virtqueue_push which calls virtqueue_fill which calls an unmap function producing the MEM_UNMAP skipped calls. virtqueue_flush is what actually writes the divergent value. A lot of the accesses to this data is handled by MACRO glue functions. Given the large number of structures that virtqueue_push and the called functions rely on it might be easier to focus on the virtio ecosystem at the macro level.

panda/src/rr/rr_log.c

@@ -949,29 +949,29 @@ static inline RR_log_entry* get_next_entry(void) {
 // same as above. make sure to consume after.
 static inline RR_log_entry* get_next_entry_checked(RR_log_entry_kind kind,
         RR_callsite_id call_site, bool check_callsite) {
-    RR_log_entry *entry = get_next_entry();
-    if (!entry) return NULL;
-
-    RR_header header = entry->header;
-    // XXX FIXME this is a temporary hack to get around the fact that we
-    // cannot currently do a tb_flush and a savevm in the same instant.
-    if (header.prog_point.guest_instr_count == 0) {
-        // We'll process this one beacuse it's the start of the log
-    } else if (rr_prog_point_compare(rr_prog_point(),
-                header.prog_point, kind) != 0) {
-        // mz rr_prog_point_compare will fail if we're ahead of the log
-        return NULL;
-    }
+        RR_log_entry *entry = get_next_entry();
+        if (!entry) return NULL;
+
+        RR_header header = entry->header;
+        // XXX FIXME this is a temporary hack to get around the fact that we
+        // cannot currently do a tb_flush and a savevm in the same instant.
+        if (header.prog_point.guest_instr_count == 0) {
+            // We'll process this one beacuse it's the start of the log
+        } else if (rr_prog_point_compare(rr_prog_point(),
+                    header.prog_point, kind) != 0) {
+            // mz rr_prog_point_compare will fail if we're ahead of the log
+            return NULL;
+        }
 
-    if (header.kind != kind) {
-        return NULL;
-    }
+        if (header.kind != kind) {
+            return NULL;
+        }
 
-    if (check_callsite && header.callsite_loc != call_site) {
-        return NULL;
-    }
+        if (check_callsite && header.callsite_loc != call_site) {
+            return NULL;
+        }
 
-    return entry;
+        return entry;
 }
 
 // mz replay 1-byte input to the CPU
@@ -1100,11 +1100,15 @@ static MemoryRegion * rr_memory_region_find_parent(MemoryRegion *root, MemoryReg
 // RR_SKIPPED_CALL_CPU_MEM_RW and RR_SKIPPED_CALL_CPU_REG_MEM_REGION
 // XXX call_site parameter no longer used...
 // bdg 07.2012: Adding RR_SKIPPED_CALL_CPU_MEM_UNMAP
+bool no_recursion = 0;
 void rr_replay_skipped_calls_internal(RR_callsite_id call_site)
 {
 #ifdef CONFIG_SOFTMMU
     uint8_t replay_done = 0;
+    if(no_recursion)
+        return;
     do {
+        no_recursion = 1;
         RR_log_entry* current_item =
             get_next_entry_checked(RR_SKIPPED_CALL, call_site, false);
         if (current_item == NULL) {
@@ -1205,6 +1209,7 @@ void rr_replay_skipped_calls_internal(RR_callsite_id call_site)
             rr_queue_pop_front();
         }
     } while (!replay_done);
+    no_recursion = 0;
 #endif
 }
 
@@ -1951,6 +1956,14 @@ uint32_t rr_checksum_regs(void) {
 #endif
     return crc;
 }
+uint32_t rr_checksum_timers(int index) {
+    uint32_t crc = crc32(0, Z_NULL, 0);
+    #if defined(TARGET_ARM)
+    CPUARMState *env = (CPUArchState *)first_cpu->env_ptr;
+    crc = crc32(crc, (unsigned char *)&env->cp15.c14_timer[index], sizeof(env->cp15.c14_timer[index]));
+    #endif
+    return crc;
+}
 
 uint8_t rr_debug_readb(target_ulong addr);
 uint8_t rr_debug_readb(target_ulong addr) {

target/arm/helper.c

@@ -15,6 +15,10 @@
 #include <zlib.h> /* For crc32 */
 #include "exec/semihost.h"
 #include "sysemu/kvm.h"
+#ifdef CONFIG_SOFTMMU
+#include "panda/rr/rr_log_all.h"
+#include "panda/rr/rr_log.h"
+#endif
 
 #define ARM_CPU_FREQ 1000000000 /* FIXME: 1 GHz, should be configurable */
 
@@ -1701,6 +1705,15 @@ static uint64_t gt_cnt_read(CPUARMState *env, const ARMCPRegInfo *ri)
 
 static uint64_t gt_virt_cnt_read(CPUARMState *env, const ARMCPRegInfo *ri)
 {
+        #ifdef CONFIG_SOFTMMU
+            uint64_t now;
+             RR_DO_RECORD_OR_REPLAY(
+                /*action*/ now = gt_get_countervalue(env) - env->cp15.cntvoff_el2,
+                /*record*/ rr_input_8(&now),
+                /*replay*/ rr_input_8(&now),
+                /*location*/RR_CALLSITE_READ_8);
+             return now;
+    #endif
     return gt_get_countervalue(env) - env->cp15.cntvoff_el2;
 }
 
@@ -1812,7 +1825,18 @@ static void gt_virt_ctl_write(CPUARMState *env, const ARMCPRegInfo *ri,
 {
     gt_ctl_write(env, ri, GTIMER_VIRT, value);
 }
-
+static uint64_t gt_virt_ctl_read(CPUARMState *env, const ARMCPRegInfo *ri)
+{
+    uint64_t ctl;
+            #ifdef CONFIG_SOFTMMU
+             RR_DO_RECORD_OR_REPLAY(
+                /*action*/ ctl = env->cp15.c14_timer[GTIMER_VIRT].ctl,
+                /*record*/ rr_input_8(&ctl),
+                /*replay*/ rr_input_8(&ctl),
+                /*location*/RR_CALLSITE_READ_8);
+        #endif
+    return ctl;
+}
 static void gt_cntvoff_write(CPUARMState *env, const ARMCPRegInfo *ri,
                               uint64_t value)
 {
@@ -1961,6 +1985,7 @@ static const ARMCPRegInfo generic_timer_cp_reginfo[] = {
       .accessfn = gt_vtimer_access,
       .fieldoffset = offsetoflow32(CPUARMState,
                                    cp15.c14_timer[GTIMER_VIRT].ctl),
+      .readfn = gt_virt_ctl_read,
       .writefn = gt_virt_ctl_write, .raw_writefn = raw_write,
     },
     { .name = "CNTV_CTL_EL0", .state = ARM_CP_STATE_AA64,
@@ -1969,6 +1994,7 @@ static const ARMCPRegInfo generic_timer_cp_reginfo[] = {
       .accessfn = gt_vtimer_access,
       .fieldoffset = offsetof(CPUARMState, cp15.c14_timer[GTIMER_VIRT].ctl),
       .resetvalue = 0,
+      .readfn = gt_virt_ctl_read,
       .writefn = gt_virt_ctl_write, .raw_writefn = raw_write,
     },
     /* TimerValue views: a 32 bit downcounting view of the underlying state */