diff --git a/openair2/UTIL/LOG/log.c b/openair2/UTIL/LOG/log.c index 72a789727179ac5b4634380cb1ddc6a173278c7d..c8486ac9a04b98f9210a05bbdb72312dad0e005a 100755 --- a/openair2/UTIL/LOG/log.c +++ b/openair2/UTIL/LOG/log.c @@ -40,62 +40,62 @@ #define COMPONENT_LOG #define COMPONENT_LOG_IF - - -//static unsigned char fifo_print_buffer[FIFO_PRINTF_MAX_STRING_SIZE]; - #include "log.h" -#include "log_vars.h" #include "vcd_signal_dumper.h" +#include "assertions.h" -//#include "UTIL/OCG/OCG.h" -//#include "UTIL/OCG/OCG_extern.h" #ifdef USER_MODE # include <pthread.h> # include <string.h> #endif #ifdef RTAI -#include <rtai.h> -#include <rtai_fifos.h> -# define FIFO_PRINTF_MAX_STRING_SIZE 1000 +# include <rtai.h> +# include <rtai_fifos.h> +# define FIFO_PRINTF_MAX_STRING_SIZE 1000 # define FIFO_PRINTF_NO 62 # define FIFO_PRINTF_SIZE 65536 #endif -// made static and not local to logRecord() for performance reasons -static char g_buff_tmp [MAX_LOG_ITEM]; -static char g_buff_info [MAX_LOG_INFO]; -static char g_buff_total[MAX_LOG_TOTAL]; +// main log variables +log_t *g_log; -static int gfd; +// vars for the log thread +LOG_params log_list[2000]; +int log_list_tail = 0; +int log_list_nb_elements = 0; -static char *log_level_highlight_start[] = {LOG_RED, LOG_RED, LOG_RED, LOG_RED, LOG_ORANGE, LOG_BLUE, "", ""}; /*!< \brief Optional start-format strings for highlighting */ -static char *log_level_highlight_end[] = {LOG_RESET, LOG_RESET, LOG_RESET, LOG_RESET, LOG_RESET,LOG_RESET, "",""}; /*!< \brief Optional end-format strings for highlighting */ +pthread_mutex_t log_lock; +pthread_cond_t log_notify; +#if !defined(LOG_NO_THREAD) +int log_list_head = 0; +int log_shutdown; +#endif -// static int bypass_log_hdr; +static int gfd; -//extern MAC_xface *mac_xface; +static char *log_level_highlight_start[] = {LOG_RED, LOG_RED, LOG_RED, LOG_RED, LOG_ORANGE, LOG_BLUE, "", ""}; /*!< \brief Optional start-format strings for highlighting */ +static char *log_level_highlight_end[] = {LOG_RESET, LOG_RESET, LOG_RESET, LOG_RESET, LOG_RESET,LOG_RESET, "",""}; /*!< \brief Optional end-format strings for highlighting */ -int logInit (void) { - +int logInit (void) +{ #ifdef USER_MODE - int i; - g_log = calloc(1, sizeof(log_t)); + int i; + g_log = calloc(1, sizeof(log_t)); #else - g_log = kmalloc(sizeof(log_t),GFP_KERNEL); + g_log = kmalloc(sizeof(log_t), GFP_KERNEL); #endif - if (g_log == NULL) { + if (g_log == NULL) { #ifdef USER_MODE - perror ("cannot allocated memory for log generation module \n"); - exit(EXIT_FAILURE); + perror ("cannot allocated memory for log generation module \n"); + exit(EXIT_FAILURE); #else - printk("cannot allocated memory for log generation module \n"); - return(-1); + printk("cannot allocated memory for log generation module \n"); + return(-1); #endif - } - + } + g_log->log_component[PHY].name = "PHY"; g_log->log_component[PHY].level = LOG_EMERG; g_log->log_component[PHY].flag = LOG_MED; @@ -103,7 +103,7 @@ int logInit (void) { g_log->log_component[PHY].fd = 0; g_log->log_component[PHY].filelog = 0; g_log->log_component[PHY].filelog_name = "/tmp/phy.log"; - + g_log->log_component[MAC].name = "MAC"; g_log->log_component[MAC].level = LOG_EMERG; g_log->log_component[MAC].flag = LOG_MED; @@ -111,7 +111,7 @@ int logInit (void) { g_log->log_component[MAC].fd = 0; g_log->log_component[MAC].filelog = 0; g_log->log_component[MAC].filelog_name = "/tmp/mac.log"; - + g_log->log_component[OPT].name = "OPT"; g_log->log_component[OPT].level = LOG_EMERG; g_log->log_component[OPT].flag = LOG_MED; @@ -127,7 +127,7 @@ int logInit (void) { g_log->log_component[RLC].fd = 0; g_log->log_component[RLC].filelog = 0; g_log->log_component[RLC].filelog_name = "/tmp/rlc.log"; - + g_log->log_component[PDCP].name = "PDCP"; g_log->log_component[PDCP].level = LOG_INFO; g_log->log_component[PDCP].flag = LOG_MED; @@ -135,7 +135,7 @@ int logInit (void) { g_log->log_component[PDCP].fd = 0; g_log->log_component[PDCP].filelog = 0; g_log->log_component[PDCP].filelog_name = "/tmp/pdcp.log"; - + g_log->log_component[RRC].name = "RRC"; g_log->log_component[RRC].level = LOG_TRACE; g_log->log_component[RRC].flag = LOG_MED; @@ -146,12 +146,12 @@ int logInit (void) { g_log->log_component[EMU].name = "EMU"; g_log->log_component[EMU].level = LOG_EMERG; - g_log->log_component[EMU].flag = LOG_MED; + g_log->log_component[EMU].flag = LOG_MED; g_log->log_component[EMU].interval = 1; g_log->log_component[EMU].fd = 0; g_log->log_component[EMU].filelog = 0; g_log->log_component[EMU].filelog_name = ""; - + g_log->log_component[OMG].name = "OMG"; g_log->log_component[OMG].level = LOG_EMERG; g_log->log_component[OMG].flag = LOG_MED; @@ -159,7 +159,7 @@ int logInit (void) { g_log->log_component[OMG].fd = 0; g_log->log_component[OMG].filelog = 0; g_log->log_component[OMG].filelog_name = ""; - + g_log->log_component[OTG].name = "OTG"; g_log->log_component[OTG].level = LOG_EMERG; g_log->log_component[OTG].flag = LOG_MED; @@ -184,7 +184,6 @@ int logInit (void) { g_log->log_component[OTG_LATENCY_BG].filelog = 0; g_log->log_component[OTG_LATENCY_BG].filelog_name = "/tmp/otg_latency_bg.dat"; - g_log->log_component[OTG_GP].name = "OTG_GP"; g_log->log_component[OTG_GP].level = LOG_EMERG; g_log->log_component[OTG_GP].flag = LOG_MED; @@ -208,7 +207,7 @@ int logInit (void) { g_log->log_component[OTG_JITTER].fd = 0; g_log->log_component[OTG_JITTER].filelog = 0; g_log->log_component[OTG_JITTER].filelog_name = "/tmp/otg_jitter.dat"; - + g_log->log_component[OCG].name = "OCG"; g_log->log_component[OCG].level = LOG_EMERG; g_log->log_component[OCG].flag = LOG_MED; @@ -216,7 +215,7 @@ int logInit (void) { g_log->log_component[OCG].fd = 0; g_log->log_component[OCG].filelog = 0; g_log->log_component[OCG].filelog_name = ""; - + g_log->log_component[PERF].name = "PERF"; g_log->log_component[PERF].level = LOG_EMERG; g_log->log_component[PERF].flag = LOG_MED; @@ -224,7 +223,7 @@ int logInit (void) { g_log->log_component[PERF].fd = 0; g_log->log_component[PERF].filelog = 0; g_log->log_component[PERF].filelog_name = ""; - + g_log->log_component[OIP].name = "OIP"; g_log->log_component[OIP].level = LOG_EMERG; g_log->log_component[OIP].flag = LOG_MED; @@ -232,7 +231,7 @@ int logInit (void) { g_log->log_component[OIP].fd = 0; g_log->log_component[OIP].filelog = 0; g_log->log_component[OIP].filelog_name = ""; - + g_log->log_component[CLI].name = "CLI"; g_log->log_component[CLI].level = LOG_EMERG; g_log->log_component[CLI].flag = LOG_MED; @@ -240,7 +239,7 @@ int logInit (void) { g_log->log_component[CLI].fd = 0; g_log->log_component[CLI].filelog = 0; g_log->log_component[CLI].filelog_name = ""; - + g_log->log_component[MSC].name = "MSC"; g_log->log_component[MSC].level = LOG_EMERG; g_log->log_component[MSC].flag = LOG_MED; @@ -248,7 +247,7 @@ int logInit (void) { g_log->log_component[MSC].fd = 0; g_log->log_component[MSC].filelog = 0; g_log->log_component[MSC].filelog_name = "/tmp/msc.log"; - + g_log->log_component[OCM].name = "OCM"; g_log->log_component[OCM].level = LOG_EMERG; g_log->log_component[OCM].flag = LOG_MED; @@ -259,11 +258,11 @@ int logInit (void) { g_log->log_component[S1AP].name = "S1AP"; g_log->log_component[S1AP].level = LOG_EMERG; - g_log->log_component[S1AP].flag = LOG_MED; + g_log->log_component[S1AP].flag = LOG_FULL; g_log->log_component[S1AP].interval = 1; g_log->log_component[S1AP].fd = 0; g_log->log_component[S1AP].filelog = 0; - g_log->log_component[S1AP].filelog_name = "/tmp/s1ap.log"; + g_log->log_component[S1AP].filelog_name = ""; g_log->log_component[SCTP].name = "SCTP"; g_log->log_component[SCTP].level = LOG_EMERG; @@ -299,443 +298,426 @@ int logInit (void) { g_log->level2string[LOG_DEBUG] = "D"; // DEBUG g_log->level2string[LOG_FILE] = "F"; // file g_log->level2string[LOG_TRACE] = "T"; // TRACE - + g_log->onlinelog = 1; //online log file - g_log->syslog = 0; + g_log->syslog = 0; g_log->filelog = 0; g_log->level = LOG_TRACE; g_log->flag = LOG_LOW; - + #ifndef RTAI - g_log->config.remote_ip = 0; - g_log->config.remote_level = LOG_EMERG; - g_log->config.facility = LOG_LOCAL7; - g_log->config.audit_ip = 0; - g_log->config.audit_facility = LOG_LOCAL6; - g_log->config.format = 0x00; // online debug inactive - - g_log->filelog_name = "/tmp/openair.log"; - - if (g_log->syslog) { - openlog(g_log->log_component[EMU].name, LOG_PID, g_log->config.facility); - } - if (g_log->filelog) { - gfd = open(g_log->filelog_name, O_WRONLY | O_CREAT, 0666); - } - // could put a loop here to check for all comps - for (i=MIN_LOG_COMPONENTS; i < MAX_LOG_COMPONENTS; i++){ - if (g_log->log_component[i].filelog == 1 ) - g_log->log_component[i].fd = open(g_log->log_component[i].filelog_name, O_WRONLY | O_CREAT | O_APPEND, 0666); - } + g_log->config.remote_ip = 0; + g_log->config.remote_level = LOG_EMERG; + g_log->config.facility = LOG_LOCAL7; + g_log->config.audit_ip = 0; + g_log->config.audit_facility = LOG_LOCAL6; + g_log->config.format = 0x00; // online debug inactive + + g_log->filelog_name = "/tmp/openair.log"; + + if (g_log->syslog) { + openlog(g_log->log_component[EMU].name, LOG_PID, g_log->config.facility); + } + if (g_log->filelog) { + gfd = open(g_log->filelog_name, O_WRONLY | O_CREAT, 0666); + } + // could put a loop here to check for all comps + for (i=MIN_LOG_COMPONENTS; i < MAX_LOG_COMPONENTS; i++) { + if (g_log->log_component[i].filelog == 1 ) { + g_log->log_component[i].fd = open(g_log->log_component[i].filelog_name, + O_WRONLY | O_CREAT | O_APPEND, 0666); + } + } #else - g_log->syslog = 0; - g_log->filelog = 0; - rtf_create (FIFO_PRINTF_NO, FIFO_PRINTF_SIZE); + g_log->syslog = 0; + g_log->filelog = 0; + rtf_create (FIFO_PRINTF_NO, FIFO_PRINTF_SIZE); #endif -#ifdef USER_MODE - printf("log init done\n"); +#ifdef USER_MODE + printf("log init done\n"); #else - printk("log init done\n"); + printk("log init done\n"); #endif - return 0; + return 0; } -//log record: add to a list -void logRecord( const char *file, const char *func, - int line, int comp, int level, - char *format, ...) { - - va_list args; - LOG_params log_params; - int len; - //LOG_elt *log = NULL; - - va_start(args, format); - len = vsnprintf(log_params.l_buff_info, MAX_LOG_INFO-1, format, args); - va_end(args); - - //2 first parameters must be passed as 'const' to the thread function - log_params.file = file; - log_params.func = func; - log_params.line = line; - log_params.comp = comp; - log_params.level = level; - log_params.format = format; - log_params.len = len; - - if(pthread_mutex_lock(&log_lock) != 0) { return; } - - log_list_tail++; - log_list[log_list_tail - 1] = log_params; - if (log_list_tail >= 1000) log_list_tail = 0; - if (log_list_nb_elements < 1000) log_list_nb_elements++; - if(pthread_cond_signal(&log_notify) != 0) { return; } - - if(pthread_mutex_unlock(&log_lock) != 0) { return; } - - //log = malloc(sizeof(LOG_elt)); - //log->next = NULL; - //log->log_params = log_params; - /* Add log task to queue */ - //log_list_add_tail_eurecom(log, &log_list); +//log record: add to a list +void logRecord(const char *file, const char *func, int line, int comp, + int level, char *format, ...) +{ + va_list args; + LOG_params log_params; + int len; + + va_start(args, format); + len = vsnprintf(log_params.l_buff_info, MAX_LOG_INFO-1, format, args); + va_end(args); + + //2 first parameters must be passed as 'const' to the thread function + log_params.file = file; + log_params.func = func; + log_params.line = line; + log_params.comp = comp; + log_params.level = level; + log_params.format = format; + log_params.len = len; + + if (pthread_mutex_lock(&log_lock) != 0) { + return; + } + + log_list_tail++; + log_list[log_list_tail - 1] = log_params; + if (log_list_tail >= 1000) { + log_list_tail = 0; + } + if (log_list_nb_elements < 1000) { + log_list_nb_elements++; + } + if(pthread_cond_signal(&log_notify) != 0) { + return; + } + + if(pthread_mutex_unlock(&log_lock) != 0) { + return; + } + + //log = malloc(sizeof(LOG_elt)); + //log->next = NULL; + //log->log_params = log_params; + /* Add log task to queue */ + //log_list_add_tail_eurecom(log, &log_list); } void logRecord_thread_safe(const char *file, const char *func, int line, int comp, int level, - int len, const char *params_string) { + int len, const char *params_string) +{ + log_component_t *c; + int total_len = 0; + char log_buffer[MAX_LOG_TOTAL]; + + c = &g_log->log_component[comp]; + + // do not apply filtering for LOG_F + // only log messages which are enabled and are below the global log level and component's level threshold + if ((level != LOG_FILE) && ((c->level > g_log->level) || + (level > c->level) || (level > g_log->level))) + { + return; + } - log_component_t *c; + vcd_signal_dumper_dump_function_by_name(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD, + VCD_FUNCTION_IN); - sprintf(g_buff_info, "%s", params_string); + // adjust syslog level for TRACE messages + if (g_log->syslog) { + if (g_log->level > LOG_DEBUG) { + g_log->level = LOG_DEBUG; + } + } - vcd_signal_dumper_dump_function_by_name(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD,1); + // make sure that for log trace the extra info is only printed once, reset when the level changes + if ((level == LOG_FILE) || (c->flag == LOG_NONE) || (level ==LOG_TRACE )) { + total_len = snprintf(&log_buffer[total_len], MAX_LOG_TOTAL - 1, "%s", + params_string); + } else { + if ((g_log->flag & FLAG_COLOR) || (c->flag & FLAG_COLOR)) { + total_len += snprintf(&log_buffer[total_len], MAX_LOG_TOTAL - total_len, "%s", + log_level_highlight_start[level]); + } - g_buff_total[0] = '\0'; - c = &g_log->log_component[comp]; + if ((g_log->flag & FLAG_COMP) || (c->flag & FLAG_COMP) ) { + total_len += snprintf(&log_buffer[total_len], MAX_LOG_TOTAL - total_len, "[%s]", + g_log->log_component[comp].name); + } - // do not apply filtering for LOG_F - // only log messages which are enabled and are below the global log level and component's level threshold - if ( (level != LOG_FILE) && ( (c->level > g_log->level) || (level > c->level) || (level > g_log->level)) ){ - // || ((mac_xface->frame % c->interval) != 0)) { - vcd_signal_dumper_dump_function_by_name(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD,0); - return; - } + if ((g_log->flag & FLAG_LEVEL) || (c->flag & FLAG_LEVEL)) { + total_len += snprintf(&log_buffer[total_len], MAX_LOG_TOTAL - total_len, "[%s]", + g_log->level2string[level]); + } - // adjust syslog level for TRACE messages - if (g_log->syslog) { - if (g_log->level > LOG_DEBUG) { - g_log->level = LOG_DEBUG; - } - } + if ((g_log->flag & FLAG_FUNCT) || (c->flag & FLAG_FUNCT)) { + total_len += snprintf(&log_buffer[total_len], MAX_LOG_TOTAL - total_len, "[%s] ", + func); + } - //if (level == LOG_TRACE) - //exit(-1); - //printf (g_buff_info); - //return; - // make sure that for log trace the extra info is only printed once, reset when the level changes - if ((level == LOG_FILE) || (c->flag == LOG_NONE) || (level ==LOG_TRACE )){ - strncat(g_buff_total, g_buff_info, MAX_LOG_TOTAL-1); - } - else{ - if ( (g_log->flag & FLAG_COLOR) || (c->flag & FLAG_COLOR) ) { - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "%s", - log_level_highlight_start[level]); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); - } + if ((g_log->flag & FLAG_FILE_LINE) || (c->flag & FLAG_FILE_LINE) ) { + total_len += snprintf(&log_buffer[total_len], MAX_LOG_TOTAL - total_len, "[%s:%d]", + file, line); + } - if ( (g_log->flag & FLAG_COMP) || (c->flag & FLAG_COMP) ){ - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "[%s]", - g_log->log_component[comp].name); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); - } + len += snprintf(&log_buffer[total_len], MAX_LOG_TOTAL - len, "%s", + params_string); - if ( (g_log->flag & FLAG_LEVEL) || (c->flag & FLAG_LEVEL) ){ - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "[%s]", - g_log->level2string[level]); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); + if ((g_log->flag & FLAG_COLOR) || (c->flag & FLAG_COLOR)) { + total_len += snprintf(&log_buffer[total_len], MAX_LOG_TOTAL - total_len, "%s", + log_level_highlight_end[level]); + } } - if ( (g_log->flag & FLAG_FUNCT) || (c->flag & FLAG_FUNCT) ) { - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "[%s] ", - func); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); + // OAI printf compatibility + if ((g_log->onlinelog == 1) && (level != LOG_FILE)) { +#ifdef RTAI + if (len > MAX_LOG_TOTAL) { + rt_printk ("[OPENAIR] FIFO_PRINTF WROTE OUTSIDE ITS MEMORY BOUNDARY : ERRORS WILL OCCUR\n"); + } + if (len > 0) { + rtf_put (FIFO_PRINTF_NO, log_buffer, len); + } +#else + fprintf(stdout, "%s", log_buffer); +#endif } - if ( (g_log->flag & FLAG_FILE_LINE) || (c->flag & FLAG_FILE_LINE) ) { - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "[%s:%d]", - file,line); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); +#ifndef RTAI + if (g_log->syslog) { + syslog(g_log->level, "%s", log_buffer); } - strncat(g_buff_total, g_buff_info, MAX_LOG_TOTAL-1); - - - if ( (g_log->flag & FLAG_COLOR) || (c->flag & FLAG_COLOR) ) { - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "%s", - log_level_highlight_end[level]); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); + if (g_log->filelog) { + write(gfd, log_buffer, total_len); + } + if ((g_log->log_component[comp].filelog) && (level == LOG_FILE)) { + write(g_log->log_component[comp].fd, log_buffer, total_len); } +#endif - /* // log trace and not reach a new line with 3 bytes -if ((level == LOG_TRACE) && (is_newline(g_buff_info,3) == 0 )){ - bypass_log_hdr = 1; + vcd_signal_dumper_dump_function_by_name(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD, + VCD_FUNCTION_OUT); } -else - bypass_log_hdr = 0; -*/ - +#if !defined(LOG_NO_THREAD) +void *log_thread_function(void *list) +{ - // strncat(g_buff_total, "\n", MAX_LOG_TOTAL); - } + LOG_params log_params; - // OAI printf compatibility - if ((g_log->onlinelog == 1) && (level != LOG_FILE)) { -#ifdef RTAI - if (len > MAX_LOG_TOTAL) { - rt_printk ("[OPENAIR] FIFO_PRINTF WROTE OUTSIDE ITS MEMORY BOUNDARY : ERRORS WILL OCCUR\n"); - } - if (len > 0) { - rtf_put (FIFO_PRINTF_NO, g_buff_total, len); - } -#else - printf("%s",g_buff_total); -#endif - } + for(;;) { -#ifndef RTAI - if (g_log->syslog) { - syslog(g_log->level, g_buff_total); - } - if (g_log->filelog) { - write(gfd, g_buff_total, strlen(g_buff_total)); - } - if ((g_log->log_component[comp].filelog) && (level == LOG_FILE)) { - write(g_log->log_component[comp].fd, g_buff_total, strlen(g_buff_total)); - } -#endif + //log_elt = NULL; - vcd_signal_dumper_dump_function_by_name(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD,0); + /* Lock must be taken to wait on conditional variable */ + pthread_mutex_lock(&log_lock); -} + /* Wait on condition variable, check for spurious wakeups. + When returning from pthread_cond_wait(), we own the lock. */ -#if !defined(LOG_NO_THREAD) -void *log_thread_function(void * list) { + // sleep + while((log_list_nb_elements == 0) && (log_shutdown == 0)) { + pthread_cond_wait(&log_notify, &log_lock); + } + // exit + if ((log_shutdown==1) && (log_list_nb_elements == 0)) { + break; + } - LOG_params log_params; + /* Grab our task */ + //log_elt = log_list_remove_head(&log_list); + log_params = log_list[log_list_head]; + log_list_head++; + log_list_nb_elements--; + if (log_list_head >= 1000) { + log_list_head = 0; + } - for(;;) { - //log_elt = NULL; + /* Unlock */ + pthread_mutex_unlock(&log_lock); - /* Lock must be taken to wait on conditional variable */ - pthread_mutex_lock(&log_lock); + /* Get to work */ + logRecord_thread_safe(log_params.file, + log_params.func, + log_params.line, + log_params.comp, + log_params.level, + log_params.len, + log_params.l_buff_info); - /* Wait on condition variable, check for spurious wakeups. - When returning from pthread_cond_wait(), we own the lock. */ + //free(log_elt); + } +} +#endif - // sleep - while((log_list_nb_elements == 0) && (log_shutdown == 0)) { - pthread_cond_wait(&log_notify, &log_lock); +//log record, format, and print: executed in the main thread (mt) +void logRecord_mt(const char *file, const char *func, int line, int comp, + int level, char *format, ...) +{ + int len = 0; + va_list args; + log_component_t *c; + + c = &g_log->log_component[comp]; + + // do not apply filtering for LOG_F + // only log messages which are enabled and are below the global log level and component's level threshold + if ((level != LOG_FILE) && ((c->level > g_log->level) || (level > c->level) + || (level > g_log->level))) { + return; } - // exit - if((log_shutdown==1) && (log_list_nb_elements == 0)) { - break; + + vcd_signal_dumper_dump_function_by_name(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD, + VCD_FUNCTION_IN); + + va_start(args, format); + + // adjust syslog level for TRACE messages + if (g_log->syslog) { + if (g_log->level > LOG_DEBUG) { + g_log->level = LOG_DEBUG; + } } - /* Grab our task */ - //log_elt = log_list_remove_head(&log_list); - log_params = log_list[log_list_head]; - log_list_head++; - log_list_nb_elements--; - if (log_list_head >= 1000) log_list_head = 0; + // make sure that for log trace the extra info is only printed once, reset when the level changes + if ((level == LOG_FILE) || (c->flag == LOG_NONE) || (level == LOG_TRACE)) { + len = vsnprintf(c->log_buffer, MAX_LOG_TOTAL-1, format, args); + } else { + if ( (g_log->flag & FLAG_COLOR) || (c->flag & FLAG_COLOR) ) { + len += snprintf(&c->log_buffer[len], MAX_LOG_TOTAL - len, "%s", + log_level_highlight_start[level]); + } + + if ( (g_log->flag & FLAG_COMP) || (c->flag & FLAG_COMP) ) { + len += snprintf(&c->log_buffer[len], MAX_LOG_TOTAL - len, "[%s]", + g_log->log_component[comp].name); + } + if ( (g_log->flag & FLAG_LEVEL) || (c->flag & FLAG_LEVEL) ) { + len += snprintf(&c->log_buffer[len], MAX_LOG_TOTAL - len, "[%s]", + g_log->level2string[level]); + } - /* Unlock */ - pthread_mutex_unlock(&log_lock); + if ( (g_log->flag & FLAG_FUNCT) || (c->flag & FLAG_FUNCT) ) { + len += snprintf(&c->log_buffer[len], MAX_LOG_TOTAL - len, "[%s] ", + func); + } - /* Get to work */ - logRecord_thread_safe(log_params.file, - log_params.func, - log_params.line, - log_params.comp, - log_params.level, - log_params.len, - log_params.l_buff_info); + if ( (g_log->flag & FLAG_FILE_LINE) || (c->flag & FLAG_FILE_LINE) ) { + len += snprintf(&c->log_buffer[len], MAX_LOG_TOTAL - len, "[%s:%d]", + file, line); + } - //free(log_elt); - } -} -#endif + len += vsnprintf(&c->log_buffer[len], MAX_LOG_TOTAL - len, format, args); -//log record, format, and print: executed in the main thread (mt) -void logRecord_mt( const char *file, const char *func, - int line, int comp, int level, - char *format, ...) { - - int len; - va_list args; - log_component_t *c; - - g_buff_total[0] = '\0'; - c = &g_log->log_component[comp]; - - // do not apply filtering for LOG_F - // only log messages which are enabled and are below the global log level and component's level threshold - if ( (level != LOG_FILE) && ( (c->level > g_log->level) || (level > c->level) || (level > g_log->level)) ){ - // || ((mac_xface->frame % c->interval) != 0)) { - return; - } - vcd_signal_dumper_dump_function_by_name(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD,1); - // adjust syslog level for TRACE messages - if (g_log->syslog) { - if (g_log->level > LOG_DEBUG) { - g_log->level = LOG_DEBUG; - } - } - va_start(args, format); - len=vsnprintf(g_buff_info, MAX_LOG_INFO-1, format, args); - va_end(args); - - - //if (level == LOG_TRACE) - //exit(-1); - //printf (g_buff_info); - //return; - // make sure that for log trace the extra info is only printed once, reset when the level changes - if ((level == LOG_FILE) || (c->flag == LOG_NONE) || (level ==LOG_TRACE )){ - strncat(g_buff_total, g_buff_info, MAX_LOG_TOTAL-1); - } - else{ - if ( (g_log->flag & FLAG_COLOR) || (c->flag & FLAG_COLOR) ) { - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "%s", - log_level_highlight_start[level]); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); - } - - if ( (g_log->flag & FLAG_COMP) || (c->flag & FLAG_COMP) ){ - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "[%s]", - g_log->log_component[comp].name); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); - } - - if ( (g_log->flag & FLAG_LEVEL) || (c->flag & FLAG_LEVEL) ){ - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "[%s]", - g_log->level2string[level]); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); - } - - if ( (g_log->flag & FLAG_FUNCT) || (c->flag & FLAG_FUNCT) ) { - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "[%s] ", - func); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); - } - - if ( (g_log->flag & FLAG_FILE_LINE) || (c->flag & FLAG_FILE_LINE) ) { - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "[%s:%d]", - file,line); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); - } - strncat(g_buff_total, g_buff_info, MAX_LOG_TOTAL-1); - - - if ( (g_log->flag & FLAG_COLOR) || (c->flag & FLAG_COLOR) ) { - len+=snprintf(g_buff_tmp, MAX_LOG_ITEM, "%s", - log_level_highlight_end[level]); - strncat(g_buff_total, g_buff_tmp, MAX_LOG_TOTAL-1); - } - - /* // log trace and not reach a new line with 3 bytes - if ((level == LOG_TRACE) && (is_newline(g_buff_info,3) == 0 )){ - bypass_log_hdr = 1; - } - else - bypass_log_hdr = 0; - */ - - - - // strncat(g_buff_total, "\n", MAX_LOG_TOTAL); - } - - // OAI printf compatibility - if ((g_log->onlinelog == 1) && (level != LOG_FILE)) + if ( (g_log->flag & FLAG_COLOR) || (c->flag & FLAG_COLOR) ) { + len += snprintf(&c->log_buffer[len], MAX_LOG_TOTAL - len, "%s", + log_level_highlight_end[level]); + } + } + + va_end(args); + + // OAI printf compatibility + if ((g_log->onlinelog == 1) && (level != LOG_FILE)) #ifdef RTAI - if (len > MAX_LOG_TOTAL) { - rt_printk ("[OPENAIR] FIFO_PRINTF WROTE OUTSIDE ITS MEMORY BOUNDARY : ERRORS WILL OCCUR\n"); - } - if (len > 0) { - rtf_put (FIFO_PRINTF_NO, g_buff_total, len); - } + if (len > MAX_LOG_TOTAL) { + rt_printk ("[OPENAIR] FIFO_PRINTF WROTE OUTSIDE ITS MEMORY BOUNDARY : ERRORS WILL OCCUR\n"); + } + if (len > 0) { + rtf_put (FIFO_PRINTF_NO, c->log_buffer, len); + } #else - printf("%s",g_buff_total); + fprintf(stdout, "%s", c->log_buffer); #endif #ifndef RTAI - if (g_log->syslog) { - syslog(g_log->level, g_buff_total); - } - if (g_log->filelog) { - write(gfd, g_buff_total, strlen(g_buff_total)); - } - if ((g_log->log_component[comp].filelog) && (level == LOG_FILE)) { - write(g_log->log_component[comp].fd, g_buff_total, strlen(g_buff_total)); - } + if (g_log->syslog) { + syslog(g_log->level, "%s", c->log_buffer); + } + if (g_log->filelog) { + write(gfd, c->log_buffer, len); + } + if ((g_log->log_component[comp].filelog) && (level == LOG_FILE)) { + write(g_log->log_component[comp].fd, c->log_buffer, len); + } #endif - vcd_signal_dumper_dump_function_by_name(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD,0); - + vcd_signal_dumper_dump_function_by_name(VCD_SIGNAL_DUMPER_FUNCTIONS_LOG_RECORD, + VCD_FUNCTION_OUT); } -int set_log(int component, int level, int interval) { - - if ((component >=MIN_LOG_COMPONENTS) && (component < MAX_LOG_COMPONENTS)){ - if ((level <= LOG_TRACE) && (level >= LOG_EMERG)){ - g_log->log_component[component].level = level; - switch (level) { - case LOG_TRACE: - g_log->log_component[component].flag = LOG_MED ; - break; - case LOG_DEBUG: - g_log->log_component[component].flag = LOG_MED ; - break; - case LOG_INFO: - g_log->log_component[component].flag = LOG_LOW ; - break; - default: - g_log->log_component[component].flag = LOG_NONE ; - break; - } - } - if ((interval > 0) && (interval <= 0xFF)){ - g_log->log_component[component].interval = interval; + +int set_log(int component, int level, int interval) +{ + /* Checking parameters */ + DevCheck((component >= MIN_LOG_COMPONENTS) && (component < MAX_LOG_COMPONENTS), + component, MIN_LOG_COMPONENTS, MAX_LOG_COMPONENTS); + DevCheck((level <= LOG_TRACE) && (level >= LOG_EMERG), level, LOG_TRACE, + LOG_EMERG); + DevCheck((interval > 0) && (interval <= 0xFF), interval, 0, 0xFF); + + g_log->log_component[component].level = level; + + switch (level) { + case LOG_TRACE: + g_log->log_component[component].flag = LOG_MED ; + break; + case LOG_DEBUG: + g_log->log_component[component].flag = LOG_MED ; + break; + case LOG_INFO: + g_log->log_component[component].flag = LOG_LOW ; + break; + default: + g_log->log_component[component].flag = LOG_NONE ; + break; } + + g_log->log_component[component].interval = interval; + return 0; - } - else - return -1; } -int set_comp_log(int component, int level, int verbosity, int interval) { - - if ((component >=MIN_LOG_COMPONENTS) && (component < MAX_LOG_COMPONENTS)){ - if ((verbosity == LOG_NONE) || (verbosity == LOG_LOW) || (verbosity == LOG_MED) || (verbosity == LOG_FULL) || (verbosity == LOG_HIGH) ) { - g_log->log_component[component].flag = verbosity; - } - if ((level <= LOG_TRACE) && (level >= LOG_EMERG)){ - g_log->log_component[component].level = level; - } - if ((interval > 0) && (interval <= 0xFF)){ - g_log->log_component[component].interval = interval; +int set_comp_log(int component, int level, int verbosity, int interval) +{ + /* Checking parameters */ + DevCheck((component >= MIN_LOG_COMPONENTS) && (component < MAX_LOG_COMPONENTS), + component, MIN_LOG_COMPONENTS, MAX_LOG_COMPONENTS); + DevCheck((level <= LOG_TRACE) && (level >= LOG_EMERG), level, LOG_TRACE, + LOG_EMERG); + DevCheck((interval > 0) && (interval <= 0xFF), interval, 0, 0xFF); + + if ((verbosity == LOG_NONE) || (verbosity == LOG_LOW) || + (verbosity == LOG_MED) || (verbosity == LOG_FULL) || + (verbosity == LOG_HIGH)) { + g_log->log_component[component].flag = verbosity; } + + g_log->log_component[component].level = level; + g_log->log_component[component].interval = interval; + return 0; - } - else - return -1; } -void set_glog(int level, int verbosity) { - g_log->level = level; - g_log->flag = verbosity; +void set_glog(int level, int verbosity) +{ + g_log->level = level; + g_log->flag = verbosity; } -void set_glog_syslog(int enable) { - g_log->syslog = enable; +void set_glog_syslog(int enable) +{ + g_log->syslog = enable; } -void set_glog_onlinelog(int enable) { - g_log->onlinelog = enable; +void set_glog_onlinelog(int enable) +{ + g_log->onlinelog = enable; } -void set_glog_filelog(int enable) { - g_log->filelog = enable; +void set_glog_filelog(int enable) +{ + g_log->filelog = enable; } -void set_component_filelog(int comp){ - - if (g_log->log_component[comp].filelog == 0){ - g_log->log_component[comp].filelog = 1; - if (g_log->log_component[comp].fd == 0) - g_log->log_component[comp].fd = open(g_log->log_component[comp].filelog_name, O_WRONLY | O_CREAT | O_TRUNC, 0666); - } +void set_component_filelog(int comp) +{ + + if (g_log->log_component[comp].filelog == 0) { + g_log->log_component[comp].filelog = 1; + if (g_log->log_component[comp].fd == 0) { + g_log->log_component[comp].fd = open(g_log->log_component[comp].filelog_name, + O_WRONLY | O_CREAT | O_TRUNC, 0666); + } + } } /* @@ -743,7 +725,8 @@ void set_component_filelog(int comp){ * with string value NULL */ /* map a string to an int. Takes a mapping array and a string as arg */ -int map_str_to_int(mapping *map, const char *str){ +int map_str_to_int(mapping *map, const char *str) +{ while (1) { if (map->name == NULL) { return(-1); @@ -756,7 +739,8 @@ int map_str_to_int(mapping *map, const char *str){ } /* map an int to a string. Takes a mapping array and a value */ -char *map_int_to_str(mapping *map, int val) { +char *map_int_to_str(mapping *map, int val) +{ while (1) { if (map->name == NULL) { return NULL; @@ -767,113 +751,119 @@ char *map_int_to_str(mapping *map, int val) { map++; } } -int is_newline( char *str, int size){ + +int is_newline( char *str, int size) +{ int i; for ( i = 0; i < size; i++ ) { - if ( str[i] == '\n' ) - return 1; + if ( str[i] == '\n' ) { + return 1; + } } /* if we get all the way to here, there must not have been a newline! */ return 0; } -void logClean (void) { - int i; + +void logClean (void) +{ + int i; #ifdef RTAI - rtf_destroy (FIFO_PRINTF_NO); + rtf_destroy (FIFO_PRINTF_NO); #else - if (g_log->syslog) { - closelog(); - } - if (g_log->filelog) { - close(gfd); - } - for (i=MIN_LOG_COMPONENTS; i < MAX_LOG_COMPONENTS; i++){ - if (g_log->log_component[i].filelog) - close(g_log->log_component[i].fd); - } + if (g_log->syslog) { + closelog(); + } + if (g_log->filelog) { + close(gfd); + } + for (i=MIN_LOG_COMPONENTS; i < MAX_LOG_COMPONENTS; i++) { + if (g_log->log_component[i].filelog) { + close(g_log->log_component[i].fd); + } + } #endif } - #ifdef LOG_TEST -int -main(int argc, char *argv[]) { +int main(int argc, char *argv[]) +{ - logInit(); + logInit(); - //set_log_syslog(1); - test_log(); - - return 1; + //set_log_syslog(1); + test_log(); + + return 1; } -int test_log(){ - - LOG_ENTER(MAC); // because the default level is DEBUG - LOG_I(EMU, "1 Starting OAI logs version %s Build date: %s on %s\n", - BUILD_VERSION, BUILD_DATE, BUILD_HOST); - LOG_D(MAC, "1 debug MAC \n"); - LOG_N(MAC, "1 notice MAC \n"); - LOG_W(MAC, "1 warning MAC \n"); - - set_comp_log(EMU, LOG_INFO, FLAG_ONLINE); - set_comp_log(MAC, LOG_WARNING, 0); - - LOG_I(EMU, "2 Starting OAI logs version %s Build date: %s on %s\n", - BUILD_VERSION, BUILD_DATE, BUILD_HOST); - LOG_E(MAC, "2 emerge MAC\n"); - LOG_D(MAC, "2 debug MAC \n"); - LOG_N(MAC, "2 notice MAC \n"); - LOG_W(MAC, "2 warning MAC \n"); - LOG_I(MAC, "2 info MAC \n"); - - - set_comp_log(MAC, LOG_NOTICE, 1); - - LOG_ENTER(MAC); - LOG_I(EMU, "3 Starting OAI logs version %s Build date: %s on %s\n", - BUILD_VERSION, BUILD_DATE, BUILD_HOST); - LOG_D(MAC, "3 debug MAC \n"); - LOG_N(MAC, "3 notice MAC \n"); - LOG_W(MAC, "3 warning MAC \n"); - LOG_I(MAC, "3 info MAC \n"); - - set_comp_log(MAC, LOG_DEBUG,1); - set_comp_log(EMU, LOG_DEBUG,1); - - LOG_ENTER(MAC); - LOG_I(EMU, "4 Starting OAI logs version %s Build date: %s on %s\n", - BUILD_VERSION, BUILD_DATE, BUILD_HOST); - LOG_D(MAC, "4 debug MAC \n"); - LOG_N(MAC, "4 notice MAC \n"); - LOG_W(MAC, "4 warning MAC \n"); - LOG_I(MAC, "4 info MAC \n"); - - - set_comp_log(MAC, LOG_DEBUG,0); - set_comp_log(EMU, LOG_DEBUG,0); - - LOG_I(LOG, "5 Starting OAI logs version %s Build date: %s on %s\n", - BUILD_VERSION, BUILD_DATE, BUILD_HOST); - LOG_D(MAC, "5 debug MAC \n"); - LOG_N(MAC, "5 notice MAC \n"); - LOG_W(MAC, "5 warning MAC \n"); - LOG_I(MAC, "5 info MAC \n"); - - - set_comp_log(MAC, LOG_TRACE,0X07F); - set_comp_log(EMU, LOG_TRACE,0X07F); - - LOG_ENTER(MAC); - LOG_I(LOG, "6 Starting OAI logs version %s Build date: %s on %s\n", - BUILD_VERSION, BUILD_DATE, BUILD_HOST); - LOG_D(MAC, "6 debug MAC \n"); - LOG_N(MAC, "6 notice MAC \n"); - LOG_W(MAC, "6 warning MAC \n"); - LOG_I(MAC, "6 info MAC \n"); - LOG_EXIT(MAC); +int test_log(void) +{ + LOG_ENTER(MAC); // because the default level is DEBUG + LOG_I(EMU, "1 Starting OAI logs version %s Build date: %s on %s\n", + BUILD_VERSION, BUILD_DATE, BUILD_HOST); + LOG_D(MAC, "1 debug MAC \n"); + LOG_N(MAC, "1 notice MAC \n"); + LOG_W(MAC, "1 warning MAC \n"); + + set_comp_log(EMU, LOG_INFO, FLAG_ONLINE); + set_comp_log(MAC, LOG_WARNING, 0); + + LOG_I(EMU, "2 Starting OAI logs version %s Build date: %s on %s\n", + BUILD_VERSION, BUILD_DATE, BUILD_HOST); + LOG_E(MAC, "2 emerge MAC\n"); + LOG_D(MAC, "2 debug MAC \n"); + LOG_N(MAC, "2 notice MAC \n"); + LOG_W(MAC, "2 warning MAC \n"); + LOG_I(MAC, "2 info MAC \n"); + + + set_comp_log(MAC, LOG_NOTICE, 1); + + LOG_ENTER(MAC); + LOG_I(EMU, "3 Starting OAI logs version %s Build date: %s on %s\n", + BUILD_VERSION, BUILD_DATE, BUILD_HOST); + LOG_D(MAC, "3 debug MAC \n"); + LOG_N(MAC, "3 notice MAC \n"); + LOG_W(MAC, "3 warning MAC \n"); + LOG_I(MAC, "3 info MAC \n"); + + set_comp_log(MAC, LOG_DEBUG,1); + set_comp_log(EMU, LOG_DEBUG,1); + + LOG_ENTER(MAC); + LOG_I(EMU, "4 Starting OAI logs version %s Build date: %s on %s\n", + BUILD_VERSION, BUILD_DATE, BUILD_HOST); + LOG_D(MAC, "4 debug MAC \n"); + LOG_N(MAC, "4 notice MAC \n"); + LOG_W(MAC, "4 warning MAC \n"); + LOG_I(MAC, "4 info MAC \n"); + + + set_comp_log(MAC, LOG_DEBUG,0); + set_comp_log(EMU, LOG_DEBUG,0); + + LOG_I(LOG, "5 Starting OAI logs version %s Build date: %s on %s\n", + BUILD_VERSION, BUILD_DATE, BUILD_HOST); + LOG_D(MAC, "5 debug MAC \n"); + LOG_N(MAC, "5 notice MAC \n"); + LOG_W(MAC, "5 warning MAC \n"); + LOG_I(MAC, "5 info MAC \n"); + + + set_comp_log(MAC, LOG_TRACE,0X07F); + set_comp_log(EMU, LOG_TRACE,0X07F); + + LOG_ENTER(MAC); + LOG_I(LOG, "6 Starting OAI logs version %s Build date: %s on %s\n", + BUILD_VERSION, BUILD_DATE, BUILD_HOST); + LOG_D(MAC, "6 debug MAC \n"); + LOG_N(MAC, "6 notice MAC \n"); + LOG_W(MAC, "6 warning MAC \n"); + LOG_I(MAC, "6 info MAC \n"); + LOG_EXIT(MAC); + return 0; } #endif diff --git a/openair2/UTIL/LOG/log.h b/openair2/UTIL/LOG/log.h index 9fbb7878402cbfbc336099c0f88d2c35c66b4af3..1b9fd091dfb894227a332ea98b54358b989d95b3 100755 --- a/openair2/UTIL/LOG/log.h +++ b/openair2/UTIL/LOG/log.h @@ -233,7 +233,7 @@ extern "C" { typedef enum { MIN_LOG_COMPONENTS = 0, - PHY, + PHY = MIN_LOG_COMPONENTS, MAC, EMU, OCG, @@ -270,12 +270,15 @@ typedef struct { typedef struct { const char *name; - int level; - int flag; - int interval; - int fd; - int filelog; - char* filelog_name; + int level; + int flag; + int interval; + int fd; + int filelog; + char *filelog_name; + + /* SR: make the log buffer component relative */ + char log_buffer[MAX_LOG_TOTAL]; }log_component_t; typedef struct { @@ -285,7 +288,7 @@ typedef struct { int facility; int audit_facility; int format; -}log_config_t; +} log_config_t; typedef struct { @@ -311,6 +314,14 @@ typedef struct LOG_params { int len; } LOG_params; +extern log_t *g_log; + +#if !defined(LOG_NO_THREAD) +extern LOG_params log_list[2000]; +extern pthread_mutex_t log_lock; +extern pthread_cond_t log_notify; +extern int log_shutdown; +#endif /*--- INCLUDES ---------------------------------------------------------------*/ # include "log_if.h" diff --git a/openair2/UTIL/LOG/log_extern.h b/openair2/UTIL/LOG/log_extern.h index 72f955c658a7a565679fd65be285b45284b86c24..e69de29bb2d1d6434b8b29ae775ad8c2e48c5391 100644 --- a/openair2/UTIL/LOG/log_extern.h +++ b/openair2/UTIL/LOG/log_extern.h @@ -1,7 +0,0 @@ - -extern log_t *g_log; - -extern LOG_params log_list[2000]; -extern pthread_mutex_t log_lock; -extern pthread_cond_t log_notify; -extern int log_shutdown; diff --git a/openair2/UTIL/LOG/log_vars.h b/openair2/UTIL/LOG/log_vars.h deleted file mode 100644 index 9d655078a2c8c5de97d97f629a839de55eceb0bb..0000000000000000000000000000000000000000 --- a/openair2/UTIL/LOG/log_vars.h +++ /dev/null @@ -1,13 +0,0 @@ - - -// main log variables -log_t *g_log; - -// vars for the log thread -LOG_params log_list[2000]; -int log_list_head = 0; -int log_list_tail = 0; -int log_list_nb_elements = 0; -pthread_mutex_t log_lock; -pthread_cond_t log_notify; -int log_shutdown;