First cut at a facility to do CPU tracing

* Also includes a test that traces booting the test disk

Makefile.am

@@ -83,7 +83,7 @@ src/font.c: src/font.txt genfont
 src/rom.c: genrom
 	./genrom src/rom/apple_IIe.rom src/rom/slot6.rom > $@
 
-src/x86/glue.S: src/disk.c src/misc.c src/display.c src/vm.c @AUDIO_GLUE_C@
+src/x86/glue.S: src/disk.c src/misc.c src/display.c src/vm.c src/cpu-supp.c @AUDIO_GLUE_C@
 	./src/x86/genglue $^ > $@
 
 ###############################################################################

src/cpu-supp.c

@@ -41,6 +41,13 @@ uint8_t cpu65_flags_decode[256] = { 0 };
 void *cpu65_vmem_r[0x10000] = { 0 };
 void *cpu65_vmem_w[0x10000] = { 0 };
 
+#if CPU_TRACING
+static int8_t opargs[3] = { 0 };
+static int8_t nargs = 0;
+static uint16_t current_pc = 0x0;
+static FILE *cpu_trace_fp = NULL;
+#endif
+
 // ----------------------------------------------------------------------------
 // 65c02 Opcode Jump Table
 
@@ -639,3 +646,143 @@ void cpu65_uninterrupt(int reason)
     pthread_mutex_unlock(&irq_mutex);
 }
 
+#if CPU_TRACING
+
+/* -------------------------------------------------------------------------
+    CPU Tracing routines
+   ------------------------------------------------------------------------- */
+
+void cpu65_trace_begin(const char *trace_file) {
+    if (trace_file) {
+        cpu_trace_fp = fopen(trace_file, "w");
+    }
+}
+
+void cpu65_trace_end(void) {
+    if (cpu_trace_fp) {
+        fflush(cpu_trace_fp);
+        fclose(cpu_trace_fp);
+        cpu_trace_fp = NULL;
+    }
+}
+
+GLUE_C_WRITE(cpu65_trace_prologue)
+{
+    nargs = 0;
+    current_pc = cpu65_pc;
+}
+
+GLUE_C_WRITE(cpu65_trace_arg)
+{
+    assert(nargs <= 2);
+    opargs[nargs++] = b;
+}
+
+GLUE_C_WRITE(cpu65_trace_arg1)
+{
+    assert(nargs <= 2);
+    opargs[2] = b;
+    ++nargs;
+}
+
+GLUE_C_WRITE(cpu65_trace_arg2)
+{
+    assert(nargs <= 2);
+    opargs[1] = b;
+    ++nargs;
+}
+
+GLUE_C_WRITE(cpu65_trace_epilogue)
+{
+    char fmt[64];
+    char buf[64];
+
+    int8_t arg1 = opargs[1];
+    int8_t arg2 = opargs[2];
+
+    if (!cpu_trace_fp) {
+        return;
+    }
+
+    assert(nargs > 0);
+    assert(nargs <= 3);
+
+#warning FIXME TODO ... need to refactor this and the debugger routines to use the same codepaths ...
+    switch (opcodes_65c02[cpu65_opcode].mode) {
+        case addr_implied:
+        case addr_accumulator:                  /* no arg */
+            sprintf(buf, "%04X: %02X %s %s", current_pc, cpu65_opcode, opcodes_65c02[cpu65_opcode].mnemonic, disasm_templates[opcodes_65c02[cpu65_opcode].mode]);
+            break;
+
+        case addr_immediate:
+        case addr_zeropage:
+        case addr_zeropage_x:
+        case addr_zeropage_y:
+        case addr_indirect:
+        case addr_indirect_x:
+        case addr_indirect_y:                   /* byte arg */
+            sprintf(fmt, "%04X: %02X%02X %s %s", current_pc, cpu65_opcode, (uint8_t)arg1, opcodes_65c02[cpu65_opcode].mnemonic, disasm_templates[opcodes_65c02[cpu65_opcode].mode]);
+            sprintf(buf, fmt, (uint8_t)arg1);
+            break;
+
+        case addr_absolute:
+        case addr_absolute_x:
+        case addr_absolute_y:
+        case addr_j_indirect:
+        case addr_j_indirect_x:                 /* word arg */
+            sprintf(fmt, "%04X: %02X%02X%02X %s %s", current_pc, cpu65_opcode, (uint8_t)arg1, (uint8_t)arg2, opcodes_65c02[cpu65_opcode].mnemonic, disasm_templates[opcodes_65c02[cpu65_opcode].mode]);
+            sprintf(buf, fmt, (uint8_t)arg2, (uint8_t)arg1);
+            break;
+
+        case addr_relative:                     /* offset */
+            sprintf(fmt, "%04X: %02X%02X %s %s", current_pc, cpu65_opcode, (uint8_t)arg1, opcodes_65c02[cpu65_opcode].mnemonic, disasm_templates[opcodes_65c02[cpu65_opcode].mode]);
+            if (arg1 < 0) {
+                sprintf(buf, fmt, current_pc + arg1 + 2, '-', (uint8_t)(-arg1));
+            } else {
+                sprintf(buf, fmt, current_pc + arg1 + 2, '+', (uint8_t)arg1);
+            }
+            break;
+
+        default:                                /* shouldn't happen */
+            sprintf(buf, "invalid opcode mode");
+            break;
+    }
+
+    char regs_buf[64];
+    sprintf(regs_buf, "EA:%04X SP:%02X X:%02X Y:%02X A:%02X", cpu65_ea, cpu65_sp, cpu65_x, cpu65_y, cpu65_a);
+
+#define FLAGS_BUFSZ 9
+    char flags_buf[FLAGS_BUFSZ];
+    memset(flags_buf, '-', FLAGS_BUFSZ);
+    if (cpu65_f & C_Flag_6502) {
+        flags_buf[0]='C';
+    }
+    if (cpu65_f & X_Flag_6502) {
+        flags_buf[1]='X';
+    }
+    if (cpu65_f & I_Flag_6502) {
+        flags_buf[2]='I';
+    }
+    if (cpu65_f & V_Flag_6502) {
+        flags_buf[3]='V';
+    }
+    if (cpu65_f & B_Flag_6502) {
+        flags_buf[4]='B';
+    }
+    if (cpu65_f & D_Flag_6502) {
+        flags_buf[5]='D';
+    }
+    if (cpu65_f & Z_Flag_6502) {
+        flags_buf[6]='Z';
+    }
+    if (cpu65_f & N_Flag_6502) {
+        flags_buf[7]='N';
+    }
+    flags_buf[8] = '\0';
+
+    fprintf(cpu_trace_fp, "%s %s %s\n", buf, regs_buf, flags_buf);
+    fflush(cpu_trace_fp);
+}
+
+#endif // CPU_TRACING
+

