maki/openairinterface5g
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Use LOG_A for log messages intended for analysis

Browse Source 
This change allows us to disable the LOG_I messages to reduce
overhead.

Removed LOG_VAR macro because it was used in only one place, and
a better solution is to simply use `__attribute__((unused))`.
This commit is contained in:
Michael Cook
2020-09-06 07:54:56 -07:00
parent 36c9df19b8
commit 3a2e4a3189
13 changed files with 86 additions and 18 deletions
Download Patch File Download Diff File Expand all files Collapse all files
common/utils/LOG/log.c
+44
View File
@@ -477,6 +477,50 @@ char *log_getthreadname(char *threadname,
}
}
#if LOG_MINIMAL
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 [%s] %c ",
ts.tv_sec,
ts.tv_nsec / 1000,
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';
}
write(STDOUT_FILENO, buf, len);
}
#endif // LOG_MINIMAL
static int log_header(char *log_buffer,
int buffsize,
int comp,
common/utils/LOG/log.h
+25 -3
View File
@@ -387,10 +387,32 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
#define LOG_DUMP_DOUBLE 1
// 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 */
#define LOG_MINIMAL 1 /* 1 for minimal logging: E, W and A */
#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 (0) 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 { 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 LOG_I
# 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)
@@ -403,11 +425,10 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
/* bitmask dependent macros, to generate debug file such as matlab file or message dump */
# define LOG_DUMPFLAG(D) (g_log->dump_mask & D)
# define LOG_M(file, vector, data, len, dec, format) do { write_file_matlab(file, vector, data, len, dec, format);} while(0)/* */
/* define variable only used in LOG macro's */
# define LOG_VAR(A,B) A B
# else /* T_TRACER: remove all debugging and tracing messages, except errors */
# define LOG_I(c, x...) do {logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_INFO, x) ; } while(0)/* */
# define LOG_W(c, x...) do {logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_WARNING, x) ; } while(0)/* */
# define LOG_A LOG_I
# define LOG_E(c, x...) do {logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_ERR, x) ; } while(0)/* */
# define LOG_D(c, x...) do {logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_DEBUG, x) ; } while(0)/* */
# define LOG_T(c, x...) /* */
@@ -417,8 +438,9 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
# define LOG_DEBUGFLAG(D) ( 0 )
# define LOG_DUMPFLAG(D) ( 0 )
# define LOG_M(file, vector, data, len, dec, format) do { write_file_matlab(file, vector, data, len, dec, format);} while(0)
# define LOG_VAR(A,B)
# 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))
#define LOG_USEDINLOG_VAR(A,B) GCC_NOTUSED A B
openair1/PHY/INIT/lte_init.c
+1 -1
View File
@@ -95,7 +95,7 @@ void phy_config_request(PHY_Config_t *phy_config) {
int Ncp = cfg->subframe_config.dl_cyclic_prefix_type.value;
int p_eNB = cfg->rf_config.tx_antenna_ports.value;
uint32_t dl_CarrierFreq = cfg->nfapi_config.earfcn.value;
LOG_I(PHY,"Configuring MIB for instance %d, CCid %d : (band %d,N_RB_DL %d, N_RB_UL %d, Nid_cell %d,eNB_tx_antenna_ports %d,Ncp %d,DL freq %u,phich_config.resource %d, phich_config.duration %d)\n",
LOG_A(PHY,"Configuring MIB for instance %d, CCid %d : (band %d,N_RB_DL %d, N_RB_UL %d, Nid_cell %d,eNB_tx_antenna_ports %d,Ncp %d,DL freq %u,phich_config.resource %d, phich_config.duration %d)\n",
Mod_id, CC_id, eutra_band, dl_Bandwidth, ul_Bandwidth, Nid_cell, p_eNB,Ncp,dl_CarrierFreq,
cfg->phich_config.phich_resource.value,
cfg->phich_config.phich_duration.value);
openair1/PHY/INIT/nr_init.c
+1 -1
View File
@@ -466,7 +466,7 @@ void nr_phy_config_request(NR_PHY_Config_t *phy_config) {
AssertFatal(fp->ul_CarrierFreq==(fp->dl_CarrierFreq+dlul_offset), "Disagreement in uplink frequency for band %d\n", fp->nr_band);
fp->threequarter_fs = openair0_cfg[0].threequarter_fs;
LOG_I(PHY,"Configuring MIB for instance %d, : (Nid_cell %d,DL freq %llu, UL freq %llu)\n",
LOG_A(PHY,"Configuring MIB for instance %d, : (Nid_cell %d,DL freq %llu, UL freq %llu)\n",
Mod_id,
gNB_config->cell_config.phy_cell_id.value,
(unsigned long long)fp->dl_CarrierFreq,
openair2/F1AP/f1ap_du_rrc_message_transfer.c
+1 -1
View File
@@ -718,7 +718,7 @@ int DU_send_UL_RRC_MESSAGE_TRANSFER(instance_t instance,
LOG_E(F1AP, "Did not find the UE context associated with UE RNTOI %x, ue_context_p is NULL\n", rnti);
} else {
LOG_I(F1AP, "Processing RRCConnectionSetupComplete UE %x\n", rnti);
LOG_A(F1AP, "Processing RRCConnectionSetupComplete UE %x\n", rnti);
ue_context_p->ue_context.Status = RRC_CONNECTED;
}
break;
openair2/LAYER2/MAC/config.c
+1 -1
View File
@@ -797,7 +797,7 @@ int rrc_mac_config_req_eNB(module_id_t Mod_idP,
RC.mac[Mod_idP]->common_channels[CC_idP].Ncp = Ncp;
RC.mac[Mod_idP]->common_channels[CC_idP].eutra_band = eutra_band;
RC.mac[Mod_idP]->common_channels[CC_idP].dl_CarrierFreq = dl_CarrierFreq;
LOG_I(MAC,
LOG_A(MAC,
"Configuring MIB for instance %d, CCid %d : (band %d,N_RB_DL %d,Nid_cell %d,p %d,DL freq %u,phich_config.resource %d, phich_config.duration %d)\n",
Mod_idP,
CC_idP,
openair2/LAYER2/MAC/eNB_scheduler_RA.c
+1 -1
View File
@@ -925,7 +925,7 @@ generate_Msg4(module_id_t module_idP,
module_idP, CC_idP, frameP, subframeP, UE_id, rrc_sdu_length);
// AssertFatal(rrc_sdu_length > 0,
// "[MAC][eNB Scheduler] CCCH not allocated, rrc_sdu_length: %d\n", rrc_sdu_length);
LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d, subframeP %d: Generating Msg4 with RRC Piggyback (RNTI %x)\n",
LOG_A(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d, subframeP %d: Generating Msg4 with RRC Piggyback (RNTI %x)\n",
module_idP, CC_idP, frameP, subframeP, ra->rnti);
/// Choose first 4 RBs for Msg4, should really check that these are free!
first_rb = 0;
openair2/LAYER2/MAC/rar_tools_ue.c
+1 -1
View File
@@ -94,7 +94,7 @@ uint16_t ue_process_rar(const module_id_t module_idP, const int CC_id, const fra
return (0xffff);
}
LOG_I(MAC,
LOG_A(MAC,
"[UE %d][RAPROC] Frame %d Received RAR (%02x|%02x.%02x.%02x.%02x.%02x.%02x) for preamble %d/%d\n",
module_idP, frameP, *(uint8_t *) rarh, rar[0], rar[1], rar[2],
rar[3], rar[4], rar[5], rarh->RAPID, preamble_index);
openair2/PHY_INTERFACE/phy_stub_UE.c
+1 -1
View File
@@ -1307,7 +1307,7 @@ const char *hexdump(const void *data, size_t data_len, char *out, size_t out_len
{
case NFAPI_RACH_INDICATION:
encoded_size = nfapi_p7_message_pack(&UL->rach_ind, buffer, sizeof(buffer), NULL);
LOG_I(MAC, "RACH_IND sent to Proxy, Size: %d Frame %d Subframe %d\n", encoded_size,
LOG_A(MAC, "RACH_IND sent to Proxy, Size: %d Frame %d Subframe %d\n", encoded_size,
NFAPI_SFNSF2SFN(UL->rach_ind.sfn_sf), NFAPI_SFNSF2SF(UL->rach_ind.sfn_sf));
break;
case NFAPI_CRC_INDICATION:
openair2/RRC/LTE/rrc_UE.c
+3 -3
View File
@@ -505,7 +505,7 @@ static void rrc_ue_generate_RRCConnectionSetupComplete( const protocol_ctxt_t *c
}
size = do_RRCConnectionSetupComplete(ctxt_pP->module_id, buffer, Transaction_id, nas_msg_length, nas_msg);
LOG_I(RRC,"[UE %d][RAPROC] Frame %d Subframe %d : Logical Channel UL-DCCH (SRB1), Generating RRCConnectionSetupComplete (bytes%d, eNB %d)\n",
LOG_A(RRC,"[UE %d][RAPROC] Frame %d Subframe %d : Logical Channel UL-DCCH (SRB1), Generating RRCConnectionSetupComplete (bytes%d, eNB %d)\n",
ctxt_pP->module_id,ctxt_pP->frame, ctxt_pP->subframe, size, eNB_index);
LOG_D(RLC,
"[FRAME %05d][RRC_UE][MOD %02d][][--- PDCP_DATA_REQ/%d Bytes (RRCConnectionSetupComplete to eNB %d MUI %d) --->][PDCP][MOD %02d][RB %02d]\n",
@@ -606,7 +606,7 @@ int rrc_ue_decode_ccch( const protocol_ctxt_t *const ctxt_pP, const SRB_INFO *co
break;
case LTE_DL_CCCH_MessageType__c1_PR_rrcConnectionSetup:
LOG_I(RRC,
LOG_A(RRC,
"[UE%d][RAPROC] Frame %d : Logical Channel DL-CCCH (SRB0), Received RRCConnectionSetup RNTI %x\n",
ctxt_pP->module_id,
ctxt_pP->frame,
@@ -1618,7 +1618,7 @@ rrc_ue_process_ueCapabilityEnquiry(
xer_fprint(stdout, &asn_DEF_LTE_UL_DCCH_Message, (void *)&ul_dcch_msg);
}
LOG_I(RRC,"UECapabilityInformation Encoded %zd bits (%zd bytes)\n",enc_rval.encoded,(enc_rval.encoded+7)/8);
LOG_A(RRC,"UECapabilityInformation Encoded %zd bits (%zd bytes)\n",enc_rval.encoded,(enc_rval.encoded+7)/8);
rrc_data_req_ue (
ctxt_pP,
DCCH,
openair2/RRC/LTE/rrc_eNB.c
+4 -4
View File
@@ -150,7 +150,7 @@ init_SI(
LOG_D(RRC,"%s()\n\n\n\n",__FUNCTION__);
if(configuration->radioresourceconfig[CC_id].mbms_dedicated_serving_cell == TRUE) {
LOG_I(RRC, "Configuring MIB FeMBMS (N_RB_DL %d)\n",
LOG_A(RRC, "Configuring MIB FeMBMS (N_RB_DL %d)\n",
(int)configuration->N_RB_DL[CC_id]);
RC.rrc[ctxt_pP->module_id]->carrier[CC_id].MIB_FeMBMS = (uint8_t *) malloc16(4);
do_MIB_FeMBMS(&RC.rrc[ctxt_pP->module_id]->carrier[CC_id],
@@ -250,7 +250,7 @@ init_SI(
carrier->N_RB_DL = configuration->N_RB_DL[CC_id];
carrier->pbch_repetition = configuration->pbch_repetition[CC_id];
LOG_I(RRC, "configuration->schedulingInfoSIB1_BR_r13[CC_id] %d\n",(int)configuration->schedulingInfoSIB1_BR_r13[CC_id]);
LOG_I(RRC, "Configuring MIB (N_RB_DL %d,phich_Resource %d,phich_Duration %d)\n",
LOG_A(RRC, "Configuring MIB (N_RB_DL %d,phich_Resource %d,phich_Duration %d)\n",
(int)configuration->N_RB_DL[CC_id],
(int)configuration->radioresourceconfig[CC_id].phich_resource,
(int)configuration->radioresourceconfig[CC_id].phich_duration);
@@ -1161,7 +1161,7 @@ rrc_eNB_process_RRCConnectionSetupComplete(
)
//-----------------------------------------------------------------------------
{
LOG_I(RRC, PROTOCOL_RRC_CTXT_UE_FMT" [RAPROC] Logical Channel UL-DCCH, " "processing LTE_RRCConnectionSetupComplete from UE (SRB1 Active)\n",
LOG_A(RRC, PROTOCOL_RRC_CTXT_UE_FMT" [RAPROC] Logical Channel UL-DCCH, " "processing LTE_RRCConnectionSetupComplete from UE (SRB1 Active)\n",
PROTOCOL_RRC_CTXT_UE_ARGS(ctxt_pP));
ue_context_pP->ue_context.Srb1.Active = 1;
ue_context_pP->ue_context.Status = RRC_CONNECTED;
@@ -7883,7 +7883,7 @@ rrc_eNB_decode_dcch(
xer_fprint(stdout, &asn_DEF_LTE_UL_DCCH_Message, (void *)ul_dcch_msg);
}
LOG_I(RRC, "got UE capabilities for UE %x\n", ctxt_pP->rnti);
LOG_A(RRC, "got UE capabilities for UE %x\n", ctxt_pP->rnti);
int eutra_index = -1;
openair3/NAS/UE/ESM/PdnConnectivity.c
+1 -1
View File
@@ -356,7 +356,7 @@ int esm_proc_pdn_connectivity_accept(nas_user_t *user, int pti, esm_proc_pdn_typ
int pid = RETURNerror;
char apn_first_char[4];
LOG_VAR(char, str[128]);
char str[128] __attribute__((unused));
if (isprint(apn->value[0])) {
apn_first_char[0] = '\0';
targets/RT/USER/lte-ru.c
+2
View File
@@ -1544,6 +1544,7 @@ static void *ru_stats_thread(void *param) {
static void *ru_thread_tx( void *param ) {
RU_t *ru = (RU_t *)param;
RU_proc_t *proc = &ru->proc;
__attribute__((unused))
LTE_DL_FRAME_PARMS *fp = ru->frame_parms;
PHY_VARS_eNB *eNB;
L1_proc_t *eNB_proc;
@@ -1958,6 +1959,7 @@ static void *ru_thread( void *param ) {
// This thread run the initial synchronization like a UE
void *ru_thread_synch(void *arg) {
RU_t *ru = (RU_t *)arg;
__attribute__((unused))
LTE_DL_FRAME_PARMS *fp = ru->frame_parms;
int64_t peak_val, avg;
static int ru_thread_synch_status = 0;