[draft / demo] Add network-enabled trace logging / add compact binary tracelog format

bsnes/Makefile

@@ -1,5 +1,7 @@
 common := ../common
 nall   := $(common)/nall
+zlib   := $(common)/zlib
+
 include $(nall)/Makefile
 snes := snes
 ifeq ($(ui),)
@@ -86,8 +88,27 @@ all: build plugins;
 include $(snes)/Makefile
 include $(ui)/Makefile
 
+
+############
+### zlib ###
+############
+
+$(objdir)/adler32.o : $(zlib)/adler32.c $(zlib)/*
+$(objdir)/crc32.o   : $(zlib)/crc32.c $(zlib)/*
+$(objdir)/inffast.o : $(zlib)/inffast.c $(zlib)/*
+$(objdir)/inflate.o : $(zlib)/inflate.c $(zlib)/*
+$(objdir)/inftrees.o: $(zlib)/inftrees.c $(zlib)/*
+$(objdir)/zutil.o   : $(zlib)/zutil.c $(zlib)/*
+$(objdir)/compress.o   : $(zlib)/compress.c $(zlib)/*
+$(objdir)/deflate.o   : $(zlib)/deflate.c $(zlib)/*
+$(objdir)/trees.o   : $(zlib)/trees.c $(zlib)/*
+
+# zlib
+objects += adler32 crc32 inffast inflate inftrees zutil compress deflate trees
+
 objects := $(patsubst %,$(objdir)/%.o,$(objects))
 
+
 # targets
 build: ui_build $(objects)
 ifeq ($(platform),osx)

bsnes/snes/cpu/core/disassembler/disassembler.cpp

@@ -154,6 +154,7 @@ void CPUcore::disassemble_opcode_ex(CPUcore::Opcode &opcode, uint32 addr, bool e
   }
 }
 
+// create a human-readable text version of the current opcode
 void CPUcore::disassemble_opcode(char *output, uint32 addr, bool hclocks) {
   static reg24_t pc;
   char t[256];
@@ -213,4 +214,81 @@ void CPUcore::disassemble_opcode(char *output, uint32 addr, bool hclocks) {
   strcat(s, t);
 }
 
-#endif
+// disassemble current opcode but represent as a binary format instead of text
+//
+// goals:
+// 1) be really fast
+// 2) be fixed length and easy to parse out later
+// 3) be as compact as possible. (abridgedFormat cuts even more stuff)
+// 4) be extensible (use a header length so we can add more info later)
+void CPUcore::disassemble_opcode_bin(char* buf, uint32 addr, int &len_out, bool abridgedFormat) {
+    static reg24_t pc;
+
+    pc.d = addr;
+    uint8 opcode = dreadb(pc.d);
+    unsigned opcode_len = SNESCPU::getOpcodeLength((regs.e || regs.p.m), (regs.e || regs.p.x), opcode);
+
+    int i = 0;
+
+    // --- header (2 bytes) ---
+
+    // watermark identifying the type of data coming next
+    buf[i++] = abridgedFormat ? 0xEE : 0xEF;
+
+    // size in bytes of data starting after this byte (we will populate final size at the end)
+    int sizeIdx = i; i++;
+
+    // --- data ---
+    buf[i++] = (addr >> 0) & 0xFF;
+    buf[i++] = (addr >> 8) & 0xFF;
+    buf[i++] = (addr >> 16) & 0xFF;
+
+    // # of bytes for the instruction we're looking at
+    buf[i++] = opcode_len; // valid values: 1,2,3,4
+
+    buf[i++] = (regs.d.w >> 0) & 0xFF;
+    buf[i++] = (regs.d.w >> 8) & 0xFF;
+
+    buf[i++] = (regs.db) & 0xFF;
+
+    buf[i++] = (regs.p) & 0xFF; // 8 flags stored as bitmask in 1 byte
+
+    if (!abridgedFormat) {
+        // we'll always transmit 4 bytes, but, consumers should only use up to 'opcode_len'
+        // and discard the remaining bytes.
+        // i.e. if opcode_len is 2,
+        // then a consumer should USE opcode and operand0 (2 bytes)
+        // then read but discard the remaining 2 bytes (operand1 and operand2 will be garbage)
+        pc.w++;
+        uint8 operand0 = dreadb(pc.d); pc.w++;
+        uint8 operand1 = dreadb(pc.d); pc.w++;
+        uint8 operand2 = dreadb(pc.d);
+
+        buf[i++] = opcode;      // always valid (opcode_len >= 1)
+        buf[i++] = operand0;    // valid if opcode_len >= 2
+        buf[i++] = operand1;    // valid if opcode_len >= 3
+        buf[i++] = operand2;    // valid if opcode_len == 4
+
+        buf[i++] = (regs.a.w >> 0) & 0xFF;
+        buf[i++] = (regs.a.w >> 8) & 0xFF;
+
+        buf[i++] = (regs.x.w >> 0) & 0xFF;
+        buf[i++] = (regs.x.w >> 8) & 0xFF;
+
+        buf[i++] = (regs.y.w >> 0) & 0xFF;
+        buf[i++] = (regs.y.w >> 8) & 0xFF;
+
+        buf[i++] = (regs.s.w >> 0) & 0xFF;
+        buf[i++] = (regs.s.w >> 8) & 0xFF;
+
+        buf[i++] = (regs.e) & 0xFF; // emu flag
+
+        // TODO: hclocks/etc if we want them.
+    }
+
+    // put the length of everything back in the header
+    len_out = i;
+    buf[sizeIdx] = len_out - sizeIdx - 1;
+}
+
+#endif

bsnes/snes/cpu/core/disassembler/disassembler.hpp

@@ -73,6 +73,7 @@ struct Opcode {
 
 void   disassemble_opcode(char *output, uint32 addr, bool hclocks = false);
 void   disassemble_opcode_ex(Opcode &opcode, uint32 addr, bool e, bool m, bool x);
+void   disassemble_opcode_bin(char* buf, uint32 addr, int &len_out, bool abridgedFormat=true);
 uint8  dreadb(uint32 addr);
 uint16 dreadw(uint32 addr);
 uint32 dreadl(uint32 addr);

bsnes/ui-qt/debugger/debugger.cpp

@@ -1,3 +1,12 @@
+#include <winsock2.h>
+#include <windows.h>
+#include <ws2tcpip.h>
+#include <stdlib.h>
+#include <stdio.h>
+
+// TODO: for demo only. not the right way to do this.
+#pragma comment (lib, "Ws2_32.lib")
+
 #include "../ui-base.hpp"
 
 #if defined(DEBUGGER)
@@ -687,6 +696,7 @@ void Debugger::frameTick() {
 
   if (frame < frameCounter) {
     autoUpdate();
+    tracer->flushTraceOutput();
   } else {
     // update memory editor every time since once per second isn't very useful
     // (TODO: and PPU viewers, maybe?) 

bsnes/ui-qt/debugger/tracer.cpp

@@ -1,13 +1,111 @@
 #include "tracer.moc"
 Tracer *tracer;
 
+#include "w32_socket.cpp"
+
+// TODO: demo only: make these checkboxes in the UI or config options
+
+// tracer output info format
+// false: binary format (small/faster),
+// true:  text format (easier to parse / but slower and HUGE))
+const bool traceOutputFormatIsText = false;
+
+// where trace output will be sent
+// true: listen on a socket port and stream data to a client
+// false: output via a logfile on disk
+const bool traceOutputMediumIsSocket = true;
+
+#define DEFAULT_TRACE_SERVER_LISTEN_PORT "27015"
+
+void Tracer::outputTrace(const char* buf, int len) {
+    outputTraceToFile(buf, len);
+    outputTraceToSocket(buf, len);
+}
+
+void Tracer::outputTraceToFile(const char *buf, int len) {
+    if (!tracefile.open())
+        return;
+
+    // perf: without trask masking, this is SUPER SLOW, grinds the emulation to 2FPS when enabled.
+    // TODO: there's probably some easy way to improve performance here, like buffering and async IO calls.
+    // this chews on gigs of data quickly, so whatever you do, be mindful of performance.
+    //
+    tracefile.write(reinterpret_cast<const uint8_t *>(buf), len);
+    if (traceOutputFormatIsText)
+        tracefile.print("\n");
+}
+
+void Tracer::outputTraceToSocket(const char *buf, int len) {
+    if (!traceServer.IsInitialized())
+        return;
+
+    traceServer.Push((const uint8_t*)buf, len);
+}
+
+void Tracer::outputCpuTrace() {
+    char buf[256]; int len; // TODO: bounds check buf/len, make sure we don't overflow
+    if (traceOutputFormatIsText) {
+        SNES::cpu.disassemble_opcode(buf, SNES::cpu.regs.pc, config().debugger.showHClocks); // text
+        len = strlen(buf) + 1; // null terminator
+    } else {
+        SNES::cpu.disassemble_opcode_bin(buf, SNES::cpu.regs.pc, len); // binary
+    }
+    outputTrace(buf, len);
+}
+
+void Tracer::outputSmpTrace() {
+    char buf[256]; int len;
+    if (traceOutputFormatIsText) {
+        SNES::smp.disassemble_opcode(buf, SNES::cpu.regs.pc);
+        len = strlen(buf) + 1; // byte size = string + null term
+    } else {
+        // TODO: implement // SNES::smp.disassemble_opcode_bin(buf, SNES::cpu.regs.pc, len); // binary
+        return; // TODO: not supported just yet
+    }
+    outputTrace(buf, len);
+}
+
+void Tracer::outputSa1Trace() {
+    char buf[256]; int len;
+    if (traceOutputFormatIsText) {
+        SNES::sa1.disassemble_opcode(buf, SNES::cpu.regs.pc, config().debugger.showHClocks);
+        len = strlen(buf) + 1; // byte size = string + null term
+    } else {
+        // TODO: implement // SNES::sa1.disassemble_opcode_bin(buf, SNES::cpu.regs.pc, config().debugger.showHClocks, len); // binary
+        return; // TODO: not supported just yet
+    }
+    outputTrace(buf, len);
+}
+
+void Tracer::outputSfxTrace() {
+    char buf[256]; int len;
+    if (traceOutputFormatIsText) {
+        SNES::superfx.disassemble_opcode(buf, SNES::cpu.regs.pc);
+        len = strlen(buf) + 1; // byte size = string + null term
+    } else {
+        // TODO: implement // SNES::superfx.disassemble_opcode_bin(buf, SNES::cpu.regs.pc, len); // binary
+        return; // TODO: not supported just yet
+    }
+    outputTrace(buf, len);
+}
+
+void Tracer::outputSgbTrace() {
+    char buf[256]; int len;
+    if (traceOutputFormatIsText) {
+        SNES::supergameboy.disassemble_opcode(buf, SNES::cpu.regs.pc);
+        len = strlen(buf) + 1; // byte size = string + null term
+    } else {
+        // TODO: implement // SNES::supergameboy.disassemble_opcode_bin(buf, SNES::cpu.regs.pc, len); // binary
+        return; // TODO: not supported just yet
+    }
+    outputTrace(buf, len);
+}
+
 void Tracer::stepCpu() {
   if(traceCpu) {
     unsigned addr = SNES::cpu.regs.pc;
     if(!traceMask || !(traceMaskCPU[addr >> 3] & (0x80 >> (addr & 7)))) {
-      char text[256];
-      SNES::cpu.disassemble_opcode(text, addr, config().debugger.showHClocks);
-      tracefile.print(string() << text << "\n");
+        outputCpuTrace();
     }
     traceMaskCPU[addr >> 3] |= 0x80 >> (addr & 7);
   }
@@ -17,9 +115,7 @@ void Tracer::stepSmp() {
   if(traceSmp) {
     unsigned addr = SNES::smp.regs.pc;
     if(!traceMask || !(traceMaskSMP[addr >> 3] & (0x80 >> (addr & 7)))) {
-      char text[256];
-      SNES::smp.disassemble_opcode(text, addr);
-      tracefile.print(string() << text << "\n");
+        outputSmpTrace();
     }
     traceMaskSMP[addr >> 3] |= 0x80 >> (addr & 7);
   }
@@ -29,9 +125,7 @@ void Tracer::stepSa1() {
   if(traceSa1) {
     unsigned addr = SNES::sa1.regs.pc;
     if(!traceMask || !(traceMaskSA1[addr >> 3] & (0x80 >> (addr & 7)))) {
-      char text[256];
-      SNES::sa1.disassemble_opcode(text, addr, config().debugger.showHClocks);
-      tracefile.print(string() << text << "\n");
+        outputSa1Trace();
     }
     traceMaskSA1[addr >> 3] |= 0x80 >> (addr & 7);
   }
@@ -41,9 +135,7 @@ void Tracer::stepSfx() {
   if(traceSfx) {
     unsigned addr = SNES::superfx.opcode_pc;
     if(!traceMask || !(traceMaskSFX[addr >> 3] & (0x80 >> (addr & 7)))) {
-      char text[256];
-      SNES::superfx.disassemble_opcode(text, addr);
-      tracefile.print(string() << text << "\n");
+        outputSfxTrace();
     }
     traceMaskSFX[addr >> 3] |= 0x80 >> (addr & 7);
   }
@@ -53,30 +145,51 @@ void Tracer::stepSgb() {
   if(traceSgb) {
     unsigned addr = SNES::supergameboy.opcode_pc;
     if(!traceMask || !(traceMaskSGB[addr >> 3] & (0x80 >> (addr & 7)))) {
-      char text[256];
-      SNES::supergameboy.disassemble_opcode(text, addr);
-      tracefile.print(string() << text << "\n");
+        outputSgbTrace();
     }
     traceMaskSGB[addr >> 3] |= 0x80 >> (addr & 7);
   }
 }
 
 void Tracer::resetTraceState() {
   tracefile.close();
+  traceServer.Shutdown();
+
   setTraceState(traceCpu || traceSmp || traceSa1 || traceSfx || traceSgb);
 
   // reset trace masks
   if (traceMask)
     setTraceMaskState(true);
 }
 
+void Tracer::ensureTraceOutputReady() {
+    if (!traceOutputMediumIsSocket && !tracefile.open()) {
+        string name = filepath(nall::basename(cartridge.fileName), config().path.data);
+        name << "-trace.log";
+        tracefile.open(name, file::mode::write);
+    }
+
+    if (traceOutputMediumIsSocket && !traceServer.IsInitialized()) {
+        // demo: this blocks the entire UI while waiting for a client to connect (not great, better ways to handle)
+        traceServer.Init(DEFAULT_TRACE_SERVER_LISTEN_PORT);
+    }
+}
+
+void Tracer::ensureTraceOutputShutdown() {
+    if (tracefile.open()) {
+        tracefile.close();
+    }
+
+    if (traceServer.IsInitialized()) {
+        traceServer.Shutdown();
+    }
+}
+
 void Tracer::setTraceState(bool state) {
-  if(state && !tracefile.open() && SNES::cartridge.loaded()) {
-    string name = filepath(nall::basename(cartridge.fileName), config().path.data);
-    name << "-trace.log";
-    tracefile.open(name, file::mode::write);
-  } else if(!traceCpu && !traceSmp && !traceSa1 && !traceSfx && !traceSgb && tracefile.open()) {
-    tracefile.close();
+  if(state && SNES::cartridge.loaded()) {
+      ensureTraceOutputReady();
+  } else if(!traceCpu && !traceSmp && !traceSa1 && !traceSfx && !traceSgb) {
+      ensureTraceOutputShutdown();
   }
 }
 
@@ -146,3 +259,7 @@ Tracer::~Tracer() {
   delete[] traceMaskSGB;
   if(tracefile.open()) tracefile.close();
 }
+
+void Tracer::flushTraceOutput() {
+    traceServer.FlushWorkingBuffer();
+}