From bfadef069d74f2ebf125dfd59a6a7ce21d6bd5e9 Mon Sep 17 00:00:00 2001 From: jiaxiaoyu Date: Thu, 19 Sep 2024 11:55:29 +0800 Subject: [PATCH] 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 --- include/cpu/decode.h | 17 ++++--- include/cpu/ifetch.h | 1 + include/utils.h | 24 +++++----- src/checkpoint/path_manager.cpp | 3 +- src/checkpoint/serializer.cpp | 4 +- src/checkpoint/simpoint.cpp | 7 +-- src/cpu/cpu-exec.c | 8 +++- src/monitor/monitor.c | 21 ++++++--- src/utils/log.c | 78 +++++++++++++++++++++------------ 9 files changed, 104 insertions(+), 59 deletions(-) diff --git a/include/cpu/decode.h b/include/cpu/decode.h index c5c6352ca..495cb3d8d 100644 --- 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 index 2e5cbde9c..6a5b14d5c 100644 --- 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 index 63e89a050..826fac34a 100644 --- 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 index 028d9a6bf..47f6a9ab8 100644 --- a/src/checkpoint/path_manager.cpp +++ b/src/checkpoint/path_manager.cpp @@ -31,7 +31,8 @@ using namespace std; extern "C" { #include 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 index f9fb95b42..500473aef 100644 --- 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 -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 index 768fe1bf2..06d16d284 100644 --- a/src/checkpoint/simpoint.cpp +++ b/src/checkpoint/simpoint.cpp @@ -53,11 +53,12 @@ namespace SimPointNS extern "C" { #include -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 index 1618dec6a..aad2f070b 100644 --- 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 index f9154c6fa..19d46879c 100644 --- 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 index b165c5152..c122743ef 100644 --- a/src/utils/log.c +++ b/src/utils/log.c @@ -15,46 +15,70 @@ #include #include -// 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] = {};