diff --git a/cmake_targets/CMakeLists.txt b/cmake_targets/CMakeLists.txt index 01928c8f53faf08cba994b5416ca1088a8eef446..795fe48eaee7c0e604ab2ed2969f638c95c4b86c 100644 --- a/cmake_targets/CMakeLists.txt +++ b/cmake_targets/CMakeLists.txt @@ -238,7 +238,7 @@ add_boolean_option(T_TRACER False "Activate the T tracer, a debugging add_boolean_option(UE_AUTOTEST_TRACE False "Activate UE autotest specific logs") add_boolean_option(UE_DEBUG_TRACE False "Activate UE debug trace") add_boolean_option(UE_TIMING_TRACE False "Activate UE timing trace") -add_boolean_option(UE_NO_LOG False "Deactivate all LOG_X") +add_boolean_option(DISABLE_LOG_X False "Deactivate all LOG_* macros") add_boolean_option(DEBUG_CONSOLE False "makes debugging easier, disables stdout/stderr buffering") diff --git a/cmake_targets/build_oai b/cmake_targets/build_oai index c97c02dca9011bc2ac5fc943d80dd32a040f826c..2640f5957b7824d660dc92b544e8b423641a7163 100755 --- a/cmake_targets/build_oai +++ b/cmake_targets/build_oai @@ -64,7 +64,7 @@ CMAKE_BUILD_TYPE="" UE_AUTOTEST_TRACE="False" UE_DEBUG_TRACE="False" UE_TIMING_TRACE="False" -UE_NO_LOG="False" +DISABLE_LOG_X="False" BUILD_ECLIPSE=0 CMAKE_CMD='cmake' trap handle_ctrl_c INT @@ -154,8 +154,8 @@ Options Enable traces for UE debugging --ue-timing Enable traces for timing ---ue-no-log - Disable all LOG_X +--disable-log + Disable all LOG_* macros --build-eclipse Build eclipse project files. Paths are auto corrected by fixprj.sh Usage (first build): @@ -333,10 +333,10 @@ function main() { UE_TIMING_TRACE="True" echo_info "Enabling UE timing trace" shift 1;; - --ue-no-log) - UE_NO_LOG="True" - echo_info "Disabling all LOG_X traces" - shift 1;; + --disable-log) + DISABLE_LOG_X="True" + echo_info "Disabling all LOG_* traces" + shift 1;; --uhd-images-dir) UHD_IMAGES_DIR=$2 echo_info "Downloading UHD images in the indicated location" @@ -527,7 +527,7 @@ function main() { echo "set (UE_AUTOTEST_TRACE $UE_AUTOTEST_TRACE)" >> $cmake_file echo "set (UE_DEBUG_TRACE $UE_DEBUG_TRACE)" >> $cmake_file echo "set (UE_TIMING_TRACE $UE_TIMING_TRACE)" >> $cmake_file - echo "set (UE_NO_LOG $UE_NO_LOG)" >> $cmake_file + echo "set (DISABLE_LOG_X $DISABLE_LOG_X)" >> $cmake_file if [ "$UE" = 1 -a "$NOS1" = "0" ] ; then echo_info "Compiling UE S1 build : enabling Linux and NETLINK" echo "set (LINUX True )" >> $cmake_file diff --git a/openair1/PHY/INIT/lte_parms.c b/openair1/PHY/INIT/lte_parms.c index 900b5edfc73ac7b5b4a4cbc4a365a2bf851cf9bb..730371dd616af8963d3d793152d18db11eaabcd6 100644 --- a/openair1/PHY/INIT/lte_parms.c +++ b/openair1/PHY/INIT/lte_parms.c @@ -44,7 +44,11 @@ int init_frame_parms(LTE_DL_FRAME_PARMS *frame_parms,uint8_t osf) uint8_t log2_osf; +#if DISABLE_LOG_X printf("Initializing frame parms for N_RB_DL %d, Ncp %d, osf %d\n",frame_parms->N_RB_DL,frame_parms->Ncp,osf); +#else + LOG_I(PHY,"Initializing frame parms for N_RB_DL %d, Ncp %d, osf %d\n",frame_parms->N_RB_DL,frame_parms->Ncp,osf); +#endif if (frame_parms->Ncp==EXTENDED) { frame_parms->nb_prefix_samples0=512; diff --git a/openair1/PHY/LTE_TRANSPORT/initial_sync.c b/openair1/PHY/LTE_TRANSPORT/initial_sync.c index 46680d8de87a3521b653236506fd0dbce80e52a6..7e5bf272dc1288964687574ce911b1bbc27afe26 100644 --- a/openair1/PHY/LTE_TRANSPORT/initial_sync.c +++ b/openair1/PHY/LTE_TRANSPORT/initial_sync.c @@ -466,13 +466,21 @@ int initial_sync(PHY_VARS_UE *ue, runmode_t mode) if( (abs(ue->common_vars.freq_offset) > 150) && (ret == 0) ) { ret=-1; +#if DISABLE_LOG_X printf("Ignore MIB with high freq offset [%d Hz] estimation \n",ue->common_vars.freq_offset); +#else + LOG_E(HW, "Ignore MIB with high freq offset [%d Hz] estimation \n",ue->common_vars.freq_offset); +#endif } if (ret==0) { // PBCH found so indicate sync to higher layers and configure frame parameters //#ifdef DEBUG_INITIAL_SYNCH +#if DISABLE_LOG_X printf("[UE%d] In synch, rx_offset %d samples\n",ue->Mod_id, ue->rx_offset); +#else + LOG_I(PHY, "[UE%d] In synch, rx_offset %d samples\n",ue->Mod_id, ue->rx_offset); +#endif //#endif if (ue->UE_scan_carrier == 0) { @@ -503,6 +511,7 @@ int initial_sync(PHY_VARS_UE *ue, runmode_t mode) } +#if DISABLE_LOG_X printf("[UE %d] Frame %d RRC Measurements => rssi %3.1f dBm (dig %3.1f dB, gain %d), N0 %d dBm, rsrp %3.1f dBm/RE, rsrq %3.1f dB\n",ue->Mod_id, ue->proc.proc_rxtx[0].frame_rx, 10*log10(ue->measurements.rssi)-ue->rx_total_gain_dB, @@ -511,9 +520,30 @@ int initial_sync(PHY_VARS_UE *ue, runmode_t mode) ue->measurements.n0_power_tot_dBm, 10*log10(ue->measurements.rsrp[0])-ue->rx_total_gain_dB, (10*log10(ue->measurements.rsrq[0]))); + + + printf("[UE %d] Frame %d MIB Information => %s, %s, NidCell %d, N_RB_DL %d, PHICH DURATION %d, PHICH RESOURCE %s, TX_ANT %d\n", + ue->Mod_id, + ue->proc.proc_rxtx[0].frame_rx, + duplex_string[ue->frame_parms.frame_type], + prefix_string[ue->frame_parms.Ncp], + ue->frame_parms.Nid_cell, + ue->frame_parms.N_RB_DL, + ue->frame_parms.phich_config_common.phich_duration, + phich_string[ue->frame_parms.phich_config_common.phich_resource], + ue->frame_parms.nb_antenna_ports_eNB); +#else + LOG_I(PHY, "[UE %d] Frame %d RRC Measurements => rssi %3.1f dBm (dig %3.1f dB, gain %d), N0 %d dBm, rsrp %3.1f dBm/RE, rsrq %3.1f dB\n",ue->Mod_id, + ue->proc.proc_rxtx[0].frame_rx, + 10*log10(ue->measurements.rssi)-ue->rx_total_gain_dB, + 10*log10(ue->measurements.rssi), + ue->rx_total_gain_dB, + ue->measurements.n0_power_tot_dBm, + 10*log10(ue->measurements.rsrp[0])-ue->rx_total_gain_dB, + (10*log10(ue->measurements.rsrq[0]))); - printf("[UE %d] Frame %d MIB Information => %s, %s, NidCell %d, N_RB_DL %d, PHICH DURATION %d, PHICH RESOURCE %s, TX_ANT %d\n", + LOG_I(PHY, "[UE %d] Frame %d MIB Information => %s, %s, NidCell %d, N_RB_DL %d, PHICH DURATION %d, PHICH RESOURCE %s, TX_ANT %d\n", ue->Mod_id, ue->proc.proc_rxtx[0].frame_rx, duplex_string[ue->frame_parms.frame_type], @@ -523,13 +553,22 @@ int initial_sync(PHY_VARS_UE *ue, runmode_t mode) ue->frame_parms.phich_config_common.phich_duration, phich_string[ue->frame_parms.phich_config_common.phich_resource], ue->frame_parms.nb_antenna_ports_eNB); +#endif #if defined(OAI_USRP) || defined(EXMIMO) || defined(OAI_BLADERF) || defined(OAI_LMSSDR) +# if DISABLE_LOG_X printf("[UE %d] Frame %d Measured Carrier Frequency %.0f Hz (offset %d Hz)\n", ue->Mod_id, ue->proc.proc_rxtx[0].frame_rx, openair0_cfg[0].rx_freq[0]-ue->common_vars.freq_offset, ue->common_vars.freq_offset); +# else + LOG_I(PHY, "[UE %d] Frame %d Measured Carrier Frequency %.0f Hz (offset %d Hz)\n", + ue->Mod_id, + ue->proc.proc_rxtx[0].frame_rx, + openair0_cfg[0].rx_freq[0]-ue->common_vars.freq_offset, + ue->common_vars.freq_offset); +# endif #endif } else { #ifdef DEBUG_INITIAL_SYNC diff --git a/openair1/SCHED/phy_procedures_lte_ue.c b/openair1/SCHED/phy_procedures_lte_ue.c index c94d7a45a37e3f22e023fc8d2b7b4ad14460b10b..389eb5a6943b7fa96a3d4e9f04c40ea43ab2e106 100644 --- a/openair1/SCHED/phy_procedures_lte_ue.c +++ b/openair1/SCHED/phy_procedures_lte_ue.c @@ -3886,10 +3886,18 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, #if UE_TIMING_TRACE stop_meas(&ue->dlsch_decoding_stats[subframe_rx&0x1]); +#if DISABLE_LOG_X printf(" --> Unscrambling for CW0 %5.3f\n", (ue->dlsch_unscrambling_stats.p_time)/(cpuf*1000.0)); printf("AbsSubframe %d.%d --> Turbo Decoding for CW0 %5.3f\n", frame_rx%1024, subframe_rx,(ue->dlsch_decoding_stats[subframe_rx&0x1].p_time)/(cpuf*1000.0)); +#else + LOG_D(PHY, " --> Unscrambling for CW0 %5.3f\n", + (ue->dlsch_unscrambling_stats.p_time)/(cpuf*1000.0)); + LOG_D(PHY, "AbsSubframe %d.%d --> Turbo Decoding for CW0 %5.3f\n", + frame_rx%1024, subframe_rx,(ue->dlsch_decoding_stats[subframe_rx&0x1].p_time)/(cpuf*1000.0)); +#endif + #endif if(is_cw1_active) @@ -3945,10 +3953,18 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, stop_meas(&ue->dlsch_decoding_stats[subframe_rx&0x1]); +#if DISABLE_LOG_X printf(" --> Unscrambling for CW1 %5.3f\n", (ue->dlsch_unscrambling_stats.p_time)/(cpuf*1000.0)); printf("AbsSubframe %d.%d --> Turbo Decoding for CW1 %5.3f\n", frame_rx%1024, subframe_rx,(ue->dlsch_decoding_stats[subframe_rx&0x1].p_time)/(cpuf*1000.0)); +#else + LOG_D(PHY, " --> Unscrambling for CW1 %5.3f\n", + (ue->dlsch_unscrambling_stats.p_time)/(cpuf*1000.0)); + LOG_D(PHY, "AbsSubframe %d.%d --> Turbo Decoding for CW1 %5.3f\n", + frame_rx%1024, subframe_rx,(ue->dlsch_decoding_stats[subframe_rx&0x1].p_time)/(cpuf*1000.0)); +#endif + #endif } @@ -4254,7 +4270,12 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin // first slot has been processed (FFTs + Channel Estimation, PCFICH/PHICH/PDCCH) #if UE_TIMING_TRACE stop_meas(&ue->generic_stat); +#if DISABLE_LOG_X printf("[SFN %d] Slot0: FFT + Channel Estimate + PCFICH/PHICH/PDCCH %5.2f \n",subframe_rx,ue->generic_stat.p_time/(cpuf*1000.0)); +#else + LOG_D(PHY, "[SFN %d] Slot0: FFT + Channel Estimate + PCFICH/PHICH/PDCCH %5.2f \n",subframe_rx,ue->generic_stat.p_time/(cpuf*1000.0)); +#endif + #endif LOG_D(PHY," ------ --> PDSCH ChannelComp/LLR slot 0: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); @@ -4362,7 +4383,12 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin } // not an S-subframe #if UE_TIMING_TRACE stop_meas(&ue->generic_stat); +#if DISABLE_LOG_X printf("[SFN %d] Slot1: FFT + Channel Estimate + Pdsch Proc Slot0 %5.2f \n",subframe_rx,ue->generic_stat.p_time/(cpuf*1000.0)); +#else + LOG_D(PHY, "[SFN %d] Slot1: FFT + Channel Estimate + Pdsch Proc Slot0 %5.2f \n",subframe_rx,ue->generic_stat.p_time/(cpuf*1000.0)); +#endif + #endif LOG_D(PHY," ------ end FFT/ChannelEst/PDCCH slot 1: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); @@ -4406,8 +4432,14 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin abstraction_flag); #if UE_TIMING_TRACE stop_meas(&ue->dlsch_procedures_stat); +#if DISABLE_LOG_X printf("[SFN %d] Slot1: Pdsch Proc %5.2f\n",subframe_rx,ue->pdsch_procedures_stat.p_time/(cpuf*1000.0)); printf("[SFN %d] Slot0 Slot1: Dlsch Proc %5.2f\n",subframe_rx,ue->dlsch_procedures_stat.p_time/(cpuf*1000.0)); +#else + LOG_D(PHY, "[SFN %d] Slot1: Pdsch Proc %5.2f\n",subframe_rx,ue->pdsch_procedures_stat.p_time/(cpuf*1000.0)); + LOG_D(PHY, "[SFN %d] Slot0 Slot1: Dlsch Proc %5.2f\n",subframe_rx,ue->dlsch_procedures_stat.p_time/(cpuf*1000.0)); +#endif + #endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PDSCH_PROC, VCD_FUNCTION_OUT); @@ -4556,7 +4588,11 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_RX, VCD_FUNCTION_OUT); #if UE_TIMING_TRACE stop_meas(&ue->phy_proc_rx[subframe_rx&0x1]); +#if DISABLE_LOG_X printf("------FULL RX PROC [SFN %d]: %5.2f ------\n",subframe_rx,ue->phy_proc_rx[subframe_rx&0x1].p_time/(cpuf*1000.0)); +#else + LOG_D(PHY, "------FULL RX PROC [SFN %d]: %5.2f ------\n",subframe_rx,ue->phy_proc_rx[subframe_rx&0x1].p_time/(cpuf*1000.0)); +#endif #endif LOG_D(PHY," ****** end RX-Chain for AbsSubframe %d.%d ****** \n", frame_rx%1024, subframe_rx); return (0); diff --git a/openair2/UTIL/LOG/log.h b/openair2/UTIL/LOG/log.h index c2663437256c5b626ae583272cf7e9c51cba7527..e80fdeb63148be1af92fca08cb0475f1694b3a32 100644 --- a/openair2/UTIL/LOG/log.h +++ b/openair2/UTIL/LOG/log.h @@ -315,7 +315,7 @@ void *log_thread_function(void * list); # define LOG_N(c, x...) /* */ # define LOG_F(c, x...) /* */ # else /* T_TRACER */ -# if UE_NO_LOG +# if DISABLE_LOG_X # define LOG_I(c, x...) /* */ # define LOG_W(c, x...) /* */ # define LOG_E(c, x...) /* */ @@ -326,7 +326,7 @@ void *log_thread_function(void * list); # define LOG_C(c, x...) /* */ # define LOG_N(c, x...) /* */ # define LOG_F(c, x...) /* */ -# else /*UE_NO_LOG*/ +# else /*DISABLE_LOG_X*/ # define LOG_G(c, x...) logIt(c, LOG_EMERG, x) # define LOG_A(c, x...) logIt(c, LOG_ALERT, x) # define LOG_C(c, x...) logIt(c, LOG_CRIT, x) @@ -337,7 +337,7 @@ void *log_thread_function(void * list); # define LOG_D(c, x...) logIt(c, LOG_DEBUG, x) # define LOG_F(c, x...) logIt(c, LOG_FILE, x) // log to a file, useful for the MSC chart generation # define LOG_T(c, x...) logIt(c, LOG_TRACE, x) -# endif /*UE_NO_LOG*/ +# endif /*DISABLE_LOG_X*/ # endif /* T_TRACER */ #else /* USER_MODE */ # define LOG_G(c, x...) printk(x) @@ -421,7 +421,11 @@ static inline void printMeas(char * txt, Meas *M, int period) { M->iterations, M->maxArray[1],M->maxArray[2], M->maxArray[3],M->maxArray[4], M->maxArray[5], M->maxArray[6],M->maxArray[7], M->maxArray[8],M->maxArray[9],M->maxArray[10]); +#if DISABLE_LOG_X printf("%s",txt2); +#else + LOG_W(PHY, "%s",txt2); +#endif } } diff --git a/targets/RT/USER/lte-ue.c b/targets/RT/USER/lte-ue.c index c1ef741fd22f729e70e983cfd159aeded0432258..1ab22b6104a57dfd73b172e2ccb4d1aa594fd82a 100644 --- a/targets/RT/USER/lte-ue.c +++ b/targets/RT/USER/lte-ue.c @@ -311,7 +311,11 @@ static void *UE_thread_synch(void *arg) { case pbch: +#if DISABLE_LOG_X printf("[UE thread Synch] Running Initial Synch (mode %d)\n",UE->mode); +#else + LOG_I(PHY, "[UE thread Synch] Running Initial Synch (mode %d)\n",UE->mode); +#endif if (initial_sync( UE, UE->mode ) == 0) { hw_slot_offset = (UE->rx_offset<<1) / UE->frame_parms.samples_per_tti; @@ -432,11 +436,19 @@ static void *UE_thread_synch(void *arg) { return &UE_thread_synch_retval; // not reached } } +#if DISABLE_LOG_X printf("[initial_sync] trying carrier off %d Hz, rxgain %d (DL %u, UL %u)\n", freq_offset, UE->rx_total_gain_dB, downlink_frequency[0][0]+freq_offset, downlink_frequency[0][0]+uplink_frequency_offset[0][0]+freq_offset ); +#else + LOG_I(PHY, "[initial_sync] trying carrier off %d Hz, rxgain %d (DL %u, UL %u)\n", + freq_offset, + UE->rx_total_gain_dB, + downlink_frequency[0][0]+freq_offset, + downlink_frequency[0][0]+uplink_frequency_offset[0][0]+freq_offset ); +#endif for (i=0; i<openair0_cfg[UE->rf_map.card].rx_num_channels; i++) { openair0_cfg[UE->rf_map.card].rx_freq[UE->rf_map.chain+i] = downlink_frequency[CC_id][i]+freq_offset;