src/cpu.h

@@ -56,6 +56,11 @@ extern unsigned char cpu65_flags_decode[256];
 extern int16_t cpu65_cycle_count;
 extern int16_t cpu65_cycles_to_execute;
 
+#if CPU_TRACING
+void cpu65_trace_begin(const char *trace_file);
+void cpu65_trace_end(void);
+#endif
+
 #endif /* !__ASSEMBLER__ */
 
 #define ResetSig        0x02

src/test/testvm.c

@@ -121,6 +121,49 @@ TEST test_boot_disk_bytes() {
     PASS();
 }
 
+// This test is fairly abusive ... it creates an ~88MB file in $HOME
+// ... but if it's correct, you're fairly assured the cpu/vm is working =)
+#define EXPECTED_CPU_TRACE_FILE_SIZE 87611579
+#define EXPECTED_CPU_TRACE_SHA "8DE74ED640E0CE4AB1AAC40E95BE9B8507A37434"
+TEST test_boot_disk_cputrace() {
+    setup_boot_disk();
+
+    char *homedir = getenv("HOME");
+    char *output = NULL;
+    asprintf(&output, "%s/a2_cputrace.raw", homedir);
+    if (output) {
+        unlink(output);
+        cpu65_trace_begin(output);
+    }
+
+    BOOT_TO_DOS();
+
+    cpu65_trace_end();
+    c_eject_6(0);
+
+    do {
+        uint8_t md[SHA_DIGEST_LENGTH];
+        char mdstr[(SHA_DIGEST_LENGTH*2)+1];
+
+        FILE *fp = fopen(output, "r");
+        char *buf = malloc(EXPECTED_CPU_TRACE_FILE_SIZE);
+        if (fread(buf, 1, EXPECTED_CPU_TRACE_FILE_SIZE, fp) != EXPECTED_CPU_TRACE_FILE_SIZE) {
+            ASSERT(false);
+        }
+        fclose(fp); fp = NULL;
+        SHA1(buf, EXPECTED_CPU_TRACE_FILE_SIZE, md);
+        FREE(buf);
+
+        sha1_to_str(md, mdstr);
+        ASSERT(strcmp(mdstr, EXPECTED_CPU_TRACE_SHA) == 0);
+    } while(0);
+
+    unlink(output);
+    FREE(output);
+
+    PASS();
+}
+
 TEST test_boot_disk() {
     setup_boot_disk();
 
@@ -3294,6 +3337,8 @@ GREATEST_SUITE(test_suite_vm) {
 
     RUN_TESTp(test_boot_disk_bytes);
 
+    RUN_TESTp(test_boot_disk_cputrace);
+
     RUN_TESTp(test_boot_disk);
 
     RUN_TESTp(test_read_keyboard);

src/x86/cpu.S

@@ -24,6 +24,25 @@
 #define DebugCurrOpcode SN(cpu65_opcode)
 #define DebugCycleCount SN(cpu65_opcycles)
 
+#if CPU_TRACING
+#   define TRACE_PROLOGUE \
+                callLQ  cpu65_trace_prologue;
+#   define TRACE_ARG \
+                callLQ  cpu65_trace_arg;
+#   define TRACE_ARG1 \
+                callLQ  cpu65_trace_arg1;
+#   define TRACE_ARG2 \
+                callLQ  cpu65_trace_arg2;
+#   define TRACE_EPILOGUE \
+                callLQ  cpu65_trace_epilogue;
+#else
+#   define TRACE_PROLOGUE
+#   define TRACE_ARG
+#   define TRACE_ARG1
+#   define TRACE_ARG2
+#   define TRACE_EPILOGUE
+#endif
+
 /* -------------------------------------------------------------------------
     CPU (6502) Helper Routines
    ------------------------------------------------------------------------- */
@@ -32,7 +51,8 @@
                 movLQ   PC_Reg_X, EffectiveAddr_X; \
                 incw    PC_Reg; \
                 SNX_PROLOGUE(cpu65_vmem_r); \
-                callLQ  *SNX(cpu65_vmem_r,EffectiveAddr_X,SZ_PTR);
+                callLQ  *SNX(cpu65_vmem_r,EffectiveAddr_X,SZ_PTR); \
+                TRACE_ARG;
 
 #define GetFromPC_W \
                 movLQ   PC_Reg_X, EffectiveAddr_X; \
@@ -41,11 +61,14 @@
                 SNX_PROLOGUE(cpu65_vmem_r); \
                 callLQ  *SNX(cpu65_vmem_r,EffectiveAddr_X,SZ_PTR); \
                 decw    EffectiveAddr; \
+                TRACE_ARG2; \
                 movb    %al, %ah; \
                 SNX_PROLOGUE(cpu65_vmem_r); \
-                callLQ  *SNX(cpu65_vmem_r,EffectiveAddr_X,SZ_PTR);
+                callLQ  *SNX(cpu65_vmem_r,EffectiveAddr_X,SZ_PTR); \
+                TRACE_ARG1;
 
 #define JumpNextInstruction \
+                TRACE_PROLOGUE; \
                 GetFromPC_B \
                 movb    %al, DebugCurrOpcode; \
                 movb    $0, DebugCycleCount; \
@@ -2105,6 +2128,7 @@ continue:
                 movb    SNX(cpu65__opcycles,_XAX,1), %al
                 addb    DebugCycleCount, %al
                 movb    %al, DebugCycleCount
+                TRACE_EPILOGUE
                 addw    %ax, SN(cpu65_cycle_count)
                 subl    %eax, SN(gc_cycles_timer_0)
                 subl    %eax, SN(gc_cycles_timer_1)