Write execution logs to a named log file (#409)

This patch adds a --log argument to spike. If not given, the behaviour
is unchanged: messages logging execution of instructions and (if
commit logging is enabled) commits go to stderr.

If --log=P is given, Spike now writes these messages to a log file at
the path P. This is nice, because they are no longer tangled up with
other errors and warnings.

The code is mostly plumbing: passing a FILE* object through to the
functions that were using stderr. I've written a simple "log_file_t"
class, which opens a log file if necessary and yields it or stderr.

1 files changed, 37 insertions, 27 deletions

diff --git a/riscv/execute.cc b/riscv/execute.cc
index 2d84242..ec0f479 100644
--- a/riscv/execute.cc
+++ b/riscv/execute.cc
@@ -20,41 +20,47 @@ static void commit_log_stash_privilege(processor_t* p)
   state->last_inst_flen = p->get_flen();
 }
 
-static void commit_log_print_value(int width, const void *data)
+static void commit_log_print_value(FILE *log_file, int width, const void *data)
 {
+  assert(log_file);
   const uint64_t *arr = (const uint64_t *)data;
 
-  fprintf(stderr, "0x");
+  fprintf(log_file, "0x");
   for (int idx = width / 64 - 1; idx >= 0; --idx) {
-    fprintf(stderr, "%016" PRIx64, arr[idx]);
+    fprintf(log_file, "%016" PRIx64, arr[idx]);
   }
 }
 
-static void commit_log_print_value(int width, uint64_t hi, uint64_t lo)
+static void commit_log_print_value(FILE *log_file,
+                                   int width, uint64_t hi, uint64_t lo)
 {
+  assert(log_file);
+
   switch (width) {
     case 8:
-      fprintf(stderr, "0x%01" PRIx8, (uint8_t)lo);
+      fprintf(log_file, "0x%01" PRIx8, (uint8_t)lo);
       break;
     case 16:
-      fprintf(stderr, "0x%04" PRIx16, (uint16_t)lo);
+      fprintf(log_file, "0x%04" PRIx16, (uint16_t)lo);
       break;
     case 32:
-      fprintf(stderr, "0x%08" PRIx32, (uint32_t)lo);
+      fprintf(log_file, "0x%08" PRIx32, (uint32_t)lo);
       break;
     case 64:
-      fprintf(stderr, "0x%016" PRIx64, lo);
+      fprintf(log_file, "0x%016" PRIx64, lo);
       break;
     case 128:
-      fprintf(stderr, "0x%016" PRIx64 "%016" PRIx64, hi, lo);
+      fprintf(log_file, "0x%016" PRIx64 "%016" PRIx64, hi, lo);
       break;
     default:
       abort();
   }
 }
 
-static void commit_log_print_insn(processor_t* p, reg_t pc, insn_t insn)
+static void commit_log_print_insn(processor_t *p, reg_t pc, insn_t insn)
 {
+  FILE *log_file = p->get_log_file();
+
   auto& reg = p->get_state()->log_reg_write;
   auto& load = p->get_state()->log_mem_read;
   auto& store = p->get_state()->log_mem_write;
@@ -62,11 +68,11 @@ static void commit_log_print_insn(processor_t* p, reg_t pc, insn_t insn)
   int xlen = p->get_state()->last_inst_xlen;
   int flen = p->get_state()->last_inst_flen;
 
-  fprintf(stderr, "%1d ", priv);
-  commit_log_print_value(xlen, 0, pc);
-  fprintf(stderr, " (");
-  commit_log_print_value(insn.length() * 8, 0, insn.bits());
-  fprintf(stderr, ")");
+  fprintf(log_file, "%1d ", priv);
+  commit_log_print_value(log_file, xlen, 0, pc);
+  fprintf(log_file, " (");
+  commit_log_print_value(log_file, insn.length() * 8, 0, insn.bits());
+  fprintf(log_file, ")");
   bool show_vec = false;
 
   for (auto item : reg) {
@@ -101,31 +107,31 @@ static void commit_log_print_insn(processor_t* p, reg_t pc, insn_t insn)
     }
 
     if (!show_vec && (is_vreg || is_vec)) {
-        fprintf(stderr, " e%ld m%ld l%ld", p->VU.vsew, p->VU.vlmul, p->VU.vl);
+        fprintf(log_file, " e%ld m%ld l%ld", p->VU.vsew, p->VU.vlmul, p->VU.vl);
         show_vec = true;
     }
 
     if (!is_vec) {
-      fprintf(stderr, " %c%2d ", prefix, rd);
+      fprintf(log_file, " %c%2d ", prefix, rd);
       if (is_vreg)
-        commit_log_print_value(size, &p->VU.elt<uint8_t>(rd, 0));
+        commit_log_print_value(log_file, size, &p->VU.elt<uint8_t>(rd, 0));
       else
-        commit_log_print_value(size, item.second.v[1], item.second.v[0]);
+        commit_log_print_value(log_file, size, item.second.v[1], item.second.v[0]);
     }
   }
 
   for (auto item : load) {
-    fprintf(stderr, " mem ");
-    commit_log_print_value(xlen, 0, std::get<0>(item));
+    fprintf(log_file, " mem ");
+    commit_log_print_value(log_file, xlen, 0, std::get<0>(item));
   }
 
   for (auto item : store) {
-    fprintf(stderr, " mem ");
-    commit_log_print_value(xlen, 0, std::get<0>(item));
-    fprintf(stderr, " ");
-    commit_log_print_value(std::get<2>(item) << 3, 0, std::get<1>(item));
+    fprintf(log_file, " mem ");
+    commit_log_print_value(log_file, xlen, 0, std::get<0>(item));
+    fprintf(log_file, " ");
+    commit_log_print_value(log_file, std::get<2>(item) << 3, 0, std::get<1>(item));
   }
-  fprintf(stderr, "\n");
+  fprintf(log_file, "\n");
 }
 #else
 static void commit_log_reset(processor_t* p) {}
@@ -150,9 +156,13 @@ static reg_t execute_insn(processor_t* p, reg_t pc, insn_fetch_t fetch)
 
   reg_t npc = fetch.func(p, fetch.insn, pc);
   if (npc != PC_SERIALIZE_BEFORE) {
-    if (p->get_log_commits()) {
+
+#ifdef RISCV_ENABLE_COMMITLOG
+    if (p->get_log_commits_enabled()) {
       commit_log_print_insn(p, pc, fetch.insn);
     }
+#endif
+
     p->update_histogram(pc);
   }
   return npc;