From 3182183860680bb07fea0881a5f52b1191dbea3e Mon Sep 17 00:00:00 2001 From: Haruki NAOI <naoi.haruki@jp.fujitsu.com> Date: Wed, 29 Aug 2018 21:46:05 +0900 Subject: [PATCH] Fix: --log-mem options is erased. --- common/utils/LOG/log.c | 299 ++++++++++++++++++++++++++++++-- common/utils/LOG/log.h | 14 ++ common/utils/LOG/log_extern.h | 2 + common/utils/itti/assertions.h | 1 - common/utils/itti/signals.c | 3 + targets/RT/USER/lte-softmodem.c | 10 +- targets/RT/USER/lte-softmodem.h | 1 + 7 files changed, 310 insertions(+), 20 deletions(-) diff --git a/common/utils/LOG/log.c b/common/utils/LOG/log.c index 02ee849202..d67cda7afe 100644 --- a/common/utils/LOG/log.c +++ b/common/utils/LOG/log.c @@ -49,7 +49,18 @@ #include "common/config/config_userapi.h" // main log variables - +log_mem_cnt_t log_mem_d[2]; +int log_mem_flag=0; +int log_mem_multi=1; +volatile int log_mem_side=0; +pthread_mutex_t log_mem_lock; +pthread_cond_t log_mem_notify; +pthread_t log_mem_thread; +int log_mem_file_cnt=0; +volatile int log_mem_write_flag=0; +volatile int log_mem_write_side=0; +char __log_mem_filename[1024]={0}; +char * log_mem_filename = &__log_mem_filename[0]; mapping log_level_names[] = { @@ -485,7 +496,7 @@ int rt = pthread_getname_np(pthread_self(), threadname,bufsize) ; void logRecord_mt(const char *file, const char *func, int line, int comp, int level, const char* format, ... ) - { +{ char threadname[PR_SET_NAME]; char log_buffer[MAX_LOG_TOTAL]; @@ -493,23 +504,23 @@ void logRecord_mt(const char *file, const char *func, int line, int comp, int le va_start(args, format); + if(log_mem_flag == 1) { + log_output_memory(file,func,line,comp,level, format,args); + } + else { + snprintf(log_buffer, MAX_LOG_TOTAL , "%s%s[%s]%s %s %s", + log_level_highlight_end[level], + ( (g_log->flag & FLAG_NOCOLOR)?"":log_level_highlight_start[level]), + g_log->log_component[comp].name, + ( (g_log->flag & FLAG_LEVEL)?g_log->level2string[level]:""), + ( (g_log->flag & FLAG_THREAD)?log_getthreadname(threadname,PR_SET_NAME+1):""), + format); - - - - snprintf(log_buffer, MAX_LOG_TOTAL , "%s%s[%s]%s %s %s", - log_level_highlight_end[level], - ( (g_log->flag & FLAG_NOCOLOR)?"":log_level_highlight_start[level]), - g_log->log_component[comp].name, - ( (g_log->flag & FLAG_LEVEL)?g_log->level2string[level]:""), - ( (g_log->flag & FLAG_THREAD)?log_getthreadname(threadname,PR_SET_NAME+1):""), - format); - - g_log->log_component[comp].fwrite(g_log->log_component[comp].stream,log_buffer, args); + g_log->log_component[comp].fwrite(g_log->log_component[comp].stream,log_buffer, args); + } va_end(args); - } @@ -531,8 +542,6 @@ int set_log(int component, int level, int interval) return 0; } - - void set_glog(int level) { for (int c=0; c< MAX_LOG_COMPONENTS; c++ ) { @@ -628,6 +637,262 @@ void logClean (void) } } + +extern int oai_exit; +void flush_mem_to_file(void) +{ + int fp; + char f_name[1024]; + struct timespec slp_tm; + slp_tm.tv_sec = 0; + slp_tm.tv_nsec = 10000; + + pthread_setname_np( pthread_self(), "flush_mem_to_file"); + + while (!oai_exit) { + pthread_mutex_lock(&log_mem_lock); + log_mem_write_flag=0; + pthread_cond_wait(&log_mem_notify, &log_mem_lock); + log_mem_write_flag=1; + pthread_mutex_unlock(&log_mem_lock); + // write! + if(log_mem_d[log_mem_write_side].enable_flag==0){ + if(log_mem_file_cnt>1){ + log_mem_file_cnt=1; + printf("log over write!!!\n"); + } + snprintf(f_name,1024, "%s_%d.log",log_mem_filename,log_mem_file_cnt); + fp=open(f_name, O_WRONLY | O_CREAT, 0666); + int ret = write(fp, log_mem_d[log_mem_write_side].buf_p, log_mem_d[log_mem_write_side].buf_index); + if ( ret < 0) { + fprintf(stderr,"{LOG} %s %d Couldn't write in %s \n",__FILE__,__LINE__,f_name); + exit(EXIT_FAILURE); + } + close(fp); + log_mem_file_cnt++; + log_mem_d[log_mem_write_side].buf_index=0; + log_mem_d[log_mem_write_side].enable_flag=1; + }else{ + printf("If you'd like to write log, you should set enable flag to 0!!!\n"); + nanosleep(&slp_tm,NULL); + } + } +} + +void log_output_memory(const char *file, const char *func, int line, int comp, int level, const char* format,va_list args) +{ + //logRecord_mt(file,func,line, pthread_self(), comp, level, format, ##args) + int len = 0; + log_component_t *c; + char *log_start; + char *log_end; + /* The main difference with the version above is the use of this local log_buffer. + * The other difference is the return value of snprintf which was not used + * correctly. It was not a big problem because in practice MAX_LOG_TOTAL is + * big enough so that the buffer is never full. + */ + char log_buffer[MAX_LOG_TOTAL]; + + /* for no gcc warnings */ + (void)log_start; + (void)log_end; + + + c = &g_log->log_component[comp]; + + //VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD, VCD_FUNCTION_IN); + + // make sure that for log trace the extra info is only printed once, reset when the level changes + if ((level == OAILOG_FILE) || (level == OAILOG_TRACE)) { + log_start = log_buffer; + len = vsnprintf(log_buffer, MAX_LOG_TOTAL, format, args); + if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; + log_end = log_buffer + len; + } else { + if ( (g_log->flag & 0x001) || (c->flag & 0x001) ) { + len += snprintf(&log_buffer[len], MAX_LOG_TOTAL - len, "%s", + log_level_highlight_start[level]); + if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; + } + + log_start = log_buffer + len; + +// if ( (g_log->flag & 0x004) || (c->flag & 0x004) ) { + len += snprintf(&log_buffer[len], MAX_LOG_TOTAL - len, "[%s]", + g_log->log_component[comp].name); + if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; +// } + +// if ( (g_log->flag & FLAG_LEVEL) || (c->flag & FLAG_LEVEL) ) { + len += snprintf(&log_buffer[len], MAX_LOG_TOTAL - len, "[%s]", + g_log->level2string[level]); + if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; +// } + + if ( (g_log->flag & FLAG_THREAD) || (c->flag & FLAG_THREAD) ) { +# define THREAD_NAME_LEN 128 + char threadname[THREAD_NAME_LEN]; + if (pthread_getname_np(pthread_self(), threadname, THREAD_NAME_LEN) != 0) + { + perror("pthread_getname_np : "); + } else { + len += snprintf(&log_buffer[len], MAX_LOG_TOTAL - len, "[%s]", threadname); + if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; + } +# undef THREAD_NAME_LEN + } + + if ( (g_log->flag & FLAG_FUNCT) || (c->flag & FLAG_FUNCT) ) { + len += snprintf(&log_buffer[len], MAX_LOG_TOTAL - len, "[%s] ", + func); + if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; + } + + if ( (g_log->flag & FLAG_FILE_LINE) || (c->flag & FLAG_FILE_LINE) ) { + len += snprintf(&log_buffer[len], MAX_LOG_TOTAL - len, "[%s:%d]", + file, line); + if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; + } + + //len += snprintf(&log_buffer[len], MAX_LOG_TOTAL - len, "[%08lx]", thread_id); + //if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; + + len += vsnprintf(&log_buffer[len], MAX_LOG_TOTAL - len, format, args); + if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; + log_end = log_buffer + len; + + if ( (g_log->flag & FLAG_NOCOLOR) || (c->flag & FLAG_NOCOLOR) ) { + len += snprintf(&log_buffer[len], MAX_LOG_TOTAL - len, "%s", + log_level_highlight_end[level]); + if (len > MAX_LOG_TOTAL) len = MAX_LOG_TOTAL; + } + } + + //va_end(args); + + // OAI printf compatibility + if ((g_log->onlinelog == 1) && (level != OAILOG_FILE)) { + if(log_mem_flag==1){ + if(log_mem_d[log_mem_side].enable_flag==1){ + int temp_index; + temp_index=log_mem_d[log_mem_side].buf_index; + if(temp_index+len+1 < LOG_MEM_SIZE){ + log_mem_d[log_mem_side].buf_index+=len; + memcpy(&log_mem_d[log_mem_side].buf_p[temp_index],log_buffer,len); + }else{ + log_mem_d[log_mem_side].enable_flag=0; + if(log_mem_d[1-log_mem_side].enable_flag==1){ + temp_index=log_mem_d[1-log_mem_side].buf_index; + if(temp_index+len+1 < LOG_MEM_SIZE){ + log_mem_d[1-log_mem_side].buf_index+=len; + log_mem_side=1-log_mem_side; + memcpy(&log_mem_d[log_mem_side].buf_p[temp_index],log_buffer,len); + /* write down !*/ + if (pthread_mutex_lock(&log_mem_lock) != 0) { + return; + } + if(log_mem_write_flag==0){ + log_mem_write_side=1-log_mem_side; + if(pthread_cond_signal(&log_mem_notify) != 0) { + } + } + if(pthread_mutex_unlock(&log_mem_lock) != 0) { + return; + } + }else{ + log_mem_d[1-log_mem_side].enable_flag=0; + } + } + } + } + }else{ + fwrite(log_buffer, len, 1, stdout); + } + } +} + +int logInit_log_mem (void) +{ + if(log_mem_flag==1){ + if(log_mem_multi==1){ + printf("log-mem multi!!!\n"); + log_mem_d[0].buf_p = malloc(LOG_MEM_SIZE); + log_mem_d[0].buf_index=0; + log_mem_d[0].enable_flag=1; + log_mem_d[1].buf_p = malloc(LOG_MEM_SIZE); + log_mem_d[1].buf_index=0; + log_mem_d[1].enable_flag=1; + log_mem_side=0; + if ((pthread_mutex_init (&log_mem_lock, NULL) != 0) + || (pthread_cond_init (&log_mem_notify, NULL) != 0)) { + log_mem_d[1].enable_flag=0; + return -1; + } + pthread_create(&log_mem_thread, NULL, (void *(*)(void *))flush_mem_to_file, (void*)NULL); + }else{ + printf("log-mem single!!!\n"); + log_mem_d[0].buf_p = malloc(LOG_MEM_SIZE); + log_mem_d[0].buf_index=0; + log_mem_d[0].enable_flag=1; + log_mem_d[1].enable_flag=0; + log_mem_side=0; + } + }else{ + log_mem_d[0].buf_p=NULL; + log_mem_d[1].buf_p=NULL; + log_mem_d[0].enable_flag=0; + log_mem_d[1].enable_flag=0; + } + + printf("log init done\n"); + + return 0; +} + +void close_log_mem(void){ + int fp; + char f_name[1024]; + + if(log_mem_flag==1){ + log_mem_d[0].enable_flag=0; + log_mem_d[1].enable_flag=0; + usleep(10); // wait for log writing + while(log_mem_write_flag==1){ + usleep(100); + } + if(log_mem_multi==1){ + snprintf(f_name,1024, "%s_%d.log",log_mem_filename,log_mem_file_cnt); + fp=open(f_name, O_WRONLY | O_CREAT, 0666); + int ret = write(fp, log_mem_d[0].buf_p, log_mem_d[0].buf_index); + if ( ret < 0) { + fprintf(stderr,"{LOG} %s %d Couldn't write in %s \n",__FILE__,__LINE__,f_name); + exit(EXIT_FAILURE); + } + close(fp); + free(log_mem_d[0].buf_p); + + snprintf(f_name,1024, "%s_%d.log",log_mem_filename,log_mem_file_cnt); + fp=open(f_name, O_WRONLY | O_CREAT, 0666); + ret = write(fp, log_mem_d[1].buf_p, log_mem_d[1].buf_index); + if ( ret < 0) { + fprintf(stderr,"{LOG} %s %d Couldn't write in %s \n",__FILE__,__LINE__,f_name); + exit(EXIT_FAILURE); + } + close(fp); + free(log_mem_d[1].buf_p); + }else{ + fp=open(log_mem_filename, O_WRONLY | O_CREAT, 0666); + int ret = write(fp, log_mem_d[0].buf_p, log_mem_d[0].buf_index); + if ( ret < 0) { + fprintf(stderr,"{LOG} %s %d Couldn't write in %s \n",__FILE__,__LINE__,log_mem_filename); + exit(EXIT_FAILURE); + } + close(fp); + free(log_mem_d[0].buf_p); + } + } + } + #ifdef LOG_TEST diff --git a/common/utils/LOG/log.h b/common/utils/LOG/log.h index 4a0552d494..edff0a5eeb 100644 --- a/common/utils/LOG/log.h +++ b/common/utils/LOG/log.h @@ -269,6 +269,20 @@ int is_newline( char *str, int size); int register_log_component(char *name, char *fext, int compidx); +#define LOG_MEM_SIZE 500*1024*1024 +#define LOG_MEM_FILE "./logmem.log" +void flush_mem_to_file(void); +void log_output_memory(const char *file, const char *func, int line, int comp, int level, const char* format,va_list args); +int logInit_log_mem(void); +void close_log_mem(void); + +typedef struct { + char* buf_p; + int buf_index; + int enable_flag; +} log_mem_cnt_t; + + /* @}*/ /*!\fn int32_t write_file_matlab(const char *fname, const char *vname, void *data, int length, int dec, char format); diff --git a/common/utils/LOG/log_extern.h b/common/utils/LOG/log_extern.h index 3c93d517ca..449333d92f 100644 --- a/common/utils/LOG/log_extern.h +++ b/common/utils/LOG/log_extern.h @@ -28,3 +28,5 @@ extern mapping log_level_names[]; extern mapping log_options[]; extern mapping log_maskmap[]; +extern int log_mem_flag; +extern char * log_mem_filename; diff --git a/common/utils/itti/assertions.h b/common/utils/itti/assertions.h index b872b009e2..bb6c27cbab 100644 --- a/common/utils/itti/assertions.h +++ b/common/utils/itti/assertions.h @@ -35,7 +35,6 @@ #ifndef ASSERTIONS_H_ #define ASSERTIONS_H_ -void output_log_mem(void); #define _Assert_Exit_ \ { \ fprintf(stderr, "\nExiting execution\n"); \ diff --git a/common/utils/itti/signals.c b/common/utils/itti/signals.c index 5dd667ae65..cfc902552e 100644 --- a/common/utils/itti/signals.c +++ b/common/utils/itti/signals.c @@ -117,18 +117,21 @@ int signal_handle(int *end) case SIGUSR1: SIG_DEBUG("Received SIGUSR1\n"); *end = 1; + close_log_mem(); break; case SIGSEGV: /* Fall through */ case SIGABRT: SIG_DEBUG("Received SIGABORT\n"); backtrace_handle_signal(&info); + close_log_mem(); break; case SIGINT: printf("Received SIGINT\n"); itti_send_terminate_message(TASK_UNKNOWN); *end = 1; + close_log_mem(); break; default: diff --git a/targets/RT/USER/lte-softmodem.c b/targets/RT/USER/lte-softmodem.c index e84f99e67f..49639c4937 100644 --- a/targets/RT/USER/lte-softmodem.c +++ b/targets/RT/USER/lte-softmodem.c @@ -70,6 +70,7 @@ unsigned short config_frames[4] = {2,9,11,13}; #endif #include "common/utils/LOG/log.h" +#include "common/utils/LOG/log_extern.h" #include "UTIL/OTG/otg_tx.h" #include "UTIL/OTG/otg_externs.h" #include "UTIL/MATH/oml.h" @@ -141,7 +142,7 @@ static int8_t threequarter_fs=0; uint32_t downlink_frequency[MAX_NUM_CCs][4]; int32_t uplink_frequency_offset[MAX_NUM_CCs][4]; - +char logmem_filename[1024] = {0}; // This is a dummy declaration (dlsch_demodulation.c is no longer compiled for eNodeB) int16_t dlsch_demod_shift = 0; @@ -550,7 +551,12 @@ static void get_options(void) { if (start_telnetsrv) { load_module_shlib("telnetsrv",NULL,0); } - + if (strlen(logmem_filename) > 0) { + log_mem_filename = &logmem_filename[0]; + log_mem_flag = 1; + printf("Enabling OPT for log save at memory %s\n",log_mem_filename); + logInit_log_mem(); + } if ( !(CONFIG_ISFLAGSET(CONFIG_ABORT)) ) { diff --git a/targets/RT/USER/lte-softmodem.h b/targets/RT/USER/lte-softmodem.h index 2f8209f2d3..5412de6365 100644 --- a/targets/RT/USER/lte-softmodem.h +++ b/targets/RT/USER/lte-softmodem.h @@ -202,6 +202,7 @@ {"R" , CONFIG_HLP_FLOG, 0, uptr:&online_log_messages, defintval:1, TYPE_INT, 0}, \ {"g" , CONFIG_HLP_LOGL, 0, uptr:&glog_level, defintval:0, TYPE_UINT, 0}, \ {"telnetsrv", CONFIG_HLP_TELN, PARAMFLAG_BOOL, uptr:&start_telnetsrv, defintval:0, TYPE_UINT, 0}, \ +{"log-mem", NULL, 0, strptr:(char **)&logmem_filename, defstrval:"./logmem.log", TYPE_STRING, sizeof(logmem_filename)}, \ } #define CMDLINE_ONLINELOG_IDX 0 #define CMDLINE_GLOGLEVEL_IDX 1 -- GitLab