diff --git a/common/config/config_load_configmodule.c b/common/config/config_load_configmodule.c index 71cab2a33a..9bb1b85f7d 100644 --- a/common/config/config_load_configmodule.c +++ b/common/config/config_load_configmodule.c @@ -302,7 +302,7 @@ configmodule_interface_t *load_configmodule(int argc, } static configmodule_interface_t *cfgptr; if (cfgptr) - printf("ERROR: Call load_configmodule more than one time\n"); + fprintf(stderr, "ERROR: Call load_configmodule more than one time\n"); // The macros are not thread safe print_params and similar cfgptr = calloc(sizeof(configmodule_interface_t), 1); @@ -369,8 +369,7 @@ configmodule_interface_t *load_configmodule(int argc, if (strstr(cfgparam,CONFIG_CMDLINEONLY) == NULL) { i=load_config_sharedlib(cfgptr); - if (i == 0) { - printf("[CONFIG] config module %s loaded\n",cfgmode); + if (i == 0) { int idx = config_paramidx_fromname(Config_Params, sizeofArray(Config_Params), CONFIGP_DEBUGFLAGS); Config_Params[idx].uptr = &(cfgptr->rtflags); idx = config_paramidx_fromname(Config_Params, sizeofArray(Config_Params), CONFIGP_TMPDIR); @@ -387,7 +386,7 @@ configmodule_interface_t *load_configmodule(int argc, cfgptr->end = (configmodule_endfunc_t)nooptfunc; } - printf("[CONFIG] debug flags: 0x%08x\n", cfgptr->rtflags); + printf_params(cfgptr, "[CONFIG] debug flags: 0x%08x\n", cfgptr->rtflags); if (modeparams != NULL) free(modeparams); @@ -413,7 +412,7 @@ void write_parsedcfg(configmodule_interface_t *cfgptr) cfgptr->status->num_write); } if (cfgptr->write_parsedcfg != NULL) { - printf("[CONFIG] calling config module write_parsedcfg function...\n"); + printf_params(cfgptr, "[CONFIG] calling config module write_parsedcfg function...\n"); cfgptr->write_parsedcfg(cfgptr); } } @@ -425,12 +424,11 @@ void end_configmodule(configmodule_interface_t *cfgptr) if (cfgptr != NULL) { write_parsedcfg(cfgptr); if (cfgptr->end != NULL) { - printf ("[CONFIG] calling config module end function...\n"); + printf_params(cfgptr, "[CONFIG] calling config module end function...\n"); cfgptr->end(cfgptr); } pthread_mutex_lock(&cfgptr->memBlocks_mutex); - printf ("[CONFIG] free %u config value pointers\n",cfgptr->numptrs); for(int i=0; inumptrs ; i++) { if (cfgptr->oneBlock[i].ptrs != NULL && cfgptr->oneBlock[i].ptrsAllocated== true && cfgptr->oneBlock[i].toFree) { diff --git a/common/config/libconfig/config_libconfig.c b/common/config/libconfig/config_libconfig.c index a41a4dab33..0934024391 100644 --- a/common/config/libconfig/config_libconfig.c +++ b/common/config/libconfig/config_libconfig.c @@ -461,13 +461,11 @@ int config_libconfig_get(configmodule_interface_t *cfg, paramdef_t *cfgoptions, } /* switch on param type */ if( notfound == 1) { - printf("[LIBCONFIG] %s not found in %s ", cfgpath,libconfig_privdata.configfile ); + fprintf(stderr, "[LIBCONFIG] %s not found in %s ", cfgpath, libconfig_privdata.configfile); if ( (cfgoptions[i].paramflags & PARAMFLAG_MANDATORY) != 0) { fatalerror=1; - printf(" mandatory parameter missing\n"); - } else { - printf("\n"); + fprintf(stderr, " mandatory parameter missing\n"); } } else { if (defval == 1) { @@ -570,8 +568,8 @@ int config_libconfig_init(configmodule_interface_t *cfg) } const char *incp = config_get_include_dir (&(libconfig_privdata.cfg)) ; - - printf("[LIBCONFIG] Path for include directive set to: %s\n", (incp!=NULL)?incp:"libconfig defaults"); + + printf_params(cfg, "[LIBCONFIG] Path for include directive set to: %s\n", (incp != NULL) ? incp : "libconfig defaults"); /* set convertion option to allow integer to float conversion*/ config_set_auto_convert (&(libconfig_privdata.cfg), CONFIG_TRUE); /* Read the file. If there is an error, report it and exit. */ @@ -582,7 +580,7 @@ int config_libconfig_init(configmodule_interface_t *cfg) config_error_line(&(libconfig_privdata.cfg)), config_error_text(&(libconfig_privdata.cfg))); config_destroy(&(libconfig_privdata.cfg)); - printf( "\n"); + fprintf(stderr, "\n"); free(tmppath); return -1; } @@ -623,11 +621,11 @@ void config_libconfig_write_parsedcfg(configmodule_interface_t *cfg) config_error_line(&(libconfig_privdata.runtcfg)), config_error_text(&(libconfig_privdata.runtcfg))); } else { - printf("[LIBCONFIG] file %s created successfully\n", cfg->status->debug_cfgname); + printf_params(cfg, "[LIBCONFIG] file %s created successfully\n", cfg->status->debug_cfgname); } free(fname); } else { - printf("[LIBCONFIG] Cannot create config file after parsing: CONFIG_SAVERUNCFG flag not specified\n"); + printf_params(cfg, "[LIBCONFIG] Cannot create config file after parsing: CONFIG_SAVERUNCFG flag not specified\n"); } } diff --git a/common/utils/LOG/log.c b/common/utils/LOG/log.c index 17ffe91c1d..62230d9ba3 100644 --- a/common/utils/LOG/log.c +++ b/common/utils/LOG/log.c @@ -517,7 +517,6 @@ int logInit (void) "Invalid log options: time and wall_clock both set but are mutually exclusive\n"); g_log->flag = g_log->flag | FLAG_INITIALIZED; - printf("log init done\n"); return 0; } @@ -946,7 +945,6 @@ int logInit_log_mem (char * filename) return -1; } pthread_create(&log_mem_thread, NULL, (void *(*)(void *))flush_mem_to_file, (void *)NULL); - printf("log init done\n"); return 0; } diff --git a/common/utils/load_module_shlib.c b/common/utils/load_module_shlib.c index 4fa1b9f357..04d3080b5b 100644 --- a/common/utils/load_module_shlib.c +++ b/common/utils/load_module_shlib.c @@ -49,7 +49,7 @@ void loader_init(void) { loader_data.mainexec_buildversion = OAI_PACKAGE_VERSION; int ret = config_get(config_get_if(), LoaderParams, sizeofArray(LoaderParams), LOADER_CONFIG_PREFIX); if (ret <0) { - printf("[LOADER] configuration couldn't be performed via config module, parameters set to default values\n"); + fprintf(stderr, "[LOADER] configuration couldn't be performed via config module, parameters set to default values\n"); if (loader_data.shlibpath == NULL) { loader_data.shlibpath=DEFAULT_PATH; } @@ -136,12 +136,9 @@ int load_module_version_shlib(char *modname, char *version, loader_shlibfunc_t * } shlib_path = loader_format_shlibpath(modname, version); - printf("shlib_path %s\n", shlib_path); for (int i = 0; i < loader_data.numshlibs; i++) { if (strcmp(loader_data.shlibs[i].name, modname) == 0) { - printf("[LOADER] library %s has been loaded previously, reloading function pointers\n", - shlib_path); lib_idx = i; break; } @@ -165,7 +162,6 @@ int load_module_version_shlib(char *modname, char *version, loader_shlibfunc_t * goto load_module_shlib_exit; } - printf("[LOADER] library %s successfully loaded\n", shlib_path); afname = malloc(strlen(modname)+15); if (!afname) { fprintf(stderr, "[LOADER] unable to allocate memory for library %s\n", shlib_path); diff --git a/executables/lte-softmodem.c b/executables/lte-softmodem.c index 69abbb4464..9d42adeb73 100644 --- a/executables/lte-softmodem.c +++ b/executables/lte-softmodem.c @@ -363,7 +363,6 @@ void wait_RUs(void) { } pthread_mutex_unlock(&RC.ru_mutex); - LOG_I(PHY,"RUs configured\n"); } void wait_eNBs(void) { diff --git a/executables/nr-gnb.c b/executables/nr-gnb.c index c1229a07e3..0954a13287 100644 --- a/executables/nr-gnb.c +++ b/executables/nr-gnb.c @@ -400,12 +400,12 @@ void term_gNB_Tpool(int inst) { void init_eNB_afterRU(void) { int inst,ru_id,i,aa; PHY_VARS_gNB *gNB; - LOG_I(PHY,"%s() RC.nb_nr_inst:%d\n", __FUNCTION__, RC.nb_nr_inst); + LOG_D(PHY, "%s() RC.nb_nr_inst:%d\n", __FUNCTION__, RC.nb_nr_inst); if(NFAPI_MODE == NFAPI_MODE_PNF) RC.nb_nr_inst = 1; for (inst=0; instldpc_offload_flag = get_softmodem_params()->ldpc_offload_flag; @@ -415,8 +415,7 @@ void init_eNB_afterRU(void) { // map antennas and PRACH signals to gNB RX if (0) AssertFatal(gNB->num_RU>0,"Number of RU attached to gNB %d is zero\n",gNB->Mod_id); - LOG_I(PHY,"Mapping RX ports from %d RUs to gNB %d\n",gNB->num_RU,gNB->Mod_id); - LOG_I(PHY,"gNB->num_RU:%d\n", gNB->num_RU); + LOG_D(PHY, "Mapping RX ports from %d RUs to gNB %d\n", gNB->num_RU, gNB->Mod_id); for (ru_id=0,aa=0; ru_idnum_RU; ru_id++) { AssertFatal(gNB->RU_list[ru_id]->common.rxdataF != NULL, "RU %d : common.rxdataF is NULL\n", gNB->RU_list[ru_id]->idx); @@ -447,30 +446,25 @@ void init_gNB(int wait_for_sync) { if (RC.gNB == NULL) { RC.gNB = (PHY_VARS_gNB **) calloc(1+RC.nb_nr_L1_inst, sizeof(PHY_VARS_gNB *)); - LOG_I(PHY,"gNB L1 structure RC.gNB allocated @ %p\n",RC.gNB); + LOG_D(PHY, "gNB L1 structure RC.gNB allocated @ %p\n", RC.gNB); } for (inst=0; instnrPolar_params, NR_POLAR_PBCH_MESSAGE_TYPE, NR_POLAR_PBCH_PAYLOAD_BITS, NR_POLAR_PBCH_AGGREGATION_LEVEL);*/ - LOG_I(PHY,"Initializing gNB %d\n",inst); - LOG_I(PHY,"Initializing gNB %d\n",inst); - LOG_I(PHY,"Registering with MAC interface module (before %p)\n",gNB->if_inst); - AssertFatal((gNB->if_inst = NR_IF_Module_init(inst))!=NULL,"Cannot register interface"); - LOG_I(PHY,"Registering with MAC interface module (after %p)\n",gNB->if_inst); + AssertFatal((gNB->if_inst = NR_IF_Module_init(inst)) != NULL, "Cannot register interface"); gNB->if_inst->NR_Schedule_response = nr_schedule_response; gNB->if_inst->NR_PHY_config_req = nr_phy_config_request; - memset((void *)&gNB->UL_INFO,0,sizeof(gNB->UL_INFO)); - LOG_I(PHY,"Setting indication lists\n"); + memset(&gNB->UL_INFO, 0, sizeof(gNB->UL_INFO)); gNB->UL_INFO.rx_ind.pdu_list = gNB->rx_pdu_list; gNB->UL_INFO.crc_ind.crc_list = gNB->crc_pdu_list; @@ -482,11 +476,7 @@ void init_gNB(int wait_for_sync) { gNB->prach_energy_counter = 0; gNB->chest_time = get_softmodem_params()->chest_time; gNB->chest_freq = get_softmodem_params()->chest_freq; - } - - - LOG_I(PHY,"[nr-gnb.c] gNB structure allocated\n"); } diff --git a/executables/nr-ru.c b/executables/nr-ru.c index 0a7e28431f..e3f13cd014 100644 --- a/executables/nr-ru.c +++ b/executables/nr-ru.c @@ -88,7 +88,7 @@ int attach_rru(RU_t *ru) { memset((void *)&rru_config_msg,0,sizeof(rru_config_msg)); rru_config_msg.type = RAU_tick; rru_config_msg.len = sizeof(RRU_CONFIG_msg_t)-MAX_RRU_CONFIG_SIZE; - LOG_I(PHY,"Sending RAU tick to RRU %d\n",ru->idx); + LOG_D(PHY, "Sending RAU tick to RRU %d\n", ru->idx); AssertFatal((ru->ifdevice.trx_ctlsend_func(&ru->ifdevice,&rru_config_msg,rru_config_msg.len)!=-1), "RU %d cannot access remote radio\n",ru->idx); msg_len = sizeof(RRU_CONFIG_msg_t)-MAX_RRU_CONFIG_SIZE+sizeof(RRU_capabilities_t); @@ -97,7 +97,7 @@ int attach_rru(RU_t *ru) { if ((len = ru->ifdevice.trx_ctlrecv_func(&ru->ifdevice, &rru_config_msg, msg_len))<0) { - LOG_I(PHY,"Waiting for RRU %d\n",ru->idx); + LOG_D(PHY, "Waiting for RRU %d\n", ru->idx); } else if (rru_config_msg.type == RRU_capabilities) { AssertFatal(rru_config_msg.len==msg_len,"Received capabilities with incorrect length (%d!=%d)\n",(int)rru_config_msg.len,(int)msg_len); LOG_I(PHY,"Received capabilities from RRU %d (len %d/%d, num_bands %d,max_pdschReferenceSignalPower %d, max_rxgain %d, nb_tx %d, nb_rx %d)\n",ru->idx, @@ -467,8 +467,7 @@ void fh_if5_north_asynch_in(RU_t *ru,int *frame,int *slot) { RU_proc_t *proc = &ru->proc; int tti_tx,frame_tx; openair0_timestamp timestamp_tx = 0; - AssertFatal(1==0,"Shouldn't get here\n"); - // printf("Received subframe %d (TS %llu) from RCC\n",tti_tx,timestamp_tx); + AssertFatal(1 == 0, "Shouldn't get here\n"); frame_tx = (timestamp_tx / (fp->samples_per_subframe*10))&1023; uint32_t idx_sf = timestamp_tx / fp->samples_per_subframe; tti_tx = (idx_sf * fp->slots_per_subframe + (int)round((float)(timestamp_tx % fp->samples_per_subframe) / fp->samples_per_slot0))%(fp->slots_per_frame); @@ -693,7 +692,6 @@ static void rx_rf(RU_t *ru, int *frame, int *slot) *slot = proc->tti_rx; } - //printf("timestamp_rx %lu, frame %d(%d), subframe %d(%d)\n",ru->timestamp_rx,proc->frame_rx,frame,proc->tti_rx,subframe); VCD_SIGNAL_DUMPER_DUMP_VARIABLE_BY_NAME( VCD_SIGNAL_DUMPER_VARIABLES_TRX_TS, (proc->timestamp_rx+ru->ts_offset)&0xffffffff ); if (rxs != samples_per_slot) { @@ -954,9 +952,7 @@ int setup_RU_buffers(RU_t *ru) { if (ru) { fp = ru->nr_frame_parms; - printf("setup_RU_buffers: frame_parms = %p\n",fp); } else { - printf("ru pointer is NULL\n"); return(-1); } @@ -973,13 +969,11 @@ int setup_RU_buffers(RU_t *ru) { for (i=0; inb_rx; i++) { card = i/4; ant = i%4; - printf("Mapping RU id %u, rx_ant %d, on card %d, chain %d\n",ru->idx,i,ru->rf_map.card+card, ru->rf_map.chain+ant); + LOG_D(PHY, "Mapping RU id %u, rx_ant %d, on card %d, chain %d\n", ru->idx, i, ru->rf_map.card + card, ru->rf_map.chain + ant); free(ru->common.rxdata[i]); - ru->common.rxdata[i] = ru->openair0_cfg.rxbase[ru->rf_map.chain+ant]; - printf("rxdata[%d] @ %p\n",i,ru->common.rxdata[i]); + ru->common.rxdata[i] = ru->openair0_cfg.rxbase[ru->rf_map.chain + ant]; - for (j=0; j<16; j++) { - printf("rxbuffer %d: %x\n",j,ru->common.rxdata[i][j]); + for (j = 0; j < 16; j++) { ru->common.rxdata[i][j] = 16-j; } } @@ -987,13 +981,11 @@ int setup_RU_buffers(RU_t *ru) { for (i=0; inb_tx; i++) { card = i/4; ant = i%4; - printf("Mapping RU id %u, tx_ant %d, on card %d, chain %d\n",ru->idx,i,ru->rf_map.card+card, ru->rf_map.chain+ant); + LOG_D(PHY, "Mapping RU id %u, tx_ant %d, on card %d, chain %d\n", ru->idx, i, ru->rf_map.card + card, ru->rf_map.chain + ant); free(ru->common.txdata[i]); - ru->common.txdata[i] = ru->openair0_cfg.txbase[ru->rf_map.chain+ant]; - printf("txdata[%d] @ %p\n",i,ru->common.txdata[i]); + ru->common.txdata[i] = ru->openair0_cfg.txbase[ru->rf_map.chain + ant]; - for (j=0; j<16; j++) { - printf("txbuffer %d: %x\n",j,ru->common.txdata[i][j]); + for (j = 0; j < 16; j++) { ru->common.txdata[i][j] = 16-j; } } @@ -1186,7 +1178,7 @@ void *ru_thread(void *param) } if (setup_RU_buffers(ru)!=0) { - printf("Exiting, cannot initialize RU Buffers\n"); + LOG_E(PHY, "Exiting, cannot initialize RU Buffers\n"); exit(-1); } @@ -1382,8 +1374,6 @@ void *ru_thread(void *param) pushNotifiedFIFO(&gNB->L1_tx_out, resTx); } - printf( "Exiting ru_thread \n"); - ru_thread_status = 0; return &ru_thread_status; } @@ -1662,18 +1652,15 @@ void set_function_spec_param(RU_t *ru) ru->start_rf = start_rf; // need to start the local RF interface ru->stop_rf = stop_rf; ru->start_write_thread = start_write_thread; // starting RF TX in different thread - printf("configuring ru_id %u (start_rf %p)\n", ru->idx, start_rf); } /* - printf("configuring ru_id %u (start_rf %p)\n", ru->idx, start_rf); fill_rf_config(ru,rf_config_file); init_frame_parms(&ru->frame_parms,1); nr_phy_init_RU(ru); ret = openair0_device_load(&ru->rfdevice,&ru->openair0_cfg); if (setup_RU_buffers(ru)!=0) { - printf("Exiting, cannot initialize RU Buffers\n"); exit(-1); } */ @@ -1736,7 +1723,6 @@ void init_NR_RU(configmodule_interface_t *cfg, char *rf_config_file) pthread_mutex_init(&RC.ru_mutex,NULL); pthread_cond_init(&RC.ru_cond,NULL); // read in configuration file) - printf("configuring RU from file\n"); NRRCconfig_RU(cfg); LOG_I(PHY,"number of L1 instances %d, number of RU %d, number of CPU cores %d\n",RC.nb_nr_L1_inst,RC.nb_RU,get_nprocs()); LOG_D(PHY,"Process RUs RC.nb_RU:%d\n",RC.nb_RU); @@ -1770,7 +1756,7 @@ void init_NR_RU(configmodule_interface_t *cfg, char *rf_config_file) AssertFatal(gNB0, "gNB0 is null!\n"); if (gNB0 && gNB_RC) { - LOG_I(PHY,"Copying frame parms from gNB in RC to gNB %d in ru %d and frame_parms in ru\n", gNB0->Mod_id, ru->idx); + LOG_D(PHY, "Copying frame parms from gNB in RC to gNB %d in ru %d and frame_parms in ru\n", gNB0->Mod_id, ru->idx); memcpy((void *)fp, &gNB_RC->frame_parms, sizeof(NR_DL_FRAME_PARMS)); memcpy((void *)&gNB0->frame_parms, (void *)&gNB_RC->frame_parms, sizeof(NR_DL_FRAME_PARMS)); // attach all RU to all gNBs in its list/ @@ -1786,14 +1772,14 @@ void init_NR_RU(configmodule_interface_t *cfg, char *rf_config_file) init_RU_proc(ru); if (ru->if_south != REMOTE_IF4p5) { int threadCnt = ru->num_tpcores; - if (threadCnt < 2) LOG_E(PHY,"Number of threads for gNB should be more than 1. Allocated only %d\n",threadCnt); - else LOG_I(PHY,"RU Thread pool size %d\n",threadCnt); + if (threadCnt < 2) + LOG_E(PHY, "Number of threads for gNB should be more than 1. Allocated only %d\n", threadCnt); char pool[80]; int s_offset = sprintf(pool,"%d",ru->tpcores[0]); for (int icpu=1; icputpcores[icpu]); } - LOG_I(PHY,"RU thread-pool core string %s\n",pool); + LOG_I(PHY, "RU thread-pool core string %s (size %d)\n", pool, threadCnt); ru->threadPool = (tpool_t*)malloc(sizeof(tpool_t)); initTpool(pool, ru->threadPool, cpumeas(CPUMEAS_GETSTATE)); // FEP RX result FIFO @@ -1834,14 +1820,12 @@ static void NRRCconfig_RU(configmodule_interface_t *cfg) if (RUParamList.numelt > 0) { RC.ru = (RU_t **)malloc(RC.nb_RU*sizeof(RU_t *)); RC.ru_mask = (1 << NB_RU) - 1; - printf("Set RU mask to %lx\n",RC.ru_mask); for (int j = 0; j < RC.nb_RU; j++) { RC.ru[j] = calloc(1, sizeof(*RC.ru[j])); RC.ru[j]->idx = j; RC.ru[j]->nr_frame_parms = calloc(1, sizeof(*RC.ru[j]->nr_frame_parms)); RC.ru[j]->frame_parms = calloc(1, sizeof(*RC.ru[j]->frame_parms)); - printf("Creating RC.ru[%d]:%p\n", j, RC.ru[j]); RC.ru[j]->if_timing = synch_to_ext_device; if (RC.nb_nr_L1_inst > 0) @@ -1895,7 +1879,7 @@ static void NRRCconfig_RU(configmodule_interface_t *cfg) LOG_E(PHY, "Erroneous RU clock source in the provided configuration file: '%s'\n", *(RUParamList.paramarray[j][RU_SDR_CLK_SRC].strptr)); } } else { - LOG_I(PHY,"Setting clock source to internal\n"); + LOG_D(PHY, "Setting clock source to internal\n"); RC.ru[j]->openair0_cfg.clock_source = internal; } @@ -1913,7 +1897,7 @@ static void NRRCconfig_RU(configmodule_interface_t *cfg) LOG_E(PHY, "Erroneous RU time source in the provided configuration file: '%s'\n", *(RUParamList.paramarray[j][RU_SDR_CLK_SRC].strptr)); } } else { - LOG_I(PHY,"Setting time source to internal\n"); + LOG_D(PHY, "Setting time source to internal\n"); RC.ru[j]->openair0_cfg.time_source = internal; } @@ -1923,7 +1907,7 @@ static void NRRCconfig_RU(configmodule_interface_t *cfg) if (!(config_isparamset(RUParamList.paramarray[j],RU_LOCAL_IF_NAME_IDX))) { RC.ru[j]->if_south = LOCAL_RF; RC.ru[j]->function = gNodeB_3GPP; - printf("Setting function for RU %d to gNodeB_3GPP\n",j); + LOG_D(PHY, "Setting function for RU %d to gNodeB_3GPP\n", j); } else { RC.ru[j]->eth_params.local_if_name = strdup(*(RUParamList.paramarray[j][RU_LOCAL_IF_NAME_IDX].strptr)); RC.ru[j]->eth_params.my_addr = strdup(*(RUParamList.paramarray[j][RU_LOCAL_ADDRESS_IDX].strptr)); @@ -1937,22 +1921,22 @@ static void NRRCconfig_RU(configmodule_interface_t *cfg) RC.ru[j]->if_south = LOCAL_RF; RC.ru[j]->function = NGFI_RRU_IF5; RC.ru[j]->eth_params.transp_preference = ETH_UDP_MODE; - printf("Setting function for RU %d to NGFI_RRU_IF5 (udp)\n",j); + LOG_D(PHY, "Setting function for RU %d to NGFI_RRU_IF5 (udp)\n", j); } else if (strcmp(*(RUParamList.paramarray[j][RU_TRANSPORT_PREFERENCE_IDX].strptr), "raw") == 0) { RC.ru[j]->if_south = LOCAL_RF; RC.ru[j]->function = NGFI_RRU_IF5; RC.ru[j]->eth_params.transp_preference = ETH_RAW_MODE; - printf("Setting function for RU %d to NGFI_RRU_IF5 (raw)\n",j); + LOG_D(PHY, "Setting function for RU %d to NGFI_RRU_IF5 (raw)\n", j); } else if (strcmp(*(RUParamList.paramarray[j][RU_TRANSPORT_PREFERENCE_IDX].strptr), "udp_if4p5") == 0) { RC.ru[j]->if_south = LOCAL_RF; RC.ru[j]->function = NGFI_RRU_IF4p5; RC.ru[j]->eth_params.transp_preference = ETH_UDP_IF4p5_MODE; - printf("Setting function for RU %d to NGFI_RRU_IF4p5 (udp)\n",j); + LOG_D(PHY, "Setting function for RU %d to NGFI_RRU_IF4p5 (udp)\n", j); } else if (strcmp(*(RUParamList.paramarray[j][RU_TRANSPORT_PREFERENCE_IDX].strptr), "raw_if4p5") == 0) { RC.ru[j]->if_south = LOCAL_RF; RC.ru[j]->function = NGFI_RRU_IF4p5; RC.ru[j]->eth_params.transp_preference = ETH_RAW_IF4p5_MODE; - printf("Setting function for RU %d to NGFI_RRU_IF4p5 (raw)\n",j); + LOG_D(PHY, "Setting function for RU %d to NGFI_RRU_IF4p5 (raw)\n", j); } } @@ -1961,7 +1945,7 @@ static void NRRCconfig_RU(configmodule_interface_t *cfg) RC.ru[j]->sf_extension = *(RUParamList.paramarray[j][RU_SF_EXTENSION_IDX].uptr); } //strcmp(local_rf, "yes") == 0 else { - printf("RU %d: Transport %s\n",j,*(RUParamList.paramarray[j][RU_TRANSPORT_PREFERENCE_IDX].strptr)); + LOG_D(PHY, "RU %d: Transport %s\n", j, *(RUParamList.paramarray[j][RU_TRANSPORT_PREFERENCE_IDX].strptr)); RC.ru[j]->eth_params.local_if_name = strdup(*(RUParamList.paramarray[j][RU_LOCAL_IF_NAME_IDX].strptr)); RC.ru[j]->eth_params.my_addr = strdup(*(RUParamList.paramarray[j][RU_LOCAL_ADDRESS_IDX].strptr)); RC.ru[j]->eth_params.remote_addr = strdup(*(RUParamList.paramarray[j][RU_REMOTE_ADDRESS_IDX].strptr)); @@ -2006,13 +1990,18 @@ static void NRRCconfig_RU(configmodule_interface_t *cfg) RC.ru[j]->openair0_cfg.nr_flag = *(RUParamList.paramarray[j][RU_NR_FLAG].iptr); RC.ru[j]->openair0_cfg.nr_band = RC.ru[j]->band[0]; RC.ru[j]->openair0_cfg.nr_scs_for_raster = *(RUParamList.paramarray[j][RU_NR_SCS_FOR_RASTER].iptr); - printf("[RU %d] Setting nr_flag %d, nr_band %d, nr_scs_for_raster %d\n",j,RC.ru[j]->openair0_cfg.nr_flag,RC.ru[j]->openair0_cfg.nr_band,RC.ru[j]->openair0_cfg.nr_scs_for_raster); + LOG_D(PHY, + "[RU %d] Setting nr_flag %d, nr_band %d, nr_scs_for_raster %d\n", + j, + RC.ru[j]->openair0_cfg.nr_flag, + RC.ru[j]->openair0_cfg.nr_band, + RC.ru[j]->openair0_cfg.nr_scs_for_raster); RC.ru[j]->openair0_cfg.rxfh_cores[0] = *(RUParamList.paramarray[j][RU_RXFH_CORE_ID].iptr); RC.ru[j]->openair0_cfg.txfh_cores[0] = *(RUParamList.paramarray[j][RU_TXFH_CORE_ID].iptr); RC.ru[j]->num_tpcores = *(RUParamList.paramarray[j][RU_NUM_TP_CORES].iptr); RC.ru[j]->half_slot_parallelization = *(RUParamList.paramarray[j][RU_HALF_SLOT_PARALLELIZATION].iptr); RC.ru[j]->ru_thread_core = *(RUParamList.paramarray[j][RU_RU_THREAD_CORE].iptr); - printf("[RU %d] Setting half-slot parallelization to %d\n",j,RC.ru[j]->half_slot_parallelization); + LOG_D(PHY, "[RU %d] Setting half-slot parallelization to %d\n", j, RC.ru[j]->half_slot_parallelization); AssertFatal(RC.ru[j]->num_tpcores <= RUParamList.paramarray[j][RU_TP_CORES].numelt, "Number of TP cores should be <=16\n"); for (int i = 0; i < RC.ru[j]->num_tpcores; i++) RC.ru[j]->tpcores[i] = RUParamList.paramarray[j][RU_TP_CORES].iptr[i]; diff --git a/executables/nr-softmodem.c b/executables/nr-softmodem.c index 1e13886a24..47548239b9 100644 --- a/executables/nr-softmodem.c +++ b/executables/nr-softmodem.c @@ -182,12 +182,9 @@ struct timespec clock_difftime(struct timespec start, struct timespec end) { return temp; } -void print_difftimes(void) { -#ifdef DEBUG - printf("difftimes min = %lu ns ; max = %lu ns\n", min_diff_time.tv_nsec, max_diff_time.tv_nsec); -#else - LOG_I(HW,"difftimes min = %lu ns ; max = %lu ns\n", min_diff_time.tv_nsec, max_diff_time.tv_nsec); -#endif +void print_difftimes(void) +{ + LOG_I(HW, "difftimes min = %lu ns ; max = %lu ns\n", min_diff_time.tv_nsec, max_diff_time.tv_nsec); } void update_difftimes(struct timespec start, struct timespec end) { @@ -268,7 +265,7 @@ static int create_gNB_tasks(ngran_node_t node_type, configmodule_interface_t *cf uint32_t gnb_id_end = gnb_id_start + gnb_nb; LOG_D(GNB_APP, "%s(gnb_nb:%d)\n", __FUNCTION__, gnb_nb); itti_wait_ready(1); - LOG_I(PHY, "%s() Task ready initialize structures\n", __FUNCTION__); + LOG_D(PHY, "%s() Task ready initialize structures\n", __FUNCTION__); #ifdef ENABLE_AERIAL AssertFatal(NFAPI_MODE == NFAPI_MODE_AERIAL,"Can only be run with '--nfapi AERIAL' when compiled with AERIAL support, if you want to run other (n)FAPI modes, please run ./build_oai without -w AERIAL"); @@ -283,7 +280,7 @@ static int create_gNB_tasks(ngran_node_t node_type, configmodule_interface_t *cf if (RC.nb_nr_macrlc_inst > 0) RCconfig_nr_macrlc(cfg); - LOG_I(PHY, "%s() RC.nb_nr_L1_inst:%d\n", __FUNCTION__, RC.nb_nr_L1_inst); + LOG_D(PHY, "%s() RC.nb_nr_L1_inst:%d\n", __FUNCTION__, RC.nb_nr_L1_inst); if (RC.nb_nr_L1_inst>0) AssertFatal(l1_north_init_gNB()==0,"could not initialize L1 north interface\n"); @@ -291,7 +288,7 @@ static int create_gNB_tasks(ngran_node_t node_type, configmodule_interface_t *cf "Number of gNB is greater than gNB defined in configuration file (%d/%d)!", gnb_nb, RC.nb_nr_inst); - LOG_I(GNB_APP,"Allocating gNB_RRC_INST for %d instances\n",RC.nb_nr_inst); + LOG_D(GNB_APP, "Allocating gNB_RRC_INST for %d instances\n", RC.nb_nr_inst); if (RC.nb_nr_inst > 0) { AssertFatal(RC.nb_nr_inst == 1, "multiple RRC instances are not supported\n"); @@ -411,7 +408,6 @@ static void get_options(configmodule_interface_t *cfg) NRRCConfig(); NB_gNB_INST = RC.nb_nr_inst; NB_RU = RC.nb_RU; - printf("Configuration: nb_rrc_inst %d, nb_nr_L1_inst %d, nb_ru %hhu\n",NB_gNB_INST,RC.nb_nr_L1_inst,NB_RU); } } @@ -461,24 +457,22 @@ void set_default_frame_parms(nfapi_nr_config_request_scf_t *config[MAX_NUM_CCs], // downlink_frequency[CC_id][1] = downlink_frequency[CC_id][0]; // downlink_frequency[CC_id][2] = downlink_frequency[CC_id][0]; // downlink_frequency[CC_id][3] = downlink_frequency[CC_id][0]; - //printf("Downlink for CC_id %d frequency set to %u\n", CC_id, downlink_frequency[CC_id][0]); frame_parms[CC_id]->dl_CarrierFreq=downlink_frequency[CC_id][0]; */ } } void wait_RUs(void) { - LOG_I(PHY,"Waiting for RUs to be configured ... RC.ru_mask:%02lx\n", RC.ru_mask); + LOG_D(PHY, "Waiting for RUs to be configured ... RC.ru_mask:%02lx\n", RC.ru_mask); // wait for all RUs to be configured over fronthaul pthread_mutex_lock(&RC.ru_mutex); while (RC.ru_mask>0) { pthread_cond_wait(&RC.ru_cond,&RC.ru_mutex); - printf("RC.ru_mask:%02lx\n", RC.ru_mask); } pthread_mutex_unlock(&RC.ru_mutex); - LOG_I(PHY,"RUs configured\n"); + LOG_D(PHY, "RUs configured\n"); } void wait_gNBs(void) { @@ -486,7 +480,7 @@ void wait_gNBs(void) { int waiting=1; while (waiting==1) { - printf("Waiting for gNB L1 instances to all get configured ... sleeping 50ms (nb_nr_sL1_inst %d)\n",RC.nb_nr_L1_inst); + LOG_D(GNB_APP, "Waiting for gNB L1 instances to all get configured ... sleeping 50ms (nb_nr_sL1_inst %d)\n", RC.nb_nr_L1_inst); usleep(50*1000); waiting=0; @@ -498,7 +492,7 @@ void wait_gNBs(void) { } } - printf("gNB L1 are configured\n"); + LOG_D(GNB_APP, "gNB L1 are configured\n"); } /* @@ -514,15 +508,14 @@ void terminate_task(task_id_t task_id, module_id_t mod_id) { //extern void free_transport(PHY_VARS_gNB *); extern void nr_phy_free_RU(RU_t *); -static void wait_nfapi_init(char *thread_name) { - printf( "waiting for NFAPI PNF connection and population of global structure (%s)\n",thread_name); +static void wait_nfapi_init(char *thread_name) +{ pthread_mutex_lock( &nfapi_sync_mutex ); while (nfapi_sync_var<0) pthread_cond_wait( &nfapi_sync_cond, &nfapi_sync_mutex ); pthread_mutex_unlock(&nfapi_sync_mutex); - printf( "NFAPI: got sync (%s)\n", thread_name); } void init_pdcp(void) { @@ -601,7 +594,6 @@ int main( int argc, char **argv ) { memset(tx_max_power,0,sizeof(int)*MAX_NUM_CCs); logInit(); lock_memory_to_ram(); - printf("Reading in command-line options\n"); get_options(uniqCfg); EPC_MODE_ENABLED = !IS_SOFTMODEM_NOS1; @@ -626,7 +618,6 @@ int main( int argc, char **argv ) { #endif //randominit (0); set_taus_seed (0); - printf("configuring for RAU/RRU\n"); cpuf=get_cpu_freq_GHz(); itti_init(TASK_MAX, tasks_info); @@ -653,27 +644,20 @@ int main( int argc, char **argv ) { usleep(1000); if (NFAPI_MODE && NFAPI_MODE != NFAPI_MODE_AERIAL) { - printf("NFAPI*** - mutex and cond created - will block shortly for completion of PNF connection\n"); pthread_cond_init(&sync_cond,NULL); pthread_mutex_init(&sync_mutex, NULL); } - printf("START MAIN THREADS\n"); // start the main threads number_of_cards = 1; - printf("RC.nb_nr_L1_inst:%d\n", RC.nb_nr_L1_inst); if (RC.nb_nr_L1_inst > 0) { - printf("Initializing gNB threads wait_for_sync:%d\n", wait_for_sync); init_gNB(wait_for_sync); } - printf("wait_gNBs()\n"); wait_gNBs(); - printf("About to Init RU threads RC.nb_RU:%d\n", RC.nb_RU); int sl_ahead = NFAPI_MODE == NFAPI_MODE_AERIAL ? 0 : 6; if (RC.nb_RU >0) { - printf("Initializing RU threads\n"); init_NR_RU(uniqCfg, get_softmodem_params()->rf_config_file); for (ru_id=0; ru_idnvipc_params_s); #endif if (RC.nb_nr_L1_inst > 0) { - printf("wait RUs\n"); wait_RUs(); - printf("ALL RUs READY!\n"); - printf("RC.nb_RU:%d\n", RC.nb_RU); // once all RUs are ready initialize the rest of the gNBs ((dependence on final RU parameters after configuration) - printf("ALL RUs ready - init gNBs\n"); for (int idx=0;idxif_inst->sl_ahead = sl_ahead; if (IS_SOFTMODEM_DOSCOPE || IS_SOFTMODEM_IMSCOPE_ENABLED) { @@ -743,15 +723,10 @@ int main( int argc, char **argv ) { } if (NFAPI_MODE != NFAPI_MODE_PNF && NFAPI_MODE != NFAPI_MODE_VNF && NFAPI_MODE != NFAPI_MODE_AERIAL) { - printf("Not NFAPI mode - call init_eNB_afterRU()\n"); init_eNB_afterRU(); - } else { - printf("NFAPI mode - DO NOT call init_gNB_afterRU()\n"); } - printf("ALL RUs ready - ALL gNBs ready\n"); // connect the TX/RX buffers - printf("Sending sync to all threads\n"); pthread_mutex_lock(&sync_mutex); sync_var=0; pthread_cond_broadcast(&sync_cond); @@ -759,12 +734,10 @@ int main( int argc, char **argv ) { } // wait for end of program - printf("Entering ITTI signals handler\n"); printf("TYPE TO TERMINATE\n"); itti_wait_tasks_end(NULL); printf("Returned from ITTI signal handler\n"); oai_exit=1; - printf("oai_exit=%d\n",oai_exit); // cleanup if (RC.nb_nr_L1_inst > 0) diff --git a/nfapi/oai_integration/nfapi.c b/nfapi/oai_integration/nfapi.c index 7b4d1b6239..3d363d25ee 100644 --- a/nfapi/oai_integration/nfapi.c +++ b/nfapi/oai_integration/nfapi.c @@ -47,15 +47,10 @@ const char *nfapi_get_strmode(void) { return nfapi_str_mode[nfapi_params.nfapi_mode]; } -void nfapi_logmode() { - LOG_I(ENB_APP,"nfapi (%d) running mode: %s\n",nfapi_params.nfapi_mode,nfapi_get_strmode()); -} - nfapi_mode_t nfapi_getmode(void) { return nfapi_params.nfapi_mode; } void nfapi_setmode(nfapi_mode_t nfapi_mode) { nfapi_params.nfapi_mode = nfapi_mode; - nfapi_logmode(); } diff --git a/openair1/PHY/INIT/lte_init_ru.c b/openair1/PHY/INIT/lte_init_ru.c index 62e8c1d5d3..967d352769 100644 --- a/openair1/PHY/INIT/lte_init_ru.c +++ b/openair1/PHY/INIT/lte_init_ru.c @@ -39,7 +39,7 @@ int phy_init_RU(RU_t *ru) { RU_CALIBRATION *calibration = &ru->calibration; int i,j,p,re; //load_dftslib(); - LOG_I(PHY,"Initializing RU signal buffers (if_south %s) nb_tx %d\n",ru_if_types[ru->if_south],ru->nb_tx); + LOG_D(PHY, "Initializing RU signal buffers (if_south %s) nb_tx %d\n", ru_if_types[ru->if_south], ru->nb_tx); if (ru->is_slave == 1) { generate_ul_ref_sigs_rx(); @@ -54,8 +54,11 @@ int phy_init_RU(RU_t *ru) { for (i=0; inb_tx; i++) { // Allocate 10 subframes of I/Q TX signal data (time) if not ru->common.txdata[i] = (int32_t *)malloc16_clear( fp->samples_per_tti*10*sizeof(int32_t) ); - LOG_I(PHY,"[INIT] common.txdata[%d] = %p (%lu bytes)\n",i,ru->common.txdata[i], - fp->samples_per_tti*10*sizeof(int32_t)); + LOG_D(PHY, + "[INIT] common.txdata[%d] = %p (%lu bytes)\n", + i, + ru->common.txdata[i], + fp->samples_per_tti * 10 * sizeof(int32_t)); } if (ru->is_slave == 1) { @@ -71,7 +74,6 @@ int phy_init_RU(RU_t *ru) { } } // IF5 or local RF else { - // LOG_I(PHY,"No rxdata/txdata for RU\n"); ru->common.txdata = (int32_t **)NULL; ru->common.rxdata = (int32_t **)NULL; } @@ -79,22 +81,21 @@ int phy_init_RU(RU_t *ru) { if (ru->function != NGFI_RRU_IF5) { // we need to do RX/TX RU processing load_dftslib(); init_7_5KHz(); - LOG_I(PHY,"nb_tx %d\n",ru->nb_tx); + LOG_D(PHY, "nb_tx %d\n", ru->nb_tx); ru->common.rxdata_7_5kHz = (int32_t **)malloc16(ru->nb_rx*sizeof(int32_t *) ); for (i=0; inb_rx; i++) { ru->common.rxdata_7_5kHz[i] = (int32_t *)malloc16_clear( 2*fp->samples_per_tti*2*sizeof(int32_t) ); - LOG_I(PHY,"rxdata_7_5kHz[%d] %p for RU %d\n",i,ru->common.rxdata_7_5kHz[i],ru->idx); + LOG_D(PHY, "rxdata_7_5kHz[%d] %p for RU %d\n", i, ru->common.rxdata_7_5kHz[i], ru->idx); } // allocate IFFT input buffers (TX) ru->common.txdataF_BF = (int32_t **)malloc16(ru->nb_tx*sizeof(int32_t *)); - LOG_I(PHY,"[INIT] common.txdata_BF= %p (%lu bytes)\n",ru->common.txdataF_BF, - ru->nb_tx*sizeof(int32_t *)); + LOG_D(PHY, "[INIT] common.txdata_BF= %p (%lu bytes)\n", ru->common.txdataF_BF, ru->nb_tx * sizeof(int32_t *)); for (i=0; inb_tx; i++) { ru->common.txdataF_BF[i] = (int32_t *)malloc16_clear(fp->symbols_per_tti*fp->ofdm_symbol_size*sizeof(int32_t) ); - LOG_I(PHY,"txdataF_BF[%d] %p for RU %d\n",i,ru->common.txdataF_BF[i],ru->idx); + LOG_D(PHY, "txdataF_BF[%d] %p for RU %d\n", i, ru->common.txdataF_BF[i], ru->idx); } // allocate FFT output buffers (RX) @@ -103,7 +104,7 @@ int phy_init_RU(RU_t *ru) { for (i=0; inb_rx; i++) { // allocate 2 subframes of I/Q signal data (frequency) ru->common.rxdataF[i] = (int32_t *)malloc16_clear(sizeof(int32_t)*(2*fp->ofdm_symbol_size*fp->symbols_per_tti) ); - LOG_I(PHY,"rxdataF[%d] %p for RU %d\n",i,ru->common.rxdataF[i],ru->idx); + LOG_D(PHY, "rxdataF[%d] %p for RU %d\n", i, ru->common.rxdataF[i], ru->idx); } if (ru->is_slave == 1) { @@ -114,7 +115,7 @@ int phy_init_RU(RU_t *ru) { for (i=0; inb_rx; i++) { // allocate 2 subframes of I/Q signal data (frequency) calibration->rxdataF_ext[i] = (int32_t *)malloc16_clear(sizeof(int32_t)*fp->N_RB_UL*12*fp->symbols_per_tti ); - LOG_I(PHY,"rxdataF_ext[%d] %p for RU %d\n",i,calibration->rxdataF_ext[i],ru->idx); + LOG_D(PHY, "rxdataF_ext[%d] %p for RU %d\n", i, calibration->rxdataF_ext[i], ru->idx); calibration->drs_ch_estimates[i] = (int32_t *)malloc16_clear(sizeof(int32_t)*fp->N_RB_UL*12*fp->symbols_per_tti); } } @@ -186,7 +187,7 @@ int phy_init_RU(RU_t *ru) { void phy_free_RU(RU_t *ru) { int i,j,p; RU_CALIBRATION *calibration = &ru->calibration; - LOG_I(PHY, "Freeing RU signal buffers (if_south %s) nb_tx %d\n", ru_if_types[ru->if_south], ru->nb_tx); + LOG_D(PHY, "Freeing RU signal buffers (if_south %s) nb_tx %d\n", ru_if_types[ru->if_south], ru->nb_tx); if (ru->if_south <= REMOTE_IF5) { // this means REMOTE_IF5 or LOCAL_RF, so free memory for time-domain signals for (i = 0; i < ru->nb_tx; i++) free_and_zero(ru->common.txdata[i]); diff --git a/openair1/PHY/INIT/nr_init.c b/openair1/PHY/INIT/nr_init.c index 57d9bbc8eb..708f23e01a 100644 --- a/openair1/PHY/INIT/nr_init.c +++ b/openair1/PHY/INIT/nr_init.c @@ -47,19 +47,19 @@ int l1_north_init_gNB() { AssertFatal(RC.nb_nr_L1_inst>0,"nb_nr_L1_inst=%d\n",RC.nb_nr_L1_inst); AssertFatal(RC.gNB!=NULL,"RC.gNB is null\n"); - LOG_I(PHY,"%s() RC.nb_nr_L1_inst:%d\n", __FUNCTION__, RC.nb_nr_L1_inst); + LOG_D(PHY, "%s() RC.nb_nr_L1_inst:%d\n", __FUNCTION__, RC.nb_nr_L1_inst); for (int i=0; iif_inst = NR_IF_Module_init(i))<0) return(-1); - - LOG_I(PHY,"%s() RC.gNB[%d] installing callbacks\n", __FUNCTION__, i); + + LOG_D(PHY, "%s() RC.gNB[%d] installing callbacks\n", __FUNCTION__, i); RC.gNB[i]->if_inst->NR_PHY_config_req = nr_phy_config_request; RC.gNB[i]->if_inst->NR_Schedule_response = nr_schedule_response; } } else { - LOG_I(PHY,"%s() Not installing PHY callbacks - RC.nb_nr_L1_inst:%d RC.gNB:%p\n", __FUNCTION__, RC.nb_nr_L1_inst, RC.gNB); + LOG_D(PHY, "%s() Not installing PHY callbacks - RC.nb_nr_L1_inst:%d RC.gNB:%p\n", __FUNCTION__, RC.nb_nr_L1_inst, RC.gNB); } return(0); @@ -125,7 +125,7 @@ void phy_init_nr_gNB(PHY_VARS_gNB *gNB) AssertFatal(Ptx > 0 && Ptx < 9,"Ptx %d is not supported\n", Ptx); AssertFatal(Prx > 0 && Prx < 9,"Prx %d is not supported\n", Prx); - LOG_I(PHY, "[gNB %d]About to wait for gNB to be configured\n", gNB->Mod_id); + LOG_D(PHY, "[gNB %d]About to wait for gNB to be configured\n", gNB->Mod_id); while(gNB->configured == 0) usleep(10000); @@ -381,8 +381,7 @@ void nr_phy_config_request_sim(PHY_VARS_gNB *gNB, init_symbol_rotation(fp); init_timeshift_rotation(fp); - gNB->configured = 1; - LOG_I(PHY,"gNB configured\n"); + gNB->configured = 1; } void nr_phy_config_request(NR_PHY_Config_t *phy_config) @@ -406,7 +405,7 @@ void nr_phy_config_request(NR_PHY_Config_t *phy_config) LOG_I(PHY, "DL frequency %lu Hz, UL frequency %lu Hz: band %d, uldl offset %d Hz\n", fp->dl_CarrierFreq, fp->ul_CarrierFreq, fp->nr_band, dlul_offset); fp->threequarter_fs = get_softmodem_params()->threequarter_fs; - LOG_A(PHY,"Configuring MIB for instance %d, : (Nid_cell %d,DL freq %llu, UL freq %llu)\n", + LOG_D(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, @@ -434,8 +433,6 @@ void nr_phy_config_request(NR_PHY_Config_t *phy_config) fp->ofdm_offset_divisor = RC.gNB[Mod_id]->ofdm_offset_divisor; init_symbol_rotation(fp); init_timeshift_rotation(fp); - - LOG_I(PHY,"gNB %d configured\n",Mod_id); } void init_DLSCH_struct(PHY_VARS_gNB *gNB, processingData_L1tx_t *msg) @@ -476,7 +473,6 @@ void init_nr_transport(PHY_VARS_gNB *gNB) NR_DL_FRAME_PARMS *fp = &gNB->frame_parms; const nfapi_nr_config_request_scf_t *cfg = &gNB->gNB_config; - LOG_I(PHY, "Initialise nr transport\n"); int nb_slots_per_period = cfg->cell_config.frame_duplex_type.value ? fp->slots_per_frame / get_nb_periods_per_frame(cfg->tdd_table.tdd_period.value) : diff --git a/openair1/PHY/INIT/nr_init_ru.c b/openair1/PHY/INIT/nr_init_ru.c index 93b95b96eb..bf447645d6 100644 --- a/openair1/PHY/INIT/nr_init_ru.c +++ b/openair1/PHY/INIT/nr_init_ru.c @@ -33,7 +33,7 @@ int nr_phy_init_RU(RU_t *ru) { NR_DL_FRAME_PARMS *fp = ru->nr_frame_parms; - LOG_I(PHY,"Initializing RU signal buffers (if_south %s) nb_tx %d, nb_rx %d\n",ru_if_types[ru->if_south],ru->nb_tx, ru->nb_rx); + LOG_D(PHY, "Initializing RU signal buffers (if_south %s) nb_tx %d, nb_rx %d\n", ru_if_types[ru->if_south], ru->nb_tx, ru->nb_rx); nfapi_nr_config_request_scf_t *cfg = &ru->config; ru->nb_log_antennas = 0; @@ -60,29 +60,30 @@ int nr_phy_init_RU(RU_t *ru) for (int i = 0; i < ru->nb_tx; i++) { // Allocate 10 subframes of I/Q TX signal data (time) if not ru->common.txdata[i] = (int32_t*)malloc16_clear((ru->sf_extension + fp->samples_per_frame)*sizeof(int32_t)); - LOG_I(PHY,"[INIT] common.txdata[%d] = %p (%lu bytes,sf_extension %d)\n",i,ru->common.txdata[i], - (ru->sf_extension + fp->samples_per_frame)*sizeof(int32_t),ru->sf_extension); + LOG_D(PHY, + "[INIT] common.txdata[%d] = %p (%lu bytes,sf_extension %d)\n", + i, + ru->common.txdata[i], + (ru->sf_extension + fp->samples_per_frame) * sizeof(int32_t), + ru->sf_extension); ru->common.txdata[i] = &ru->common.txdata[i][ru->sf_extension]; - LOG_I(PHY,"[INIT] common.txdata[%d] = %p \n",i,ru->common.txdata[i]); - + LOG_D(PHY, "[INIT] common.txdata[%d] = %p \n", i, ru->common.txdata[i]); } for (int i = 0; i < ru->nb_rx; i++) { ru->common.rxdata[i] = (int32_t*)malloc16_clear( fp->samples_per_frame*sizeof(int32_t) ); } } // IF5 or local RF else { - // LOG_I(PHY,"No rxdata/txdata for RU\n"); ru->common.txdata = (int32_t**)NULL; ru->common.rxdata = (int32_t**)NULL; - } if (ru->function != NGFI_RRU_IF5) { // we need to do RX/TX RU processing - LOG_I(PHY,"nb_tx %d\n",ru->nb_tx); + LOG_D(PHY, "nb_tx %d\n", ru->nb_tx); ru->common.rxdata_7_5kHz = (int32_t**)malloc16(ru->nb_rx*sizeof(int32_t*) ); for (int i = 0; i < ru->nb_rx; i++) { ru->common.rxdata_7_5kHz[i] = (int32_t*)malloc16_clear( 2*fp->samples_per_subframe*2*sizeof(int32_t) ); - LOG_I(PHY,"rxdata_7_5kHz[%d] %p for RU %d\n",i,ru->common.rxdata_7_5kHz[i],ru->idx); + LOG_D(PHY, "rxdata_7_5kHz[%d] %p for RU %d\n", i, ru->common.rxdata_7_5kHz[i], ru->idx); } @@ -94,10 +95,10 @@ int nr_phy_init_RU(RU_t *ru) // allocate IFFT input buffers (TX) ru->common.txdataF_BF = (int32_t **)malloc16(ru->nb_tx*sizeof(int32_t*)); - LOG_I(PHY,"[INIT] common.txdata_BF= %p (%lu bytes)\n", ru->common.txdataF_BF, ru->nb_tx*sizeof(int32_t*)); + LOG_D(PHY, "[INIT] common.txdata_BF= %p (%lu bytes)\n", ru->common.txdataF_BF, ru->nb_tx * sizeof(int32_t *)); for (int i = 0; i < ru->nb_tx; i++) { ru->common.txdataF_BF[i] = (int32_t*)malloc16_clear(fp->samples_per_subframe_wCP*sizeof(int32_t) ); - LOG_I(PHY,"txdataF_BF[%d] %p for RU %d\n",i,ru->common.txdataF_BF[i],ru->idx); + LOG_D(PHY, "txdataF_BF[%d] %p for RU %d\n", i, ru->common.txdataF_BF[i], ru->idx); } // allocate FFT output buffers (RX) ru->common.rxdataF = (int32_t**)malloc16(ru->nb_rx*sizeof(int32_t*) ); @@ -105,7 +106,7 @@ int nr_phy_init_RU(RU_t *ru) // allocate 4 slots of I/Q signal data (frequency) int size = RU_RX_SLOT_DEPTH * fp->symbols_per_slot * fp->ofdm_symbol_size; ru->common.rxdataF[i] = (int32_t*)malloc16_clear(sizeof(**ru->common.rxdataF) * size); - LOG_I(PHY,"rxdataF[%d] %p for RU %d\n",i,ru->common.rxdataF[i],ru->idx); + LOG_D(PHY, "rxdataF[%d] %p for RU %d\n", i, ru->common.rxdataF[i], ru->idx); } /* number of elements of an array X is computed as sizeof(X) / sizeof(X[0]) */ @@ -124,7 +125,7 @@ int nr_phy_init_RU(RU_t *ru) AssertFatal(ru->num_gNB <= NUMBER_OF_gNB_MAX,"gNB instances %d > %d\n", ru->num_gNB,NUMBER_OF_gNB_MAX); - LOG_I(PHY,"[INIT] %s() ru->num_gNB:%d \n", __FUNCTION__, ru->num_gNB); + LOG_D(PHY, "[INIT] %s() ru->num_gNB:%d \n", __FUNCTION__, ru->num_gNB); } // !=IF5 @@ -135,7 +136,7 @@ int nr_phy_init_RU(RU_t *ru) void nr_phy_free_RU(RU_t *ru) { - LOG_I(PHY, "Freeing RU signal buffers (if_south %s) nb_tx %d\n", ru_if_types[ru->if_south], ru->nb_tx); + LOG_D(PHY, "Freeing RU signal buffers (if_south %s) nb_tx %d\n", ru_if_types[ru->if_south], ru->nb_tx); if (ru->if_south <= REMOTE_IF5) { // this means REMOTE_IF5 or LOCAL_RF, so free memory for time-domain signals // Hack: undo what is done at allocation diff --git a/openair1/PHY/MODULATION/nr_modulation.c b/openair1/PHY/MODULATION/nr_modulation.c index 10cafe7d51..e8b215accc 100644 --- a/openair1/PHY/MODULATION/nr_modulation.c +++ b/openair1/PHY/MODULATION/nr_modulation.c @@ -371,7 +371,7 @@ void perform_symbol_rotation(NR_DL_FRAME_PARMS *fp, double f0, c16_t *symbol_rot const double Ncp0=16*64 + (144*64*(1/(float)(1<numerology_index))); const double Ncp1=(144*64*(1/(float)(1<numerology_index))); - LOG_I(PHY, "Doing symbol rotation calculation for TX/RX, f0 %f Hz, Nsymb %d\n", f0, nsymb); + LOG_D(PHY, "Doing symbol rotation calculation for TX/RX, f0 %f Hz, Nsymb %d\n", f0, nsymb); double tl = 0.0; double poff = 0.0; diff --git a/openair1/PHY/defs_common.h b/openair1/PHY/defs_common.h index ff774d7789..cd3202eeb9 100644 --- a/openair1/PHY/defs_common.h +++ b/openair1/PHY/defs_common.h @@ -1050,16 +1050,17 @@ typedef uint8_t(encoder_if_t)(uint8_t *input, extern int oai_exit; -static inline void wait_sync(char *thread_name) { +static inline void wait_sync(char *thread_name) +{ int rc; - printf( "waiting for sync (%s,%d/%p,%p,%p)\n",thread_name,sync_var,&sync_var,&sync_cond,&sync_mutex); + LOG_D(PHY, "waiting for sync (%s,%d/%p,%p,%p)\n", thread_name, sync_var, &sync_var, &sync_cond, &sync_mutex); AssertFatal((rc = pthread_mutex_lock( &sync_mutex ))==0,"sync mutex lock error"); while (sync_var<0 && !oai_exit) pthread_cond_wait( &sync_cond, &sync_mutex ); AssertFatal((rc = pthread_mutex_unlock( &sync_mutex ))==0,"sync mutex unlock error"); - printf( "got sync (%s)\n", thread_name); + LOG_I(PHY, "got sync (%s)\n", thread_name); /* * Raphael Defosseux: added for CI to get faster the got sync message. */ diff --git a/openair1/SCHED_NR/nr_prach_procedures.c b/openair1/SCHED_NR/nr_prach_procedures.c index 426b25638d..280a39c371 100644 --- a/openair1/SCHED_NR/nr_prach_procedures.c +++ b/openair1/SCHED_NR/nr_prach_procedures.c @@ -153,7 +153,7 @@ void L1_nr_prach_procedures(PHY_VARS_gNB *gNB,int frame,int slot) { if ((gNB->prach_energy_counter == 100) && (max_preamble_energy[0] > gNB->measurements.prach_I0 + gNB->prach_thres) && (pdu_index < MAX_NUM_NR_RX_RACH_PDUS)) { - LOG_I(NR_PHY, + LOG_A(NR_PHY, "[RAPROC] %d.%d Initiating RA procedure with preamble %d, energy %d.%d dB (I0 %d, thres %d), delay %d start symbol " "%u freq index %u\n", frame, diff --git a/openair2/GNB_APP/gnb_app.c b/openair2/GNB_APP/gnb_app.c index 0e7e25e2c0..49b53aa572 100644 --- a/openair2/GNB_APP/gnb_app.c +++ b/openair2/GNB_APP/gnb_app.c @@ -72,23 +72,15 @@ uint32_t gNB_app_register(uint32_t gnb_id_start, uint32_t gnb_id_end)//, const E for (gnb_id = gnb_id_start; (gnb_id < gnb_id_end) ; gnb_id++) { { if(get_softmodem_params()->sa){ - ngap_register_gnb_req_t *ngap_register_gNB; //Type Temporarily reuse - // note: there is an implicit relationship between the data structure and the message name msg_p = itti_alloc_new_message (TASK_GNB_APP, 0, NGAP_REGISTER_GNB_REQ); //Message Temporarily reuse RCconfig_NR_NG(msg_p, gnb_id); - ngap_register_gNB = &NGAP_REGISTER_GNB_REQ(msg_p); //Message Temporarily reuse - - LOG_I(GNB_APP,"default drx %d\n",ngap_register_gNB->default_drx); - itti_send_msg_to_task (TASK_NGAP, GNB_MODULE_ID_TO_INSTANCE(gnb_id), msg_p); } } - LOG_I(GNB_APP,"[gNB %d] gNB_app_register for instance %d\n", gnb_id, GNB_MODULE_ID_TO_INSTANCE(gnb_id)); - register_gnb_pending++; } @@ -105,7 +97,6 @@ uint32_t gNB_app_register_x2(uint32_t gnb_id_start, uint32_t gnb_id_end) { for (gnb_id = gnb_id_start; (gnb_id < gnb_id_end) ; gnb_id++) { { msg_p = itti_alloc_new_message (TASK_GNB_APP, 0, X2AP_REGISTER_ENB_REQ); - LOG_I(X2AP, "GNB_ID: %d \n", gnb_id); RCconfig_NR_X2(msg_p, gnb_id); itti_send_msg_to_task (TASK_X2AP, ENB_MODULE_ID_TO_INSTANCE(gnb_id), msg_p); register_gnb_x2_pending++; diff --git a/openair2/GNB_APP/gnb_config.c b/openair2/GNB_APP/gnb_config.c index 73e0481a4b..08e4d97a31 100644 --- a/openair2/GNB_APP/gnb_config.c +++ b/openair2/GNB_APP/gnb_config.c @@ -863,7 +863,7 @@ void RCconfig_NR_L1(void) int XP = *GNBParamList.paramarray[0][GNB_PDSCH_ANTENNAPORTS_XP_IDX].iptr; char *ulprbbl = *GNBParamList.paramarray[0][GNB_ULPRBBLACKLIST_IDX].strptr; if (ulprbbl) - LOG_I(NR_PHY, "PRB blacklist %s\n", ulprbbl); + LOG_D(NR_PHY, "PRB blacklist %s\n", ulprbbl); char *save = NULL; char *pt = strtok_r(ulprbbl, ",", &save); int prbbl[275]; @@ -874,13 +874,13 @@ void RCconfig_NR_L1(void) const int rb = atoi(pt); AssertFatal(rb < 275, "RB %d out of bounds (max 275)\n", rb); prbbl[rb] = 0x3FFF; // all symbols taken - LOG_I(NR_PHY, "Blacklisting prb %d\n", atoi(pt)); + LOG_D(NR_PHY, "Blacklisting prb %d\n", atoi(pt)); pt = strtok_r(NULL, ",", &save); num_prbbl++; } RC.gNB[j]->num_ulprbbl = num_prbbl; - LOG_I(NR_PHY, "Copying %d blacklisted PRB to L1 context\n", num_prbbl); + LOG_D(NR_PHY, "Copying %d blacklisted PRB to L1 context\n", num_prbbl); memcpy(RC.gNB[j]->ulprbbl, prbbl, 275 * sizeof(int)); RC.gNB[j]->ap_N1 = N1; @@ -897,7 +897,6 @@ void RCconfig_NR_L1(void) for (j = 0; j < RC.nb_nr_L1_inst; j++) { if (RC.gNB[j] == NULL) { RC.gNB[j] = (PHY_VARS_gNB *)malloc(sizeof(PHY_VARS_gNB)); - LOG_I(NR_PHY, "RC.gNB[%d] = %p\n", j, RC.gNB[j]); memset(RC.gNB[j], 0, sizeof(PHY_VARS_gNB)); RC.gNB[j]->Mod_id = j; } @@ -934,9 +933,15 @@ void RCconfig_NR_L1(void) RC.nb_nr_CC = (int *)malloc((1 + RC.nb_nr_inst) * sizeof(int)); RC.nb_nr_CC[0] = 1; - LOG_I(PHY, "%s() NFAPI PNF mode - RC.nb_nr_inst=1 this is because phy_init_RU() uses that to index and not RC.num_gNB - why the 2 similar variables?\n", __FUNCTION__); - LOG_I(PHY, "%s() NFAPI PNF mode - RC.nb_nr_CC[0]=%d for init_gNB_afterRU()\n", __FUNCTION__, RC.nb_nr_CC[0]); - LOG_I(PHY, "%s() NFAPI PNF mode - RC.nb_nr_macrlc_inst:%d because used by mac_top_init_gNB()\n", __FUNCTION__, RC.nb_nr_macrlc_inst); + LOG_D(PHY, + "%s() NFAPI PNF mode - RC.nb_nr_inst=1 this is because phy_init_RU() uses that to index and not RC.num_gNB - why the " + "2 similar variables?\n", + __FUNCTION__); + LOG_D(PHY, "%s() NFAPI PNF mode - RC.nb_nr_CC[0]=%d for init_gNB_afterRU()\n", __FUNCTION__, RC.nb_nr_CC[0]); + LOG_D(PHY, + "%s() NFAPI PNF mode - RC.nb_nr_macrlc_inst:%d because used by mac_top_init_gNB()\n", + __FUNCTION__, + RC.nb_nr_macrlc_inst); configure_nr_nfapi_pnf(RC.gNB[j]->eth_params_n.remote_addr, RC.gNB[j]->eth_params_n.remote_portc, @@ -946,10 +951,9 @@ void RCconfig_NR_L1(void) } else { // other midhaul } } // for (j = 0; j < RC.nb_nr_L1_inst; j++) - printf("Initializing northbound interface for L1\n"); l1_north_init_gNB(); } else { - LOG_I(PHY, "No " CONFIG_STRING_L1_LIST " configuration found"); + LOG_E(PHY, "No " CONFIG_STRING_L1_LIST " configuration found"); // need to create some structures for VNF @@ -958,7 +962,6 @@ void RCconfig_NR_L1(void) if (RC.gNB[j] == NULL) { RC.gNB[j] = (PHY_VARS_gNB *)malloc(sizeof(PHY_VARS_gNB)); memset((void *)RC.gNB[j], 0, sizeof(PHY_VARS_gNB)); - LOG_I(PHY, "RC.gNB[%d] = %p\n", j, RC.gNB[j]); RC.gNB[j]->Mod_id = j; } } @@ -1422,7 +1425,6 @@ void RCconfig_nr_macrlc(configmodule_interface_t *cfg) } else if (strcmp(*(MacRLC_ParamList.paramarray[j][MACRLC_TRANSPORT_N_PREFERENCE_IDX].strptr), "f1") == 0 || strcmp(*(MacRLC_ParamList.paramarray[j][MACRLC_TRANSPORT_N_PREFERENCE_IDX].strptr), "cudu") == 0) { - printf("Configuring F1 interfaces for MACRLC\n"); char **f1caddr = MacRLC_ParamList.paramarray[j][MACRLC_LOCAL_N_ADDRESS_IDX].strptr; RC.nrmac[j]->eth_params_n.my_addr = strdup(*f1caddr); char **f1uaddr = MacRLC_ParamList.paramarray[j][MACRLC_LOCAL_N_ADDRESS_F1U_IDX].strptr; @@ -1447,16 +1449,14 @@ void RCconfig_nr_macrlc(configmodule_interface_t *cfg) RC.nrmac[j]->eth_params_s.remote_portd = *(MacRLC_ParamList.paramarray[j][MACRLC_REMOTE_S_PORTD_IDX].iptr); RC.nrmac[j]->eth_params_s.transp_preference = ETH_UDP_MODE; - printf("**************** vnf_port:%d\n", RC.nrmac[j]->eth_params_s.my_portc); configure_nr_nfapi_vnf( RC.nrmac[j]->eth_params_s.my_addr, RC.nrmac[j]->eth_params_s.my_portc, RC.nrmac[j]->eth_params_s.remote_addr, RC.nrmac[j]->eth_params_s.remote_portd, RC.nrmac[j]->eth_params_s.my_portd); - printf("**************** RETURNED FROM configure_nfapi_vnf() vnf_port:%d\n", RC.nrmac[j]->eth_params_s.my_portc); } else if(strcmp(*(MacRLC_ParamList.paramarray[j][MACRLC_TRANSPORT_S_PREFERENCE_IDX].strptr), "aerial") == 0){ #ifdef ENABLE_AERIAL RC.nrmac[j]->nvipc_params_s.nvipc_shm_prefix = strdup(*(MacRLC_ParamList.paramarray[j][MACRLC_TRANSPORT_S_SHM_PREFIX].strptr)); RC.nrmac[j]->nvipc_params_s.nvipc_poll_core = *(MacRLC_ParamList.paramarray[j][MACRLC_TRANSPORT_S_POLL_CORE].i8ptr); - printf("Configuring VNF for Aerial connection with prefix %s\n", RC.nrmac[j]->eth_params_s.local_if_name); + LOG_I(GNB_APP, "Configuring VNF for Aerial connection with prefix %s\n", RC.nrmac[j]->eth_params_s.local_if_name); aerial_configure_nr_fapi_vnf(); #endif } else { // other midhaul @@ -1839,7 +1839,7 @@ void RCconfig_NRRRC(gNB_RRC_INST *rrc) sprintf(aprefix, "%s.[%i]", GNB_CONFIG_STRING_GNB_LIST, 0); - printf("NRRRC %d: Southbound Transport %s\n", i, *(GNBParamList.paramarray[i][GNB_TRANSPORT_S_PREFERENCE_IDX].strptr)); + LOG_D(GNB_APP, "NRRRC %d: Southbound Transport %s\n", i, *(GNBParamList.paramarray[i][GNB_TRANSPORT_S_PREFERENCE_IDX].strptr)); rrc->node_type = get_node_type(); rrc->node_id = gnb_id; @@ -2158,8 +2158,6 @@ void NRRCConfig(void) { /* get global parameters, defined outside any section in the config file */ - LOG_I(GNB_APP, "Getting GNBSParams\n"); - config_get(config_get_if(), GNBSParams, sizeofArray(GNBSParams), NULL); RC.nb_nr_inst = GNBSParams[GNB_ACTIVE_GNBS_IDX].numelt; diff --git a/openair2/LAYER2/NR_MAC_gNB/config.c b/openair2/LAYER2/NR_MAC_gNB/config.c index ea4fbed192..7baca618d1 100644 --- a/openair2/LAYER2/NR_MAC_gNB/config.c +++ b/openair2/LAYER2/NR_MAC_gNB/config.c @@ -288,7 +288,6 @@ static void config_common(gNB_MAC_INST *nrmac, cfg->carrier_config.dl_bandwidth.value = get_supported_bw_mhz(frequency_range, bw_index); cfg->carrier_config.dl_bandwidth.tl.tag = NFAPI_NR_CONFIG_DL_BANDWIDTH_TAG; // temporary cfg->num_tlv++; - LOG_I(NR_MAC, "DL_Bandwidth:%d\n", cfg->carrier_config.dl_bandwidth.value); cfg->carrier_config.dl_frequency.value = from_nrarfcn(*frequencyInfoDL->frequencyBandList.list.array[0], *scc->ssbSubcarrierSpacing, @@ -318,7 +317,6 @@ static void config_common(gNB_MAC_INST *nrmac, cfg->carrier_config.uplink_bandwidth.value = get_supported_bw_mhz(frequency_range, bw_index); cfg->carrier_config.uplink_bandwidth.tl.tag = NFAPI_NR_CONFIG_UPLINK_BANDWIDTH_TAG; // temporary cfg->num_tlv++; - LOG_I(NR_MAC, "DL_Bandwidth:%d\n", cfg->carrier_config.uplink_bandwidth.value); int UL_pointA; if (frequencyInfoUL->absoluteFrequencyPointA == NULL) @@ -496,7 +494,7 @@ static void config_common(gNB_MAC_INST *nrmac, nrmac->ssb_SubcarrierOffset = cfg->ssb_table.ssb_subcarrier_offset.value; nrmac->ssb_OffsetPointA = cfg->ssb_table.ssb_offset_point_a.value; - LOG_I(NR_MAC, + LOG_D(NR_MAC, "ssb_OffsetPointA %d, ssb_SubcarrierOffset %d\n", cfg->ssb_table.ssb_offset_point_a.value, cfg->ssb_table.ssb_subcarrier_offset.value); @@ -582,7 +580,7 @@ static void config_common(gNB_MAC_INST *nrmac, __FUNCTION__); cfg->tdd_table.tdd_period.value = *scc->tdd_UL_DL_ConfigurationCommon->pattern1.ext1->dl_UL_TransmissionPeriodicity_v1530; } - LOG_I(NR_MAC, "Setting TDD configuration period to %d\n", cfg->tdd_table.tdd_period.value); + LOG_D(NR_MAC, "Setting TDD configuration period to %d\n", cfg->tdd_table.tdd_period.value); int periods_per_frame = set_tdd_config_nr(cfg, frequencyInfoUL->scs_SpecificCarrierList.list.array[0]->subcarrierSpacing, scc->tdd_UL_DL_ConfigurationCommon->pattern1.nrofDownlinkSlots, @@ -675,7 +673,7 @@ void nr_mac_config_scc(gNB_MAC_INST *nrmac, NR_ServingCellConfigCommon_t *scc, c initialize_beam_information(&nrmac->beam_info, *scc->ssbSubcarrierSpacing, n); - LOG_I(NR_MAC, "Configuring common parameters from NR ServingCellConfig\n"); + LOG_D(NR_MAC, "Configuring common parameters from NR ServingCellConfig\n"); config_common(nrmac, config, scc); fapi_beam_index_allocation(scc, nrmac); diff --git a/openair2/LAYER2/NR_MAC_gNB/gNB_scheduler_RA.c b/openair2/LAYER2/NR_MAC_gNB/gNB_scheduler_RA.c index 3e738db42a..9dd76099d9 100644 --- a/openair2/LAYER2/NR_MAC_gNB/gNB_scheduler_RA.c +++ b/openair2/LAYER2/NR_MAC_gNB/gNB_scheduler_RA.c @@ -728,7 +728,7 @@ void nr_initiate_ra_proc(module_id_t module_idP, } int index = ra - cc->ra; - LOG_I(NR_MAC, "%d.%d UE RA-RNTI %04x TC-RNTI %04x: Activating RA process index %d\n", frameP, slotP, ra->RA_rnti, ra->rnti, index); + LOG_A(NR_MAC, "%d.%d UE RA-RNTI %04x TC-RNTI %04x: Activating RA process index %d\n", frameP, slotP, ra->RA_rnti, ra->rnti, index); // Configure RA BWP configure_UE_BWP(nr_mac, scc, NULL, ra, NULL, -1, -1); @@ -1692,6 +1692,8 @@ static void nr_generate_Msg2(module_id_t module_idP, ra->Msg3_frame, ra->Msg3_slot); + LOG_A(NR_MAC, "%d.%d Send RAR to RA-RNTI %04x\n", frameP, slotP, ra->RA_rnti); + T(T_GNB_MAC_DL_RAR_PDU_WITH_DATA, T_INT(module_idP), T_INT(CC_id), diff --git a/openair2/LAYER2/NR_MAC_gNB/mac_rrc_dl_handler.c b/openair2/LAYER2/NR_MAC_gNB/mac_rrc_dl_handler.c index 63e7ff9d99..1faee06a39 100644 --- a/openair2/LAYER2/NR_MAC_gNB/mac_rrc_dl_handler.c +++ b/openair2/LAYER2/NR_MAC_gNB/mac_rrc_dl_handler.c @@ -823,7 +823,7 @@ void dl_rrc_message_transfer(const f1ap_dl_rrc_message_t *dl_rrc) pthread_mutex_unlock(&mac->sched_lock); if (!du_exists_f1_ue_data(dl_rrc->gNB_DU_ue_id)) { - LOG_I(NR_MAC, "No CU UE ID stored for UE RNTI %04x, adding CU UE ID %d\n", dl_rrc->gNB_DU_ue_id, dl_rrc->gNB_CU_ue_id); + LOG_D(NR_MAC, "No CU UE ID stored for UE RNTI %04x, adding CU UE ID %d\n", dl_rrc->gNB_DU_ue_id, dl_rrc->gNB_CU_ue_id); f1_ue_data_t new_ue_data = {.secondary_ue = dl_rrc->gNB_CU_ue_id}; du_add_f1_ue_data(dl_rrc->gNB_DU_ue_id, &new_ue_data); } diff --git a/openair2/LAYER2/NR_MAC_gNB/main.c b/openair2/LAYER2/NR_MAC_gNB/main.c index 1407a2cbb3..a663ed522c 100644 --- a/openair2/LAYER2/NR_MAC_gNB/main.c +++ b/openair2/LAYER2/NR_MAC_gNB/main.c @@ -217,8 +217,6 @@ void mac_top_init_gNB(ngran_node_t node_type, AssertFatal(RC.nb_nr_macrlc_inst == 1, "what is the point of calling %s() if you don't need exactly one MAC?\n", __func__); - LOG_I(MAC, "[MAIN] Init function start:nb_nr_macrlc_inst=%d\n",RC.nb_nr_macrlc_inst); - if (RC.nb_nr_macrlc_inst > 0) { RC.nrmac = (gNB_MAC_INST **) malloc16(RC.nb_nr_macrlc_inst *sizeof(gNB_MAC_INST *)); diff --git a/openair2/NR_PHY_INTERFACE/NR_IF_Module.c b/openair2/NR_PHY_INTERFACE/NR_IF_Module.c index 2e4687a352..dfd50c91cf 100644 --- a/openair2/NR_PHY_INTERFACE/NR_IF_Module.c +++ b/openair2/NR_PHY_INTERFACE/NR_IF_Module.c @@ -497,13 +497,13 @@ void NR_UL_indication(NR_UL_IND_t *UL_info) { NR_IF_Module_t *NR_IF_Module_init(int Mod_id) { AssertFatal(Mod_id %d\n",Mod_id,MAX_IF_MODULES); - LOG_I(PHY,"Installing callbacks for IF_Module - UL_indication\n"); + LOG_D(PHY, "Installing callbacks for IF_Module - UL_indication\n"); if (nr_if_inst[Mod_id]==NULL) { nr_if_inst[Mod_id] = (NR_IF_Module_t*)malloc(sizeof(NR_IF_Module_t)); memset((void*)nr_if_inst[Mod_id],0,sizeof(NR_IF_Module_t)); - LOG_I(MAC,"Allocating shared L1/L2 interface structure for instance %d @ %p\n",Mod_id,nr_if_inst[Mod_id]); + LOG_D(MAC, "Allocating shared L1/L2 interface structure for instance %d @ %p\n", Mod_id, nr_if_inst[Mod_id]); nr_if_inst[Mod_id]->CC_mask=0; nr_if_inst[Mod_id]->NR_UL_indication = NR_UL_indication; diff --git a/openair2/RRC/NR/nr_rrc_config.c b/openair2/RRC/NR/nr_rrc_config.c index 2f42652338..cae49d3f53 100644 --- a/openair2/RRC/NR/nr_rrc_config.c +++ b/openair2/RRC/NR/nr_rrc_config.c @@ -1990,7 +1990,8 @@ NR_MeasurementTimingConfiguration_t *get_new_MeasurementTimingConfiguration(cons int encode_MeasurementTimingConfiguration(const struct NR_MeasurementTimingConfiguration *mtc, uint8_t *buf, int buf_len) { DevAssert(mtc != NULL); - xer_fprint(stdout, &asn_DEF_NR_MeasurementTimingConfiguration, mtc); + if (LOG_DEBUGFLAG(DEBUG_ASN1)) + xer_fprint(stdout, &asn_DEF_NR_MeasurementTimingConfiguration, mtc); asn_enc_rval_t enc_rval = uper_encode_to_buffer(&asn_DEF_NR_MeasurementTimingConfiguration, NULL, mtc, buf, buf_len); AssertFatal(enc_rval.encoded > 0, "ASN1 message encoding failed (%s, %lu)!\n", enc_rval.failed_type->name, enc_rval.encoded); return (enc_rval.encoded + 7) / 8; diff --git a/openair2/RRC/NR/nr_rrc_defs.h b/openair2/RRC/NR/nr_rrc_defs.h index 14d08e9c45..7650718e66 100644 --- a/openair2/RRC/NR/nr_rrc_defs.h +++ b/openair2/RRC/NR/nr_rrc_defs.h @@ -69,12 +69,6 @@ #include "intertask_interface.h" -#define PROTOCOL_NR_RRC_CTXT_UE_FMT PROTOCOL_CTXT_FMT -#define PROTOCOL_NR_RRC_CTXT_UE_ARGS(CTXT_Pp) PROTOCOL_NR_CTXT_ARGS(CTXT_Pp) - -#define PROTOCOL_NR_RRC_CTXT_FMT PROTOCOL_CTXT_FMT -#define PROTOCOL_NR_RRC_CTXT_ARGS(CTXT_Pp) PROTOCOL_NR_CTXT_ARGS(CTXT_Pp) - // 3GPP TS 38.331 Section 12 Table 12.1-1: UE performance requirements for RRC procedures for UEs #define NR_RRC_SETUP_DELAY_MS 10 #define NR_RRC_RECONFIGURATION_DELAY_MS 10 @@ -243,6 +237,7 @@ typedef struct gNB_RRC_UE_s { uint64_t ng_5G_S_TMSI_Part1; NR_EstablishmentCause_t establishment_cause; + uint64_t nr_cellid; uint32_t rrc_ue_id; uint64_t amf_ue_ngap_id; nr_rrc_guami_t ue_guami; @@ -426,6 +421,13 @@ typedef struct gNB_RRC_INST_s { } gNB_RRC_INST; +#define UE_LOG_FMT "(cellID %lx, UE ID %d RNTI %04x)" +#define UE_LOG_ARGS(ue_context) (ue_context)->nr_cellid, (ue_context)->rrc_ue_id, (ue_context)->rnti + +#define LOG_UE_DL_EVENT(ue_context, fmt, ...) LOG_A(NR_RRC, "[DL] " UE_LOG_FMT " " fmt, UE_LOG_ARGS(ue_context) __VA_OPT__(,) __VA_ARGS__) +#define LOG_UE_EVENT(ue_context, fmt, ...) LOG_A(NR_RRC, "[--] " UE_LOG_FMT " " fmt, UE_LOG_ARGS(ue_context) __VA_OPT__(,) __VA_ARGS__) +#define LOG_UE_UL_EVENT(ue_context, fmt, ...) LOG_A(NR_RRC, "[UL] " UE_LOG_FMT " " fmt, UE_LOG_ARGS(ue_context) __VA_OPT__(,) __VA_ARGS__) + #include "nr_rrc_proto.h" //should be put here otherwise compilation error #endif diff --git a/openair2/RRC/NR/rrc_gNB.c b/openair2/RRC/NR/rrc_gNB.c index 1ff2747ec4..ce42a7be3f 100644 --- a/openair2/RRC/NR/rrc_gNB.c +++ b/openair2/RRC/NR/rrc_gNB.c @@ -211,7 +211,7 @@ static void init_NR_SI(gNB_RRC_INST *rrc) rrc->carrier.SIB23 = (uint8_t *) malloc16(100); AssertFatal(rrc->carrier.SIB23 != NULL, "cannot allocate memory for SIB"); rrc->carrier.sizeof_SIB23 = do_SIB23_NR(&rrc->carrier); - LOG_I(NR_RRC,"do_SIB23_NR, size %d \n ", rrc->carrier.sizeof_SIB23); + LOG_I(NR_RRC, "do_SIB23_NR, size %d\n", rrc->carrier.sizeof_SIB23); AssertFatal(rrc->carrier.sizeof_SIB23 != 255,"FATAL, RC.nrrrc[mod].carrier[CC_id].sizeof_SIB23 == 255"); } @@ -291,7 +291,7 @@ static void rrc_gNB_process_AdditionRequestInformation(const module_id_t gnb_mod AssertFatal(cg_configinfo->criticalExtensions.choice.c1->present == NR_CG_ConfigInfo__criticalExtensions__c1_PR_cg_ConfigInfo, "ueCapabilityInformation not present\n"); parse_CG_ConfigInfo(rrc,cg_configinfo,m); - LOG_A(NR_RRC, "Successfully parsed CG_ConfigInfo of size %zu bits. (%zu bytes)\n", + LOG_I(NR_RRC, "Successfully parsed CG_ConfigInfo of size %zu bits. (%zu bytes)\n", dec_rval.consumed, (dec_rval.consumed +7/8)); } @@ -400,7 +400,7 @@ static void rrc_gNB_generate_RRCSetup(instance_t instance, int masterCellGroup_len) //----------------------------------------------------------------------------- { - LOG_I(NR_RRC, "rrc_gNB_generate_RRCSetup for RNTI %04x\n", rnti); + LOG_UE_DL_EVENT(&ue_context_pP->ue_context, "Send RRC Setup\n"); gNB_RRC_UE_t *ue_p = &ue_context_pP->ue_context; gNB_RRC_INST *rrc = RC.nrrrc[instance]; @@ -430,9 +430,9 @@ static void rrc_gNB_generate_RRCSetup(instance_t instance, static void rrc_gNB_generate_RRCReject(module_id_t module_id, rrc_gNB_ue_context_t *const ue_context_pP) //----------------------------------------------------------------------------- { - LOG_I(NR_RRC, "rrc_gNB_generate_RRCReject \n"); gNB_RRC_INST *rrc = RC.nrrrc[module_id]; gNB_RRC_UE_t *ue_p = &ue_context_pP->ue_context; + LOG_A(NR_RRC, "Send RRCReject to RNTI %04x\n", ue_p->rnti); unsigned char buf[1024]; int size = do_RRCReject(buf); @@ -466,7 +466,6 @@ static void rrc_gNB_generate_RRCReject(module_id_t module_id, rrc_gNB_ue_context static void rrc_gNB_process_RRCSetupComplete(gNB_RRC_INST *rrc, gNB_RRC_UE_t *UE, NR_RRCSetupComplete_IEs_t *rrcSetupComplete) //----------------------------------------------------------------------------- { - LOG_A(NR_RRC, "UE %d Processing NR_RRCSetupComplete from UE\n", UE->rrc_ue_id); UE->Srb[1].Active = 1; UE->Srb[2].Active = 0; @@ -568,7 +567,7 @@ static void rrc_gNB_generate_dedicatedRRCReconfiguration(gNB_RRC_INST *rrc, gNB_ int size = rrc_gNB_encode_RRCReconfiguration(rrc, ue_p, xid, dedicatedNAS_MessageList, buffer, sizeof(buffer), false); DevAssert(size > 0 && size <= sizeof(buffer)); - LOG_I(NR_RRC, "UE %d: Generate RRCReconfiguration (bytes %d, xid %d)\n", ue_p->rrc_ue_id, size, xid); + LOG_UE_DL_EVENT(ue_p, "Generate RRCReconfiguration (bytes %d, xid %d)\n", size, xid); nr_rrc_transfer_protected_rrc_message(rrc, ue_p, DCCH, buffer, size); } @@ -825,7 +824,7 @@ static void rrc_gNB_generate_RRCReestablishment(rrc_gNB_ue_context_t *ue_context uint32_t ssb_arfcn = get_ssb_arfcn(du); int size = do_RRCReestablishment(ue_context_pP, buffer, NR_RRC_BUF_SIZE, xid, cell_info->nr_pci, ssb_arfcn); - LOG_I(NR_RRC, "[RAPROC] UE %04x Logical Channel DL-DCCH, Generating NR_RRCReestablishment (bytes %d)\n", ue_p->rnti, size); + LOG_A(NR_RRC, "Send RRCReestablishment [%d bytes] to RNTI %04x\n", size, ue_p->rnti); /* Ciphering and Integrity according to TS 33.501 */ nr_pdcp_entity_security_keys_and_algos_t security_parameters; @@ -1053,6 +1052,7 @@ static void rrc_handle_RRCSetupRequest(gNB_RRC_INST *rrc, gNB_RRC_UE_t *UE = &ue_context_p->ue_context; UE = &ue_context_p->ue_context; UE->establishment_cause = rrcSetupRequest->establishmentCause; + UE->nr_cellid = msg->nr_cellid; UE->masterCellGroup = cellGroupConfig; activate_srb(UE, 1); rrc_gNB_generate_RRCSetup(0, msg->crnti, ue_context_p, msg->du2cu_rrc_container, msg->du2cu_rrc_container_length); @@ -1202,6 +1202,7 @@ static void rrc_handle_RRCReestablishmentRequest(gNB_RRC_INST *rrc, // update with new RNTI, and update secondary UE association UE->rnti = msg->crnti; + UE->nr_cellid = msg->nr_cellid; f1_ue_data_t ue_data = cu_get_f1_ue_data(UE->rrc_ue_id); ue_data.secondary_ue = msg->gNB_DU_ue_id; cu_remove_f1_ue_data(UE->rrc_ue_id); @@ -1399,6 +1400,8 @@ void rrc_forward_ue_nas_message(gNB_RRC_INST *rrc, gNB_RRC_UE_t *UE) if (UE->nas_pdu.buffer == NULL || UE->nas_pdu.length == 0) return; // no problem: the UE will re-request a NAS PDU + LOG_UE_DL_EVENT(UE, "Send DL Information Transfer [%d bytes]\n", UE->nas_pdu.length); + uint8_t buffer[4096]; unsigned int xid = rrc_gNB_get_next_transaction_identifier(rrc->module_id); uint32_t length = do_NR_DLInformationTransfer(buffer, sizeof(buffer), xid, UE->nas_pdu.length, UE->nas_pdu.buffer); @@ -1420,7 +1423,6 @@ static void handle_ueCapabilityInformation(gNB_RRC_INST *rrc, gNB_RRC_UE_t *UE, return; } - LOG_I(NR_RRC, "UE %d: received UE capabilities (xid %d)\n", UE->rrc_ue_id, xid); int eutra_index = -1; if (ue_cap_info->criticalExtensions.present == NR_UECapabilityInformation__criticalExtensions_PR_ueCapabilityInformation) { @@ -1437,6 +1439,7 @@ static void handle_ueCapabilityInformation(gNB_RRC_INST *rrc, gNB_RRC_UE_t *UE, LOG_E(RRC, "could not encode UE-CapabilityRAT-ContainerList, abort handling capabilities\n"); return; } + LOG_UE_UL_EVENT(UE, "Received UE capabilities\n"); for (int i = 0; i < ue_CapabilityRAT_ContainerList->list.count; i++) { const NR_UE_CapabilityRAT_Container_t *ue_cap_container = ue_CapabilityRAT_ContainerList->list.array[i]; @@ -1591,7 +1594,6 @@ static void handle_rrcReconfigurationComplete(gNB_RRC_INST *rrc, gNB_RRC_UE_t *U { uint8_t xid = reconfig_complete->rrc_TransactionIdentifier; UE->ue_reconfiguration_counter++; - LOG_I(NR_RRC, "UE %d: Receive RRC Reconfiguration Complete message (xid %d)\n", UE->rrc_ue_id, xid); switch (UE->xids[xid]) { case RRC_PDUSESSION_RELEASE: { @@ -1692,10 +1694,12 @@ static int rrc_gNB_decode_dcch(gNB_RRC_INST *rrc, const f1ap_ul_rrc_message_t *m break; case NR_UL_DCCH_MessageType__c1_PR_rrcReconfigurationComplete: + LOG_UE_UL_EVENT(UE, "Received RRCReconfigurationComplete\n"); handle_rrcReconfigurationComplete(rrc, UE, ul_dcch_msg->message.choice.c1->choice.rrcReconfigurationComplete); break; case NR_UL_DCCH_MessageType__c1_PR_rrcSetupComplete: + LOG_UE_UL_EVENT(UE, "Received RRCSetupComplete (RRC_CONNECTED reached)\n"); handle_rrcSetupComplete(rrc, UE, ul_dcch_msg->message.choice.c1->choice.rrcSetupComplete); break; @@ -1704,10 +1708,12 @@ static int rrc_gNB_decode_dcch(gNB_RRC_INST *rrc, const f1ap_ul_rrc_message_t *m break; case NR_UL_DCCH_MessageType__c1_PR_ulInformationTransfer: + LOG_UE_UL_EVENT(UE, "Received RRC UL Information Transfer [%d bytes]\n", msg->rrc_container_length); rrc_gNB_send_NGAP_UPLINK_NAS(rrc, UE, ul_dcch_msg); break; case NR_UL_DCCH_MessageType__c1_PR_securityModeComplete: + LOG_UE_UL_EVENT(UE, "Received Security Mode Complete\n"); /* configure ciphering */ nr_rrc_pdcp_config_security(UE, true); UE->as_security_active = true; @@ -1740,6 +1746,7 @@ static int rrc_gNB_decode_dcch(gNB_RRC_INST *rrc, const f1ap_ul_rrc_message_t *m break; case NR_UL_DCCH_MessageType__c1_PR_rrcReestablishmentComplete: + LOG_UE_UL_EVENT(UE, "Received RRCReestablishmentComplete\n"); handle_rrcReestablishmentComplete(rrc, UE, ul_dcch_msg->message.choice.c1->choice.rrcReestablishmentComplete); break; @@ -2107,6 +2114,7 @@ static void rrc_CU_process_ue_context_modification_response(MessageDef *msg_p, i nr_ho_source_cu_t *source_ctx = UE->ho_context->source; DevAssert(source_ctx->old_rnti == UE->rnti); UE->rnti = target_ctx->new_rnti; + UE->nr_cellid = target_ctx->du->setup_req->cell[0].info.nr_cellid; } } @@ -2668,8 +2676,7 @@ void rrc_gNB_generate_RRCRelease(gNB_RRC_INST *rrc, gNB_RRC_UE_t *UE) uint8_t buffer[NR_RRC_BUF_SIZE] = {0}; int size = do_NR_RRCRelease(buffer, NR_RRC_BUF_SIZE, rrc_gNB_get_next_transaction_identifier(rrc->module_id)); - LOG_I(NR_RRC, "UE %d: Generate RRCRelease (bytes %d)\n", UE->rrc_ue_id, size); - + LOG_UE_DL_EVENT(UE, "Send RRC Release\n"); f1_ue_data_t ue_data = cu_get_f1_ue_data(UE->rrc_ue_id); RETURN_IF_INVALID_ASSOC_ID(ue_data.du_assoc_id); f1ap_ue_context_release_cmd_t ue_context_release_cmd = { diff --git a/openair2/RRC/NR/rrc_gNB_NGAP.c b/openair2/RRC/NR/rrc_gNB_NGAP.c index 8c45728523..6a35f61b3f 100644 --- a/openair2/RRC/NR/rrc_gNB_NGAP.c +++ b/openair2/RRC/NR/rrc_gNB_NGAP.c @@ -615,11 +615,10 @@ static void set_UE_security_algos(const gNB_RRC_INST *rrc, gNB_RRC_UE_t *UE, con UE->ciphering_algorithm = cipheringAlgorithm; UE->integrity_algorithm = integrityProtAlgorithm; - LOG_I(NR_RRC, - "[UE %d] Selected security algorithms: ciphering %lx, integrity %x\n", - UE->rrc_ue_id, - cipheringAlgorithm, - integrityProtAlgorithm); + LOG_UE_EVENT(UE, + "Selected security algorithms: ciphering %lx, integrity %x\n", + cipheringAlgorithm, + integrityProtAlgorithm); } //------------------------------------------------------------------------------ @@ -1143,7 +1142,6 @@ void rrc_gNB_send_NGAP_UE_CONTEXT_RELEASE_COMPLETE(instance_t instance, NGAP_UE_CONTEXT_RELEASE_COMPLETE(msg).num_pdu_sessions = num_pdu; for (int i = 0; i < num_pdu; ++i) NGAP_UE_CONTEXT_RELEASE_COMPLETE(msg).pdu_session_id[i] = pdu_session_id[i]; - LOG_W(RRC, "trigger release with %d pdu\n", num_pdu); itti_send_msg_to_task(TASK_NGAP, instance, msg); } diff --git a/openair2/RRC/NR/rrc_gNB_UE_context.c b/openair2/RRC/NR/rrc_gNB_UE_context.c index 82c5d29116..15f644955d 100644 --- a/openair2/RRC/NR/rrc_gNB_UE_context.c +++ b/openair2/RRC/NR/rrc_gNB_UE_context.c @@ -142,11 +142,11 @@ void rrc_gNB_remove_ue_context(gNB_RRC_INST *rrc_instance_pP, rrc_gNB_ue_context return; } + LOG_UE_EVENT(&ue_context_pP->ue_context, "Remove UE context\n"); RB_REMOVE(rrc_nr_ue_tree_s, &rrc_instance_pP->rrc_ue_head, ue_context_pP); uid_linear_allocator_free(&rrc_instance_pP->uid_allocator, ue_context_pP->ue_context.rrc_ue_id - 1); cu_remove_f1_ue_data(ue_context_pP->ue_context.rrc_ue_id); rrc_gNB_free_mem_ue_context(ue_context_pP); - LOG_I(NR_RRC, "Removed UE context\n"); } //----------------------------------------------------------------------------- @@ -204,11 +204,11 @@ rrc_gNB_ue_context_t *rrc_gNB_create_ue_context(sctp_assoc_t assoc_id, cu_add_f1_ue_data(ue->rrc_ue_id, &ue_data); RB_INSERT(rrc_nr_ue_tree_s, &rrc_instance_pP->rrc_ue_head, ue_context_p); - LOG_I(NR_RRC, - "Created new UE context: CU UE ID %u DU UE ID %u (rnti: %04x, random ue id %lx)\n", - ue->rrc_ue_id, - du_ue_id, - ue->rnti, - ue->random_ue_identity); + LOG_UE_EVENT(ue, + "Create UE context: CU UE ID %u DU UE ID %u (rnti: %04x, random ue id %lx)\n", + ue->rrc_ue_id, + du_ue_id, + ue->rnti, + ue->random_ue_identity); return ue_context_p; } diff --git a/openair2/RRC/NR/rrc_gNB_cuup.c b/openair2/RRC/NR/rrc_gNB_cuup.c index d37a1f430b..729f5f28b4 100644 --- a/openair2/RRC/NR/rrc_gNB_cuup.c +++ b/openair2/RRC/NR/rrc_gNB_cuup.c @@ -46,10 +46,10 @@ static const nr_rrc_cuup_container_t *select_cuup_slice(const struct rrc_cuup_tr for (int s = 0; s < sr->plmn[p].supported_slices; ++s) { e1ap_nssai_t *nssai = &sr->plmn[p].slice[s]; if (nssai->sst == sst && nssai->sd == sd) { - LOG_A(RRC, "selecting CU-UP ID %ld based on exact NSSAI match (%d:0x%06x)\n", sr->gNB_cu_up_id, sst, sd); + LOG_UE_EVENT(ue, "selecting CU-UP ID %ld based on exact NSSAI match (%d:0x%06x)\n", sr->gNB_cu_up_id, sst, sd); return cuup; /* exact match */ } else if (nssai->sst == sst && second_best_match == NULL) { - LOG_I(RRC, "second best match: CU-UP ID %ld matches SST %d\n", sr->gNB_cu_up_id, sst); + LOG_UE_EVENT(ue, "second best match: CU-UP ID %ld matches SST %d\n", sr->gNB_cu_up_id, sst); second_best_match = cuup; /* only the SST matches -> "good enough" */ } } diff --git a/openair3/NGAP/ngap_gNB.c b/openair3/NGAP/ngap_gNB.c index 45183407a3..70f6bd5e49 100644 --- a/openair3/NGAP/ngap_gNB.c +++ b/openair3/NGAP/ngap_gNB.c @@ -254,6 +254,7 @@ void ngap_gNB_handle_sctp_association_resp(instance_t instance, sctp_new_associa ngap_amf_data_p->in_streams = sctp_new_association_resp->in_streams; ngap_amf_data_p->out_streams = sctp_new_association_resp->out_streams; /* Prepare new NG Setup Request */ + LOG_A(NGAP, "Send NGSetupRequest to AMF\n"); ngap_gNB_generate_ng_setup_request(instance_p, ngap_amf_data_p); } diff --git a/openair3/NGAP/ngap_gNB_handlers.c b/openair3/NGAP/ngap_gNB_handlers.c index de113b3100..59b2792602 100644 --- a/openair3/NGAP/ngap_gNB_handlers.c +++ b/openair3/NGAP/ngap_gNB_handlers.c @@ -87,6 +87,7 @@ void ngap_handle_ng_setup_message(ngap_gNB_amf_data_t *amf_desc_p, int sctp_shut } } } else { + LOG_A(NGAP, "Received NGSetupResponse from AMF\n"); /* Check that at least one setup message is pending */ DevCheck(amf_desc_p->ngap_gNB_instance->ngap_amf_pending_nb > 0, amf_desc_p->ngap_gNB_instance->instance, amf_desc_p->ngap_gNB_instance->ngap_amf_pending_nb, 0);