fix(snprintf),refactor(small/fast log): fix truncated writing warning…

…, refactor output to log file When snprintf dest buffer is a static array with fixed length, and src also a static array with fixed length, compiler will tell if there will be a write truncation and warn about it. This commit could fix this warn. The logic for outputting the log to a file was a bit hard to understand, refactored this part of the code. Signed-off-by: jiaxiaoyu <[email protected]>
OpenXiangShan · Sep 19, 2024 · bfadef0 · bfadef0
1 parent 0bcc737
commit bfadef0
Show file tree

Hide file tree

Showing 9 changed files with 104 additions and 59 deletions.
diff --git a/include/cpu/decode.h b/include/cpu/decode.h
@@ -44,6 +44,10 @@ enum {
   INSTR_TYPE_I, // indirect
 };
 
+IFDEF(CONFIG_DEBUG, extern char log_bytebuf[80];)
+// max size is (strlen(str(instr)) + strlen(suffix_char(id_dest->width)) + sizeof(id_dest->str) + sizeof(id_src2->str) + sizeof(id_src1->str))
+IFDEF(CONFIG_DEBUG, extern char log_asmbuf[80 + (sizeof(((Operand*)0)->str) * 3)]);
+
 typedef struct Decode {
   union {
     struct {
@@ -64,7 +68,7 @@ typedef struct Decode {
   uint16_t idx_in_bb; // the number of instruction in the basic block, start from 1
   uint8_t type;
   ISADecodeInfo isa;
-  IFDEF(CONFIG_DEBUG, char logbuf[80]);
+  IFDEF(CONFIG_DEBUG, char logbuf[80 + sizeof(log_asmbuf) + sizeof(log_bytebuf)]);
   #ifdef CONFIG_RVV
   // for vector
   int v_width;
@@ -178,7 +182,6 @@ static inline void pattern_decode(const char *str, int len,
 #define def_INSTR_TABW(pattern, tab, width) def_INSTR_IDTABW(pattern, empty, tab, width)
 #define def_INSTR_TAB(pattern, tab)         def_INSTR_IDTABW(pattern, empty, tab, 0)
 
-
 #define print_Dop(...) IFDEF(CONFIG_DEBUG, snprintf(__VA_ARGS__))
 #define print_asm(...) IFDEF(CONFIG_DEBUG, snprintf(log_asmbuf, sizeof(log_asmbuf), __VA_ARGS__))
 
@@ -187,20 +190,20 @@ static inline void pattern_decode(const char *str, int len,
 #endif
 
 #define print_asm_template0(instr) \
-  print_asm(str(instr) "%c", suffix_char(id_dest->width))
+  print_asm("%s %c", str(instr), suffix_char(id_dest->width))
 
 #define print_asm_template1(instr) \
-  print_asm(str(instr) "%c %s", suffix_char(id_dest->width), id_dest->str)
+  print_asm("%s %c %s", str(instr), suffix_char(id_dest->width), id_dest->str)
 
 #define print_asm_template2(instr) \
-  print_asm(str(instr) "%c %s,%s", suffix_char(id_dest->width), id_dest->str, id_src1->str)
+  print_asm("%s %c %s,%s", str(instr), suffix_char(id_dest->width), id_dest->str, id_src1->str)
 
 #define print_asm_template3(instr) \
-  print_asm(str(instr) "%c %s,%s,%s", suffix_char(id_dest->width), id_dest->str, id_src1->str, id_src2->str)
+  print_asm("%s %c %s,%s,%s", str(instr), suffix_char(id_dest->width), id_dest->str, id_src1->str, id_src2->str)
 
 #if defined(CONFIG_ISA_riscv64) || defined(CONFIG_ISA_riscv32)
 #define print_asm_template3_csr(instr) \
-  print_asm(str(instr) "%c %s,%s,%s", suffix_char(id_dest->width), id_dest->str, id_src2->str, id_src1->str)
+  print_asm("%s %c %s,%s,%s", str(instr), suffix_char(id_dest->width), id_dest->str, id_src2->str, id_src1->str)
 #endif
 
 #endif
diff --git a/include/cpu/ifetch.h b/include/cpu/ifetch.h
@@ -26,6 +26,7 @@ static inline uint32_t instr_fetch(vaddr_t *pc, int len) {
 #ifdef CONFIG_DEBUG
   uint8_t *p_instr = (void *)&instr;
   int i;
+  extern char log_bytebuf[80];
   for (i = 0; i < len; i ++) {
     int l = strlen(log_bytebuf);
     snprintf(log_bytebuf + l, sizeof(log_bytebuf) - l, "%02x ", p_instr[i]);

diff --git a/include/utils.h b/include/utils.h
@@ -49,6 +49,13 @@ uint64_t get_time();
 
 // ----------- log -----------
 
+// control when the log is printed, unit: number of instructions
+#define LOG_START (0)
+#define LOG_END   (1024 * 1024 * 50)
+
+#define SMALL_LOG_ROW_NUM (50 * 1024 * 1024) // row number, 50M instructions
+#define SMALL_LOG_ROW_BYTES 512
+
 /* #define log_write(...) MUXDEF(CONFIG_DEBUG, \
   do { \
     extern FILE* log_fp; \
@@ -67,17 +74,17 @@ uint64_t get_time();
  )*/
 #define log_write(...) \
   do { \
+    extern bool enable_fast_log; \
     extern bool enable_small_log; \
-    extern FILE* log_fp; \
+    extern FILE *log_fp; \
     extern char *log_filebuf; \
     extern uint64_t record_row_number; \
-    extern bool log_enable(); \
-    extern void log_flush(); \
+    extern void log_buffer_flush(); \
     if (log_fp != NULL) { \
-      if (enable_small_log) { \
-        snprintf(log_filebuf + record_row_number * 300, 300, __VA_ARGS__);\
-        log_flush(); \
-      } else if (log_enable()){ \
+      if (enable_fast_log || enable_small_log) { \
+        snprintf(log_filebuf + record_row_number * SMALL_LOG_ROW_BYTES, SMALL_LOG_ROW_BYTES, __VA_ARGS__);\
+        log_buffer_flush(); \
+      } else { \
         fprintf(log_fp, __VA_ARGS__); \
         fflush(log_fp); \
       } \
@@ -91,9 +98,6 @@ uint64_t get_time();
     log_write(__VA_ARGS__); \
   } while (0)
 
-extern char log_bytebuf[80];
-extern char log_asmbuf[80];
-
 // ----------- expr -----------
 
 word_t expr(char *e, bool *success);

diff --git a/src/checkpoint/path_manager.cpp b/src/checkpoint/path_manager.cpp
@@ -31,7 +31,8 @@ using namespace std;
 extern "C" {
 #include <debug.h>
 extern bool log_enable();
-extern void log_flush();
+extern void log_buffer_flush();
+extern void log_file_flush();
 }
 
 void PathManager::init() {

diff --git a/src/checkpoint/serializer.cpp b/src/checkpoint/serializer.cpp
@@ -69,8 +69,8 @@ uint8_t *get_pmem();
 word_t paddr_read(paddr_t addr, int len, int type, int trap_type, int mode, vaddr_t vaddr);
 uint8_t *guest_to_host(paddr_t paddr);
 #include <debug.h>
-extern bool log_enable();
-extern void log_flush();
+extern void log_buffer_flush();
+extern void log_file_flush();
 extern unsigned long MEMORY_SIZE;
 }
 

diff --git a/src/checkpoint/simpoint.cpp b/src/checkpoint/simpoint.cpp
@@ -53,11 +53,12 @@ namespace SimPointNS
 
 extern "C" {
 #include <debug.h>
-extern bool log_enable();
-extern void log_flush();
-extern char *log_filebuf;
 extern uint64_t record_row_number;
 extern FILE *log_fp;
+extern char *log_filebuf;
+extern void log_buffer_flush();
+extern void log_file_flush();
+extern bool enable_fast_log;
 extern bool enable_small_log;
 }
 

diff --git a/src/cpu/cpu-exec.c b/src/cpu/cpu-exec.c
@@ -575,13 +575,17 @@ static int execute(int n) {
 }
 #endif
 
+IFDEF(CONFIG_DEBUG, char log_bytebuf[80] = {};)
+// max size is (strlen(str(instr)) + strlen(suffix_char(id_dest->width)) + sizeof(id_dest->str) + sizeof(id_src2->str) + sizeof(id_src1->str))
+IFDEF(CONFIG_DEBUG, char log_asmbuf[80 + (sizeof(((Operand*)0)->str) * 3)] = {};)
+
 void fetch_decode(Decode *s, vaddr_t pc) {
   s->pc = pc;
   s->snpc = pc;
   IFDEF(CONFIG_DEBUG, log_bytebuf[0] = '\0');
   int idx = isa_fetch_decode(s);
-  Logtid(FMT_WORD ":   %s%*.s%s", s->pc, log_bytebuf,
-         40 - (12 + 3 * (int)(s->snpc - s->pc)), "", log_asmbuf);
+  Logtid(FMT_WORD ":   %s%*.s%s", s->pc, MUXDEF(CONFIG_DEBUG, log_bytebuf, ""),
+         40 - (12 + 3 * (int)(s->snpc - s->pc)), "", MUXDEF(CONFIG_DEBUG, log_asmbuf, ""));
   IFDEF(CONFIG_DEBUG,
         snprintf(s->logbuf, sizeof(s->logbuf), FMT_WORD ":   %s%*.s%s", s->pc,
                  log_bytebuf, 40 - (12 + 3 * (int)(s->snpc - s->pc)), "",

diff --git a/src/monitor/monitor.c b/src/monitor/monitor.c
@@ -28,7 +28,7 @@
 
 #ifndef CONFIG_SHARE
 void init_aligncheck();
-void init_log(const char *log_file, const bool small_log);
+void init_log(const char *log_file, const bool fast_log, const bool small_log);
 void init_mem();
 void init_regex();
 void init_wp_pool();
@@ -37,6 +37,7 @@ void init_device();
 
 static char *log_file = NULL;
 bool small_log = false;
+bool fast_log = false;
 static char *diff_so_file = NULL;
 static char *img_file = NULL;
 static int batch_mode = false;
@@ -86,6 +87,8 @@ static inline int parse_args(int argc, char *argv[]) {
     {"batch"    , no_argument      , NULL, 'b'},
     {"max-instr", required_argument, NULL, 'I'},
     {"log"      , required_argument, NULL, 'l'},
+    {"log-fast" , no_argument      , NULL,  8 },
+    {"log-small", no_argument      , NULL,  15},
     {"diff"     , required_argument, NULL, 'd'},
     {"port"     , required_argument, NULL, 'p'},
     {"help"     , no_argument      , NULL, 'h'},
@@ -122,9 +125,6 @@ static inline int parse_args(int argc, char *argv[]) {
     {"dump-mem"           , required_argument, NULL, 'M'},
     {"dump-reg"           , required_argument, NULL, 'R'},
 
-    // small log file
-    {"small-log"          , required_argument, NULL, 8},
-
     {0          , 0                , NULL,  0 },
   };
   int o;
@@ -239,7 +239,9 @@ static inline int parse_args(int argc, char *argv[]) {
         }
         break;
       case 8:
-        log_file = optarg;
+        fast_log = true;
+        break;
+      case 15:
         small_log = true;
         break;
       case 14: sscanf(optarg, "%lu", &warmup_interval); break;
@@ -274,6 +276,10 @@ static inline int parse_args(int argc, char *argv[]) {
         printf("\t--simpoint-profile      simpoint profiling\n");
         printf("\t--dont-skip-boot        profiling/checkpoint immediately after boot\n");
         printf("\t--mem_use_record_file   result output file for analyzing the memory use segment\n");
+
+        printf("\t--log-fast              output log to file by buffer\n");
+        printf("\t--log-small             keep the last 50M instruction log\n");
+
 //        printf("\t--cpt-id                checkpoint id\n");
         printf("\t-M,--dump-mem=DUMP_FILE dump memory into FILE\n");
         printf("\t-R,--dump-reg=DUMP_FILE dump register value into FILE\n");
@@ -294,6 +300,9 @@ void init_monitor(int argc, char *argv[]) {
   parse_args(argc, argv);
 #endif
 
+  /* Open the log file. */
+  init_log(log_file, fast_log, small_log);
+
   if (warmup_interval == 0) {
     warmup_interval = checkpoint_interval;
   }
@@ -315,8 +324,6 @@ void init_monitor(int argc, char *argv[]) {
     simpoint_init();
     init_serializer();
   }
-  /* Open the log file. */
-  init_log(log_file, small_log);
 
   /* Initialize memory. */
   init_mem();

diff --git a/src/utils/log.c b/src/utils/log.c
@@ -15,46 +15,70 @@
 
 #include <utils.h>
 #include <malloc.h>
-// control when the log is printed, unit: number of instructions
-#define LOG_START (0)
-// restrict the size of log file
-#define LOG_END   (1024 * 1024 * 50)
-#define SMALL_LOG_ROW_NUM (100 * 1024) // row number
+
 uint64_t record_row_number = 0;
 FILE *log_fp = NULL;
-char *log_filebuf;
+char *log_filebuf = NULL;
+int loop_index = 0;
+bool enable_fast_log = false;
 bool enable_small_log = false;
-void init_log(const char *log_file, const bool small_log) {
+
+void init_log(const char *log_file, const bool fast_log, const bool small_log) {
   if (log_file == NULL) return;
   log_fp = fopen(log_file, "w");
   Assert(log_fp, "Can not open '%s'", log_file);
+
+  if(fast_log || small_log){
+    log_filebuf = (void*)malloc(sizeof(char) * SMALL_LOG_ROW_NUM * SMALL_LOG_ROW_BYTES);
+    Assert(log_filebuf, "Can not alloc memory for log_filebuf");
+    memset(log_filebuf, 0, sizeof(char) * SMALL_LOG_ROW_NUM * SMALL_LOG_ROW_BYTES);
+  }
+
+  enable_fast_log = fast_log;
   enable_small_log = small_log;
-  if (enable_small_log)
-    log_filebuf = (char *)malloc(sizeof(char) * SMALL_LOG_ROW_NUM * 300);
 }
 
-bool log_enable() {
-  extern uint64_t g_nr_guest_instr;
-  return (g_nr_guest_instr >= LOG_START) && (g_nr_guest_instr <= LOG_END);
+void log_file_flush(bool log_close) {
+  if (!enable_small_log) {
+    for (int i = 0;
+         i < (SMALL_LOG_ROW_NUM < record_row_number ? SMALL_LOG_ROW_NUM
+                                                    : record_row_number);
+         i++) {
+      fprintf(log_fp, "%s", log_filebuf + i * SMALL_LOG_ROW_BYTES);
+    }
+    fflush(log_fp);
+  } else if (log_close) {
+    int loop_start_index = record_row_number;
+    for (int i = loop_start_index; i < SMALL_LOG_ROW_NUM; i++) {
+      if (*(log_filebuf + i * SMALL_LOG_ROW_BYTES) != 0) {
+        fprintf(log_fp, "%s", log_filebuf + i * SMALL_LOG_ROW_BYTES);
+      }
+    }
+    for (int i = 0; i < record_row_number; i++) {
+      fprintf(log_fp, "%s", log_filebuf + i * SMALL_LOG_ROW_BYTES);
+    }
+  }
 }
 
-void log_flush() {
-  record_row_number ++;
-  if(record_row_number > SMALL_LOG_ROW_NUM){
-    // rewind(log_fp);
+void log_buffer_flush() {
+  record_row_number++;
+  if (record_row_number > SMALL_LOG_ROW_NUM) {
+    log_file_flush(false);
     record_row_number = 0;
   }
 }
-void log_close(){
-  if (enable_small_log == false) return;
-  if (log_fp == NULL) return;
-  // fprintf(log_fp, "%s", log_filebuf);
-  for (int i = 0; i < record_row_number; i++)
-  {
-    fprintf(log_fp, "%s", log_filebuf + i * 300);
+
+void log_close() {
+  if (!log_fp && !log_filebuf) {
+    return;
+  }
+
+  if (log_filebuf) {
+    log_file_flush(true);
+    free(log_filebuf);
+  }
+
+  if (log_fp) {
+    fclose(log_fp);
   }
-  fclose(log_fp);
-  free(log_filebuf);
 }
-char log_bytebuf[80] = {};
-char log_asmbuf[80] = {};