diff --git a/.gitignore b/.gitignore index 3902eb0b..4854b162 100644 --- a/.gitignore +++ b/.gitignore @@ -5,6 +5,7 @@ *.d *.pyc *.ini +*.log tags cscope.* build/ diff --git a/am/amtrace.h b/am/amtrace.h index e702852d..3ddfd0e1 100644 --- a/am/amtrace.h +++ b/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 diff --git a/am/arch/x86-qemu/src/trace.c b/am/arch/x86-qemu/src/trace.c index cd7f2e5c..62a20a0f 100644 --- a/am/arch/x86-qemu/src/trace.c +++ b/am/arch/x86-qemu/src/trace.c @@ -11,15 +11,57 @@ void _trace_off(uint32_t flags) { trace_flags &= ~flags; } -#include // 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))) diff --git a/tests/tracetest/Makefile b/tests/tracetest/Makefile index 0c28de35..699ebc8b 100644 --- a/tests/tracetest/Makefile +++ b/tests/tracetest/Makefile @@ -1,3 +1,3 @@ -NAME = main +NAME = tracetest SRCS = main.c include $(AM_HOME)/Makefile.app diff --git a/tests/tracetest/run b/tests/tracetest/run new file mode 100755 index 00000000..56616b7d --- /dev/null +++ b/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