nr-ip-over-LTE: Resolved issue with duplicate IP packet at the receiver UE IP...

nr-ip-over-LTE: Resolved issue with duplicate IP packet at the receiver UE IP interface and packet losses are reduced. Remaining to identify why occasionally IP packets are received at the PDCP stack later than the time slot of their arrival at PHY/MAC. Introduced some debug logs, to be removed later.

executables/nr-ue.c

@@ -382,16 +382,18 @@ void processSlotRX( PHY_VARS_NR_UE *UE, UE_nr_rxtx_proc_t *proc) {
     LOG_D(PHY,"phy_procedures_nrUE_RX: slot:%d, time %lu\n", proc->nr_tti_rx, (rdtsc()-a)/3500);
     //printf(">>> nr_ue_pdcch_procedures ended\n");
 #endif
-  }
-
-  if(IS_SOFTMODEM_NOS1){
+  if(IS_SOFTMODEM_NOS1){ //&& proc->nr_tti_rx==1
 	  //Hardcoded rnti value
 	  protocol_ctxt_t ctxt;
 	  PROTOCOL_CTXT_SET_BY_MODULE_ID(&ctxt, UE->Mod_id, ENB_FLAG_NO,
                                    0x1234, proc->frame_rx,
                                    proc->nr_tti_rx, 0);
-	  pdcp_run(&ctxt);
+	  //pdcp_run(&ctxt);
+          pdcp_fifo_flush_sdus(&ctxt);
   }
+  }
+
+  
   // no UL for now
   /*
   if (UE->mac_enabled==1) {
@@ -744,7 +746,7 @@ void *UE_thread(void *arg) {
     msgToPush->key=slot_nr;
     pushTpool(Tpool, msgToPush);
 
-    if (getenv("RFSIMULATOR")) {
+    if (getenv("RFSIMULATOR") || IS_SOFTMODEM_NOS1) {  //getenv("RFSIMULATOR")
       // FixMe: Wait previous thread is done, because race conditions seems too bad
       // in case of actual RF board, the overlap between threads mitigate the issue
       // We must receive one message, that proves the slot processing is done

openair1/PHY/NR_UE_ESTIMATION/nr_dl_channel_estimation.c

@@ -645,7 +645,7 @@ int nr_pdcch_channel_estimation(PHY_VARS_NR_UE *ue,
           for (p=0; p<ue->frame_parms.nb_antenna_ports_eNB; p++) {
               if (ue->pdcch_vars[ue->current_thread_id[Ns]][eNB_offset]->dl_ch_estimates[(p<<1)+aarx])
               {
-		LOG_I(PHY,"Channel Impulse Computation Slot %d ThreadId %d Symbol %d \n", Ns, ue->current_thread_id[Ns], symbol);
+		LOG_D(PHY,"Channel Impulse Computation Slot %d ThreadId %d Symbol %d \n", Ns, ue->current_thread_id[Ns], symbol);
 		idft((int16_t*) &ue->pdcch_vars[ue->current_thread_id[Ns]][eNB_offset]->dl_ch_estimates[(p<<1)+aarx][0],
 		     (int16_t*) ue->pdcch_vars[ue->current_thread_id[Ns]][eNB_offset]->dl_ch_estimates_time[(p<<1)+aarx],1);
               }

openair1/PHY/NR_UE_TRANSPORT/nr_dlsch_decoding.c

@@ -574,7 +574,7 @@ uint32_t nr_dlsch_decoding(PHY_VARS_NR_UE *phy_vars_ue,
 
 
     if ((err_flag == 0) && (ret>=(1+dlsch->max_ldpc_iterations))) {// a Code segment is in error so break;
-      LOG_I(PHY,"AbsSubframe %d.%d CRC failed, segment %d/%d \n",frame%1024,nr_tti_rx,r,harq_process->C-1);
+      LOG_D(PHY,"AbsSubframe %d.%d CRC failed, segment %d/%d \n",frame%1024,nr_tti_rx,r,harq_process->C-1);
       err_flag = 1;
     }
   }

openair1/SCHED_NR_UE/fapi_nr_ue_l1.c

@@ -217,17 +217,17 @@ int8_t nr_ue_phy_config_request(nr_phy_config_t *phy_config){
   
   if(phy_config != NULL){
     if(phy_config->config_req.config_mask & FAPI_NR_CONFIG_REQUEST_MASK_PBCH){
-      LOG_I(MAC,"[L1][IF module][PHY CONFIG]\n");
-      LOG_I(MAC,"subcarrier spacing:          %d\n", phy_config->config_req.pbch_config.subcarrier_spacing_common);
-      LOG_I(MAC,"ssb carrier offset:          %d\n", phy_config->config_req.pbch_config.ssb_subcarrier_offset);
-      LOG_I(MAC,"dmrs type A position:        %d\n", phy_config->config_req.pbch_config.dmrs_type_a_position);
-      LOG_I(MAC,"pdcch config sib1:           %d\n", phy_config->config_req.pbch_config.pdcch_config_sib1);
-      LOG_I(MAC,"cell barred:                 %d\n", phy_config->config_req.pbch_config.cell_barred);
-      LOG_I(MAC,"intra frequency reselection: %d\n", phy_config->config_req.pbch_config.intra_frequency_reselection);
-      LOG_I(MAC,"system frame number:         %d\n", phy_config->config_req.pbch_config.system_frame_number);
-      LOG_I(MAC,"ssb index:                   %d\n", phy_config->config_req.pbch_config.ssb_index);
-      LOG_I(MAC,"half frame bit:              %d\n", phy_config->config_req.pbch_config.half_frame_bit);
-      LOG_I(MAC,"-------------------------------\n");
+      LOG_D(MAC,"[L1][IF module][PHY CONFIG]\n");
+      LOG_D(MAC,"subcarrier spacing:          %d\n", phy_config->config_req.pbch_config.subcarrier_spacing_common);
+      LOG_D(MAC,"ssb carrier offset:          %d\n", phy_config->config_req.pbch_config.ssb_subcarrier_offset);
+      LOG_D(MAC,"dmrs type A position:        %d\n", phy_config->config_req.pbch_config.dmrs_type_a_position);
+      LOG_D(MAC,"pdcch config sib1:           %d\n", phy_config->config_req.pbch_config.pdcch_config_sib1);
+      LOG_D(MAC,"cell barred:                 %d\n", phy_config->config_req.pbch_config.cell_barred);
+      LOG_D(MAC,"intra frequency reselection: %d\n", phy_config->config_req.pbch_config.intra_frequency_reselection);
+      LOG_D(MAC,"system frame number:         %d\n", phy_config->config_req.pbch_config.system_frame_number);
+      LOG_D(MAC,"ssb index:                   %d\n", phy_config->config_req.pbch_config.ssb_index);
+      LOG_D(MAC,"half frame bit:              %d\n", phy_config->config_req.pbch_config.half_frame_bit);
+      LOG_D(MAC,"-------------------------------\n");
 
       memcpy(&nrUE_config.pbch_config,&phy_config->config_req.pbch_config,sizeof(fapi_nr_pbch_config_t));
       

openair1/SCHED_NR_UE/phy_procedures_nr_ue.c

@@ -4336,7 +4336,7 @@ int phy_procedures_nrUE_RX(PHY_VARS_NR_UE *ue,
   // looking for pbch only in slot where it is supposed to be
   if ((ue->decode_MIB == 1) && slot_pbch)
     {
-      LOG_I(PHY," ------  PBCH ChannelComp/LLR: frame.slot %d.%d ------  \n", frame_rx%1024, nr_tti_rx);
+      LOG_D(PHY," ------  PBCH ChannelComp/LLR: frame.slot %d.%d ------  \n", frame_rx%1024, nr_tti_rx);
 
       for (int i=1; i<4; i++) {
 

openair2/LAYER2/NR_MAC_UE/nr_ue_procedures.c

@@ -228,7 +228,7 @@ int8_t nr_ue_decode_mib(
 	void 		*pduP,
     uint16_t    cell_id ){
 
-    LOG_I(MAC,"[L2][MAC] decode mib\n");
+    LOG_D(MAC,"[L2][MAC] decode mib\n");
 
 	NR_UE_MAC_INST_t *mac = get_mac_inst(module_id);
 
@@ -2387,15 +2387,15 @@ nr_ue_send_sdu(module_id_t module_idP,
 #endif
 	    if ((rx_lcids[i] < NB_RB_MAX) && (rx_lcids[i] > DCCH1)) {
 
-		LOG_I(MAC,
+		LOG_D(MAC,
 		      "[UE %d] Frame %d : DLSCH -> DL-DTCH%d (eNB %d, %d bytes)\n",
 		      module_idP, frameP, rx_lcids[i], eNB_index,
 		      rx_lengths[i]);
 
 #if defined(ENABLE_MAC_PAYLOAD_DEBUG)
-		LOG_I(MAC, "Printing MAC PDU contents \n");
+		LOG_I(MAC, "Printing MAC PDU contents at slot: %d \n", subframeP);
 		int j;
-		for (j = 0; j < 10; j++) //rx_lengths[i]
+		for (j = 0; j < 20; j++) //rx_lengths[i]
 			LOG_I(MAC, "%x.", (unsigned char) payload_ptr[j]);
 		LOG_I(MAC, "\n");
 #endif

openair2/LAYER2/NR_MAC_gNB/gNB_scheduler_phytest.c

@@ -285,6 +285,11 @@ int configure_fapi_dl_Tx(nfapi_nr_dl_config_request_body_t *dl_req,
 }
 
 
+
+
+
+
+
 void nr_schedule_uss_dlsch_phytest(module_id_t   module_idP,
                                    frame_t       frameP,
                                    sub_frame_t   slotP)
@@ -430,7 +435,7 @@ void nr_schedule_uss_dlsch_phytest(module_id_t   module_idP,
     		post_padding = 1;
     	}
 
-    	offset = generate_dlsch_header((unsigned char *) DLSCH_pdu.payload[0],
+    	offset = generate_dlsch_header((unsigned char *)nr_mac->UE_list.DLSCH_pdu[CC_id][0][0].payload[0], //DLSCH_pdu.payload[0],
     	        		num_sdus,    //num_sdus
     	        		sdu_lengths,    //
     	        		sdu_lcids, 255,    // no drx
@@ -442,20 +447,17 @@ void nr_schedule_uss_dlsch_phytest(module_id_t   module_idP,
     	// Probably there should be other actions done before that
     	// cycle through SDUs and place in dlsch_buffer
 
-    	// Since we do not have an active UE_list for now we replace with a single DLSCH_pdu
     	//memcpy(&UE_list->DLSCH_pdu[CC_id][0][UE_id].payload[0][offset], dlsch_buffer, sdu_length_total);
-    	memcpy(&DLSCH_pdu.payload[0][offset], dlsch_buffer, sdu_length_total);
+        memcpy(&nr_mac->UE_list.DLSCH_pdu[CC_id][0][UE_id].payload[0][offset], dlsch_buffer, sdu_length_total);
+          
 
     	// fill remainder of DLSCH with 0
     	for (int j = 0; j < (TBS - sdu_length_total - offset); j++) {
-    		// Since we do not have an active UE_list for now we replace with a single DLSCH_pdu
     		//UE_list->DLSCH_pdu[CC_id][0][UE_id].payload[0][offset + sdu_length_total + j] = 0;
-    		DLSCH_pdu.payload[0][offset + sdu_length_total + j] = 0;
+                nr_mac->UE_list.DLSCH_pdu[CC_id][0][0].payload[0][offset + sdu_length_total + j] = 0;
     	}
 
-    	TBS_bytes = configure_fapi_dl_Tx(dl_req, TX_req, cfg, &nr_mac->coreset[CC_id][1], &nr_mac->search_space[CC_id][1], nr_mac->pdu_index[CC_id]);
-
-    	memcpy(nr_mac->UE_list.DLSCH_pdu[CC_id][0][0].payload[0],DLSCH_pdu.payload[0],TBS_bytes);
+    	TBS_bytes = configure_fapi_dl_Tx(dl_req, TX_req, cfg, &nr_mac->coreset[CC_id][1], &nr_mac->search_space[CC_id][1], nr_mac->pdu_index[CC_id]);        
 
     	LOG_I(MAC, "Printing first 10 payload bytes at the gNB side, Frame: %d, slot: %d, , TBS size: %d \n \n", frameP, slotP, TBS_bytes);
     	  for(int i = 0; i < 10; i++) { // TBS_bytes dlsch_pdu_rel15->transport_block_size/8 6784/8
@@ -504,3 +506,5 @@ void nr_schedule_uss_dlsch_phytest(module_id_t   module_idP,
 	  }
   } //for (CC_id=0; CC_id<MAX_NUM_CCs; CC_id++)
 }
+
+

openair2/LAYER2/PDCP_v10.1.0/pdcp.c

@@ -528,6 +528,8 @@ pdcp_data_ind(
   VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_PDCP_DATA_IND,VCD_FUNCTION_IN);
   LOG_DUMPMSG(PDCP,DEBUG_PDCP,(char *)sdu_buffer_pP->data,sdu_buffer_sizeP,
               "[MSG] PDCP UL %s PDU on rb_id %d\n", (srb_flagP)? "CONTROL" : "DATA", rb_idP);
+
+
 #if T_TRACER
 
   if (ctxt_pP->enb_flag != ENB_FLAG_NO)
@@ -1050,6 +1052,11 @@ pdcp_data_ind(
       memcpy(&new_sdu_p->data[sizeof (pdcp_data_ind_header_t)],
              &sdu_buffer_pP->data[payload_offset],
              sdu_buffer_sizeP - payload_offset);
+      
+      LOG_I(PDCP, "Printing PDCP SDU before adding it to the list: \n");
+      for (int i=0; i<30; i++){
+    	  LOG_I(PDCP, "%x", sdu_buffer_pP->data[i]);
+      }
       list_add_tail_eurecom (new_sdu_p, sdu_list_p);
     }
 

openair2/LAYER2/PDCP_v10.1.0/pdcp_fifo.c

@@ -135,6 +135,10 @@ int pdcp_fifo_flush_sdus(const protocol_ctxt_t *const  ctxt_pP) {
     }  //  PDCP_USE_NETLINK
 
     AssertFatal(ret >= 0,"[PDCP_FIFOS] pdcp_fifo_flush_sdus (errno: %d %s)\n", errno, strerror(errno));
+    LOG_I(PDCP, "Printing PDCP SDU before removing it from the list: \n");
+      for (int i=0; i<30; i++){
+    	  LOG_I(PDCP, "%x", sdu_p->data[i]);
+      }
     list_remove_head (&pdcp_sdu_list);
     free_mem_block (sdu_p, __func__);
     pdcp_nb_sdu_sent ++;

openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_dar.c

@@ -723,10 +723,10 @@ void rlc_um_check_timer_dar_time_out(
   signed int     in_window;
   rlc_usn_t      old_vr_ur;
 
-
   VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_RLC_UM_CHECK_TIMER_DAR_TIME_OUT,VCD_FUNCTION_IN);
 
   if ((rlc_pP->t_reordering.running)) {
+    //LOG_I(RLC, "[rlc_um_check_timer_dar_time_out] 2 \n");
     if (
       // CASE 1:          start              time out
       //        +-----------+------------------+----------+
@@ -787,6 +787,7 @@ void rlc_um_check_timer_dar_time_out(
         LOG_D(RLC, " %d", rlc_pP->vr_ur);
         LOG_D(RLC, "\n");
 #endif
+        LOG_I(RLC, "[rlc_um_check_timer_dar_time_out] 3 \n");
         rlc_um_try_reassembly(ctxt_pP, rlc_pP ,old_vr_ur, rlc_pP->vr_ur);
 
         in_window = rlc_um_in_window(ctxt_pP, rlc_pP, rlc_pP->vr_ur,  rlc_pP->vr_uh,  rlc_pP->vr_uh);
@@ -1039,6 +1040,7 @@ rlc_um_receive_process_dar (
   } else {
     free_mem_block(pdu_mem_pP, __func__);
     pdu_mem_pP = NULL;
+    //LOG_I(RLC, "[rlc_um_receive_process_dar] Problematic case 1 \n");
     return;
   }
 
@@ -1065,6 +1067,7 @@ rlc_um_receive_process_dar (
     rlc_pP->stat_rx_data_pdu_out_of_window   += 1;
     rlc_pP->stat_rx_data_bytes_out_of_window += tb_sizeP;
     free_mem_block(pdu_mem_pP, __func__);
+    //LOG_I(RLC, "[rlc_um_receive_process_dar] Problematic case 2 \n");
     pdu_mem_pP = NULL;
     RLC_UM_MUTEX_UNLOCK(&rlc_pP->lock_dar_buffer);
     VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_RLC_UM_RECEIVE_PROCESS_DAR, VCD_FUNCTION_OUT);
@@ -1083,6 +1086,7 @@ rlc_um_receive_process_dar (
       //discard the PDU
       rlc_pP->stat_rx_data_pdus_duplicate  += 1;
       rlc_pP->stat_rx_data_bytes_duplicate += tb_sizeP;
+      //LOG_I(RLC, "[rlc_um_receive_process_dar] Problematic case 3 \n");
       free_mem_block(pdu_mem_pP, __func__);
       pdu_mem_pP = NULL;
       RLC_UM_MUTEX_UNLOCK(&rlc_pP->lock_dar_buffer);
@@ -1115,6 +1119,7 @@ rlc_um_receive_process_dar (
   //      -if VR(UR) falls outside of the reordering window:
   //          -set VR(UR) to (VR(UH) – UM_Window_Size);
   if (rlc_um_in_reordering_window(ctxt_pP, rlc_pP, sn) < 0) {
+    LOG_I(RLC, "[rlc_um_receive_process_dar] Before calling rlc_um_try_reassembly() 1 \n");
 #if TRACE_RLC_UM_DAR
     LOG_D(RLC, PROTOCOL_RLC_UM_CTXT_FMT" RX PDU  SN %d OUTSIDE REORDERING WINDOW VR(UH)=%d UM_Window_Size=%d\n",
           PROTOCOL_RLC_UM_CTXT_ARGS(ctxt_pP, rlc_pP),
@@ -1130,12 +1135,13 @@ rlc_um_receive_process_dar (
       if (in_window < 0) {
         in_window = in_window + rlc_pP->rx_sn_modulo;
       }
-
+      LOG_I(RLC, "[rlc_um_receive_process_dar] Before calling rlc_um_try_reassembly() 2 \n");
       rlc_um_try_reassembly(ctxt_pP, rlc_pP, rlc_pP->vr_ur, in_window);
     }
 
 
     if (rlc_um_in_reordering_window(ctxt_pP, rlc_pP, rlc_pP->vr_ur) < 0) {
+     //LOG_I(RLC, "[rlc_um_receive_process_dar] Problematic case 4 \n");
 #if TRACE_RLC_UM_DAR
       LOG_D(RLC, PROTOCOL_RLC_UM_CTXT_FMT" VR(UR) %d OUTSIDE REORDERING WINDOW SET TO VR(UH) – UM_Window_Size = %d\n",
             PROTOCOL_RLC_UM_CTXT_ARGS(ctxt_pP, rlc_pP),
@@ -1154,13 +1160,18 @@ rlc_um_receive_process_dar (
   //          SDUs to upper layer in ascending order of the RLC SN if not
   //          delivered before;
   if ((sn == rlc_pP->vr_ur) && rlc_um_get_pdu_from_dar_buffer(ctxt_pP, rlc_pP, rlc_pP->vr_ur)) {
+    LOG_I(RLC, "[rlc_um_receive_process_dar] Before calling rlc_um_try_reassembly() 3 \n");
     //sn_tmp = rlc_pP->vr_ur;
     do {
       rlc_pP->vr_ur = (rlc_pP->vr_ur+1) % rlc_pP->rx_sn_modulo;
     } while (rlc_um_get_pdu_from_dar_buffer(ctxt_pP, rlc_pP, rlc_pP->vr_ur) && (rlc_pP->vr_ur != rlc_pP->vr_uh));
-
+    LOG_I(RLC, "[rlc_um_receive_process_dar] Before calling rlc_um_try_reassembly() 4 \n");
     rlc_um_try_reassembly(ctxt_pP, rlc_pP, sn, rlc_pP->vr_ur);
   }
+  else if (sn != rlc_pP->vr_ur)
+   LOG_I(RLC, "[rlc_um_receive_process_dar] Problematic case 5, sn: %d, rlc_pP->vr_ur: %d \n",sn, rlc_pP->vr_ur);
+  else if(!rlc_um_get_pdu_from_dar_buffer(ctxt_pP, rlc_pP, rlc_pP->vr_ur))
+   //LOG_I(RLC, "[rlc_um_receive_process_dar] Problematic case 6 \n");   
 
   // -if t-Reordering is running:
   //      -if VR(UX) <= VR(UR); or