From 536b5d8760c01d8aaa4d90b456890b306f7b6d91 Mon Sep 17 00:00:00 2001 From: Laurent THOMAS <laurent.thomas@open-cells.com> Date: Thu, 23 Jan 2025 11:59:01 +0100 Subject: [PATCH] Clean up logging module debug flags cleanup debug/dump flags by avoiding repetitions in the source code and enable compiler checks. Add a help text if we set a wrong debug trace option. --- common/utils/LOG/log.c | 89 ++++++-------- common/utils/LOG/log.h | 94 ++++++++++----- common/utils/telnetsrv/telnetsrv_proccmd.c | 83 ++++++------- openair1/PHY/LTE_TRANSPORT/prach.c | 43 +++---- openair1/PHY/NR_TRANSPORT/nr_prach.c | 21 ++-- openair1/SCHED_UE/phy_procedures_lte_ue.c | 120 +++++++++---------- openair1/SIMULATION/LTE_PHY/dlsim.c | 2 +- openair1/SIMULATION/LTE_PHY/mbmssim.c | 2 +- openair1/SIMULATION/LTE_PHY/ulsim.c | 2 +- openair1/SIMULATION/NR_PHY/prachsim.c | 2 +- openair2/F1AP/f1ap_cu_interface_management.c | 4 +- 11 files changed, 233 insertions(+), 229 deletions(-) diff --git a/common/utils/LOG/log.c b/common/utils/LOG/log.c index af6c30b858d..b8349fb3585 100644 --- a/common/utils/LOG/log.c +++ b/common/utils/LOG/log.c @@ -120,28 +120,6 @@ mapping * log_option_names_ptr(void) return log_options; } -static mapping log_maskmap[] = {{"PRACH", DEBUG_PRACH}, - {"RU", DEBUG_RU}, - {"UE_PHYPROC", DEBUG_UE_PHYPROC}, - {"LTEESTIM", DEBUG_LTEESTIM}, - {"DLCELLSPEC", DEBUG_DLCELLSPEC}, - {"ULSCH", DEBUG_ULSCH}, - {"RRC", DEBUG_RRC}, - {"PDCP", DEBUG_PDCP}, - {"DFT", DEBUG_DFT}, - {"ASN1", DEBUG_ASN1}, - {"CTRLSOCKET", DEBUG_CTRLSOCKET}, - {"SECURITY", DEBUG_SECURITY}, - {"NAS", DEBUG_NAS}, - {"RLC", DEBUG_RLC}, - {"DLSCH_DECOD", DEBUG_DLSCH_DECOD}, - {"UE_TIMING", UE_TIMING}, - {NULL, -1}}; -mapping * log_maskmap_ptr(void) -{ - return log_maskmap; -} - /* .log_format = 0x13 uncolored standard messages * .log_format = 0x93 colored standard messages */ /* keep white space in first position; switching it to 0 allows colors to be disabled*/ @@ -327,6 +305,9 @@ int write_file_matlab(const char *fname, const char *vname, void *data, int leng return 0; } +#define FLAG_SETDEBUG(flag) g_log->debug_mask.DEBUG_##flag = *logparams_debug[i++].uptr; +#define FLAG_SETDUMP(flag) g_log->dump_mask.DEBUG_##flag = *logparams_dump[i++].uptr; + /* get log parameters from configuration file */ void log_getconfig(log_t *g_log) { @@ -335,8 +316,6 @@ void log_getconfig(log_t *g_log) paramdef_t logparams_defaults[] = LOG_GLOBALPARAMS_DESC; paramdef_t logparams_level[MAX_LOG_PREDEF_COMPONENTS]; paramdef_t logparams_logfile[MAX_LOG_PREDEF_COMPONENTS]; - paramdef_t logparams_debug[sizeofArray(log_maskmap)]; - paramdef_t logparams_dump[sizeofArray(log_maskmap)]; int ret = config_get(config_get_if(), logparams_defaults, sizeofArray(logparams_defaults), CONFIG_STRING_LOG_PREFIX); if (ret <0) { @@ -404,37 +383,45 @@ void log_getconfig(log_t *g_log) } /* build then read the debug and dump parameter array */ - for (int i=0; log_maskmap[i].name != NULL ; i++) { - sprintf(logparams_debug[i].optname, LOG_CONFIG_DEBUG_FORMAT, log_maskmap[i].name); - sprintf(logparams_dump[i].optname, LOG_CONFIG_DUMP_FORMAT, log_maskmap[i].name); - logparams_debug[i].defuintval = 0; - logparams_debug[i].type = TYPE_UINT; - logparams_debug[i].paramflags = PARAMFLAG_BOOL; - logparams_debug[i].uptr = NULL; - logparams_debug[i].chkPptr = NULL; - logparams_debug[i].numelt = 0; - logparams_dump[i].defuintval = 0; - logparams_dump[i].type = TYPE_UINT; - logparams_dump[i].paramflags = PARAMFLAG_BOOL; - logparams_dump[i].uptr = NULL; - logparams_dump[i].chkPptr = NULL; - logparams_dump[i].numelt = 0; + int sz = 0; + for (const char *const *ptr = flag_name; strlen(*ptr) > 1; ptr++) + sz++; + paramdef_t logparams_debug[sz]; + paramdef_t logparams_dump[sz]; + for (int i = 0; i < sz; i++) { + logparams_debug[i] = (paramdef_t){ + .type = TYPE_UINT, + .paramflags = PARAMFLAG_BOOL, + }; + sprintf(logparams_debug[i].optname, LOG_CONFIG_DEBUG_FORMAT, flag_name[i]); + logparams_dump[i] = (paramdef_t){.type = TYPE_UINT, .paramflags = PARAMFLAG_BOOL}; + sprintf(logparams_dump[i].optname, LOG_CONFIG_DUMP_FORMAT, flag_name[i]); } - config_get(config_get_if(), logparams_debug, sizeofArray(log_maskmap) - 1, CONFIG_STRING_LOG_PREFIX); - config_get(config_get_if(), logparams_dump, sizeofArray(log_maskmap) - 1, CONFIG_STRING_LOG_PREFIX); - - if (config_check_unknown_cmdlineopt(config_get_if(), CONFIG_STRING_LOG_PREFIX) > 0) + config_get(config_get_if(), logparams_debug, sz, CONFIG_STRING_LOG_PREFIX); + config_get(config_get_if(), logparams_dump, sz, CONFIG_STRING_LOG_PREFIX); + + bool old = CONFIG_ISFLAGSET(CONFIG_NOABORTONCHKF); + CONFIG_SETRTFLAG(CONFIG_NOABORTONCHKF); + if (config_check_unknown_cmdlineopt(config_get_if(), CONFIG_STRING_LOG_PREFIX) > 0) { + printf("Existing log_config options:\n"); + printf(" Boolean options:\n"); + for (int i = 0; i < sz; i++) + printf(" %s, \t%s\n", logparams_debug[i].optname, logparams_dump[i].optname); + printf(" Log level per module ("); + for (int i = 0; log_level_names[i].name != NULL; i++) + printf("%s ", log_level_names[i].name); + printf(")\n"); + for (int i = 0; i < MAX_LOG_PREDEF_COMPONENTS; i++) + printf(" %s\n", logparams_level[i].optname); exit(1); - - /* set the debug mask according to the debug parameters values */ - for (int i=0; log_maskmap[i].name != NULL ; i++) { - if (*(logparams_debug[i].uptr) ) - g_log->debug_mask = g_log->debug_mask | log_maskmap[i].value; - - if (*(logparams_dump[i].uptr) ) - g_log->dump_mask = g_log->dump_mask | log_maskmap[i].value; } + if (!old) + CONFIG_CLEARRTFLAG(CONFIG_NOABORTONCHKF); + int i = 0; + FOREACH_FLAG(FLAG_SETDEBUG); + i = 0; + FOREACH_FLAG(FLAG_SETDUMP); /* log globally enabled/disabled */ set_glog_onlinelog(consolelog); diff --git a/common/utils/LOG/log.h b/common/utils/LOG/log.h index f16ee296d47..d153a4aeafd 100644 --- a/common/utils/LOG/log.h +++ b/common/utils/LOG/log.h @@ -88,7 +88,7 @@ extern "C" { #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)*/ /** @}*/ -#define SET_LOG_OPTION(O) g_log->flag = (g_log->flag | O) +#define SET_LOG_OPTION(O) g_log->flag = (g_log->flag | O) #define CLEAR_LOG_OPTION(O) g_log->flag = (g_log->flag & (~O)) /** @defgroup macros to identify a debug entity @@ -99,28 +99,37 @@ extern "C" { * server. * @brief * @{*/ -#define DEBUG_PRACH (1<<0) -#define DEBUG_RU (1<<1) -#define DEBUG_UE_PHYPROC (1<<2) -#define DEBUG_LTEESTIM (1<<3) -#define DEBUG_DLCELLSPEC (1<<4) -#define DEBUG_ULSCH (1<<5) -#define DEBUG_RRC (1<<6) -#define DEBUG_PDCP (1<<7) -#define DEBUG_DFT (1<<8) -#define DEBUG_ASN1 (1<<9) -#define DEBUG_CTRLSOCKET (1<<10) -#define DEBUG_SECURITY (1<<11) -#define DEBUG_NAS (1<<12) -#define DEBUG_RLC (1<<13) -#define DEBUG_DLSCH_DECOD (1<<14) -#define UE_TIMING (1<<20) - -#define SET_LOG_DEBUG(B) g_log->debug_mask = (g_log->debug_mask | B) -#define CLEAR_LOG_DEBUG(B) g_log->debug_mask = (g_log->debug_mask & (~B)) - -#define SET_LOG_DUMP(B) g_log->dump_mask = (g_log->dump_mask | B) -#define CLEAR_LOG_DUMP(B) g_log->dump_mask = (g_log->dump_mask & (~B)) + +#define FOREACH_FLAG(FLAG_DEF) \ + FLAG_DEF(PRACH) \ + FLAG_DEF(UE_PHYPROC) \ + FLAG_DEF(LTEESTIM) \ + FLAG_DEF(DLCELLSPEC) \ + FLAG_DEF(ULSCH) \ + FLAG_DEF(RRC) \ + FLAG_DEF(PDCP) \ + FLAG_DEF(DFT) \ + FLAG_DEF(ASN1) \ + FLAG_DEF(CTRLSOCKET) \ + FLAG_DEF(SECURITY) \ + FLAG_DEF(NAS) \ + FLAG_DEF(DLSCH_DECOD) \ + FLAG_DEF(UE_TIMING) \ + FLAG_DEF(F1AP) + +#define FLAG_BITF(flag) uint64_t DEBUG_##flag: 1; +typedef struct { + FOREACH_FLAG(FLAG_BITF) +} debug_flags_t; + +#define FLAG_TEXT(flag) #flag, +static const char *const flag_name[] = {FOREACH_FLAG(FLAG_TEXT) ""}; + +#define SET_LOG_DEBUG(B) g_log->debug_mask.B = true +#define CLEAR_LOG_DEBUG(B) g_log->debug_mask.B = false + +#define SET_LOG_DUMP(B) g_log->dump_mask.B = true +#define CLEAR_LOG_DUMP(B) g_log->dump_mask.B = false #define FOREACH_COMP(COMP_DEF) \ COMP_DEF(PHY, log) \ @@ -215,8 +224,8 @@ typedef struct { char level2string[NUM_LOG_LEVEL]; int flag; char *filelog_name; - uint64_t debug_mask; - uint64_t dump_mask; + debug_flags_t debug_mask; + debug_flags_t dump_mask; } log_t; #ifdef LOG_MAIN @@ -230,7 +239,28 @@ extern "C" { } #endif #endif - +#define FLAG_DEBUG_SET(flag) \ + if (strcmp(name, #flag) == 0) { \ + g_log->debug_mask.DEBUG_##flag = val; \ + return true; \ + }; +static inline bool set_log_debug(char *name, bool val) +{ + FOREACH_FLAG(FLAG_DEBUG_SET); + printf("Error: setting log debug of %s option, not existing\n", name); + return false; +} +#define FLAG_DUMP_SET(flag) \ + if (strcmp(name, #flag) == 0) { \ + g_log->dump_mask.DEBUG_##flag = val; \ + return true; \ + }; +static inline bool set_log_dump(char *name, bool val) +{ + FOREACH_FLAG(FLAG_DUMP_SET); + printf("Error: setting log dump of %s option, not existing\n", name); + return false; +} /*----------------------------------------------------------------------------*/ int logInit (void); void logTerm (void); @@ -418,15 +448,15 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int /* 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) \ + if (g_log->dump_mask.f) \ log_dump(c, b, s, LOG_DUMP_CHAR, x); \ } while (0) /* bitmask dependent macros, to isolate debugging code */ -#define LOG_DEBUGFLAG(D) (g_log->debug_mask & D) +#define LOG_DEBUGFLAG(D) (g_log->debug_mask.D) /* 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_DUMPFLAG(D) (g_log->dump_mask.D) #define LOG_M(file, vector, data, len, dec, format) \ do { \ @@ -529,11 +559,11 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int } while (0) #define nfapi_log(FILE, FNC, LN, COMP, LVL, FMT...) -#define LOG_DEBUGFLAG(D) (g_log->debug_mask & D) -#define LOG_DUMPFLAG(D) (g_log->dump_mask & D) +#define LOG_DEBUGFLAG(D) (g_log->debug_mask.D) +#define LOG_DUMPFLAG(D) (g_log->dump_mask.D) #define LOG_DUMPMSG(c, f, b, s, x...) \ do { \ - if (g_log->dump_mask & f) \ + if (g_log->dump_mask.f) \ log_dump(c, b, s, LOG_DUMP_CHAR, x); \ } while (0) /* */ diff --git a/common/utils/telnetsrv/telnetsrv_proccmd.c b/common/utils/telnetsrv/telnetsrv_proccmd.c index f081bb66a1c..f79e9f5287b 100644 --- a/common/utils/telnetsrv/telnetsrv_proccmd.c +++ b/common/utils/telnetsrv/telnetsrv_proccmd.c @@ -251,12 +251,17 @@ void print_threads(char *buf, int debug, telnet_printfunc_t prnt) proccmd_get_threaddata(buf, debug, prnt, NULL); } +#define FLAG_PRINT_DEBUG_DUMP(flag) \ + logsdata->lines[i].val[0] = (char *)flag_name[i]; \ + logsdata->lines[i].val[1] = g_log->debug_mask.DEBUG_##flag ? "true" : "false"; \ + logsdata->lines[i].val[1] = g_log->dump_mask.DEBUG_##flag ? "true" : "false"; \ + i++; + int proccmd_websrv_getdata(char *cmdbuff, int debug, void *data, telnet_printfunc_t prnt) { webdatadef_t *logsdata = (webdatadef_t *)data; const mapping *const log_level_names = log_level_names_ptr(); const mapping *const log_options = log_option_names_ptr(); - const mapping *log_maskmap = log_maskmap_ptr(); if (strncmp(cmdbuff, "set", 3) == 0) { telnet_printfunc_t printfunc = (prnt != NULL) ? prnt : (telnet_printfunc_t)printf; if (strcasestr(cmdbuff, "loglvl") != NULL) { @@ -291,23 +296,16 @@ int proccmd_websrv_getdata(char *cmdbuff, int debug, void *data, telnet_printfun } } if (strcasestr(cmdbuff, "dbgopt") != NULL) { - int optbit = map_str_to_int(log_maskmap, logsdata->lines[0].val[0]); - if (optbit < 0) { - printfunc("debug option %s unknown\n", logsdata->lines[0].val[0]); - } else { - if (strcmp(logsdata->lines[0].val[1], "true") == 0) - SET_LOG_DEBUG(optbit); - else - CLEAR_LOG_DEBUG(optbit); - if (strcmp(logsdata->lines[0].val[2], "true") == 0) - SET_LOG_DUMP(optbit); - else - CLEAR_LOG_DUMP(optbit); - printfunc("%s debug %s dump %s\n", - logsdata->lines[0].val[0], - (strcmp(logsdata->lines[0].val[1], "true") == 0) ? "enabled" : "disabled", - (strcmp(logsdata->lines[0].val[2], "true") == 0) ? "enabled" : "disabled"); - } + if (strcmp(logsdata->lines[0].val[1], "true") == 0) + if (!set_log_debug(logsdata->lines[0].val[0], strcmp(logsdata->lines[0].val[2], "true") == 0)) + printfunc("debug option %s unknown\n", logsdata->lines[0].val[0]); + if (strcmp(logsdata->lines[0].val[2], "true") == 0) + if (!set_log_dump(logsdata->lines[0].val[0], strcmp(logsdata->lines[0].val[2], "true") == 0)) + printfunc("debug option %s unknown\n", logsdata->lines[0].val[0]); + printfunc("%s debug %s dump %s\n", + logsdata->lines[0].val[0], + (strcmp(logsdata->lines[0].val[1], "true") == 0) ? "enabled" : "disabled", + (strcmp(logsdata->lines[0].val[2], "true") == 0) ? "enabled" : "disabled"); } if (strcasestr(cmdbuff, "threadsched") != NULL) { unsigned int tid = strtoll(logsdata->lines[0].val[0], NULL, 0); @@ -354,12 +352,9 @@ int proccmd_websrv_getdata(char *cmdbuff, int debug, void *data, telnet_printfun snprintf(logsdata->columns[2].coltitle, TELNET_CMD_MAXSIZE, "dump"); logsdata->columns[2].coltype = TELNET_CHECKVAL_BOOL; - for (int i = 0; log_maskmap[i].name != NULL; i++) { - logsdata->numlines++; - logsdata->lines[i].val[0] = (char *)log_maskmap[i].name; - logsdata->lines[i].val[1] = (g_log->debug_mask & log_maskmap[i].value) ? "true" : "false"; - logsdata->lines[i].val[2] = (g_log->dump_mask & log_maskmap[i].value) ? "true" : "false"; - } + int i = 0; + FOREACH_FLAG(FLAG_PRINT_DEBUG_DUMP); + logsdata->numlines += i; } if (strcasestr(cmdbuff, "logopt") != NULL) { @@ -385,6 +380,14 @@ int proccmd_websrv_getdata(char *cmdbuff, int debug, void *data, telnet_printfun return 0; } +#define FLAG_PRINT2_DEBUG_DUMP(flag) \ + prnt("%02i %17.17s %5.5s %5.5s\n", \ + i, \ + flag_name[i], \ + g_log->debug_mask.DEBUG_##flag ? "Y" : "N", \ + g_log->dump_mask.DEBUG_##flag ? "Y" : "N"); \ + i++; + int proccmd_show(char *buf, int debug, telnet_printfunc_t prnt) { if (buf == NULL) { @@ -422,12 +425,8 @@ int proccmd_show(char *buf, int debug, telnet_printfunc_t prnt) } if (strcasestr(buf,"dbgopt") != NULL) { prnt("\n module debug dumpfile\n"); - const mapping *log_maskmap = log_maskmap_ptr(); - for (int i=0; log_maskmap[i].name != NULL ; i++) { - prnt("%02i %17.17s %5.5s %5.5s\n",i ,log_maskmap[i].name, - ((g_log->debug_mask & log_maskmap[i].value)?"Y":"N"), - ((g_log->dump_mask & log_maskmap[i].value)?"Y":"N") ); - } + int i = 0; + FOREACH_FLAG(FLAG_PRINT2_DEBUG_DUMP); } if (strcasestr(buf,"config") != NULL) { prnt("Command line arguments:\n"); @@ -593,28 +592,16 @@ int s = sscanf(buf,"%ms %i-%i\n",&logsubcmd, &idx1,&idx2); } } else if (l == 2 && strcmp(logparam,"debug") == 0){ - optbit = map_str_to_int(log_maskmap, opt); - if (optbit < 0) { + int ret = set_log_debug(opt, idx1 > 0); + if (!ret) prnt("module %s unknown\n", opt); - } else { - if (idx1 > 0) - SET_LOG_DEBUG(optbit); - else - CLEAR_LOG_DEBUG(optbit); - proccmd_show("dbgopt", debug, prnt); - } + proccmd_show("dbgopt", debug, prnt); } else if (l == 2 && strcmp(logparam,"dump") == 0){ - optbit = map_str_to_int(log_maskmap, opt); - if (optbit < 0) { + int ret = set_log_dump(opt, idx1 > 0); + if (!ret) prnt("module %s unknown\n", opt); - } else { - if (idx1 > 0) - SET_LOG_DUMP(optbit); - else - CLEAR_LOG_DUMP(optbit); - proccmd_show("dump", debug, prnt); - } + proccmd_show("dump", debug, prnt); } if (logparam != NULL) free(logparam); if (opt != NULL) free(opt); diff --git a/openair1/PHY/LTE_TRANSPORT/prach.c b/openair1/PHY/LTE_TRANSPORT/prach.c index 92350194ca6..e2205490456 100644 --- a/openair1/PHY/LTE_TRANSPORT/prach.c +++ b/openair1/PHY/LTE_TRANSPORT/prach.c @@ -132,7 +132,7 @@ void rx_prach0(PHY_VARS_eNB *eNB, prach_ifftp = eNB->prach_vars_br.prach_ifft[ce_level]; rxsigF = eNB->prach_vars_br.rxsigF[ce_level]; - if (LOG_DEBUGFLAG(PRACH)) { + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { if (((frame_prach)&1023) < 20) LOG_D(PHY, "PRACH (eNB) : running rx_prach (br_flag %d, ce_level %d) for frame %d subframe %d, prach_FreqOffset %d, prach_ConfigIndex %d, rootSequenceIndex %d, repetition number %d,numRepetitionsPrePreambleAttempt %d\n", br_flag,ce_level,frame_prach,subframe, @@ -145,23 +145,26 @@ void rx_prach0(PHY_VARS_eNB *eNB, prach_ifftp = eNB->prach_vars.prach_ifft[0]; rxsigF = eNB->prach_vars.rxsigF[0]; - //if (LOG_DEBUGFLAG(PRACH)) { - if (((frame_prach)&1023) < 20) LOG_D(PHY,"PRACH (eNB) : running rx_prach for subframe %d, prach_FreqOffset %d, prach_ConfigIndex %d , rootSequenceIndex %d\n", subframe, - fp->prach_config_common.prach_ConfigInfo.prach_FreqOffset,prach_ConfigIndex,rootSequenceIndex); - //} + if (((frame_prach) & 1023) < 20) + LOG_D(PHY, + "PRACH (eNB) : running rx_prach for subframe %d, prach_FreqOffset %d, prach_ConfigIndex %d , rootSequenceIndex %d\n", + subframe, + fp->prach_config_common.prach_ConfigInfo.prach_FreqOffset, + prach_ConfigIndex, + rootSequenceIndex); } } else { if (br_flag == 1) { rxsigF = ru->prach_rxsigF_br[ce_level]; - if (LOG_DEBUGFLAG(PRACH)) { + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { if (((frame_prach)&1023) < 20) LOG_D(PHY,"PRACH (RU) : running rx_prach (br_flag %d, ce_level %d) for frame %d subframe %d, prach_FreqOffset %d, prach_ConfigIndex %d\n", br_flag,ce_level,frame_prach,subframe,fp->prach_emtc_config_common.prach_ConfigInfo.prach_FreqOffset[ce_level],prach_ConfigIndex); } } else { rxsigF = ru->prach_rxsigF[0]; - if (LOG_DEBUGFLAG(PRACH)) { + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { if (((frame_prach)&1023) < 20) LOG_D(PHY,"PRACH (RU) : running rx_prach for subframe %d, prach_FreqOffset %d, prach_ConfigIndex %d\n", subframe,fp->prach_config_common.prach_ConfigInfo.prach_FreqOffset,prach_ConfigIndex); } @@ -178,7 +181,7 @@ void rx_prach0(PHY_VARS_eNB *eNB, // DJP - indexing below in subframe zero takes us off the beginning of the array??? prach[aa] = (int16_t *)&ru->common.rxdata[aa][(subframe*fp->samples_per_tti)-ru->N_TA_offset]; - if (LOG_DUMPFLAG(PRACH)) { + if (LOG_DUMPFLAG(DEBUG_PRACH)) { int32_t en0=signal_energy((int32_t *)prach[aa],fp->samples_per_tti); dBEn0 = dB_fixed(en0); int8_t rach_dBm = dBEn0 - ru->rx_total_gain_dB; @@ -281,7 +284,7 @@ void rx_prach0(PHY_VARS_eNB *eNB, if (((eNB!=NULL) && (ru->function != NGFI_RAU_IF4p5))|| ((eNB==NULL) && (ru->function == NGFI_RRU_IF4p5))) { // compute the DFTs of the PRACH temporal resources // Do forward transform - if (LOG_DEBUGFLAG(PRACH)) { + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { LOG_D(PHY,"rx_prach: Doing FFT for N_RB_UL %d nb_rx:%d Ncp:%d\n",fp->N_RB_UL, nb_rx, Ncp); } @@ -353,7 +356,7 @@ void rx_prach0(PHY_VARS_eNB *eNB, return; } else if (eNB!=NULL) { - if ( LOG_DEBUGFLAG(PRACH)) { + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { int en = dB_fixed(signal_energy((int32_t *)&rxsigF[0][0],840)); if ((en > 10)&&(br_flag==1)) LOG_I(PHY,"PRACH (br_flag %d,ce_level %d, n_ra_prb %d, k %d): Frame %d, Subframe %d => %d dB\n",br_flag,ce_level,n_ra_prb,k,frame_prach,subframe,en); @@ -394,8 +397,8 @@ void rx_prach0(PHY_VARS_eNB *eNB, uint64_t avg_en=0; for (preamble_index=0 ; preamble_index<64 ; preamble_index++) { - if (LOG_DEBUGFLAG(PRACH)) { - // int en = dB_fixed(signal_energy((int32_t *)&rxsigF[0][0],840)); + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { + // int en = dB_fixed(signal_energy((int32_t *)&rxsigF[0][0],840)); if (dBEn0>30) LOG_I(PHY,"frame %d, subframe %d : Trying preamble %d (br_flag %d)\n",frame_prach,subframe,preamble_index,br_flag); } @@ -479,7 +482,7 @@ void rx_prach0(PHY_VARS_eNB *eNB, } // Compute DFT of RX signal (conjugate input, results in conjugate output) for each new rootSequenceIndex - if (LOG_DEBUGFLAG(PRACH)) { + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { //en = dB_fixed(signal_energy((int32_t *)&rxsigF[0][0],840)); if (dBEn0>30) LOG_I(PHY,"frame %d, subframe %d : preamble index %d: offset %d, preamble shift %d (br_flag %d, en %d)\n", @@ -502,8 +505,8 @@ void rx_prach0(PHY_VARS_eNB *eNB, memset(prach_ifft,0,((N_ZC==839) ? 2048 : 256)*sizeof(int32_t)); } c16_t prachF[1024] __attribute__((aligned(32)))={0}; - - if (LOG_DUMPFLAG(PRACH)) + + if (LOG_DUMPFLAG(DEBUG_PRACH)) for (int z=0; z<nb_rx; z++) if( prach[z] ) { char tmp[128]; @@ -543,7 +546,7 @@ void rx_prach0(PHY_VARS_eNB *eNB, prach_ifft[i] += (prach_ifft_tmp[i<<1]*prach_ifft_tmp[(i<<1)] + prach_ifft_tmp[1+(i<<1)]*prach_ifft_tmp[1+(i<<1)])>>9; } - if (LOG_DUMPFLAG(PRACH)) { + if (LOG_DUMPFLAG(DEBUG_PRACH)) { if (aa==0) LOG_M("prach_rxF_comp0.m","prach_rxF_comp0",prachF,1024,1,1); if (aa==1) LOG_M("prach_rxF_comp1.m","prach_rxF_comp1",prachF,1024,1,1); @@ -555,7 +558,7 @@ void rx_prach0(PHY_VARS_eNB *eNB, if ((br_flag==0) || (eNB->prach_vars_br.repetition_number[ce_level]== eNB->frame_parms.prach_emtc_config_common.prach_ConfigInfo.prach_numRepetitionPerPreambleAttempt[ce_level])) { - if (LOG_DEBUGFLAG(PRACH)) { + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { int en = dB_fixed(signal_energy((int32_t *)&rxsigF[0][0],840)); if (en>60) LOG_I(PHY,"frame %d, subframe %d: Checking for peak in time-domain (br_flag %d, en %d)\n",frame_prach,subframe,br_flag,en); @@ -573,8 +576,8 @@ void rx_prach0(PHY_VARS_eNB *eNB, *max_preamble_delay = ((i*fft_size)>>log2_ifft_size)*update_TA/update_TA2; *max_preamble = preamble_index; - if (LOG_DEBUGFLAG(PRACH)) { - // int en = dB_fixed(signal_energy((int32_t *)&rxsigF[0][0],840)); + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { + // int en = dB_fixed(signal_energy((int32_t *)&rxsigF[0][0],840)); if (dBEn0>30) LOG_D(PHY,"frame %d, subframe %d : max_preamble_energy %d, max_preamble_delay %d, max_preamble %d (br_flag %d,ce_level %d, levdB %d, lev %d)\n", @@ -613,7 +616,7 @@ void rx_prach0(PHY_VARS_eNB *eNB, LOG_M("prach_ifft0_br.m","prach_t0_br",prach_ifft,1024,1,1); } } - } /* LOG_DUMPFLAG(PRACH) */ + } if (eNB) stop_meas(&eNB->rx_prach); AssertFatal(exit_flag==0,"exiting\n"); diff --git a/openair1/PHY/NR_TRANSPORT/nr_prach.c b/openair1/PHY/NR_TRANSPORT/nr_prach.c index 3f41712f2cf..9e3df3f2234 100644 --- a/openair1/PHY/NR_TRANSPORT/nr_prach.c +++ b/openair1/PHY/NR_TRANSPORT/nr_prach.c @@ -383,11 +383,10 @@ void rx_nr_prach_ru(RU_t *ru, int prachFormat, int numRA, int prachStartSymbol, const dft_size_idx_t dftsize = get_dft(dftlen); // Do forward transform - if (LOG_DEBUGFLAG(PRACH)) { + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { LOG_D(PHY, "rx_prach: Doing PRACH FFT for nb_rx:%d Ncp:%d dftlen:%d\n", ru->nb_rx, Ncp, dftlen); } - // Note: Assumes PUSCH SCS @ 30 kHz, take values for formats 0-2 and adjust for others below int kbar = 1; int K = 24; @@ -497,7 +496,7 @@ void rx_nr_prach(PHY_VARS_gNB *gNB, LOG_D(PHY,"L1 PRACH RX: rooSequenceIndex %d, numRootSeqeuences %d, NCS %d, N_ZC %d, format %d \n",rootSequenceIndex,numrootSequenceIndex,NCS,N_ZC,prach_fmt); prach_ifft = gNB->prach_vars.prach_ifft; - if (LOG_DEBUGFLAG(PRACH)){ + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { if ((frame&1023) < 20) LOG_D(PHY,"PRACH (gNB) : running rx_prach for slot %d, msg1_frequencystart %d, rootSequenceIndex %d\n", slot, msg1_frequencystart, rootSequenceIndex); } @@ -520,8 +519,7 @@ void rx_nr_prach(PHY_VARS_gNB *gNB, *max_preamble = 0; int16_t prachF[2 * 1024]; for (preamble_index=0 ; preamble_index<64 ; preamble_index++) { - - if (LOG_DEBUGFLAG(PRACH)){ + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { int en = dB_fixed(signal_energy((int32_t*)&rxsigF[0][0],(N_ZC==839) ? 840: 140)); if (en>60) LOG_D(PHY,"frame %d, slot %d : Trying preamble %d \n",frame,slot,preamble_index); } @@ -599,7 +597,7 @@ void rx_nr_prach(PHY_VARS_gNB *gNB, } // Compute DFT of RX signal (conjugate input, results in conjugate output) for each new rootSequenceIndex - if (LOG_DEBUGFLAG(PRACH)) { + if (LOG_DEBUGFLAG(DEBUG_PRACH)) { int en = dB_fixed(signal_energy((int32_t*)&rxsigF[0][0],840)); if (en>60) LOG_D(PHY, @@ -626,11 +624,11 @@ void rx_nr_prach(PHY_VARS_gNB *gNB, memset(prach_ifft,0,((N_ZC==839) ? 2048 : 256)*sizeof(int32_t)); memset(prachF, 0, sizeof(int16_t) * 2 * 1024); - if (LOG_DUMPFLAG(PRACH)) { + if (LOG_DUMPFLAG(DEBUG_PRACH)) { LOG_M("prach_rxF0.m","prach_rxF0",rxsigF[0],N_ZC,1,1); LOG_M("prach_rxF1.m","prach_rxF1",rxsigF[1],6144,1,1); } - + for (int aa = 0; aa < nb_rx; aa++) { // Do componentwise product with Xu* on each antenna @@ -653,7 +651,7 @@ void rx_nr_prach(PHY_VARS_gNB *gNB, prach_ifft[i] += (int32_t)prach_ifft_tmp[i<<1]*(int32_t)prach_ifft_tmp[(i<<1)] + (int32_t)prach_ifft_tmp[1+(i<<1)]*(int32_t)prach_ifft_tmp[1+(i<<1)]; } - if (LOG_DUMPFLAG(PRACH)) { + if (LOG_DUMPFLAG(DEBUG_PRACH)) { if (aa == 0) LOG_M("prach_rxF_comp0.m","prach_rxF_comp0", prachF, 1024, 1, 1); if (aa == 1) @@ -717,8 +715,7 @@ void rx_nr_prach(PHY_VARS_gNB *gNB, } else *TA = *TA/2; - - if (LOG_DUMPFLAG(PRACH)) { + if (LOG_DUMPFLAG(DEBUG_PRACH)) { //int en = dB_fixed(signal_energy((int32_t*)&rxsigF[0][0],840)); // if (en>60) { int k = (12 * n_ra_prb) - 6 * fp->N_RB_UL; @@ -734,7 +731,7 @@ void rx_nr_prach(PHY_VARS_gNB *gNB, LOG_M("Xu.m","xu", Xu, N_ZC, 1, 1); LOG_M("prach_ifft0.m","prach_t0", prach_ifft, 1024, 1, 1); // } - } /* LOG_DUMPFLAG(PRACH) */ + } stop_meas(&gNB->rx_prach); } diff --git a/openair1/SCHED_UE/phy_procedures_lte_ue.c b/openair1/SCHED_UE/phy_procedures_lte_ue.c index 1f165380d4a..32e248d52b5 100644 --- a/openair1/SCHED_UE/phy_procedures_lte_ue.c +++ b/openair1/SCHED_UE/phy_procedures_lte_ue.c @@ -1145,7 +1145,7 @@ void ulsch_common_procedures(PHY_VARS_UE *ue, int dummy_tx_buffer[frame_parms->samples_per_tti] __attribute__((aligned(16))); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_TX_ULSCH_COMMON,VCD_FUNCTION_IN); - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ofdm_mod_stats); } @@ -1211,7 +1211,7 @@ void ulsch_common_procedures(PHY_VARS_UE *ue, } } //nb_antennas_tx - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ofdm_mod_stats); } @@ -1544,7 +1544,7 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue, ue->prach_resources[eNB_id]->Msg3[7], ue->prach_resources[eNB_id]->Msg3[8]); - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ulsch_encoding_stats); } @@ -1556,7 +1556,7 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue, ue->transmission_mode[eNB_id],0,0)==0, "ulsch_coding.c: FATAL ERROR: returning\n"); - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->phy_proc_tx); LOG_I(PHY,"------FULL TX PROC : %5.2f ------\n",ue->phy_proc_tx.p_time/(cpuf*1000.0)); stop_meas(&ue->ulsch_encoding_stats); @@ -1605,7 +1605,7 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue, ulsch_input_buffer[i]= (uint8_t)(taus()&0xff); } - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ulsch_encoding_stats); } @@ -1620,7 +1620,7 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue, LOG_E(PHY,"ulsch_coding.c: FATAL ERROR: returning\n"); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_TX, VCD_FUNCTION_OUT); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->phy_proc_tx); } @@ -1628,7 +1628,7 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue, } } - if(LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ulsch_encoding_stats); } } @@ -1656,7 +1656,7 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue, Mod_id,harq_pid,frame_tx%1024,subframe_tx,ue->tx_power_dBm[subframe_tx],ue->tx_power_max_dBm, tx_amp); } - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ulsch_modulation_stats); } @@ -1679,7 +1679,7 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue, nb_rb, aa); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ulsch_modulation_stats); } } @@ -2123,7 +2123,7 @@ void phy_procedures_UE_TX(PHY_VARS_UE *ue, T(T_UE_PHY_UL_TICK, T_INT(ue->Mod_id), T_INT(frame_tx%1024), T_INT(subframe_tx)); ue->generate_ul_signal[eNB_id] = 0; - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->phy_proc_tx); } @@ -2208,7 +2208,7 @@ void phy_procedures_UE_TX(PHY_VARS_UE *ue, LOG_D(PHY,"****** end TX-Chain for AbsSubframe %d.%d ******\n", frame_tx, subframe_tx); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_TX, VCD_FUNCTION_OUT); - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->phy_proc_tx); } } @@ -2489,7 +2489,7 @@ int ue_pdcch_procedures(uint8_t eNB_id, LOG_D(PHY,"DCI Decoding procedure in %d.%d\n",frame_rx,subframe_rx); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_PDCCH_PROCEDURES, VCD_FUNCTION_IN); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->dlsch_rx_pdcch_stats); } @@ -2790,7 +2790,7 @@ int ue_pdcch_procedures(uint8_t eNB_id, } } - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->dlsch_rx_pdcch_stats); } @@ -3086,7 +3086,7 @@ void ue_pdsch_procedures(PHY_VARS_UE *ue, else first_symbol_flag = 0; - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { uint8_t slot = 0; if(m >= ue->frame_parms.symbols_per_tti>>1) @@ -3108,7 +3108,7 @@ void ue_pdsch_procedures(PHY_VARS_UE *ue, i_mod, dlsch0->current_harq_pid); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { uint8_t slot = 0; if(m >= ue->frame_parms.symbols_per_tti>>1) @@ -3299,7 +3299,7 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, subframe_rx, ue->transmission_mode[eNB_id]<7?0:ue->transmission_mode[eNB_id]); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->dlsch_unscrambling_stats); } @@ -3311,7 +3311,7 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, 0, subframe_rx<<1); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->dlsch_unscrambling_stats); } @@ -3326,7 +3326,7 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, LOG_D(PHY,"start turbo decode for CW 0 for AbsSubframe %d.%d / %d --> Pdcch Sym %d \n", frame_rx, subframe_rx, harq_pid, ue->pdcch_vars[ue->current_thread_id[subframe_rx]][eNB_id]->num_pdcch_symbols); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->dlsch_decoding_stats[ue->current_thread_id[subframe_rx]]); } @@ -3341,7 +3341,7 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, pdsch==PDSCH?1:0, dlsch0->harq_processes[harq_pid]->TBS>256?1:0); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->dlsch_decoding_stats[ue->current_thread_id[subframe_rx]]); LOG_I(PHY, " --> Unscrambling for CW0 %5.3f\n", (ue->dlsch_unscrambling_stats.p_time)/(cpuf*1000.0)); @@ -3361,7 +3361,7 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, subframe_rx, ue->transmission_mode[eNB_id]<7?0:ue->transmission_mode[eNB_id]); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->dlsch_unscrambling_stats); } @@ -3373,7 +3373,7 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, 1, subframe_rx<<1); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->dlsch_unscrambling_stats); } @@ -3386,7 +3386,7 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, LOG_D(PHY,"start turbo decode for CW 1 for AbsSubframe %d.%d / %d --> Pdcch Sym %d \n", frame_rx, subframe_rx, harq_pid, ue->pdcch_vars[ue->current_thread_id[subframe_rx]][eNB_id]->num_pdcch_symbols); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->dlsch_decoding_stats[ue->current_thread_id[subframe_rx]]); } @@ -3401,7 +3401,7 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, pdsch==PDSCH?1:0, dlsch1->harq_processes[harq_pid]->TBS>256?1:0); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->dlsch_decoding_stats[ue->current_thread_id[subframe_rx]]); LOG_I(PHY, " --> Unscrambling for CW1 %5.3f\n", (ue->dlsch_unscrambling_stats.p_time)/(cpuf*1000.0)); @@ -3653,7 +3653,7 @@ void *UE_thread_slot1_dl_processing(void *arg) { } /**** Slot1 FE Processing ****/ - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ue_front_end_per_slot_stat[ue->current_thread_id[subframe_rx]][1]); } @@ -3680,7 +3680,7 @@ void *UE_thread_slot1_dl_processing(void *arg) { for (int l=1; l<ue->frame_parms.symbols_per_tti>>1; l++) { //if( (l != pilot0) && (l != pilot1)) { - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ofdm_demod_stats); } @@ -3693,7 +3693,7 @@ void *UE_thread_slot1_dl_processing(void *arg) { 0); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SLOT_FEP, VCD_FUNCTION_OUT); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ofdm_demod_stats); } } @@ -3746,7 +3746,7 @@ void *UE_thread_slot1_dl_processing(void *arg) { //printf(" [slot1 dl processing] ==> Start LLR Comuptation slot1 for AbsSubframe %d.%d \n", proc->frame_rx, proc->subframe_rx); - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ue_front_end_per_slot_stat[ue->current_thread_id[subframe_rx]][1]); LOG_D(PHY, "[AbsSFN %d.%d] Slot1: FFT + Channel Estimate + Pdsch Proc Slot0 %5.2f \n",frame_rx,subframe_rx,ue->ue_front_end_per_slot_stat[ue->current_thread_id[subframe_rx]][1].p_time/(cpuf*1000.0)); } @@ -3766,7 +3766,7 @@ void *UE_thread_slot1_dl_processing(void *arg) { // do procedures for C-RNTI //printf("AbsSubframe %d.%d Pdsch Procedure (slot1)\n",frame_rx,subframe_rx); - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->pdsch_procedures_per_slot_stat[ue->current_thread_id[subframe_rx]][1]); } @@ -3840,7 +3840,7 @@ void *UE_thread_slot1_dl_processing(void *arg) { proc->llr_slot1_available=1; //printf("Set available LLR slot1 to 1 AbsSubframe %d.%d \n",frame_rx,subframe_rx); - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->pdsch_procedures_per_slot_stat[ue->current_thread_id[subframe_rx]][1]); LOG_D(PHY, "[AbsSFN %d.%d] Slot1: LLR Computation %5.2f \n",frame_rx,subframe_rx,ue->pdsch_procedures_per_slot_stat[ue->current_thread_id[subframe_rx]][1].p_time/(cpuf*1000.0)); } @@ -3891,7 +3891,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, LOG_D(PHY," ****** start RX-Chain for AbsSubframe %d.%d ****** \n", frame_rx%1024, subframe_rx); } - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->phy_proc_rx[ue->current_thread_id[subframe_rx]]); start_meas(&ue->ue_front_end_stat[ue->current_thread_id[subframe_rx]]); } @@ -3994,7 +3994,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, /**** Slot0 FE Processing ****/ // I- start main thread for FFT/ChanEst symbol: 0/1 --> 7 - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ue_front_end_per_slot_stat[ue->current_thread_id[subframe_rx]][0]); } @@ -4028,7 +4028,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, for (l=first_ofdm_sym; l<=l2; l++) { if( (l != pilot0) && (l != pilot1)) { //printf("AbsSubframe %d.%d FFT slot %d, symbol %d\n", frame_rx,subframe_rx,slot0,l); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ofdm_demod_stats); } @@ -4040,7 +4040,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, 0); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SLOT_FEP, VCD_FUNCTION_OUT); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ofdm_demod_stats); } } @@ -4060,14 +4060,14 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, } if (do_pdcch_flag) { - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->pdcch_procedures_stat[ue->current_thread_id[subframe_rx]]); } if (ue_pdcch_procedures(eNB_id,ue,proc,abstraction_flag) == -1) { LOG_E(PHY,"[UE %d] Frame %d, subframe %d: Error in pdcch procedures\n",ue->Mod_id,frame_rx,subframe_rx); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { LOG_D(PHY, "[AbsSFN %d.%d] Slot0: PDCCH %5.2f \n",frame_rx,subframe_rx,ue->pdcch_procedures_stat[ue->current_thread_id[subframe_rx]].p_time/(cpuf*1000.0)); } @@ -4076,7 +4076,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, } //proc->dci_slot0_available=1; - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->pdcch_procedures_stat[ue->current_thread_id[subframe_rx]]); LOG_D(PHY, "[AbsSFN %d.%d] Slot0: PDCCH %5.2f \n",frame_rx,subframe_rx,ue->pdcch_procedures_stat[ue->current_thread_id[subframe_rx]].p_time/(cpuf*1000.0)); } @@ -4085,7 +4085,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, //printf("num_pdcch_symbols %d\n",ue->pdcch_vars[ue->current_thread_id[subframe_rx]][eNB_id]->num_pdcch_symbols); // first slot has been processed (FFTs + Channel Estimation, PCFICH/PHICH/PDCCH) - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ue_front_end_per_slot_stat[ue->current_thread_id[subframe_rx]][0]); LOG_D(PHY, "[AbsSFN %d.%d] Slot0: FFT + Channel Estimate + PCFICH/PHICH/PDCCH %5.2f \n",frame_rx,subframe_rx, ue->ue_front_end_per_slot_stat[ue->current_thread_id[subframe_rx]][0].p_time/(cpuf*1000.0)); @@ -4099,7 +4099,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, wait++; } - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ue_front_end_stat[ue->current_thread_id[subframe_rx]]); LOG_D(PHY, "[AbsSFN %d.%d] FULL FE Processing %5.2f \n",frame_rx,subframe_rx,ue->ue_front_end_per_slot_stat[ue->current_thread_id[subframe_rx]][0].p_time/(cpuf*1000.0)); } @@ -4116,11 +4116,11 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, //printf("AbsSubframe %d.%d Pdsch Procedure (slot0)\n",frame_rx%1024,subframe_rx); //printf("AbsSubframe %d.%d Pdsch Procedure PDSCH Active %d \n",frame_rx%1024,subframe_rx, ue->dlsch[ue->current_thread_id[subframe_rx]][0][0]->active); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->pdsch_procedures_stat[ue->current_thread_id[subframe_rx]]); } - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->pdsch_procedures_per_slot_stat[ue->current_thread_id[subframe_rx]][0]); } @@ -4187,7 +4187,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, proc->dci_slot0_available=1; //printf("Set available dci slot0 to 1 AbsSubframe %d.%d \n",frame_rx%1024,subframe_rx); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->pdsch_procedures_per_slot_stat[ue->current_thread_id[subframe_rx]][0]); LOG_D(PHY, "[AbsSFN %d.%d] Slot0: LLR Computation %5.2f \n",frame_rx,subframe_rx,ue->pdsch_procedures_per_slot_stat[ue->current_thread_id[subframe_rx]][0].p_time/(cpuf*1000.0)); } @@ -4200,13 +4200,13 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, wait++; } - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->pdsch_procedures_stat[ue->current_thread_id[subframe_rx]]); LOG_D(PHY, "[AbsSFN %d.%d] Full LLR Computation %5.2f \n",frame_rx,subframe_rx,ue->pdsch_procedures_stat[ue->current_thread_id[subframe_rx]].p_time/(cpuf*1000.0)); } //=====================================================================// - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->dlsch_procedures_stat[ue->current_thread_id[subframe_rx]]); } @@ -4272,7 +4272,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, ue->dlsch_ra[eNB_id]->active = 0; } - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->dlsch_procedures_stat[ue->current_thread_id[subframe_rx]]); LOG_D(PHY, "[AbsSFN %d.%d] Channel Decoder: %5.2f \n",frame_rx,subframe_rx,ue->dlsch_procedures_stat[ue->current_thread_id[subframe_rx]].p_time/(cpuf*1000.0)); } @@ -4332,7 +4332,7 @@ int phy_procedures_slot_parallelization_UE_RX(PHY_VARS_UE *ue, VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_RX, VCD_FUNCTION_OUT); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->phy_proc_rx[ue->current_thread_id[subframe_rx]]); LOG_I(PHY, "------FULL RX PROC [AbsSFN %d.%d]: %5.2f ------\n",frame_rx,subframe_rx,ue->phy_proc_rx[ue->current_thread_id[subframe_rx]].p_time/(cpuf*1000.0)); } @@ -4371,7 +4371,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, LOG_I(PHY," ****** start RX-Chain for AbsSubframe->0 %d.%d ****** \n", frame_rx%1024, subframe_rx); } - if(LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->phy_proc_rx[ue->current_thread_id[subframe_rx]]); start_meas(&ue->ue_front_end_stat[ue->current_thread_id[subframe_rx]]); } @@ -4447,7 +4447,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, for (; l<=l2; l++) { if (abstraction_flag == 0) { - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ofdm_demod_stats); } @@ -4460,7 +4460,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, 0); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SLOT_FEP, VCD_FUNCTION_OUT); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ofdm_demod_stats); } } @@ -4516,14 +4516,14 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, 0); // first slot has been processed (FFTs + Channel Estimation, PCFICH/PHICH/PDCCH) - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ue_front_end_stat[ue->current_thread_id[subframe_rx]]); LOG_I(PHY, "[SFN %d] Slot0: FFT + Channel Estimate + PCFICH/PHICH/PDCCH %5.2f \n",subframe_rx,ue->ue_front_end_stat[ue->current_thread_id[subframe_rx]].p_time/(cpuf*1000.0)); } LOG_D(PHY," ------ --> PDSCH ChannelComp/LLR slot 0: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->generic_stat); start_meas(&ue->crnti_procedures_stats); } @@ -4543,7 +4543,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PDSCH_PROC, VCD_FUNCTION_OUT); } - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->crnti_procedures_stats); } @@ -4600,7 +4600,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, if (subframe_select(&ue->frame_parms,subframe_rx) != SF_S) { // do front-end processing for second slot, and first symbol of next subframe for (l=1; l<ue->frame_parms.symbols_per_tti>>1; l++) { if (abstraction_flag == 0) { - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->ofdm_demod_stats); } @@ -4613,7 +4613,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, 0); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SLOT_FEP, VCD_FUNCTION_OUT); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->ofdm_demod_stats); } } @@ -4635,7 +4635,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, } } // not an S-subframe - if(LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->generic_stat); LOG_I(PHY, "[SFN %d] Slot1: FFT + Channel Estimate + Pdsch Proc Slot0 %5.2f \n",subframe_rx,ue->generic_stat.p_time/(cpuf*1000.0)); } @@ -4652,7 +4652,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, if (ue->dlsch[ue->current_thread_id[subframe_rx]][eNB_id][0]->active == 1) { VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PDSCH_PROC, VCD_FUNCTION_IN); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->pdsch_procedures_stat[ue->current_thread_id[subframe_rx]]); } @@ -4668,7 +4668,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, LOG_D(PHY," ------ end PDSCH ChannelComp/LLR slot 0: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); LOG_D(PHY," ------ --> PDSCH Turbo Decoder slot 0/1: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->pdsch_procedures_stat[ue->current_thread_id[subframe_rx]]); start_meas(&ue->dlsch_procedures_stat[ue->current_thread_id[subframe_rx]]); } @@ -4683,7 +4683,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, mode, abstraction_flag); - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->dlsch_procedures_stat[ue->current_thread_id[subframe_rx]]); LOG_I(PHY, "[SFN %d] Slot1: Pdsch Proc %5.2f\n",subframe_rx,ue->pdsch_procedures_stat[ue->current_thread_id[subframe_rx]].p_time/(cpuf*1000.0)); LOG_I(PHY, "[SFN %d] Slot0 Slot1: Dlsch Proc %5.2f\n",subframe_rx,ue->dlsch_procedures_stat[ue->current_thread_id[subframe_rx]].p_time/(cpuf*1000.0)); @@ -4692,7 +4692,7 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PDSCH_PROC, VCD_FUNCTION_OUT); } - if (LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { start_meas(&ue->generic_stat); } @@ -4818,14 +4818,14 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue, } } - if ( LOG_DEBUGFLAG(UE_TIMING)) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->generic_stat); LOG_I(PHY,"after tubo until end of Rx %5.2f \n",ue->generic_stat.p_time/(cpuf*1000.0)); } VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_RX, VCD_FUNCTION_OUT); - if ( LOG_DEBUGFLAG(UE_TIMING) ) { + if (LOG_DEBUGFLAG(DEBUG_UE_TIMING)) { stop_meas(&ue->phy_proc_rx[ue->current_thread_id[subframe_rx]]); LOG_I(PHY, "------FULL RX PROC [SFN %d]: %5.2f ------\n",subframe_rx,ue->phy_proc_rx[ue->current_thread_id[subframe_rx]].p_time/(cpuf*1000.0)); } diff --git a/openair1/SIMULATION/LTE_PHY/dlsim.c b/openair1/SIMULATION/LTE_PHY/dlsim.c index 40d35c4a008..5cfb21f8b03 100644 --- a/openair1/SIMULATION/LTE_PHY/dlsim.c +++ b/openair1/SIMULATION/LTE_PHY/dlsim.c @@ -892,7 +892,7 @@ int main(int argc, char **argv) { set_glog_onlinelog(true); // enable these lines if you need debug info set_glog(loglvl); - SET_LOG_DEBUG(UE_TIMING); + SET_LOG_DEBUG(DEBUG_UE_TIMING); // moreover you need to init itti with the following line // however itti will catch all signals, so ctrl-c won't work anymore // alternatively you can disable ITTI completely in CMakeLists.txt diff --git a/openair1/SIMULATION/LTE_PHY/mbmssim.c b/openair1/SIMULATION/LTE_PHY/mbmssim.c index f10c287a1a7..ac50bf62bd6 100644 --- a/openair1/SIMULATION/LTE_PHY/mbmssim.c +++ b/openair1/SIMULATION/LTE_PHY/mbmssim.c @@ -989,7 +989,7 @@ int main(int argc, char **argv) { set_glog_onlinelog(true); // enable these lines if you need debug info set_glog(loglvl); - SET_LOG_DEBUG(UE_TIMING); + set_log_debug("UE_TIMING", true); // moreover you need to init itti with the following line // however itti will catch all signals, so ctrl-c won't work anymore // alternatively you can disable ITTI completely in CMakeLists.txt diff --git a/openair1/SIMULATION/LTE_PHY/ulsim.c b/openair1/SIMULATION/LTE_PHY/ulsim.c index 14e3c696965..d17f767a2a2 100644 --- a/openair1/SIMULATION/LTE_PHY/ulsim.c +++ b/openair1/SIMULATION/LTE_PHY/ulsim.c @@ -938,7 +938,7 @@ int main(int argc, char **argv) { ndi=0; phy_reset_ue(0,0,0); UE->UE_mode[eNB_id]=PUSCH; - SET_LOG_DEBUG(UE_TIMING); + set_log_debug("UE_TIMING", true); for (trials = 0; trials<n_frames; trials++) { // printf("*"); diff --git a/openair1/SIMULATION/NR_PHY/prachsim.c b/openair1/SIMULATION/NR_PHY/prachsim.c index 5eab1c69748..7e8ecced70e 100644 --- a/openair1/SIMULATION/NR_PHY/prachsim.c +++ b/openair1/SIMULATION/NR_PHY/prachsim.c @@ -403,7 +403,7 @@ int main(int argc, char **argv){ // Configure log logInit(); set_glog(loglvl); - SET_LOG_DEBUG(PRACH); + SET_LOG_DEBUG(DEBUG_PRACH); // Configure gNB and RU RC.gNB = (PHY_VARS_gNB**) malloc(2*sizeof(PHY_VARS_gNB *)); diff --git a/openair2/F1AP/f1ap_cu_interface_management.c b/openair2/F1AP/f1ap_cu_interface_management.c index bc5480a11b8..9e25aeb63e5 100644 --- a/openair2/F1AP/f1ap_cu_interface_management.c +++ b/openair2/F1AP/f1ap_cu_interface_management.c @@ -160,7 +160,7 @@ int CU_send_gNB_DU_CONFIGURATION_UPDATE_ACKNOWLEDGE(sctp_assoc_t assoc_id, f1ap_ LOG_E(F1AP, "Failed to encode F1 gNB-DU Configuration Update Acknowledge\n"); return -1; } - LOG_DUMPMSG(F1AP, LOG_DUMP_CHAR, buffer, len, "F1AP gNB-DU CONFIGURATION UPDATE : "); + LOG_DUMPMSG(F1AP, DEBUG_F1AP, buffer, len, "F1AP gNB-DU CONFIGURATION UPDATE : "); ASN_STRUCT_FREE(asn_DEF_F1AP_F1AP_PDU, pdu); f1ap_itti_send_sctp_data_req(assoc_id, buffer, len); return 0; @@ -185,7 +185,7 @@ int CU_send_gNB_CU_CONFIGURATION_UPDATE(sctp_assoc_t assoc_id, f1ap_gnb_cu_confi LOG_E(F1AP, "Failed to encode F1 gNB-CU Configuration Update\n"); return -1; } - LOG_DUMPMSG(F1AP, LOG_DUMP_CHAR, buffer, len, "F1AP gNB-CU CONFIGURATION UPDATE : "); + LOG_DUMPMSG(F1AP, DEBUG_F1AP, buffer, len, "F1AP gNB-CU CONFIGURATION UPDATE : "); ASN_STRUCT_FREE(asn_DEF_F1AP_F1AP_PDU, pdu); f1ap_itti_send_sctp_data_req(assoc_id, buffer, len); return 0; -- GitLab