add binary output trace to COM2

.gitignore

@@ -5,6 +5,7 @@
 *.d
 *.pyc
 *.ini
+*.log
 tags
 cscope.*
 build/

am/amtrace.h

@@ -12,24 +12,25 @@ typedef union _Payload {
 } _CallPayload;
 
 struct _TraceEvent {
-  uint16_t cpu;
-  uint16_t type;
-  uint32_t time;
-  uintptr_t ref;
-  char payload[];
+  uint16_t cpu;   // cpu id (0 based)
+  uint16_t type;  // _TRACE_ ## { CALL | RET }
+  uint32_t time;  // time stamp
+  uintptr_t ref;  // a pointer
+  char payload[]; // _Payload: CALL -> .args
+                  //            RET -> .retval
 } __attribute__((packed));
 typedef struct _TraceEvent _TraceEvent;
 
 // ========================= trace components ========================
 
-#define _TRACE_IOE     0x00000001
-#define _TRACE_ASYE    0x00000002
-#define _TRACE_PTE     0x00000004
+#define _TRACE_IOE     0x00010000
+#define _TRACE_ASYE    0x00020000
+#define _TRACE_PTE     0x00040000
 
 // =========================== trace points ==========================
 
-#define _TRACE_CALL    0x00010000
-#define _TRACE_RET     0x00020000
+#define _TRACE_CALL    0x00000001
+#define _TRACE_RET     0x00000002
 #define _TRACE_FUNC    (_TRACE_CALL | _TRACE_RET)
 
 #define _TRACE_ALL     0xffffffff

am/arch/x86-qemu/src/trace.c

@@ -11,15 +11,57 @@ void _trace_off(uint32_t flags) {
   trace_flags &= ~flags;
 }
 
-#include <klib.h> // TODO: find a better way to write trace logs
+#define COM2_PORT 0x2f8
+
+volatile intptr_t lock = 1;
+
+static inline void log_lock() {
+  while (1) {
+    intptr_t val = _atomic_xchg(&lock, 0);
+    if (val == 1) {
+      break;
+    }
+    asm volatile ("pause");
+  }
+}
+
+static inline void log_unlock(){
+  _atomic_xchg(&lock, 1);
+}
+
+static inline void log_byte(uint8_t ch) {
+  while ( (inb(COM2_PORT + 5) & 0x20) == 0 ) {
+    // TODO: see if this happens in practice
+    panic("writing to file serial port fail");
+  }
+  outb(COM2_PORT, ch);
+}
+
+static inline void log_ev(_TraceEvent ev, int length, void *ptr) {
+  log_lock();
+  for (int i = 0; i < sizeof(ev); i++) {
+    log_byte(((char *)&ev)[i]);
+  }
+  for (int i = 0; i < length; i++) {
+    log_byte(((char *)ptr)[i]);
+  }
+  log_unlock();
+}
+
+static int tsc = 0;
+
+#define EV(_type, _ref) \
+  (_TraceEvent) { \
+    .cpu = (uint16_t)_cpu(), \
+    .type = _type, \
+    .time = tsc++, \
+    .ref = (uintptr_t)_ref }
 
 #define TRACE_CALL(fn, args) \
   do { \
     uint32_t flags = trace_flags; \
     if (SHOULD_TRACE(flags, _TRACE_CALL)) { \
-      printf("[trace] call  " #fn \
-             " (%x) with args {%x, %x, %x, %x}\n", (void *)fn, \
-        args.a0, args.a1, args.a2, args.a3); \
+      log_ev(EV(_TRACE_CALL, fn), sizeof(args), &args); \
     } \
   } while (0)
 
@@ -27,11 +69,13 @@ void _trace_off(uint32_t flags) {
   do { \
     uint32_t flags = trace_flags; \
     if (SHOULD_TRACE(flags, _TRACE_RET)) { \
-      printf("[trace]  ret  " #fn " (%x) -> %x\n", \
-             (void *)fn, (uintptr_t)retval); \
+      uintptr_t v = (uintptr_t)retval; \
+      log_ev(EV(_TRACE_RET, fn), sizeof(uintptr_t), &v); \
     } \
   } while (0)
 
+// ========================= trace wrappers ==========================
+
 #define SHOULD_TRACE(flags, require) \
   (((flags) & TRACE_THIS) && ((flags) & (require)))
 

tests/tracetest/Makefile

@@ -1,3 +1,3 @@
-NAME = main
+NAME = tracetest
 SRCS = main.c
 include $(AM_HOME)/Makefile.app

tests/tracetest/run

@@ -0,0 +1,8 @@
+#!/bin/bash
+make ARCH=x86-qemu && \
+qemu-system-i386 \
+  -chardev stdio,mux=on,id=char0 \
+  -chardev file,path=trace.log,id=char1 \
+  -serial chardev:char0 \
+  -serial chardev:char1 \
+  build/tracetest-x86-qemu