diff --git a/cmake_targets/CMakeLists.txt b/cmake_targets/CMakeLists.txt index e20718ac3670650c90508cc3d17d0f66e37ca39a..01928c8f53faf08cba994b5416ca1088a8eef446 100644 --- a/cmake_targets/CMakeLists.txt +++ b/cmake_targets/CMakeLists.txt @@ -236,6 +236,9 @@ add_boolean_option(XFORMS False "This adds the possibility to see t add_boolean_option(PRINT_STATS False "This adds the possibility to see the status") add_boolean_option(T_TRACER False "Activate the T tracer, a debugging/monitoring framework" ) 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(DEBUG_CONSOLE False "makes debugging easier, disables stdout/stderr buffering") diff --git a/cmake_targets/build_oai b/cmake_targets/build_oai index 07278d82b143a7d4ce640c92a447085510f33574..331765df36d278b10f2aa22243756836d2c72d35 100755 --- a/cmake_targets/build_oai +++ b/cmake_targets/build_oai @@ -62,6 +62,9 @@ T_TRACER="False" DISABLE_HARDWARE_DEPENDENCY="False" CMAKE_BUILD_TYPE="" UE_AUTOTEST_TRACE="False" +UE_DEBUG_TRACE="False" +UE_TIMING_TRACE="False" +UE_NO_LOG="False" BUILD_ECLIPSE=0 CMAKE_CMD='cmake' trap handle_ctrl_c INT @@ -147,6 +150,12 @@ Options Disable HW dependency during installation --ue-autotest-trace Enable specific traces for UE autotest framework +--ue-trace + Enable traces for UE debugging +--ue-timing + Enable traces for timing +--ue-no-log + Disable all LOG_X --build-eclipse Build eclipse project files. Paths are auto corrected by fixprj.sh Usage (first build): @@ -316,6 +325,18 @@ function main() { UE_AUTOTEST_TRACE="True" echo_info "Enabling autotest specific trace for UE" shift 1;; + --ue-trace) + UE_DEBUG_TRACE="True" + echo_info "Enabling UE trace for debug" + shift 1;; + --ue-timing) + 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;; --uhd-images-dir) UHD_IMAGES_DIR=$2 echo_info "Downloading UHD images in the indicated location" @@ -504,6 +525,9 @@ function main() { echo "set (CPU_AFFINITY \"${CPU_AFFINITY_FLAG_USER}\" )" >>$cmake_file echo "set ( T_TRACER $T_TRACER )" >> $cmake_file 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 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/LTE_TRANSPORT/dci.c b/openair1/PHY/LTE_TRANSPORT/dci.c index 21c4c8aba84c57cb312e0edb0900955e965db662..c4a4b818039a75a36f5fdc4325b9704579a639af 100644 --- a/openair1/PHY/LTE_TRANSPORT/dci.c +++ b/openair1/PHY/LTE_TRANSPORT/dci.c @@ -1754,7 +1754,7 @@ int32_t rx_pdcch(PHY_VARS_UE *ue, avgs = cmax(avgs,avgP[(aarx<<1)+aatx]); log2_maxh = (log2_approx(avgs)/2) + 5; //+frame_parms->nb_antennas_rx; -#ifdef DEBUG_PHY +#ifdef UE_DEBUG_TRACE LOG_I(PHY,"subframe %d: pdcch log2_maxh = %d (%d,%d)\n",subframe,log2_maxh,avgP[0],avgs); #endif diff --git a/openair1/PHY/LTE_TRANSPORT/dci_tools.c b/openair1/PHY/LTE_TRANSPORT/dci_tools.c index 5aa676da9a65df3de769e3edd941f38c85bd15b3..90634045f8f1f8fe5b2ec9230da117bf66a6f892 100644 --- a/openair1/PHY/LTE_TRANSPORT/dci_tools.c +++ b/openair1/PHY/LTE_TRANSPORT/dci_tools.c @@ -6386,22 +6386,21 @@ int generate_ue_dlsch_params_from_dci(int frame, } -#ifdef DEBUG_DCI +#ifdef UE_DEBUG_TRACE if (dlsch[0] && (dlsch[0]->rnti != 0xffff)) { - printf("dci_format:%d Abssubframe: %d.%d \n",dci_format,frame%1024,subframe); - printf("PDSCH dlsch0 UE: rnti %x\n",dlsch[0]->rnti); - printf("PDSCH dlsch0 UE: NBRB %d\n",dlsch0_harq->nb_rb); - printf("PDSCH dlsch0 UE: rballoc %x\n",dlsch0_harq->rb_alloc_even[0]); - printf("PDSCH dlsch0 UE: harq_pid %d\n",harq_pid); - //printf("PDSCH dlsch0 UE: tpc %d\n",TPC); - printf("PDSCH dlsch0 UE: g %d\n",dlsch[0]->g_pucch); - printf("PDSCH dlsch0 UE: round %d\n",dlsch0_harq->round); - printf("PDSCH dlsch0 UE: DCINdi %d\n",dlsch0_harq->DCINdi); - printf("PDSCH dlsch0 UE: rvidx %d\n",dlsch0_harq->rvidx); - printf("PDSCH dlsch0 UE: TBS %d\n",dlsch0_harq->TBS); - printf("PDSCH dlsch0 UE: mcs %d\n",dlsch0_harq->mcs); - printf("PDSCH dlsch0 UE: pwr_off %d\n",dlsch0_harq->dl_power_off); + LOG_I(PHY,"dci_format:%d Abssubframe: %d.%d \n",dci_format,frame%1024,subframe); + LOG_I(PHY,"PDSCH dlsch0 UE: rnti %x\n",dlsch[0]->rnti); + LOG_I(PHY,"PDSCH dlsch0 UE: NBRB %d\n",dlsch0_harq->nb_rb); + LOG_I(PHY,"PDSCH dlsch0 UE: rballoc %x\n",dlsch0_harq->rb_alloc_even[0]); + LOG_I(PHY,"PDSCH dlsch0 UE: harq_pid %d\n",harq_pid); + LOG_I(PHY,"PDSCH dlsch0 UE: g %d\n",dlsch[0]->g_pucch); + LOG_I(PHY,"PDSCH dlsch0 UE: round %d\n",dlsch0_harq->round); + LOG_I(PHY,"PDSCH dlsch0 UE: DCINdi %d\n",dlsch0_harq->DCINdi); + LOG_I(PHY,"PDSCH dlsch0 UE: rvidx %d\n",dlsch0_harq->rvidx); + LOG_I(PHY,"PDSCH dlsch0 UE: TBS %d\n",dlsch0_harq->TBS); + LOG_I(PHY,"PDSCH dlsch0 UE: mcs %d\n",dlsch0_harq->mcs); + LOG_I(PHY,"PDSCH dlsch0 UE: pwr_off %d\n",dlsch0_harq->dl_power_off); } #endif @@ -8099,28 +8098,28 @@ int generate_ue_ulsch_params_from_dci(void *dci_pdu, // ulsch->n_DMRS2 = ((DCI0_5MHz_TDD_1_6_t *)dci_pdu)->cshift; -#ifdef DEBUG_DCI - - printf("Format 0 DCI : ulsch (ue): AbsSubframe %d.%d\n",proc->frame_rx%1024,subframe); - printf("Format 0 DCI : ulsch (ue): NBRB %d\n",ulsch->harq_processes[harq_pid]->nb_rb); - printf("Format 0 DCI :ulsch (ue): first_rb %d\n",ulsch->harq_processes[harq_pid]->first_rb); - printf("Format 0 DCI :ulsch (ue): rballoc %d\n",rballoc); - printf("Format 0 DCI :ulsch (ue): harq_pid %d\n",harq_pid); - printf("Format 0 DCI :ulsch (ue): first_tx %d\n",ulsch->harq_processes[harq_pid]->first_tx); - printf("Format 0 DCI :ulsch (ue): DCINdi %d\n",ulsch->harq_processes[harq_pid]->DCINdi); - printf("Format 0 DCI :ulsch (ue): round %d\n",ulsch->harq_processes[harq_pid]->round); - //printf("Format 0 DCI :ulsch (ue): TBS %d\n",ulsch->harq_processes[harq_pid]->TBS); - printf("Format 0 DCI :ulsch (ue): mcs %d\n",ulsch->harq_processes[harq_pid]->mcs); - //printf("Format 0 DCI :ulsch (ue): O %d\n",ulsch->O); - //printf("Format 0 DCI :ulsch (ue): cqiReq %d\n",cqi_req); +#ifdef UE_DEBUG_TRACE + + LOG_I(PHY,"Format 0 DCI : ulsch (ue): AbsSubframe %d.%d\n",proc->frame_rx%1024,subframe); + LOG_I(PHY,"Format 0 DCI : ulsch (ue): NBRB %d\n",ulsch->harq_processes[harq_pid]->nb_rb); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): first_rb %d\n",ulsch->harq_processes[harq_pid]->first_rb); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): rballoc %d\n",rballoc); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): harq_pid %d\n",harq_pid); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): first_tx %d\n",ulsch->harq_processes[harq_pid]->first_tx); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): DCINdi %d\n",ulsch->harq_processes[harq_pid]->DCINdi); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): round %d\n",ulsch->harq_processes[harq_pid]->round); + //LOG_I(PHY,"Format 0 DCI :ulsch (ue): TBS %d\n",ulsch->harq_processes[harq_pid]->TBS); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): mcs %d\n",ulsch->harq_processes[harq_pid]->mcs); + //LOG_I(PHY,"Format 0 DCI :ulsch (ue): O %d\n",ulsch->O); + //LOG_I(PHY,"Format 0 DCI :ulsch (ue): cqiReq %d\n",cqi_req); //if (frame_parms->frame_type == TDD) - // printf("Format 0 DCI :ulsch (ue): O_ACK/DAI %d/%d\n",ulsch->harq_processes[harq_pid]->O_ACK,dai); + // LOG_I(PHY,"Format 0 DCI :ulsch (ue): O_ACK/DAI %d/%d\n",ulsch->harq_processes[harq_pid]->O_ACK,dai); //else - // printf("Format 0 DCI :ulsch (ue): O_ACK %d\n",ulsch->harq_processes[harq_pid]->O_ACK); + // LOG_I(PHY,"Format 0 DCI :ulsch (ue): O_ACK %d\n",ulsch->harq_processes[harq_pid]->O_ACK); - printf("Format 0 DCI :ulsch (ue): Nsymb_pusch %d\n",ulsch->Nsymb_pusch); - printf("Format 0 DCI :ulsch (ue): cshift %d\n",ulsch->harq_processes[harq_pid]->n_DMRS2); - printf("Format 0 DCI :ulsch (ue): phich status %d\n",ulsch->harq_processes[harq_pid]->status); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): Nsymb_pusch %d\n",ulsch->Nsymb_pusch); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): cshift %d\n",ulsch->harq_processes[harq_pid]->n_DMRS2); + LOG_I(PHY,"Format 0 DCI :ulsch (ue): phich status %d\n",ulsch->harq_processes[harq_pid]->status); #else UNUSED_VARIABLE(dai); #endif diff --git a/openair1/PHY/LTE_TRANSPORT/dlsch_decoding.c b/openair1/PHY/LTE_TRANSPORT/dlsch_decoding.c index 05f458e94a2e05b49172e1d8b5351181faaa7888..87d5d481627e1fb903825da13dd5be5d8b291978 100644 --- a/openair1/PHY/LTE_TRANSPORT/dlsch_decoding.c +++ b/openair1/PHY/LTE_TRANSPORT/dlsch_decoding.c @@ -167,10 +167,11 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, uint8_t llr8_flag) { - +#if UE_TIMING_TRACE time_stats_t *dlsch_rate_unmatching_stats=&phy_vars_ue->dlsch_rate_unmatching_stats; time_stats_t *dlsch_turbo_decoding_stats=&phy_vars_ue->dlsch_turbo_decoding_stats; time_stats_t *dlsch_deinterleaving_stats=&phy_vars_ue->dlsch_deinterleaving_stats; +#endif uint32_t A,E; uint32_t G; uint32_t ret,offset; @@ -372,7 +373,9 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, printf("f1 %d, f2 %d, F %d\n",f1f2mat_old[2*iind],f1f2mat_old[1+(2*iind)],(r==0) ? harq_process->F : 0); #endif +#if UE_TIMING_TRACE start_meas(dlsch_rate_unmatching_stats); +#endif memset(&dummy_w[r][0],0,3*(6144+64)*sizeof(short)); harq_process->RTC[r] = generate_dummy_w(4+(Kr_bytes*8), (uint8_t*) &dummy_w[r][0], @@ -406,12 +409,17 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, harq_process->Nl, r, &E)==-1) { +#if UE_TIMING_TRACE stop_meas(dlsch_rate_unmatching_stats); +#endif LOG_E(PHY,"dlsch_decoding.c: Problem in rate_matching\n"); return(dlsch->max_turbo_iterations); } else + { +#if UE_TIMING_TRACE stop_meas(dlsch_rate_unmatching_stats); - +#endif + } r_offset += E; /* @@ -419,13 +427,16 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, harq_process->d[r], harq_process->w); */ +#if UE_TIMING_TRACE start_meas(dlsch_deinterleaving_stats); +#endif sub_block_deinterleaving_turbo(4+Kr, &harq_process->d[r][96], harq_process->w[r]); +#if UE_TIMING_TRACE stop_meas(dlsch_deinterleaving_stats); - +#endif #ifdef DEBUG_DLSCH_DECODING /* if (r==0) { @@ -470,8 +481,9 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, AssertFatal (Kr >= 256, "turbo algo issue Kr=%d cb_cnt=%d C=%d nbRB=%d TBSInput=%d TBSHarq=%d TBSplus24=%d mcs=%d Qm=%d RIV=%d round=%d\n", Kr,r,harq_process->C,harq_process->nb_rb,A,harq_process->TBS,harq_process->B,harq_process->mcs,harq_process->Qm,harq_process->rvidx,harq_process->round); } - - start_meas(dlsch_turbo_decoding_stats); +#if UE_TIMING_TRACE + start_meas(dlsch_turbo_decoding_stats); +#endif LOG_D(PHY,"AbsSubframe %d.%d Start turbo segment %d/%d \n",frame%1024,subframe,r,harq_process->C-1); ret = tc (&harq_process->d[r][96], @@ -490,14 +502,17 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, &phy_vars_ue->dlsch_tc_intl1_stats, &phy_vars_ue->dlsch_tc_intl2_stats); //(is_crnti==0)?harq_pid:harq_pid+1); - +#if UE_TIMING_TRACE stop_meas(dlsch_turbo_decoding_stats); +#endif } #else if ((harq_process->C == 1) || ((r==harq_process->C-1) && (skipped_last==0))) { // last segment with odd number of segments - start_meas(dlsch_turbo_decoding_stats); +#if UE_TIMING_TRACE + start_meas(dlsch_turbo_decoding_stats); +#endif ret = tc (&harq_process->d[r][96], harq_process->c[r], @@ -514,7 +529,9 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, &phy_vars_ue->dlsch_tc_ext_stats, &phy_vars_ue->dlsch_tc_intl1_stats, &phy_vars_ue->dlsch_tc_intl2_stats); //(is_crnti==0)?harq_pid:harq_pid+1); + #if UE_TIMING_TRACE stop_meas(dlsch_turbo_decoding_stats); +#endif // printf("single decode, exit\n"); // exit(-1); } @@ -531,7 +548,9 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, #ifdef DEBUG_DLSCH_DECODING printf("single decoding segment %d (%p)\n",r-1,&harq_process->d[r-1][96]); #endif +#if UE_TIMING_TRACE start_meas(dlsch_turbo_decoding_stats); +#endif #ifdef DEBUG_DLSCH_DECODING printf("double decoding segments %d,%d (%p,%p)\n",r-1,r,&harq_process->d[r-1][96],&harq_process->d[r][96]); #endif @@ -572,10 +591,14 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, &phy_vars_ue->dlsch_tc_intl2_stats); //(is_crnti==0)?harq_pid:harq_pid+1); exit(-1);*/ - stop_meas(dlsch_turbo_decoding_stats); +#if UE_TIMING_TRACE + stop_meas(dlsch_turbo_decoding_stats); +#endif } else { // Kr_last != Kr +#if UE_TIMING_TRACE start_meas(dlsch_turbo_decoding_stats); +#endif ret = tc (&harq_process->d[r-1][96], harq_process->c[r-1], @@ -592,9 +615,12 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, &phy_vars_ue->dlsch_tc_ext_stats, &phy_vars_ue->dlsch_tc_intl1_stats, &phy_vars_ue->dlsch_tc_intl2_stats); //(is_crnti==0)?harq_pid:harq_pid+1); - stop_meas(dlsch_turbo_decoding_stats); +#if UE_TIMING_TRACE + stop_meas(dlsch_turbo_decoding_stats); start_meas(dlsch_turbo_decoding_stats); +#endif + ret = tc (&harq_process->d[r][96], harq_process->c[r], @@ -611,6 +637,9 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, &phy_vars_ue->dlsch_tc_ext_stats, &phy_vars_ue->dlsch_tc_intl1_stats, &phy_vars_ue->dlsch_tc_intl2_stats); //(is_crnti==0)?harq_pid:harq_pid+1); + +#if UE_TIMING_TRACE + stop_meas(dlsch_turbo_decoding_stats); /*printf("Segmentation: C %d r %d, dlsch_rate_unmatching_stats %5.3f dlsch_deinterleaving_stats %5.3f dlsch_turbo_decoding_stats %5.3f \n", @@ -619,7 +648,7 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, dlsch_rate_unmatching_stats->p_time/(cpuf*1000.0), dlsch_deinterleaving_stats->p_time/(cpuf*1000.0), dlsch_turbo_decoding_stats->p_time/(cpuf*1000.0));*/ - +#endif } } } @@ -641,9 +670,10 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, frame_rx_prev = frame_rx_prev%1024; if (err_flag == 1) { - //LOG_I(PHY,"[UE %d] DLSCH: Setting NAK for SFN/SF %d/%d (pid %d, status %d, round %d, TBS %d, mcs %d) Kr %d r %d harq_process->round %d\n", - // phy_vars_ue->Mod_id, frame, subframe, harq_pid,harq_process->status, harq_process->round,harq_process->TBS,harq_process->mcs,Kr,r,harq_process->round); - +#if UE_DEBUG_TRACE + LOG_I(PHY,"[UE %d] DLSCH: Setting NAK for SFN/SF %d/%d (pid %d, status %d, round %d, TBS %d, mcs %d) Kr %d r %d harq_process->round %d\n", + phy_vars_ue->Mod_id, frame, subframe, harq_pid,harq_process->status, harq_process->round,harq_process->TBS,harq_process->mcs,Kr,r,harq_process->round); +#endif dlsch->harq_ack[subframe].ack = 0; dlsch->harq_ack[subframe].harq_id = harq_pid; dlsch->harq_ack[subframe].send_harq_status = 1; @@ -664,9 +694,10 @@ uint32_t dlsch_decoding(PHY_VARS_UE *phy_vars_ue, return((1+dlsch->max_turbo_iterations)); } else { - - //LOG_I(PHY,"[UE %d] DLSCH: Setting ACK for subframe %d TBS %d harq_process->mcs %d harq_process->nb_rb %d\n", - //phy_vars_ue->Mod_id,subframe,harq_process->TBS,harq_process->mcs,harq_process->nb_rb); +#if UE_DEBUG_TRACE + LOG_I(PHY,"[UE %d] DLSCH: Setting ACK for subframe %d TBS %d mcs %d nb_rb %d\n", + phy_vars_ue->Mod_id,subframe,harq_process->TBS,harq_process->mcs,harq_process->nb_rb); +#endif harq_process->status = SCH_IDLE; harq_process->round = 0; diff --git a/openair1/PHY/LTE_TRANSPORT/dlsch_demodulation.c b/openair1/PHY/LTE_TRANSPORT/dlsch_demodulation.c index 1450209c260a6d7abb8fa1904df9afe42cf8d7a7..cf68ca2a8fc01a5d022863f57d50a3fd63a24d0f 100644 --- a/openair1/PHY/LTE_TRANSPORT/dlsch_demodulation.c +++ b/openair1/PHY/LTE_TRANSPORT/dlsch_demodulation.c @@ -465,13 +465,13 @@ int rx_pdsch(PHY_VARS_UE *ue, avg, symbol, nb_rb); -#ifdef DEBUG_PHY +#ifdef UE_DEBUG_TRACE LOG_I(PHY,"[DLSCH] AbsSubframe %d.%d log2_maxh = %d [log2_maxh0 %d log2_maxh1 %d] (%d,%d)\n", frame%1024,subframe, pdsch_vars[eNB_id]->log2_maxh, pdsch_vars[eNB_id]->log2_maxh0, pdsch_vars[eNB_id]->log2_maxh1, avg[0],avgs); - LOG_D(PHY,"[DLSCH] mimo_mode = %d\n", dlsch0_harq->mimo_mode); + //LOG_D(PHY,"[DLSCH] mimo_mode = %d\n", dlsch0_harq->mimo_mode); #endif } diff --git a/openair1/PHY/LTE_TRANSPORT/phich.c b/openair1/PHY/LTE_TRANSPORT/phich.c index d363d4dcf65faf9312a1dc70357f45eab7f5f6a8..51505d59e23c0735bbda82251b9a9e1b2c4ffb27 100644 --- a/openair1/PHY/LTE_TRANSPORT/phich.c +++ b/openair1/PHY/LTE_TRANSPORT/phich.c @@ -1368,7 +1368,7 @@ void rx_phich(PHY_VARS_UE *ue, if (HI16>0) { //NACK if (ue->ulsch_Msg3_active[eNB_id] == 1) { - LOG_D(PHY,"[UE %d][PUSCH %d][RAPROC] Frame %d subframe %d Msg3 PHICH, received NAK (%d) nseq %d, ngroup %d\n", + LOG_I(PHY,"[UE %d][PUSCH %d][RAPROC] Frame %d subframe %d Msg3 PHICH, received NAK (%d) nseq %d, ngroup %d\n", ue->Mod_id,harq_pid, proc->frame_rx, subframe, @@ -1388,8 +1388,8 @@ void rx_phich(PHY_VARS_UE *ue, ue->ulsch_Msg3_active[eNB_id] = 0; } } else { - //#ifdef DEBUG_PHICH - LOG_D(PHY,"[UE %d][PUSCH %d] Frame %d subframe %d PHICH, received NAK (%d) nseq %d, ngroup %d round %d (Mlimit %d)\n", +#ifdef UE_DEBUG_TRACE + LOG_I(PHY,"[UE %d][PUSCH %d] Frame %d subframe %d PHICH, received NAK (%d) nseq %d, ngroup %d round %d (Mlimit %d)\n", ue->Mod_id,harq_pid, proc->frame_rx%1024, subframe, @@ -1397,7 +1397,7 @@ void rx_phich(PHY_VARS_UE *ue, nseq_PHICH, ngroup_PHICH, ulsch->Mlimit); - //#endif +#endif // ulsch->harq_processes[harq_pid]->Ndi = 0; ulsch->harq_processes[harq_pid]->round++; @@ -1436,20 +1436,20 @@ void rx_phich(PHY_VARS_UE *ue, } else { //ACK if (ue->ulsch_Msg3_active[eNB_id] == 1) { - LOG_D(PHY,"[UE %d][PUSCH %d][RAPROC] Frame %d subframe %d Msg3 PHICH, received ACK (%d) nseq %d, ngroup %d\n\n", + LOG_I(PHY,"[UE %d][PUSCH %d][RAPROC] Frame %d subframe %d Msg3 PHICH, received ACK (%d) nseq %d, ngroup %d\n\n", ue->Mod_id,harq_pid, proc->frame_rx, subframe, HI16, nseq_PHICH,ngroup_PHICH); } else { - //#ifdef PHICH_DEBUG - LOG_D(PHY,"[UE %d][PUSCH %d] Frame %d subframe %d PHICH, received ACK (%d) nseq %d, ngroup %d\n\n", +#ifdef UE_DEBUG_TRACE + LOG_I(PHY,"[UE %d][PUSCH %d] Frame %d subframe %d PHICH, received ACK (%d) nseq %d, ngroup %d\n\n", ue->Mod_id,harq_pid, proc->frame_rx%1024, subframe, HI16, nseq_PHICH,ngroup_PHICH); - //#endif +#endif } // LOG_I(PHY,"[HARQ-UL harqId: %d] subframe_scheduling_flag = %d \n",harq_pid, ulsch->harq_processes[harq_pid]->subframe_scheduling_flag); diff --git a/openair1/PHY/MODULATION/slot_fep.c b/openair1/PHY/MODULATION/slot_fep.c index 3a3b3b4c0d48ed810ba7c1236314b7e994c2a24f..4fc17348410c45fe2454ae238ef885df4406ef8a 100644 --- a/openair1/PHY/MODULATION/slot_fep.c +++ b/openair1/PHY/MODULATION/slot_fep.c @@ -129,11 +129,15 @@ int slot_fep(PHY_VARS_UE *ue, dft((int16_t *)tmp_dft_in, (int16_t *)&common_vars->common_vars_rx_data_per_thread[(Ns>>1)&0x1].rxdataF[aa][frame_parms->ofdm_symbol_size*symbol],1); } else { // use dft input from RX buffer directly - start_meas(&ue->rx_dft_stats); +#if UE_TIMING_TRACE + start_meas(&ue->rx_dft_stats); +#endif dft((int16_t *)&common_vars->rxdata[aa][(rx_offset) % frame_length_samples], (int16_t *)&common_vars->common_vars_rx_data_per_thread[(Ns>>1)&0x1].rxdataF[aa][frame_parms->ofdm_symbol_size*symbol],1); +#if UE_TIMING_TRACE stop_meas(&ue->rx_dft_stats); +#endif } } else { @@ -150,8 +154,9 @@ int slot_fep(PHY_VARS_UE *ue, memcpy((void *)&common_vars->rxdata[aa][frame_length_samples], (void *)&common_vars->rxdata[aa][0], frame_parms->ofdm_symbol_size*sizeof(int)); - +#if UE_TIMING_TRACE start_meas(&ue->rx_dft_stats); +#endif if ((rx_offset&7)!=0) { // if input to dft is not 128-bit aligned, issue for size 6 and 15 PRBs memcpy((void *)tmp_dft_in, @@ -164,8 +169,9 @@ int slot_fep(PHY_VARS_UE *ue, dft((int16_t *)&common_vars->rxdata[aa][(rx_offset) % frame_length_samples], (int16_t *)&common_vars->common_vars_rx_data_per_thread[(Ns>>1)&0x1].rxdataF[aa][frame_parms->ofdm_symbol_size*symbol],1); } - +#if UE_TIMING_TRACE stop_meas(&ue->rx_dft_stats); +#endif } @@ -183,13 +189,17 @@ int slot_fep(PHY_VARS_UE *ue, #ifdef DEBUG_FEP printf("Channel estimation eNB %d, aatx %d, slot %d, symbol %d\n",eNB_id,aa,Ns,l); #endif +#if UE_TIMING_TRACE start_meas(&ue->dlsch_channel_estimation_stats); +#endif lte_dl_channel_estimation(ue,eNB_id,0, Ns, aa, l, symbol); +#if UE_TIMING_TRACE stop_meas(&ue->dlsch_channel_estimation_stats); +#endif for (i=0; i<ue->measurements.n_adj_cells; i++) { lte_dl_channel_estimation(ue,eNB_id,i+1, @@ -208,13 +218,17 @@ int slot_fep(PHY_VARS_UE *ue, #endif if (l==(4-frame_parms->Ncp)) { - start_meas(&ue->dlsch_freq_offset_estimation_stats); +#if UE_TIMING_TRACE + start_meas(&ue->dlsch_freq_offset_estimation_stats); +#endif lte_est_freq_offset(common_vars->common_vars_rx_data_per_thread[(Ns>>1)&0x1].dl_ch_estimates[0], frame_parms, l, &common_vars->freq_offset, reset_freq_est); +#if UE_TIMING_TRACE stop_meas(&ue->dlsch_freq_offset_estimation_stats); +#endif } } diff --git a/openair1/PHY/MODULATION/slot_fep_mbsfn.c b/openair1/PHY/MODULATION/slot_fep_mbsfn.c index bead242dd8b9608a53e83a44fd9bec00aaaa1fcb..e20a984bd17b0708f3fe8873c52682fbcc050ee5 100644 --- a/openair1/PHY/MODULATION/slot_fep_mbsfn.c +++ b/openair1/PHY/MODULATION/slot_fep_mbsfn.c @@ -111,13 +111,17 @@ int slot_fep_mbsfn(PHY_VARS_UE *ue, for (aa=0; aa<frame_parms->nb_antennas_rx; aa++) { memset(&common_vars->common_vars_rx_data_per_thread[subframe&0x1].rxdataF[aa][frame_parms->ofdm_symbol_size*l],0,frame_parms->ofdm_symbol_size*sizeof(int)); if (l==0) { - start_meas(&ue->rx_dft_stats); +#if UE_TIMING_TRACE + start_meas(&ue->rx_dft_stats); +#endif dft((int16_t *)&common_vars->rxdata[aa][(sample_offset + nb_prefix_samples0 + subframe_offset - SOFFSET) % frame_length_samples], (int16_t *)&common_vars->common_vars_rx_data_per_thread[subframe&0x1].rxdataF[aa][frame_parms->ofdm_symbol_size*l],1); +#if UE_TIMING_TRACE stop_meas(&ue->rx_dft_stats); +#endif } else { if ((sample_offset + (frame_parms->ofdm_symbol_size+nb_prefix_samples0+nb_prefix_samples) + @@ -128,14 +132,18 @@ int slot_fep_mbsfn(PHY_VARS_UE *ue, (short *)&common_vars->rxdata[aa][0], frame_parms->ofdm_symbol_size*sizeof(int)); +#if UE_TIMING_TRACE start_meas(&ue->rx_dft_stats); +#endif dft((int16_t *)&common_vars->rxdata[aa][(sample_offset + (frame_parms->ofdm_symbol_size+nb_prefix_samples0+nb_prefix_samples) + (frame_parms->ofdm_symbol_size+nb_prefix_samples)*(l-1) + subframe_offset- SOFFSET) % frame_length_samples], (int16_t *)&common_vars->common_vars_rx_data_per_thread[subframe&0x1].rxdataF[aa][frame_parms->ofdm_symbol_size*l],1); +#if UE_TIMING_TRACE stop_meas(&ue->rx_dft_stats); +#endif } } diff --git a/openair1/PHY/TOOLS/time_meas.h b/openair1/PHY/TOOLS/time_meas.h index 233d16ebbea83f7e95acebbbc196dc7c82fffca0..ff94fce22ea087394ee1d534ff165389c20868a0 100644 --- a/openair1/PHY/TOOLS/time_meas.h +++ b/openair1/PHY/TOOLS/time_meas.h @@ -97,7 +97,6 @@ static inline uint32_t rdtsc_oai(void) static inline void start_meas(time_stats_t *ts) { - if (opp_enabled) { if (ts->meas_flag==0) { ts->trials++; diff --git a/openair1/SCHED/phy_procedures_lte_ue.c b/openair1/SCHED/phy_procedures_lte_ue.c index 663dc33b49696e294882b89875fedbb67741fa7c..9ac912a161d636e212edd9741194a0a6f6f9b658 100644 --- a/openair1/SCHED/phy_procedures_lte_ue.c +++ b/openair1/SCHED/phy_procedures_lte_ue.c @@ -947,8 +947,9 @@ void ulsch_common_procedures(PHY_VARS_UE *ue, UE_rxtx_proc_t *proc, uint8_t empt #endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_TX_ULSCH_COMMON,VCD_FUNCTION_IN); - +#if UE_TIMING_TRACE start_meas(&ue->ofdm_mod_stats); +#endif nsymb = (frame_parms->Ncp == 0) ? 14 : 12; #if defined(EXMIMO) || defined(OAI_USRP) || defined(OAI_BLADERF) || defined(OAI_LMSSDR)//this is the EXPRESS MIMO case @@ -1083,8 +1084,9 @@ void ulsch_common_procedures(PHY_VARS_UE *ue, UE_rxtx_proc_t *proc, uint8_t empt } //nb_antennas_tx - stop_meas(&ue->ofdm_mod_stats); - +#if UE_TIMING_TRACE + stop_meas(&ue->ofdm_mod_stats); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_TX_ULSCH_COMMON,VCD_FUNCTION_OUT); } @@ -1275,7 +1277,9 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB Mod_id,frame_tx, subframe_tx); mac_xface->macphy_exit("Error in ulsch_decoding"); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_TX, VCD_FUNCTION_OUT); - stop_meas(&ue->phy_proc_tx); +#if UE_TIMING_TRACE + stop_meas(&ue->phy_proc_tx); +#endif return; } @@ -1397,17 +1401,18 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB T_INT(ue->dlsch[proc->subframe_rx&0x1][eNB_id][0]->current_harq_pid)); } #endif - - LOG_D(PHY,"[UE %d][PDSCH %x] AbsSubFrame %d.%d Generating ACK (%d,%d) for %d bits on PUSCH\n", +#ifdef UE_DEBUG_TRACE + LOG_I(PHY,"[UE %d][PDSCH %x] AbsSubFrame %d.%d Generating ACK (%d,%d) for %d bits on PUSCH\n", Mod_id, ue->ulsch[eNB_id]->rnti, frame_tx%1024,subframe_tx, ue->ulsch[eNB_id]->o_ACK[0],ue->ulsch[eNB_id]->o_ACK[1], ue->ulsch[eNB_id]->harq_processes[harq_pid]->O_ACK); +#endif } -#ifdef DEBUG_PHY_PROC - LOG_D(PHY, +#ifdef UE_DEBUG_TRACE + LOG_I(PHY, "[UE %d][PUSCH %d] AbsSubframe %d.%d Generating PUSCH : first_rb %d, nb_rb %d, round %d, mcs %d, rv %d, " "cyclic_shift %d (cyclic_shift_common %d,n_DMRS2 %d,n_PRS %d), ACK (%d,%d), O_ACK %d, ack_status_cw0 %d ack_status_cw1 %d bundling %d, Nbundled %d, CQI %d, RI %d\n", Mod_id,harq_pid,frame_tx%1024,subframe_tx, @@ -1450,8 +1455,9 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB ue->prach_resources[eNB_id]->Msg3[6], ue->prach_resources[eNB_id]->Msg3[7], ue->prach_resources[eNB_id]->Msg3[8]); - +#if UE_TIMING_TRACE start_meas(&ue->ulsch_encoding_stats); +#endif if (abstraction_flag==0) { if (ulsch_encoding(ue->prach_resources[eNB_id]->Msg3, @@ -1463,8 +1469,10 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB LOG_E(PHY,"ulsch_coding.c: FATAL ERROR: returning\n"); mac_xface->macphy_exit("Error in ulsch_coding"); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_TX, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&ue->phy_proc_tx); - //printf("------FULL TX PROC : %5.2f ------\n",ue->phy_proc_tx.p_time/(cpuf*1000.0)); + printf("------FULL TX PROC : %5.2f ------\n",ue->phy_proc_tx.p_time/(cpuf*1000.0)); +#endif return; } } @@ -1476,8 +1484,9 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB #endif +#if UE_TIMING_TRACE stop_meas(&ue->ulsch_encoding_stats); - +#endif if (ue->mac_enabled == 1) { // signal MAC that Msg3 was sent mac_xface->Msg3_transmitted(Mod_id, @@ -1523,8 +1532,9 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB } +#if UE_TIMING_TRACE start_meas(&ue->ulsch_encoding_stats); - +#endif if (abstraction_flag==0) { if (ulsch_encoding(ulsch_input_buffer, @@ -1536,7 +1546,9 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB Nbundled)!=0) { 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); - stop_meas(&ue->phy_proc_tx); +#if UE_TIMING_TRACE + stop_meas(&ue->phy_proc_tx); +#endif return; } } @@ -1547,7 +1559,9 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB } #endif +#if UE_TIMING_TRACE stop_meas(&ue->ulsch_encoding_stats); +#endif } if (abstraction_flag == 0) { @@ -1572,9 +1586,13 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB T(T_UE_PHY_PUSCH_TX_POWER, T_INT(eNB_id),T_INT(Mod_id), T_INT(frame_tx%1024), T_INT(subframe_tx),T_INT(ue->tx_power_dBm[subframe_tx]), T_INT(tx_amp),T_INT(ue->ulsch[eNB_id]->f_pusch),T_INT(get_PL(Mod_id,0,eNB_id)),T_INT(nb_rb)); #endif - LOG_D(PHY,"[UE %d][PUSCH %d] AbsSubFrame %d.%d, generating PUSCH, Po_PUSCH: %d dBm (max %d dBm), amp %d\n", +#ifdef UE_DEBUG_TRACE + LOG_I(PHY,"[UE %d][PUSCH %d] AbsSubFrame %d.%d, generating PUSCH, Po_PUSCH: %d dBm (max %d dBm), amp %d\n", Mod_id,harq_pid,frame_tx%1024,subframe_tx,ue->tx_power_dBm[subframe_tx],ue->tx_power_max_dBm, tx_amp); +#endif +#if UE_TIMING_TRACE start_meas(&ue->ulsch_modulation_stats); +#endif ulsch_modulation(ue->common_vars.txdataF, tx_amp, frame_tx, @@ -1590,8 +1608,9 @@ void ue_ulsch_uespec_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB first_rb, nb_rb, aa); - +#if UE_TIMING_TRACE stop_meas(&ue->ulsch_modulation_stats); +#endif } if (abstraction_flag==1) { @@ -1757,7 +1776,6 @@ void ue_pucch_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin uint8_t pucch_ack_payload[2]; - uint8_t n2_pucch = -1; uint16_t pucch_resource; ANFBmode_t bundling_flag; PUCCH_FMT_t format; @@ -1922,9 +1940,11 @@ void ue_pucch_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin T(T_UE_PHY_PUCCH_TX_POWER, T_INT(eNB_id),T_INT(Mod_id), T_INT(frame_tx%1024), T_INT(subframe_tx),T_INT(ue->tx_power_dBm[subframe_tx]), T_INT(tx_amp),T_INT(ue->dlsch[proc->subframe_rx&0x1][eNB_id][0]->g_pucch),T_INT(get_PL(ue->Mod_id,ue->CC_id,eNB_id))); #endif + +#ifdef UE_DEBUG_TRACE if(format == pucch_format1) { - LOG_D(PHY,"[UE %d][SR %x] AbsSubframe %d.%d Generating PUCCH 1 (SR for PUSCH), an_srs_simultanous %d, shorten_pucch %d, n1_pucch %d, Po_PUCCH %d\n", + LOG_I(PHY,"[UE %d][SR %x] AbsSubframe %d.%d Generating PUCCH 1 (SR for PUSCH), an_srs_simultanous %d, shorten_pucch %d, n1_pucch %d, Po_PUCCH %d\n", Mod_id, ue->dlsch[proc->subframe_rx&0x1][eNB_id][0]->rnti, frame_tx%1024, subframe_tx, @@ -1936,7 +1956,7 @@ void ue_pucch_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin else { if (SR_payload>0) { - LOG_D(PHY,"[UE %d][SR %x] AbsSubFrame %d.%d Generating PUCCH %s payload %d,%d (with SR for PUSCH), an_srs_simultanous %d, shorten_pucch %d, n1_pucch %d, Po_PUCCH %d, amp %d\n", + LOG_I(PHY,"[UE %d][SR %x] AbsSubFrame %d.%d Generating PUCCH %s payload %d,%d (with SR for PUSCH), an_srs_simultanous %d, shorten_pucch %d, n1_pucch %d, Po_PUCCH %d, amp %d\n", Mod_id, ue->dlsch[proc->subframe_rx&0x1][eNB_id][0]->rnti, frame_tx % 1024, subframe_tx, @@ -1949,7 +1969,7 @@ void ue_pucch_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin Po_PUCCH, tx_amp); } else { - LOG_D(PHY,"[UE %d][PDSCH %x] AbsSubFrame %d.%d rx_offset_diff: %d, Generating PUCCH %s, an_srs_simultanous %d, shorten_pucch %d, n1_pucch %d, b[0]=%d,b[1]=%d (SR_Payload %d), Po_PUCCH %d, amp %d\n", + LOG_I(PHY,"[UE %d][PDSCH %x] AbsSubFrame %d.%d rx_offset_diff: %d, Generating PUCCH %s, an_srs_simultanous %d, shorten_pucch %d, n1_pucch %d, b[0]=%d,b[1]=%d (SR_Payload %d), Po_PUCCH %d, amp %d\n", Mod_id, ue->dlsch[proc->subframe_rx&0x1][eNB_id][0]->rnti, frame_tx%1024, subframe_tx,ue->rx_offset_diff, @@ -1962,6 +1982,7 @@ void ue_pucch_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin tx_amp); } } +#endif #if T_TRACER if(pucch_payload[0]) @@ -2027,16 +2048,15 @@ void ue_pucch_procedures(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin T(T_UE_PHY_PUCCH_TX_POWER, T_INT(eNB_id),T_INT(Mod_id), T_INT(frame_tx%1024), T_INT(subframe_tx),T_INT(ue->tx_power_dBm[subframe_tx]), T_INT(tx_amp),T_INT(ue->dlsch[proc->subframe_rx&0x1][eNB_id][0]->g_pucch),T_INT(get_PL(ue->Mod_id,ue->CC_id,eNB_id))); #endif - - LOG_D(PHY,"[UE %d][RNTI %x] AbsSubFrame %d.%d Generating PUCCH 2 (RI or CQI), n2_pucch %d, Po_PUCCH %d, isShortenPucch %d, amp %d\n", +#ifdef UE_DEBUG_TRACE + LOG_D(PHY,"[UE %d][RNTI %x] AbsSubFrame %d.%d Generating PUCCH 2 (RI or CQI), Po_PUCCH %d, isShortenPucch %d, amp %d\n", Mod_id, ue->dlsch[proc->subframe_rx&0x1][eNB_id][0]->rnti, frame_tx%1024, subframe_tx, - n2_pucch, Po_PUCCH, isShortenPucch, tx_amp); - +#endif generate_pucch2x(ue->common_vars.txdataF, &ue->frame_parms, ue->ncs_cell, @@ -2089,8 +2109,9 @@ void phy_procedures_UE_TX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,ui #endif ue->generate_ul_signal[eNB_id] = 0; - +#if UE_TIMING_TRACE start_meas(&ue->phy_proc_tx); +#endif #ifdef EMOS //phy_procedures_emos_UE_TX(next_slot); @@ -2233,7 +2254,9 @@ void phy_procedures_UE_TX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,ui VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_TX, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&ue->phy_proc_tx); +#endif } void phy_procedures_UE_S_TX(PHY_VARS_UE *ue,uint8_t eNB_id,uint8_t abstraction_flag,relaying_type_t r_type) @@ -2714,7 +2737,9 @@ int ue_pdcch_procedures(uint8_t eNB_id,PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint #endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_PDCCH_PROCEDURES, VCD_FUNCTION_IN); +#if UE_TIMING_TRACE start_meas(&ue->dlsch_rx_pdcch_stats); +#endif // if (subframe_rx != 5) // return 0; @@ -3068,8 +3093,9 @@ int ue_pdcch_procedures(uint8_t eNB_id,PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint } } - +#if UE_TIMING_TRACE stop_meas(&ue->dlsch_rx_pdcch_stats); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_PDCCH_PROCEDURES, VCD_FUNCTION_OUT); return(0); } @@ -3313,8 +3339,9 @@ void ue_pdsch_procedures(PHY_VARS_UE *ue, UE_rxtx_proc_t *proc, int eNB_id, PDSC first_symbol_flag = 1; else first_symbol_flag = 0; - +#if UE_TIMING_TRACE start_meas(&ue->dlsch_llr_stats); +#endif // process DLSCH received in first slot rx_pdsch(ue, pdsch, @@ -3327,7 +3354,9 @@ void ue_pdsch_procedures(PHY_VARS_UE *ue, UE_rxtx_proc_t *proc, int eNB_id, PDSC dual_stream_UE, i_mod, dlsch0->current_harq_pid); +#if UE_TIMING_TRACE stop_meas(&ue->dlsch_llr_stats); +#endif } // CRNTI active } } @@ -3513,7 +3542,9 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, frame_rx, subframe_rx, ue->transmission_mode[eNB_id]<7?0:ue->transmission_mode[eNB_id]); +#if UE_TIMING_TRACE start_meas(&ue->dlsch_unscrambling_stats); +#endif dlsch_unscrambling(&ue->frame_parms, 0, dlsch0, @@ -3521,7 +3552,9 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, pdsch_vars->llr[0], 0, subframe_rx<<1); +#if UE_TIMING_TRACE stop_meas(&ue->dlsch_unscrambling_stats); +#endif #if 0 LOG_I(PHY," ------ start turbo decoder for AbsSubframe %d.%d / %d ------ \n", frame_rx, subframe_rx, harq_pid); @@ -3533,8 +3566,10 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, LOG_I(PHY,"start turbo decode for CW 0 for AbsSubframe %d.%d / %d --> Kmimo %d \n", frame_rx, subframe_rx, harq_pid, dlsch0->Kmimo); LOG_I(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[subframe_rx & 0x1][eNB_id]->num_pdcch_symbols); #endif - +#if UE_TIMING_TRACE start_meas(&ue->dlsch_decoding_stats[subframe_rx&0x1]); +#endif + ret = dlsch_decoding(ue, pdsch_vars->llr[0], &ue->frame_parms, @@ -3545,13 +3580,14 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, harq_pid, pdsch==PDSCH?1:0, dlsch0->harq_processes[harq_pid]->TBS>256?1:0); +#if UE_TIMING_TRACE stop_meas(&ue->dlsch_decoding_stats[subframe_rx&0x1]); - LOG_D(PHY," --> Unscrambling for CW0 %5.3f\n", + printf(" --> 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", + 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)); - +#endif if(is_cw1_active) { @@ -3565,8 +3601,9 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, frame_rx, subframe_rx, ue->transmission_mode[eNB_id]<7?0:ue->transmission_mode[eNB_id]); - +#if UE_TIMING_TRACE start_meas(&ue->dlsch_unscrambling_stats); +#endif dlsch_unscrambling(&ue->frame_parms, 0, dlsch1, @@ -3574,7 +3611,9 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, pdsch_vars->llr[1], 1, subframe_rx<<1); +#if UE_TIMING_TRACE stop_meas(&ue->dlsch_unscrambling_stats); +#endif #if 0 LOG_I(PHY,"start turbo decode for CW 1 for AbsSubframe %d.%d / %d --> nb_rb %d \n", frame_rx, subframe_rx, harq_pid, dlsch1->harq_processes[harq_pid]->nb_rb); @@ -3586,8 +3625,9 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, LOG_I(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[subframe_rx & 0x1][eNB_id]->num_pdcch_symbols); #endif +#if UE_TIMING_TRACE start_meas(&ue->dlsch_decoding_stats[subframe_rx&0x1]); - +#endif ret1 = dlsch_decoding(ue, pdsch_vars->llr[1], &ue->frame_parms, @@ -3598,13 +3638,15 @@ void ue_dlsch_procedures(PHY_VARS_UE *ue, harq_pid, pdsch==PDSCH?1:0, dlsch1->harq_processes[harq_pid]->TBS>256?1:0); - stop_meas(&ue->dlsch_decoding_stats[subframe_rx&0x1]); +#if UE_TIMING_TRACE + stop_meas(&ue->dlsch_decoding_stats[subframe_rx&0x1]); - LOG_D(PHY," --> Unscrambling for CW1 %5.3f\n", + printf(" --> 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", + 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)); +#endif } LOG_D(PHY," ------ end turbo decoder for AbsSubframe %d.%d ------ \n", frame_rx, subframe_rx); @@ -3790,17 +3832,21 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin #if T_TRACER T(T_UE_PHY_DL_TICK, T_INT(ue->Mod_id), T_INT(frame_rx%1024), T_INT(subframe_rx)); -#endif T(T_UE_PHY_INPUT_SIGNAL, T_INT(ue->Mod_id), T_INT(frame_rx%1024), T_INT(subframe_rx), T_INT(0), T_BUFFER(&ue->common_vars.rxdata[0][subframe_rx*ue->frame_parms.samples_per_tti], ue->frame_parms.samples_per_tti * 4)); +#endif // start timers - +#ifdef UE_DEBUG_TRACE LOG_D(PHY," ****** start RX-Chain for AbsSubframe %d.%d ****** \n", frame_rx%1024, subframe_rx); +#endif + +#if UE_TIMING_TRACE start_meas(&ue->phy_proc_rx[subframe_rx&0x1]); start_meas(&ue->generic_stat); +#endif pmch_flag = is_pmch_subframe(frame_rx,subframe_rx,&ue->frame_parms) ? 1 : 0; @@ -3857,7 +3903,9 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin LOG_D(PHY," ------ --> FFT/ChannelEst/PDCCH slot 0: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); for (; l<=l2; l++) { if (abstraction_flag == 0) { - start_meas(&ue->ofdm_demod_stats); +#if UE_TIMING_TRACE + start_meas(&ue->ofdm_demod_stats); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SLOT_FEP, VCD_FUNCTION_IN); slot_fep(ue, l, @@ -3866,7 +3914,9 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin 0, 0); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SLOT_FEP, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&ue->ofdm_demod_stats); +#endif } ue_measurement_procedures(l-1,ue,proc,eNB_id,(subframe_rx<<1),abstraction_flag,mode); @@ -3899,11 +3949,15 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin 0); // first slot has been processed (FFTs + Channel Estimation, PCFICH/PHICH/PDCCH) +#if UE_TIMING_TRACE stop_meas(&ue->generic_stat); - 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)); - LOG_D(PHY," ------ --> PDSCH ChannelComp/LLR slot 0: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); + printf("[SFN %d] Slot0: FFT + Channel Estimate + PCFICH/PHICH/PDCCH %5.2f \n",subframe_rx,ue->generic_stat.p_time/(cpuf*1000.0)); +#endif + LOG_D(PHY," ------ --> PDSCH ChannelComp/LLR slot 0: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); +#if UE_TIMING_TRACE start_meas(&ue->generic_stat); +#endif // do procedures for C-RNTI if (ue->dlsch[subframe_rx&0x1][eNB_id][0]->active == 1) { VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PDSCH_PROC, VCD_FUNCTION_IN); @@ -3971,7 +4025,9 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin 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) { - start_meas(&ue->ofdm_demod_stats); +#if UE_TIMING_TRACE + start_meas(&ue->ofdm_demod_stats); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SLOT_FEP, VCD_FUNCTION_IN); slot_fep(ue, l, @@ -3980,7 +4036,9 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin 0, 0); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SLOT_FEP, VCD_FUNCTION_OUT); - stop_meas(&ue->ofdm_demod_stats); +#if UE_TIMING_TRACE + stop_meas(&ue->ofdm_demod_stats); +#endif } ue_measurement_procedures(l-1,ue,proc,eNB_id,1+(subframe_rx<<1),abstraction_flag,mode); @@ -3999,10 +4057,11 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin 0); } } // not an S-subframe - +#if UE_TIMING_TRACE stop_meas(&ue->generic_stat); + printf("[SFN %d] Slot1: FFT + Channel Estimate + Pdsch Proc Slot0 %5.2f \n",subframe_rx,ue->generic_stat.p_time/(cpuf*1000.0)); +#endif - 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)); LOG_D(PHY," ------ end FFT/ChannelEst/PDCCH slot 1: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); if ( (subframe_rx == 0) && (ue->decode_MIB == 1)) @@ -4014,7 +4073,9 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin LOG_D(PHY," ------ --> PDSCH ChannelComp/LLR slot 0: AbsSubframe %d.%d ------ \n", frame_rx%1024, subframe_rx); if (ue->dlsch[subframe_rx&0x1][eNB_id][0]->active == 1) { VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PDSCH_PROC, VCD_FUNCTION_IN); +#if UE_TIMING_TRACE start_meas(&ue->pdsch_procedures_stat); +#endif ue_pdsch_procedures(ue, proc, eNB_id, @@ -4024,12 +4085,13 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin 1+(ue->frame_parms.symbols_per_tti>>1), ue->frame_parms.symbols_per_tti-1, abstraction_flag); - stop_meas(&ue->pdsch_procedures_stat); 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 UE_TIMING_TRACE + stop_meas(&ue->pdsch_procedures_stat); start_meas(&ue->dlsch_procedures_stat); +#endif ue_dlsch_procedures(ue, proc, eNB_id, @@ -4039,15 +4101,18 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin &ue->dlsch_errors[eNB_id], mode, abstraction_flag); +#if UE_TIMING_TRACE stop_meas(&ue->dlsch_procedures_stat); - 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)); + 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)); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PDSCH_PROC, VCD_FUNCTION_OUT); } - +#if UE_TIMING_TRACE start_meas(&ue->generic_stat); +#endif #if 0 if(subframe_rx==5 && ue->dlsch[subframe_rx&0x1][eNB_id][0]->harq_processes[ue->dlsch[subframe_rx&0x1][eNB_id][0]->current_harq_pid]->nb_rb > 20){ @@ -4175,8 +4240,10 @@ int phy_procedures_UE_RX(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,uin } +#if UE_TIMING_TRACE stop_meas(&ue->generic_stat); - //printf("after tubo until end of Rx %5.2f \n",ue->generic_stat.p_time/(cpuf*1000.0)); + printf("after tubo until end of Rx %5.2f \n",ue->generic_stat.p_time/(cpuf*1000.0)); +#endif #ifdef EMOS phy_procedures_emos_UE_RX(ue,slot,eNB_id); @@ -4184,9 +4251,10 @@ 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]); - - 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)); + printf("------FULL RX PROC [SFN %d]: %5.2f ------\n",subframe_rx,ue->phy_proc_rx[subframe_rx&0x1].p_time/(cpuf*1000.0)); +#endif LOG_D(PHY," ****** end RX-Chain for AbsSubframe %d.%d ****** \n", frame_rx%1024, subframe_rx); return (0); } @@ -4247,7 +4315,9 @@ void phy_procedures_UE_lte(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,u VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_LTE,1); +#if UE_TIMING_TRACE start_meas(&ue->phy_proc); +#endif #if defined(ENABLE_ITTI) do { @@ -4339,7 +4409,9 @@ void phy_procedures_UE_lte(PHY_VARS_UE *ue,UE_rxtx_proc_t *proc,uint8_t eNB_id,u } VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PHY_PROCEDURES_UE_LTE,0); +#if UE_TIMING_TRACE stop_meas(&ue->phy_proc); +#endif } // slot } diff --git a/openair2/LAYER2/MAC/ue_procedures.c b/openair2/LAYER2/MAC/ue_procedures.c index f9488ce5437d97169a94b90f1d9a39d9afe800fb..d7e779c607e80dfa844f2e6adf6e4e070aceadfb 100644 --- a/openair2/LAYER2/MAC/ue_procedures.c +++ b/openair2/LAYER2/MAC/ue_procedures.c @@ -345,8 +345,9 @@ ue_send_sdu( unsigned char rx_lcids[NB_RB_MAX]; unsigned short rx_lengths[NB_RB_MAX]; unsigned char *tx_sdu; - +#if UE_TIMING_TRACE start_meas(&UE_mac_inst[module_idP].rx_dlsch_sdu); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SEND_SDU, VCD_FUNCTION_IN); LOG_T(MAC,"sdu: %x.%x.%x\n",sdu[0],sdu[1],sdu[2]); @@ -504,13 +505,16 @@ ue_send_sdu( } // end if (payload_ptr != NULL) VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SEND_SDU, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].rx_dlsch_sdu); +#endif } void ue_decode_si(module_id_t module_idP,int CC_id,frame_t frameP, uint8_t eNB_index, void *pdu,uint16_t len) { - - start_meas(&UE_mac_inst[module_idP].rx_si); +#if UE_TIMING_TRACE + start_meas(&UE_mac_inst[module_idP].rx_si); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_DECODE_SI, VCD_FUNCTION_IN); LOG_D(MAC,"[UE %d] Frame %d Sending SI to RRC (LCID Id %d,len %d)\n",module_idP,frameP,BCCH,len); @@ -526,7 +530,9 @@ void ue_decode_si(module_id_t module_idP,int CC_id,frame_t frameP, uint8_t eNB_i eNB_index, 0); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_DECODE_SI, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].rx_si); +#endif if (opt_enabled == 1) { trace_pdu(0, (uint8_t *)pdu, @@ -545,8 +551,9 @@ void ue_decode_si(module_id_t module_idP,int CC_id,frame_t frameP, uint8_t eNB_i void ue_decode_p(module_id_t module_idP,int CC_id,frame_t frameP, uint8_t eNB_index, void *pdu,uint16_t len) { - - start_meas(&UE_mac_inst[module_idP].rx_p); +#if UE_TIMING_TRACE + start_meas(&UE_mac_inst[module_idP].rx_p); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_DECODE_PCCH, VCD_FUNCTION_IN); LOG_D(MAC,"[UE %d] Frame %d Sending Paging message to RRC (LCID Id %d,len %d)\n",module_idP,frameP,PCCH,len); @@ -562,7 +569,9 @@ void ue_decode_p(module_id_t module_idP,int CC_id,frame_t frameP, uint8_t eNB_in eNB_index, 0); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_DECODE_PCCH, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].rx_p); +#endif if (opt_enabled == 1) { trace_pdu(0, (uint8_t *)pdu, @@ -636,8 +645,9 @@ void ue_send_mch_sdu(module_id_t module_idP, uint8_t CC_id, frame_t frameP, uint unsigned char num_sdu, i, *payload_ptr; unsigned char rx_lcids[NB_RB_MAX]; unsigned short rx_lengths[NB_RB_MAX]; - +#if UE_TIMING_TRACE start_meas(&UE_mac_inst[module_idP].rx_mch_sdu); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SEND_MCH_SDU, VCD_FUNCTION_IN); LOG_D(MAC,"[UE %d] Frame %d : process the mch PDU for sync area %d \n",module_idP,frameP, sync_area); @@ -696,7 +706,9 @@ void ue_send_mch_sdu(module_id_t module_idP, uint8_t CC_id, frame_t frameP, uint } VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SEND_MCH_SDU, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].rx_mch_sdu); +#endif } int8_t ue_get_mbsfn_sf_alloction (module_id_t module_idP, uint8_t mbsfn_sync_area, unsigned char eNB_index) @@ -721,8 +733,9 @@ int ue_query_mch(module_id_t module_idP, uint8_t CC_id, uint32_t frameP, uint32_ int mbsfn_period = 0;// 1<<(UE_mac_inst[module_idP].mbsfn_SubframeConfig[0]->radioframeAllocationPeriod); int mcch_period = 0;// 32<<(UE_mac_inst[module_idP].mbsfn_AreaInfo[0]->mcch_Config_r9.mcch_RepetitionPeriod_r9); int mch_scheduling_period = -1; - +#if UE_TIMING_TRACE start_meas(&UE_mac_inst[module_idP].ue_query_mch); +#endif if (UE_mac_inst[module_idP].pmch_Config[0]) { mch_scheduling_period = 8<<(UE_mac_inst[module_idP].pmch_Config[0]->mch_SchedulingPeriod_r9); @@ -977,8 +990,9 @@ int ue_query_mch(module_id_t module_idP, uint8_t CC_id, uint32_t frameP, uint32_ } } } // end of for - +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].ue_query_mch); +#endif if ( (mcch_flag==1)) { // || (msi_flag==1)) *mcch_active=1; @@ -1302,8 +1316,9 @@ void ue_get_sdu(module_id_t module_idP,int CC_id,frame_t frameP,sub_frame_t subf mac_xface->macphy_exit("MAC FATAL CC_id>0"); return; } - +#if UE_TIMING_TRACE start_meas(&UE_mac_inst[module_idP].tx_ulsch_sdu); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_GET_SDU, VCD_FUNCTION_IN); #ifdef CBA @@ -1785,7 +1800,9 @@ for (lcid=DCCH; (lcid < MAX_NUM_LCID) && (is_all_lcid_processed == FALSE) ; lcid } VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_GET_SDU, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].tx_ulsch_sdu); +#endif if (opt_enabled) { trace_pdu(0, ulsch_buffer, buflen, module_idP, 3, UE_mac_inst[module_idP].crnti, UE_mac_inst[module_idP].txFrame, UE_mac_inst[module_idP].txSubframe, 0, 0); @@ -1829,7 +1846,9 @@ ue_scheduler( instance_t instance; int result; #endif +#if UE_TIMING_TRACE start_meas(&UE_mac_inst[module_idP].ue_scheduler); +#endif VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SCHEDULER, VCD_FUNCTION_IN); PROTOCOL_CTXT_SET_BY_MODULE_ID(&ctxt, module_idP, ENB_FLAG_NO, UE_mac_inst[module_idP].crnti, txFrameP, txSubframeP,eNB_indexP); @@ -1889,14 +1908,18 @@ ue_scheduler( case RRC_ConnSetup_failed: LOG_E(MAC,"RRCConnectionSetup failed, returning to IDLE state\n"); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SCHEDULER, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].ue_scheduler); +#endif return(CONNECTION_LOST); break; case RRC_PHY_RESYNCH: LOG_E(MAC,"RRC Loss of synch, returning PHY_RESYNCH\n"); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SCHEDULER, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].ue_scheduler); +#endif return(PHY_RESYNCH); case RRC_Handover_failed: @@ -1909,7 +1932,9 @@ ue_scheduler( case RRC_HO_STARTED: LOG_I(MAC,"RRC handover, Instruct PHY to start the contention-free PRACH and synchronization\n"); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SCHEDULER, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].ue_scheduler); +#endif return(PHY_HO_PRACH); default: @@ -1926,7 +1951,9 @@ ue_scheduler( } else { LOG_E(MAC,"FATAL: radioResourceConfigCommon is NULL!!!\n"); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SCHEDULER, VCD_FUNCTION_OUT); - stop_meas(&UE_mac_inst[module_idP].ue_scheduler); +#if UE_TIMING_TRACE + stop_meas(&UE_mac_inst[module_idP].ue_scheduler); +#endif mac_xface->macphy_exit(""); //return(RRC_OK); } @@ -2011,7 +2038,9 @@ ue_scheduler( UE_mac_inst[module_idP].ul_active=0; LOG_T(MAC,"[UE %d] Release all SRs \n", module_idP); VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SCHEDULER, VCD_FUNCTION_OUT); +#if UE_TIMING_TRACE stop_meas(&UE_mac_inst[module_idP].ue_scheduler); +#endif return(CONNECTION_OK); } @@ -2059,7 +2088,9 @@ ue_scheduler( //If the UE has UL resources allocated for new transmission for this TTI here: VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_UE_SCHEDULER, VCD_FUNCTION_OUT); - stop_meas(&UE_mac_inst[module_idP].ue_scheduler); +#if UE_TIMING_TRACE + stop_meas(&UE_mac_inst[module_idP].ue_scheduler); +#endif return(CONNECTION_OK); } diff --git a/openair2/UTIL/LOG/log.h b/openair2/UTIL/LOG/log.h index 3a67e85d3d9495e01ef3ec7ec35aa4e9a1cd1ced..eb6b88eca29c9080dad31e4d7fa7c55fe9afdfa4 100644 --- a/openair2/UTIL/LOG/log.h +++ b/openair2/UTIL/LOG/log.h @@ -315,16 +315,29 @@ void *log_thread_function(void * list); # define LOG_N(c, x...) /* */ # define LOG_F(c, x...) /* */ # else /* T_TRACER */ -# 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) -# define LOG_E(c, x...) logIt(c, LOG_ERR, x) -# define LOG_W(c, x...) logIt(c, LOG_WARNING, x) -# define LOG_N(c, x...) logIt(c, LOG_NOTICE, x) -# define LOG_I(c, x...) logIt(c, LOG_INFO, x) -# 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) +# if UE_NO_LOG +# define LOG_I(c, x...) /* */ +# define LOG_W(c, x...) /* */ +# define LOG_E(c, x...) /* */ +# define LOG_D(c, x...) /* */ +# define LOG_T(c, x...) /* */ +# define LOG_G(c, x...) /* */ +# define LOG_A(c, x...) /* */ +# define LOG_C(c, x...) /* */ +# define LOG_N(c, x...) /* */ +# define LOG_F(c, x...) /* */ +# else /*UE_NO_LOG*/ +# 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) +# define LOG_E(c, x...) logIt(c, LOG_ERR, x) +# define LOG_W(c, x...) logIt(c, LOG_WARNING, x) +# define LOG_N(c, x...) logIt(c, LOG_NOTICE, x) +# define LOG_I(c, x...) logIt(c, LOG_INFO, x) +# 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 /* T_TRACER */ #else /* USER_MODE */ # define LOG_G(c, x...) printk(x) @@ -408,7 +421,7 @@ 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]); - LOG_W(PHY,"%s",txt2); + printf("%s",txt2); } } diff --git a/targets/RT/USER/lte-ue.c b/targets/RT/USER/lte-ue.c index f07a0628f8979d6093ac92e8cabbbd81a0d4daff..5dd0e66da06e4d7f95f3c8d4793c1ad2e1242703 100644 --- a/targets/RT/USER/lte-ue.c +++ b/targets/RT/USER/lte-ue.c @@ -546,8 +546,9 @@ static void *UE_thread_rxn_txnp4(void *arg) { phy_procedures_UE_RX( UE, proc, 0, 0, UE->mode, no_relay, NULL ); } +#if UE_TIMING_TRACE start_meas(&UE->generic_stat); - +#endif if (UE->mac_enabled==1) { ret = mac_xface->ue_scheduler(UE->Mod_id, @@ -577,8 +578,9 @@ static void *UE_thread_rxn_txnp4(void *arg) { UE->Mod_id, proc->frame_rx, proc->subframe_tx,txt ); } } - +#if UE_TIMING_TRACE stop_meas(&UE->generic_stat); +#endif // Prepare the future Tx data