Commit 0b396900 authored by Robert Schmidt's avatar Robert Schmidt

Merge remote-tracking branch 'origin/episys-remove-log-minimal' into integration_2022_wk05_b

parents 49df71dd 5e182c4e
......@@ -3,6 +3,7 @@
```C
LOG_E(<component>,<format>,<argument>,...)
LOG_W(<component>,<format>,<argument>,...)
LOG_A(<component>,<format>,<argument>,...)
LOG_I(<component>,<format>,<argument>,...)
LOG_D(<component>,<format>,<argument>,...)
LOG_T(<component>,<format>,<argument>,...)
......@@ -14,9 +15,10 @@ these macros are used in place of the printf C function. The additionnal ***comp
|:---------|:---------------|:---------------|----------------:|
| LOG_E | E | 0 | error |
| LOG_W | W | 1 | warning |
| LOG_I | I | 2 | informational |
| LOG_D | D | 3 | debug |
| LOG_T | T | 4 | trace |
| LOG_A | A | 2 | analysis |
| LOG_I | I | 3 | informational |
| LOG_D | D | 4 | debug |
| LOG_T | T | 5 | trace |
component list is defined as an `enum` in [log.h](https://gitlab.eurecom.fr/oai/openairinterface5g/blob/develop/common/utils/LOG/log.h). A new component can be defined by adding an item in this type, it must also be defined in the T tracer [T_messages.txt ](https://gitlab.eurecom.fr/oai/openairinterface5g/blob/develop/common/utils/T/T_messages.txt).
......
......@@ -7,9 +7,9 @@ All logging facility parameters are defined in the log_config section. Some para
| name | type | default | description |
|:---:|:---:|:---:|:----|
| `global_log_level` | `pre-defined string of char` | `info` | Allows printing of messages up to the specified level. Available levels, from lower to higher are `error`,`warn`,`info`,`debug`,`trace` |
| `global_log_level` | `pre-defined string of char` | `info` | Allows printing of messages up to the specified level. Available levels, from lower to higher are `error`,`warn`,`analysis`,`info`,`debug`,`trace` |
| `global_log_online` | `boolean` | 1 (=true) | If false, all console messages are discarded, whatever their level |
| `global_log_options` | `list of pre-defined string of char` | | 3 options can be specified to trigger the information added in the header of the message: `nocolor`, disable color usage in log messages, usefull when redirecting logs to a file, where escape sequences used for color selection can be annoying, `level`, add a one letter level id in the message header (T,D,I,W,E for trace, debug, info, warning, error),`thread`, add the thread name in the message header, `function`, adds the function name, `line_num`, adds the line number, `time` adds the time since process starts|
| `global_log_options` | `list of pre-defined string of char` | | 5 options can be specified to trigger the information added in the header of the message: `nocolor`, disable color usage in log messages, usefull when redirecting logs to a file, where escape sequences used for color selection can be annoying, `level`, add a one letter level id in the message header (T,D,I,A,W,E for trace, debug, info, analysis, warning, error),`thread`, add the thread name in the message header, `thread_id`, adds the thread ID in the message header, `function`, adds the function name, `line_num`, adds the line number, `time` adds the time since process starts|
### Component specific parameters
| name | type | default | description |
......
......@@ -65,6 +65,7 @@ char logmem_filename[1024] = {0};
mapping log_level_names[] = {
{"error", OAILOG_ERR},
{"warn", OAILOG_WARNING},
{"analysis", OAILOG_ANALYSIS},
{"info", OAILOG_INFO},
{"debug", OAILOG_DEBUG},
{"trace", OAILOG_TRACE},
......@@ -78,14 +79,15 @@ mapping log_options[] = {
{"line_num", FLAG_FILE_LINE },
{"function", FLAG_FUNCT},
{"time", FLAG_TIME},
{"thread_id", FLAG_THREAD_ID},
{NULL,-1}
};
mapping log_maskmap[] = LOG_MASKMAP_INIT;
char *log_level_highlight_start[] = {LOG_RED, LOG_ORANGE, "", LOG_BLUE, LOG_CYBL}; /*!< \brief Optional start-format strings for highlighting */
char *log_level_highlight_end[] = {LOG_RESET,LOG_RESET,LOG_RESET, LOG_RESET,LOG_RESET}; /*!< \brief Optional end-format strings for highlighting */
char *log_level_highlight_start[] = {LOG_RED, LOG_ORANGE, LOG_GREEN, "", LOG_BLUE, LOG_CYBL}; /*!< \brief Optional start-format strings for highlighting */
char *log_level_highlight_end[] = {LOG_RESET, LOG_RESET, LOG_RESET, LOG_RESET, LOG_RESET, LOG_RESET}; /*!< \brief Optional end-format strings for highlighting */
static void log_output_memory(log_component_t *c, const char *file, const char *func, int line, int comp, int level, const char* format,va_list args);
......@@ -501,6 +503,7 @@ int logInit (void)
return 0;
}
#include <sys/syscall.h>
static inline int log_header(log_component_t *c,
char *log_buffer,
int buffsize,
......@@ -514,32 +517,45 @@ static inline int log_header(log_component_t *c,
char threadname[64];
if (flag & FLAG_THREAD ) {
threadname[0]='{';
if ( pthread_getname_np(pthread_self(), threadname+1,61) != 0)
if (pthread_getname_np(pthread_self(), threadname + 1, sizeof(threadname) - 3) != 0)
strcpy(threadname+1, "?thread?");
strcat(threadname,"}");
strcat(threadname,"} ");
} else {
threadname[0]=0;
}
char l[32];
if (flag & FLAG_FILE_LINE && flag & FLAG_FUNCT )
snprintf(l, sizeof l," (%s:%d) ", func, line);
snprintf(l, sizeof l, "(%s:%d) ", func, line);
else if (flag & FLAG_FILE_LINE)
sprintf(l," (%d) ", line);
snprintf(l, sizeof l, "(%d) ", line);
else if (flag & FLAG_FUNCT)
snprintf(l, sizeof l, "(%s) ", func);
else
l[0]=0;
l[0] = 0;
char timeString[32];
if ( flag & FLAG_TIME ) {
struct timespec t;
clock_gettime(CLOCK_MONOTONIC, &t);
snprintf(timeString, sizeof t,"%05.3f",t.tv_sec+t.tv_nsec/1.0e9);
if (clock_gettime(CLOCK_MONOTONIC, &t) == -1)
abort();
snprintf(timeString, sizeof(timeString), "%lu.%06lu ",
t.tv_sec,
t.tv_nsec / 1000);
} else {
timeString[0]=0;
timeString[0] = 0;
}
return snprintf(log_buffer, buffsize, "%s%s[%s]%c%s %s ",
timeString,
char threadIdString[32];
if (flag & FLAG_THREAD_ID) {
snprintf(threadIdString, sizeof(threadIdString), "%08lx ", syscall(__NR_gettid));
} else {
threadIdString[0] = 0;
}
return snprintf(log_buffer, buffsize, "%s%s%s[%s] %c %s%s",
flag & FLAG_NOCOLOR ? "" : log_level_highlight_start[level],
timeString,
threadIdString,
c->name,
flag & FLAG_LEVEL ? g_log->level2string[level] : ' ',
l,
......@@ -547,53 +563,6 @@ static inline int log_header(log_component_t *c,
);
}
#if LOG_MINIMAL
#include <sys/syscall.h>
void logMinimal(int comp, int level, const char *format, ...)
{
struct timespec ts;
if (clock_gettime(CLOCK_MONOTONIC, &ts) == -1)
abort();
char buf[MAX_LOG_TOTAL];
int n = snprintf(buf, sizeof(buf), "%lu.%06lu %08lx [%s] %c ",
ts.tv_sec,
ts.tv_nsec / 1000,
syscall(__NR_gettid),
g_log->log_component[comp].name,
level);
if (n < 0 || n >= sizeof(buf))
{
fprintf(stderr, "%s: n=%d\n", __func__, n);
return;
}
va_list args;
va_start(args, format);
int m = vsnprintf(buf + n, sizeof(buf) - n, format, args);
va_end(args);
if (m < 0)
{
fprintf(stderr, "%s: n=%d m=%d\n", __func__, n, m);
return;
}
int len = n + m;
if (len > sizeof(buf) - 1)
{
len = sizeof(buf) - 1;
}
if (buf[len - 1] != '\n')
{
buf[len++] = '\n';
}
__attribute__((unused))
int unused = write(STDOUT_FILENO, buf, len);
}
#endif // LOG_MINIMAL
void logRecord_mt(const char *file,
const char *func,
int line,
......@@ -864,7 +833,14 @@ void flush_mem_to_file(void)
}
}
char logmem_log_level[NUM_LOG_LEVEL]={'E','W','I','D','T'};
const char logmem_log_level[NUM_LOG_LEVEL] = {
[OAILOG_ERR] = 'E',
[OAILOG_WARNING] = 'W',
[OAILOG_ANALYSIS] = 'A',
[OAILOG_INFO] = 'I',
[OAILOG_DEBUG] = 'D',
[OAILOG_TRACE] = 'T',
};
static void log_output_memory(log_component_t *c, const char *file, const char *func, int line, int comp, int level, const char* format,va_list args)
{
......@@ -878,11 +854,31 @@ static void log_output_memory(log_component_t *c, const char *file, const char *
char log_buffer[MAX_LOG_TOTAL];
// make sure that for log trace the extra info is only printed once, reset when the level changes
if (level < OAILOG_TRACE)
len += log_header(c, log_buffer, MAX_LOG_TOTAL, file, func, line, level);
len += vsnprintf(log_buffer+len, MAX_LOG_TOTAL-len, format, args);
if ( !((g_log->flag | c->flag) & FLAG_NOCOLOR) )
len+=snprintf(log_buffer+len, MAX_LOG_TOTAL-len, "%s", log_level_highlight_end[level]);
if (level < OAILOG_TRACE) {
int n = log_header(c, log_buffer+len, MAX_LOG_TOTAL, file, func, line, level);
if (n > 0) {
len += n;
if (len > MAX_LOG_TOTAL) {
len = MAX_LOG_TOTAL;
}
}
}
int n = vsnprintf(log_buffer+len, MAX_LOG_TOTAL-len, format, args);
if (n > 0) {
len += n;
if (len > MAX_LOG_TOTAL) {
len = MAX_LOG_TOTAL;
}
}
if ( !((g_log->flag | c->flag) & FLAG_NOCOLOR) ) {
int n = snprintf(log_buffer+len, MAX_LOG_TOTAL-len, "%s", log_level_highlight_end[level]);
if (n > 0) {
len += n;
if (len > MAX_LOG_TOTAL) {
len = MAX_LOG_TOTAL;
}
}
}
// OAI printf compatibility
if(log_mem_flag==1){
......@@ -919,6 +915,7 @@ static void log_output_memory(log_component_t *c, const char *file, const char *
}
}
}else{
AssertFatal(len >= 0 && len <= MAX_LOG_TOTAL, "Bad len %d\n", len);
if (write(fileno(c->stream), log_buffer, len)) {};
}
}
......
......@@ -90,11 +90,12 @@ extern "C" {
# define OAILOG_DISABLE -1 /*!< \brief disable all LOG messages, cannot be used in LOG macros, use only in LOG module */
# define OAILOG_ERR 0 /*!< \brief critical error conditions, impact on "must have" functionalities */
# define OAILOG_WARNING 1 /*!< \brief warning conditions, shouldn't happen but doesn't impact "must have" functionalities */
# define OAILOG_INFO 2 /*!< \brief informational messages most people don't need, shouldn't impact real-time behavior */
# define OAILOG_DEBUG 3 /*!< \brief first level debug-level messages, for developers, may impact real-time behavior */
# define OAILOG_TRACE 4 /*!< \brief second level debug-level messages, for developers, likely impact real-time behavior*/
# define OAILOG_ANALYSIS 2 /*!< \brief informational messages most people don't need, shouldn't impact real-time behavior */
# define OAILOG_INFO 3 /*!< \brief informational messages most people don't need, shouldn't impact real-time behavior */
# define OAILOG_DEBUG 4 /*!< \brief first level debug-level messages, for developers, may impact real-time behavior */
# define OAILOG_TRACE 5 /*!< \brief second level debug-level messages, for developers, likely impact real-time behavior*/
#define NUM_LOG_LEVEL 5 /*!< \brief the number of message levels users have with LOG (OAILOG_DISABLE is not available to user as a level, so it is not included)*/
#define NUM_LOG_LEVEL 6 /*!< \brief the number of message levels users have with LOG (OAILOG_DISABLE is not available to user as a level, so it is not included)*/
/* @}*/
......@@ -127,6 +128,7 @@ extern "C" {
#define FLAG_FUNCT 0x0020
#define FLAG_FILE_LINE 0x0040
#define FLAG_TIME 0x0100
#define FLAG_THREAD_ID 0x0200
#define FLAG_INITIALIZED 0x8000
#define SET_LOG_OPTION(O) g_log->flag = (g_log->flag | O)
......@@ -390,7 +392,7 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
/* optname help paramflags XXXptr defXXXval type numelt */
/*-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------*/
#define LOG_GLOBALPARAMS_DESC { \
{LOG_CONFIG_STRING_GLOBAL_LOG_LEVEL, "Default log level for all componemts\n", 0, strptr:(char **)&gloglevel, defstrval:log_level_names[2].name, TYPE_STRING, 0}, \
{LOG_CONFIG_STRING_GLOBAL_LOG_LEVEL, "Default log level for all componemts\n", 0, strptr:(char **)&gloglevel, defstrval:log_level_names[3].name, TYPE_STRING, 0}, \
{LOG_CONFIG_STRING_GLOBAL_LOG_ONLINE, "Default console output option, for all components\n", 0, iptr:&(consolelog), defintval:1, TYPE_INT, 0}, \
{LOG_CONFIG_STRING_GLOBAL_LOG_OPTIONS, LOG_CONFIG_HELP_OPTIONS, 0, strlistptr:NULL, defstrlistval:NULL, TYPE_STRINGLIST, 0} \
}
......@@ -408,32 +410,14 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
// debugging macros
#define LOG_F LOG_I /* because LOG_F was originaly to dump a message or buffer but is also used as a regular level...., to dump use LOG_DUMPMSG */
#if LOG_MINIMAL
void logMinimal(int component, int level, const char *format, ...) __attribute__((format(printf, 3, 4)));
# define LOG_E(COMPONENT, ...) do if (1) logMinimal(COMPONENT, 'E', __VA_ARGS__); while (0)
# define LOG_W(COMPONENT, ...) do if (1) logMinimal(COMPONENT, 'W', __VA_ARGS__); while (0)
# define LOG_A(COMPONENT, ...) do if (1) logMinimal(COMPONENT, 'A', __VA_ARGS__); while (0) /* logs intended for analysis */
# define LOG_I(COMPONENT, ...) do if (1) logMinimal(COMPONENT, 'I', __VA_ARGS__); while (0)
# define LOG_D(COMPONENT, ...) do if (0) logMinimal(COMPONENT, 'D', __VA_ARGS__); while (0)
# define LOG_T(COMPONENT, ...) do if (0) logMinimal(COMPONENT, 'T', __VA_ARGS__); while (0)
# define LOG_M(FILE, VECTOR, DATA, LEN, DEC, FORMAT) ((void) 0)
# define LOG_DUMPFLAG(D) 0
# define LOG_DEBUGFLAG(D) 0
# define LOG_DUMPMSG(C, B, S, X...) ((void) 0)
# define VLOG(C, L, F, ARGS) ((void) 0)
#else // LOG_MINIMAL
# if T_TRACER
/* per component, level dependent macros */
# define LOG_E(c, x...) do { T(T_LEGACY_ ## c ## _ERROR, T_PRINTF(x)) ; if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_ERR ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_ERR, x) ;} } while (0)
# define LOG_W(c, x...) do { T(T_LEGACY_ ## c ## _WARNING, T_PRINTF(x)); if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_WARNING) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_WARNING, x);} } while (0)
# define LOG_A LOG_I
# define LOG_I(c, x...) do { T(T_LEGACY_ ## c ## _INFO, T_PRINTF(x)) ; if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_INFO ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_INFO, x) ;} } while (0)
# define LOG_D(c, x...) do { T(T_LEGACY_ ## c ## _DEBUG, T_PRINTF(x)) ; if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_DEBUG ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_DEBUG, x) ;} } while (0)
# define LOG_T(c, x...) do { T(T_LEGACY_ ## c ## _TRACE, T_PRINTF(x)) ; if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_TRACE ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_TRACE, x) ;} } while (0)
# define LOG_E(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_ERR ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_ERR, x) ;} else { T(T_LEGACY_ ## c ## _ERROR, T_PRINTF(x)) ;}} while (0)
# define LOG_W(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_WARNING) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_WARNING, x) ;} else { T(T_LEGACY_ ## c ## _WARNING, T_PRINTF(x)) ;}} while (0)
# define LOG_A(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_ANALYSIS) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_ANALYSIS, x) ;} else { T(T_LEGACY_ ## c ## _INFO, T_PRINTF(x)) ;}} while (0)
# define LOG_I(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_INFO ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_INFO, x) ;} else { T(T_LEGACY_ ## c ## _INFO, T_PRINTF(x)) ;}} while (0)
# define LOG_D(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_DEBUG ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_DEBUG, x) ;} else { T(T_LEGACY_ ## c ## _DEBUG, T_PRINTF(x)) ;}} while (0)
# define LOG_T(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_TRACE ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_TRACE, x) ;} else { T(T_LEGACY_ ## c ## _TRACE, T_PRINTF(x)) ;}} while (0)
# define VLOG(c,l, f, args) do { if (T_stdout) { if( g_log->log_component[c].level >= l ) vlogRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, l, f, args) ;} } while (0)
/* macro used to dump a buffer or a message as in openair2/RRC/LTE/RRC_eNB.c, replaces LOG_F macro */
# define LOG_DUMPMSG(c, f, b, s, x...) do { if(g_log->dump_mask & f) log_dump(c, b, s, LOG_DUMP_CHAR, x) ;} while (0) /* */
......@@ -449,8 +433,8 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
# define LOG_E(c, x...) do { if( g_log->log_component[c].level >= OAILOG_ERR ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_ERR, x) ;} while (0)
# define LOG_W(c, x...) do { if( g_log->log_component[c].level >= OAILOG_WARNING) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_WARNING, x) ;} while (0)
# define LOG_A(c, x...) do { if( g_log->log_component[c].level >= OAILOG_ANALYSIS) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_ANALYSIS, x);} while (0)
# define LOG_I(c, x...) do { if( g_log->log_component[c].level >= OAILOG_INFO ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_INFO, x) ;} while (0)
# define LOG_A LOG_I
# define LOG_D(c, x...) do { if( g_log->log_component[c].level >= OAILOG_DEBUG ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_DEBUG, x) ;} while (0)
# define LOG_T(c, x...) do { if( g_log->log_component[c].level >= OAILOG_TRACE ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_TRACE, x) ;} while (0)
# define VLOG(c,l, f, args) do { if( g_log->log_component[c].level >= l ) vlogRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, l, f, args) ; } while (0)
......@@ -464,7 +448,6 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
# define LOG_VAR(A,B) A B
# define T_ACTIVE(a) (0)
# endif /* T_TRACER */
#endif // LOG_MINIMAL
/* avoid warnings for variables only used in LOG macro's but set outside debug section */
#define GCC_NOTUSED __attribute__((unused))
......
......@@ -617,7 +617,7 @@ rrc_gNB_process_RRCSetupComplete(
)
//-----------------------------------------------------------------------------
{
LOG_I(NR_RRC, PROTOCOL_NR_RRC_CTXT_UE_FMT" [RAPROC] Logical Channel UL-DCCH, " "processing NR_RRCSetupComplete from UE (SRB1 Active)\n",
LOG_A(NR_RRC, PROTOCOL_NR_RRC_CTXT_UE_FMT" [RAPROC] Logical Channel UL-DCCH, " "processing NR_RRCSetupComplete from UE (SRB1 Active)\n",
PROTOCOL_NR_RRC_CTXT_UE_ARGS(ctxt_pP));
ue_context_pP->ue_context.Srb1.Active = 1;
ue_context_pP->ue_context.Srb1.Srb_info.Srb_id = 1;
......@@ -1347,7 +1347,7 @@ rrc_gNB_process_RRCReconfigurationComplete(
for (int i = 0; i < DRB_configList->list.count; i++) {
if (DRB_configList->list.array[i]) {
drb_id = (int)DRB_configList->list.array[i]->drb_Identity;
LOG_I(NR_RRC, "[gNB %d] Frame %d : Logical Channel UL-DCCH, Received NR_RRCReconfigurationComplete from UE rnti %x, reconfiguring DRB %d\n",
LOG_A(NR_RRC, "[gNB %d] Frame %d : Logical Channel UL-DCCH, Received NR_RRCReconfigurationComplete from UE rnti %x, reconfiguring DRB %d\n",
ctxt_pP->module_id,
ctxt_pP->frame,
ctxt_pP->rnti,
......
......@@ -674,7 +674,7 @@ void decodeDownlinkNASTransport(as_nas_info_t *initialNasMsg, uint8_t * pdu_buff
sprintf(baseNetAddress, "%d.%d", *(pdu_buffer + 39),*(pdu_buffer + 40));
int third_octet = *(pdu_buffer + 41);
int fourth_octet = *(pdu_buffer + 42);
LOG_I(NAS, "Received PDU Session Establishment Accept\n");
LOG_A(NAS, "Received PDU Session Establishment Accept\n");
nas_config(1,third_octet,fourth_octet,"ue");
} else {
LOG_E(NAS, "Received unexpected message in DLinformationTransfer %d\n", msg_type);
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment