pa2.2: add ftrace

flake.nix

@@ -65,6 +65,7 @@
         devShells.nemu = pkgs.mkShell {
           packages = with pkgs; [
             clang-tools
+            gdb
           ];
           inputsFrom = [
             self.packages.${system}.nemu

nemu/Kconfig

@@ -143,8 +143,11 @@ config TRACE_END
 
 config ITRACE
   depends on TRACE && TARGET_NATIVE_ELF && ENGINE_INTERPRETER
-  bool "Enable instruction tracer"
+  bool "Enable instruction tracing"
   default y
+  help
+    Instraction tracing will log past instructions into a ring buffer
+    and print them when NEMU exit unexpectedly.
 
 config ITRACE_COND
   depends on ITRACE
@@ -158,8 +161,8 @@ config ITRACE_BUFFER
 
 config MTRACE
   depends on TRACE && TARGET_NATIVE_ELF && ENGINE_INTERPRETER
-  bool "Enable memory tracer"
+  bool "Enable memory tracing"
-
+  default n
 
 config MTRACE_RANGE
   depends on MTRACE
@@ -174,6 +177,21 @@ config MTRACE_RANGE_MAX
   int "Max range count in MTRACE_RANGE"
   default 10
 
+config FTRACE
+  depends on TRACE && TARGET_NATIVE_ELF && ENGINE_INTERPRETER
+  bool "Enable function tracing"
+  default y
+
+config FTRACE_STACK_SIZE
+  depends on FTRACE
+  int "Max function track stack size"
+  default 100
+
+config FTRACE_LOG
+  depends on FTRACE
+  bool "Print log when entering a funciton"
+  default n
+
 config DIFFTEST
   depends on TARGET_NATIVE_ELF
   bool "Enable differential testing"

nemu/include/ftrace.h

@@ -0,0 +1,18 @@
+#ifndef __FUNC_DEF_H__
+#define __FUNC_DEF_H__
+#include <common.h>
+
+#ifdef CONFIG_FTRACE
+typedef struct {
+  vaddr_t start;
+  vaddr_t len;
+  char * name;
+} func_t;
+
+extern func_t *func_table;
+void ftrace_call(vaddr_t, vaddr_t);
+void ftrace_return(vaddr_t, vaddr_t);
+// const char *get_func_name(vaddr_t addr);
+#endif
+
+#endif

nemu/include/macro.h

@@ -92,6 +92,8 @@
 
 #define PG_ALIGN __attribute((aligned(4096)))
 
+#define FAILED_GOTO(tag, exp) do {if((exp)) goto tag;} while(0)
+
 #if !defined(likely)
 #define likely(cond)   __builtin_expect(cond, 1)
 #define unlikely(cond) __builtin_expect(cond, 0)

nemu/src/isa/riscv32/inst.c

@@ -18,6 +18,7 @@
 #include <cpu/cpu.h>
 #include <cpu/ifetch.h>
 #include <cpu/decode.h>
+#include <ftrace.h>
 
 #define R(i) gpr(i)
 #define Mr vaddr_read
@@ -59,6 +60,16 @@ static void do_branch(Decode *s, bool condition, word_t offset) {
   }
 }
 
+static void ftrace(Decode *s, int rd, vaddr_t dst) {
+  uint32_t i = s->isa.inst.val;
+  int rs1 = BITS(i, 19, 15);
+  if(rs1 == 1 && rd == 0) {
+    ftrace_return(s->pc, dst);
+  } else {
+    ftrace_call(s->pc, dst);
+  }
+}
+
 static int decode_exec(Decode *s) {
   int rd = 0;
   word_t src1 = 0, src2 = 0, imm = 0;
@@ -74,8 +85,8 @@ static int decode_exec(Decode *s) {
   INSTPAT("??????? ????? ????? ??? ????? 01101 11", lui    , U, R(rd) = imm);
   INSTPAT("??????? ????? ????? ??? ????? 00101 11", auipc  , U, R(rd) = s->pc + imm);
 
-  INSTPAT("??????? ????? ????? ??? ????? 11011 11", jal    , J, do {s->dnpc = s->pc + imm; R(rd) = s->pc + 4; } while(0));
+  INSTPAT("??????? ????? ????? ??? ????? 11011 11", jal    , J, do {s->dnpc = s->pc + imm; R(rd) = s->pc + 4; ftrace_call(s->pc, s->pc + imm); } while(0));
-  INSTPAT("??????? ????? ????? ??? ????? 11001 11", jalr   , I, do {s->dnpc = src1 + imm; R(rd) = s->pc + 4; } while(0));
+  INSTPAT("??????? ????? ????? ??? ????? 11001 11", jalr   , I, do {s->dnpc = src1 + imm; R(rd) = s->pc + 4; ftrace(s, rd, src1 + imm); } while(0));
   INSTPAT("??????? ????? ????? 000 ????? 11000 11", beq    , B, do_branch(s, src1 == src2, imm));
   INSTPAT("??????? ????? ????? 001 ????? 11000 11", bne    , B, do_branch(s, src1 != src2, imm));
   INSTPAT("??????? ????? ????? 100 ????? 11000 11", blt    , B, do_branch(s, (sword_t)src1 < (sword_t)src2, imm));

nemu/src/monitor/monitor.c

@@ -40,6 +40,7 @@ static void welcome() {
 void sdb_set_batch_mode();
 
 static char *log_file = NULL;
+static char *elf_file = NULL;
 static char *diff_so_file = NULL;
 static char *img_file = NULL;
 static int difftest_port = 1234;
@@ -72,6 +73,7 @@ static int parse_args(int argc, char *argv[]) {
     {"log"      , required_argument, NULL, 'l'},
     {"diff"     , required_argument, NULL, 'd'},
     {"port"     , required_argument, NULL, 'p'},
+    {"elf"      , required_argument, NULL, 'f'},
     {"help"     , no_argument      , NULL, 'h'},
     {0          , 0                , NULL,  0 },
   };
@@ -82,6 +84,7 @@ static int parse_args(int argc, char *argv[]) {
       case 'p': sscanf(optarg, "%d", &difftest_port); break;
       case 'l': log_file = optarg; break;
       case 'd': diff_so_file = optarg; break;
+      case 'f': elf_file = optarg; break;
       case 1: img_file = optarg; return 0;
       default:
         printf("Usage: %s [OPTION...] IMAGE [args]\n\n", argv[0]);
@@ -89,6 +92,7 @@ static int parse_args(int argc, char *argv[]) {
         printf("\t-l,--log=FILE           output log to FILE\n");
         printf("\t-d,--diff=REF_SO        run DiffTest with reference REF_SO\n");
         printf("\t-p,--port=PORT          run DiffTest with port PORT\n");
+        printf("\t-f,--elf=FILE           elf file with debug info\n");
         printf("\n");
         exit(0);
     }
@@ -126,6 +130,12 @@ void init_monitor(int argc, char *argv[]) {
   /* Initialize the simple debugger. */
   init_sdb();
 
+  // printf("elf_file: %s\n", elf_file);
+  if(elf_file != NULL) {
+    void init_elf(const char *path);
+    init_elf(elf_file);
+  }
+
 #ifndef CONFIG_ISA_loongarch32r
   IFDEF(CONFIG_ITRACE, init_disasm(
     MUXDEF(CONFIG_ISA_x86,     "i686",

nemu/src/utils/ftrace.c

@@ -0,0 +1,125 @@
+#include "debug.h"
+#include "macro.h"
+#include <assert.h>
+#include <common.h>
+#include <elf.h>
+#include <ftrace.h>
+
+// Put this into another file
+#ifdef CONFIG_FTRACE
+static vaddr_t ftrace_stack[CONFIG_FTRACE_STACK_SIZE] = {0};
+static vaddr_t ftrace_stack_len = 0;
+func_t *func_table = NULL;
+int func_table_len = 0, func_table_size = 8;
+#endif
+
+static int cmp_func_t(const void *a, const void *b) {
+  return ((func_t *)a)->start > ((func_t *)b)->start;
+}
+
+static func_t *get_func(vaddr_t addr) {
+  int l = 0, r = func_table_len - 1;
+  while(l <= r) {
+    int mid = (l + r) / 2;
+    if(func_table[mid].start <= addr)  l = mid + 1;
+    else r = mid - 1;
+  }
+  return l == 0 ? NULL : &func_table[l - 1];
+}
+
+void init_elf(const char *path) {
+  FILE *elf_file = fopen(path, "rb");
+  Elf32_Ehdr header;
+  Elf32_Shdr section_header[200], *psh;
+
+  func_table = (func_t *)calloc(func_table_size, sizeof(func_t));
+  assert(func_table);
+
+  FAILED_GOTO(failed_header, fread(&header, sizeof(Elf32_Ehdr), 1, elf_file) <= 0);
+  FAILED_GOTO(failed_header, fseek(elf_file, header.e_shoff, SEEK_SET) != 0);
+  FAILED_GOTO(failed_header, fread(section_header, header.e_shentsize, header.e_shnum, elf_file) <= 0);
+
+  char *shstrtab = calloc(1, section_header[header.e_shstrndx].sh_size);
+  FAILED_GOTO(failed_shstrtab, fseek(elf_file, section_header[header.e_shstrndx].sh_offset, SEEK_SET) != 0);
+  FAILED_GOTO(failed_shstrtab, fread(shstrtab, section_header[header.e_shstrndx].sh_size, 1, elf_file) <= 0);
+
+  Elf32_Shdr *symtab = NULL, *strtab = NULL;
+  for(int i = 0; i < header.e_shnum; i++) {
+    psh = section_header + i;
+    if (psh->sh_type == SHT_SYMTAB) {
+      symtab = psh;
+    } else if (psh->sh_type == SHT_STRTAB && strncmp(shstrtab + psh->sh_name, ".strtab", 8) == 0) {
+      strtab = psh;
+    }
+  }
+
+  int sym_length = symtab->sh_size / sizeof(Elf32_Sym);
+  Elf32_Sym *sym = calloc(sym_length, sizeof(Elf32_Sym));
+  assert(sym);
+  FAILED_GOTO(failed_funcname, fseek(elf_file, symtab->sh_offset, SEEK_SET) != 0);
+  FAILED_GOTO(failed_funcname, fread(sym, sizeof(Elf32_Sym), sym_length, elf_file) <= 0);
+  
+  for(int j = 0; j < sym_length; j++) {
+    if(ELF32_ST_TYPE(sym[j].st_info) != STT_FUNC) continue;
+    // Only read function type symbol
+    func_t *f = &func_table[func_table_len];
+    char *func = (char *)malloc(30);
+    FAILED_GOTO(failed_funcname, fseek(elf_file, strtab->sh_offset + sym[j].st_name, SEEK_SET) != 0);
+    FAILED_GOTO(failed_funcname, fgets(func, 30, elf_file) <= 0);
+    f->start = sym[j].st_value;
+    f->len = sym[j].st_size;
+    f->name = func;
+    ++func_table_len;
+    if(func_table_len >= func_table_size) {
+      Assert(func_table_size * 2 > func_table_size, "Function table exceed memory limit");
+      func_table_size *= 2;
+      func_table = realloc(func_table, func_table_size * sizeof(func_t));
+      Assert(func_table, "Function table exceed memory limit");
+    }
+  }
+  qsort(func_table, func_table_len, sizeof(func_t), cmp_func_t);
+  goto success;
+
+success:
+  free(sym);
+  free(shstrtab);
+  return;
+
+failed_funcname:
+  free(sym);
+failed_shstrtab:
+  free(shstrtab);
+failed_header:
+  for(int i = 0; i < func_table_len; i++) {
+    func_t *f = &func_table[i];
+    if(f->name) { free(f->name); }
+  } 
+  free(func_table);
+  Error("Failed reading elf file");
+  return;
+}
+
+void ftrace_call(vaddr_t pc, vaddr_t addr) {
+  func_t *f = get_func(addr);
+  Assert(ftrace_stack_len < CONFIG_FTRACE_STACK_SIZE,
+         "Ftrace stack exceed size limit, consider turn off ftrace or increase "
+         "FTRACE_STACK_SIZE.");
+  ftrace_stack[ftrace_stack_len] = pc + 4;
+  Trace("%*s0x%x call 0x%x <%s+0x%x>", ftrace_stack_len, "", pc, addr,
+        f == NULL ? "???" : f->name, addr - f->start);
+  ftrace_stack_len++;
+}
+
+void ftrace_return(vaddr_t pc, vaddr_t addr) {
+  --ftrace_stack_len;
+  for (; addr != ftrace_stack[ftrace_stack_len] && ftrace_stack_len >= 0;
+       ftrace_stack_len--) {
+    vaddr_t tco_addr = ftrace_stack[ftrace_stack_len];
+    func_t *f = get_func(tco_addr);
+    Trace("%*s0x%x ret 0x%x <%s+0x%x> (TCO)", ftrace_stack_len, "", pc, tco_addr,
+          f == NULL ? "???" : f->name, tco_addr - f->start);
+  }
+  func_t *f = get_func(addr);
+  Trace("%*s0x%x ret 0x%x <%s+0x%x>", ftrace_stack_len, "", pc, addr, 
+        f == NULL ? "???" : f->name, addr - f->start);
+}