From 062d13a18f11dc8e9c34e56854d69b64dbfc07cb Mon Sep 17 00:00:00 2001 From: Lionel Gauthier <lionel.gauthier@eurecom.fr> Date: Tue, 25 Nov 2014 12:36:19 +0000 Subject: [PATCH] debug traces for uplink problem (missing packets with dongle bandluxe) git-svn-id: http://svn.eurecom.fr/openair4G/trunk@6102 818b1a75-f10b-46b9-bf7c-635c3b92a50f --- openair2/LAYER2/RLC/UM_v9.3.0/rlc_um.c | 27 ++- openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_dar.c | 163 ++++++++++++------ .../LAYER2/RLC/UM_v9.3.0/rlc_um_reassembly.c | 27 ++- .../LAYER2/RLC/UM_v9.3.0/rlc_um_receiver.c | 35 +--- 4 files changed, 148 insertions(+), 104 deletions(-) diff --git a/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um.c b/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um.c index b370122120..b31af2aee2 100755 --- a/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um.c +++ b/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um.c @@ -169,11 +169,12 @@ rlc_um_get_pdus (void *argP, frame_t frameP) break; default: - LOG_E(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] MAC_DATA_REQ UNKNOWN PROTOCOL STATE %02X hex\n", + LOG_E(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][%s %02d] MAC_DATA_REQ UNKNOWN PROTOCOL STATE %02X hex\n", frameP, (rlc_p->is_enb) ? "eNB" : "UE", rlc_p->enb_module_id, rlc_p->ue_module_id, + (rlc_p->is_data_plane) ? "DRB" : "SRB", rlc_p->rb_id, rlc_p->protocol_state); } @@ -256,11 +257,12 @@ rlc_um_rx (void *argP, frame_t frameP, eNB_flag_t eNB_flagP, struct mac_data_ind #ifdef TRACE_RLC_UM_PDU if (data_indP.data.nb_elements > 0) { - LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] MAC_DATA_IND %d TBs\n", + LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][%s %02d] MAC_DATA_IND %d TBs\n", frameP, (l_rlc_p->is_enb) ? "eNB" : "UE", l_rlc_p->enb_module_id, l_rlc_p->ue_module_id, + (l_rlc_p->is_data_plane) ? "DRB" : "SRB", l_rlc_p->rb_id, data_indP.data.nb_elements); @@ -351,11 +353,12 @@ rlc_um_rx (void *argP, frame_t frameP, eNB_flag_t eNB_flagP, struct mac_data_ind // - stays in the LOCAL_SUSPEND state; // - modifies only the protocol parameters and timers as indicated by // upper layers. - LOG_N(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] RLC_LOCAL_SUSPEND_STATE\n", + LOG_N(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][%s %02d] RLC_LOCAL_SUSPEND_STATE\n", frameP, (l_rlc_p->is_enb) ? "eNB" : "UE", l_rlc_p->enb_module_id, l_rlc_p->ue_module_id, + (l_rlc_p->is_data_plane) ? "DRB" : "SRB", l_rlc_p->rb_id); /*if (data_indP.data.nb_elements > 0) { LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] MAC_DATA_IND %d TBs\n", l_rlc_p->module_id, l_rlc_p->rb_id, frameP, data_indP.data.nb_elements); @@ -386,11 +389,12 @@ rlc_um_rx (void *argP, frame_t frameP, eNB_flag_t eNB_flagP, struct mac_data_ind break; default: - LOG_E(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] TX UNKNOWN PROTOCOL STATE %02X hex\n", + LOG_E(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][%s %02d] TX UNKNOWN PROTOCOL STATE %02X hex\n", frameP, (l_rlc_p->is_enb) ? "eNB" : "UE", l_rlc_p->enb_module_id, l_rlc_p->ue_module_id, + (l_rlc_p->is_data_plane) ? "DRB" : "SRB", l_rlc_p->rb_id, l_rlc_p->protocol_state); } @@ -449,30 +453,33 @@ rlc_um_mac_status_indication (void *rlc_pP, frame_t frameP, eNB_flag_t eNB_flagP status_resp.rlc_info.rlc_protocol_state = ((rlc_um_entity_t *) rlc_pP)->protocol_state; #ifdef DEBUG_RLC_UM_TX_STATUS if ((((rlc_um_entity_t *) rlc_pP)->rb_id > 0) && (status_resp.buffer_occupancy_in_bytes > 0)) { - LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] MAC_STATUS_INDICATION (DATA) %d bytes requested -> %d bytes available\n", + LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][%s %02d] MAC_STATUS_INDICATION (DATA) %d bytes requested -> %d bytes available\n", frameP, (rlc_p->is_enb) ? "eNB" : "UE", rlc_p->enb_module_id, rlc_p->ue_module_id, + (rlc_p->is_data_plane) ? "DRB" : "SRB", rlc_p->rb_id, tbs_sizeP, status_resp.buffer_occupancy_in_bytes); if ((tx_statusP.tx_status == MAC_TX_STATUS_SUCCESSFUL) && (tx_statusP.no_pdu)) { - LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] MAC_STATUS_INDICATION TX STATUS SUCCESSFUL %d PDUs\n", + LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][%s %02d] MAC_STATUS_INDICATION TX STATUS SUCCESSFUL %d PDUs\n", frameP, (rlc_p->is_enb) ? "eNB" : "UE", rlc_p->enb_module_id, rlc_p->ue_module_id, + (rlc_p->is_data_plane) ? "DRB" : "SRB", rlc_p->rb_id, tx_statusP.no_pdu); } if ((tx_statusP.tx_status == MAC_TX_STATUS_UNSUCCESSFUL) && (tx_statusP.no_pdu)) { - LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] MAC_STATUS_INDICATION TX STATUS UNSUCCESSFUL %d PDUs\n", + LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][%s %02d] MAC_STATUS_INDICATION TX STATUS UNSUCCESSFUL %d PDUs\n", frameP, (rlc_p->is_enb) ? "eNB" : "UE", rlc_p->enb_module_id, rlc_p->ue_module_id, + (rlc_p->is_data_plane) ? "DRB" : "SRB", rlc_p->rb_id, tx_statusP.no_pdu); } @@ -518,11 +525,12 @@ rlc_um_mac_data_request (void *rlc_pP,frame_t frameP) while (tb_p != NULL) { tb_size_in_bytes = ((struct mac_tb_req *) (tb_p->data))->tb_size; - LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] MAC_DATA_REQUEST TB SIZE %u\n", + LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][%s %02d] MAC_DATA_REQUEST TB SIZE %u\n", frameP, (l_rlc_p->is_enb) ? "eNB" : "UE", l_rlc_p->enb_module_id, l_rlc_p->ue_module_id, + (l_rlc_p->is_data_plane) ? "DRB" : "SRB", l_rlc_p->rb_id, ((struct mac_tb_req *) (tb_p->data))->tb_size); l_rlc_p->stat_tx_data_pdu += 1; @@ -625,11 +633,12 @@ rlc_um_data_req (void *rlc_pP, frame_t frameP, mem_block_t *sdu_pP) uint16_t data_size; #endif - LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][RB %02d] RLC_UM_DATA_REQ size %d Bytes, BO %d , NB SDU %d\n", + LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %02u/%02u][%s %02d] RLC_UM_DATA_REQ size %d Bytes, BO %d , NB SDU %d\n", frameP, (rlc_p->is_enb) ? "eNB" : "UE", rlc_p->enb_module_id, rlc_p->ue_module_id, + (rlc_p->is_data_plane) ? "DRB" : "SRB", rlc_p->rb_id, ((struct rlc_um_data_req *) (sdu_pP->data))->data_size, rlc_p->buffer_occupancy, diff --git a/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_dar.c b/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_dar.c index 5f264a8fb9..6aa29d3c9d 100644 --- a/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_dar.c +++ b/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_dar.c @@ -39,10 +39,8 @@ #include "MAC_INTERFACE/extern.h" #include "UTIL/LOG/log.h" -//#define TRACE_RLC_UM_DAR 1 -#define TRACE_RLC_UM_RX_DECODE +#define TRACE_RLC_UM_DAR 1 //#define TRACE_RLC_UM_RX 1 -//#define TRACE_DISPLAY_NVIDIA 1 //----------------------------------------------------------------------------- signed int rlc_um_get_pdu_infos( const frame_t frameP, @@ -184,11 +182,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e if (start_snP < 0) start_snP = start_snP + rlc_pP->rx_sn_modulo; #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY FROM PDU SN=%03d+1 TO PDU SN=%03d SN Length = %d bits\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY FROM PDU SN=%03d+1 TO PDU SN=%03d SN Length = %d bits\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->last_reassemblied_sn, end_snP, @@ -209,11 +208,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e if ((rlc_pP->last_reassemblied_sn+1)%rlc_pP->rx_sn_modulo != sn) { #if defined (TRACE_RLC_UM_DAR) - LOG_W(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] FINDING a HOLE in RLC UM SN: CLEARING OUTPUT SDU BECAUSE NEW SN (%03d) TO REASSEMBLY NOT CONTIGUOUS WITH LAST REASSEMBLIED SN (%03d)\n", + LOG_W(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] FINDING a HOLE in RLC UM SN: CLEARING OUTPUT SDU BECAUSE NEW SN (%03d) TO REASSEMBLY NOT CONTIGUOUS WITH LAST REASSEMBLIED SN (%03d)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn, rlc_pP->last_reassemblied_sn); @@ -224,11 +224,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e tb_ind_p = (struct mac_tb_ind *)(pdu_mem_p->data); if (rlc_pP->rx_sn_length == 10) { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY 10 PDU SN=%03d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY 10 PDU SN=%03d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn); #endif @@ -239,11 +240,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e data_p = &tb_ind_p->data_ptr[2]; } else { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY 5 PDU SN=%03d Byte 0=%02X\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY 5 PDU SN=%03d Byte 0=%02X\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn, ((rlc_um_pdu_sn_5_t*)(tb_ind_p->data_ptr))->b1); @@ -254,11 +256,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e size = tb_ind_p->size - 1; data_p = &tb_ind_p->data_ptr[1]; #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] e=%01X fi=%01X\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] e=%01X fi=%01X\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, e, fi); @@ -268,11 +271,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e switch (fi) { case RLC_FI_1ST_BYTE_DATA_IS_1ST_BYTE_SDU_LAST_BYTE_DATA_IS_LAST_BYTE_SDU: #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY PDU NO E_LI FI=11 (00)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY PDU NO E_LI FI=11 (00)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif // one complete SDU @@ -285,11 +289,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e break; case RLC_FI_1ST_BYTE_DATA_IS_1ST_BYTE_SDU_LAST_BYTE_DATA_IS_NOT_LAST_BYTE_SDU: #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY PDU NO E_LI FI=10 (01)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY PDU NO E_LI FI=10 (01)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif // one beginning segment of SDU in PDU @@ -300,11 +305,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e break; case RLC_FI_1ST_BYTE_DATA_IS_NOT_1ST_BYTE_SDU_LAST_BYTE_DATA_IS_LAST_BYTE_SDU: #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY PDU NO E_LI FI=01 (10)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY PDU NO E_LI FI=01 (10)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif // one last segment of SDU @@ -320,11 +326,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e break; case RLC_FI_1ST_BYTE_DATA_IS_NOT_1ST_BYTE_SDU_LAST_BYTE_DATA_IS_NOT_LAST_BYTE_SDU: #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY PDU NO E_LI FI=00 (11)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY PDU NO E_LI FI=00 (11)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif if (rlc_pP->reassembly_missing_sn_detected == 0) { @@ -332,11 +339,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e rlc_um_reassembly (data_p, size, rlc_pP,frameP); } else { #if defined (TRACE_RLC_UM_DAR) - LOG_W(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY PDU NO E_LI FI=00 (11) MISSING SN DETECTED\n", + LOG_W(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY PDU NO E_LI FI=00 (11) MISSING SN DETECTED\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif //LOG_D(RLC, "[MSC_NBOX][FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u][Missing SN detected][RLC_UM][MOD %u/%u][RB %u]\n", @@ -346,22 +354,24 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e rlc_pP->stat_rx_data_bytes_dropped += tb_ind_p->size; #if defined(RLC_STOP_ON_LOST_PDU) AssertFatal( rlc_pP->reassembly_missing_sn_detected == 1, - "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] MISSING PDU DETECTED\n", + "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] MISSING PDU DETECTED\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif } break; default: - AssertFatal( 0 , "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY SHOULD NOT GO HERE\n", + AssertFatal( 0 , "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY SHOULD NOT GO HERE\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); } } else { @@ -369,11 +379,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e switch (fi) { case RLC_FI_1ST_BYTE_DATA_IS_1ST_BYTE_SDU_LAST_BYTE_DATA_IS_LAST_BYTE_SDU: #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY PDU FI=11 (00) Li=", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY PDU FI=11 (00) Li=", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); for (i=0; i < num_li; i++) { @@ -399,11 +410,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e break; case RLC_FI_1ST_BYTE_DATA_IS_1ST_BYTE_SDU_LAST_BYTE_DATA_IS_NOT_LAST_BYTE_SDU: #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY PDU FI=10 (01) Li=", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY PDU FI=10 (01) Li=", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); for (i=0; i < num_li; i++) { LOG_D(RLC, "%d ",li_array[i]); @@ -426,11 +438,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e break; case RLC_FI_1ST_BYTE_DATA_IS_NOT_1ST_BYTE_SDU_LAST_BYTE_DATA_IS_LAST_BYTE_SDU: #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY PDU FI=01 (10) Li=", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY PDU FI=01 (10) Li=", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); for (i=0; i < num_li; i++) { LOG_D(RLC, "%d ",li_array[i]); @@ -461,11 +474,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e break; case RLC_FI_1ST_BYTE_DATA_IS_NOT_1ST_BYTE_SDU_LAST_BYTE_DATA_IS_NOT_LAST_BYTE_SDU: #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRY REASSEMBLY PDU FI=00 (11) Li=", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRY REASSEMBLY PDU FI=00 (11) Li=", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); for (i=0; i < num_li; i++) { LOG_D(RLC, "%d ",li_array[i]); @@ -474,11 +488,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e #endif if (rlc_pP->reassembly_missing_sn_detected) { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] DISCARD FIRST LI %d", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] DISCARD FIRST LI %d", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, li_array[0]); #endif @@ -499,11 +514,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e // data_p is already ok, done by last loop above rlc_um_reassembly (data_p, size, rlc_pP,frameP); } else { - AssertFatal( 0 !=0, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] SHOULD NOT GO HERE\n", + AssertFatal( 0 !=0, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] SHOULD NOT GO HERE\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); //rlc_pP->stat_rx_data_pdu_dropped += 1; rlc_pP->stat_rx_data_bytes_dropped += size; @@ -512,11 +528,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e break; default: #if defined (TRACE_RLC_UM_DAR) - LOG_W(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] Missing SN detected\n", + LOG_W(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] Missing SN detected\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif rlc_pP->stat_rx_data_pdu_dropped += 1; @@ -525,22 +542,24 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e rlc_pP->reassembly_missing_sn_detected = 1; #if defined(RLC_STOP_ON_LOST_PDU) AssertFatal( rlc_pP->reassembly_missing_sn_detected == 1, - "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] MISSING PDU DETECTED\n", + "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] MISSING PDU DETECTED\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif } } } #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] REMOVE PDU FROM DAR BUFFER SN=%03d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] REMOVE PDU FROM DAR BUFFER SN=%03d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn); #endif @@ -549,11 +568,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e } else { rlc_pP->last_reassemblied_missing_sn = sn; #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] Missing SN %04d detected, clearing RX SDU\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] Missing SN %04d detected, clearing RX SDU\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn); #endif @@ -561,11 +581,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e rlc_um_clear_rx_sdu(rlc_pP); #if defined(RLC_STOP_ON_LOST_PDU) AssertFatal( rlc_pP->reassembly_missing_sn_detected == 1, - "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] MISSING PDU DETECTED\n", + "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] MISSING PDU DETECTED\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif } @@ -575,11 +596,12 @@ void rlc_um_try_reassembly(rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t e } } #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TRIED REASSEMBLY VR(UR)=%03d VR(UX)=%03d VR(UH)=%03d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TRIED REASSEMBLY VR(UR)=%03d VR(UX)=%03d VR(UH)=%03d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->vr_ur, rlc_pP->vr_ux, @@ -592,11 +614,12 @@ void rlc_um_stop_and_reset_timer_reordering(rlc_um_entity_t *rlc_pP,frame_t fram //----------------------------------------------------------------------------- { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u][T-REORDERING] STOPPED AND RESET\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u][T-REORDERING] STOPPED AND RESET\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif rlc_pP->t_reordering.running = 0; @@ -613,11 +636,12 @@ void rlc_um_start_timer_reordering(rlc_um_entity_t *rlc_pP,frame_t frameP) rlc_pP->t_reordering.frame_start = frameP; rlc_pP->t_reordering.timed_out = 0; #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u][T-REORDERING] STARTED (TIME-OUT = FRAME %05u)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u][T-REORDERING] STARTED (TIME-OUT = FRAME %05u)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->t_reordering.frame_time_out); #endif @@ -666,44 +690,50 @@ void rlc_um_check_timer_dar_time_out(rlc_um_entity_t *rlc_pP, frame_t frameP, eN // -set VR(UX) to VR(UH). rlc_pP->stat_timer_reordering_timed_out += 1; #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u]*****************************************************\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u]*****************************************************\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u]* T I M E - O U T *\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u]* T I M E - O U T *\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u]*****************************************************\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u]*****************************************************\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] TIMER t-Reordering expiration\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] TIMER t-Reordering expiration\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] timer_reordering=%d frameP=%d expire frameP %d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] timer_reordering=%d frameP=%d expire frameP %d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->t_reordering.time_out, rlc_pP->t_reordering.frame_time_out, frameP); - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] set VR(UR)=%03d to", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] set VR(UR)=%03d to", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->vr_ur); #endif @@ -724,21 +754,23 @@ void rlc_um_check_timer_dar_time_out(rlc_um_entity_t *rlc_pP, frame_t frameP, eN rlc_um_start_timer_reordering(rlc_pP, frameP); rlc_pP->vr_ux = rlc_pP->vr_uh; #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] restarting t-Reordering set VR(UX) to %d (VR(UH)>VR(UR))\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] restarting t-Reordering set VR(UX) to %d (VR(UH)>VR(UR))\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->vr_ux); #endif } else { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] STOP t-Reordering VR(UX) = %03d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] STOP t-Reordering VR(UX) = %03d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->vr_ux); #endif @@ -754,11 +786,11 @@ rlc_um_remove_pdu_from_dar_buffer(rlc_um_entity_t *rlc_pP, rlc_usn_t snP) //----------------------------------------------------------------------------- mem_block_t * pdu_p = rlc_pP->dar_buffer[snP]; #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] REMOVE PDU FROM DAR BUFFER SN=%03d\n", - frameP, + LOG_D(RLC, "[FRAME ?????][%s][RLC_UM][MOD %u/%u][%s %u] REMOVE PDU FROM DAR BUFFER SN=%03d\n", (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, snP); #endif @@ -778,11 +810,12 @@ rlc_um_store_pdu_in_dar_buffer(rlc_um_entity_t *rlc_pP, frame_t frameP, mem_bloc { //----------------------------------------------------------------------------- #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] STORE PDU IN DAR BUFFER SN=%03d VR(UR)=%03d VR(UX)=%03d VR(UH)=%03d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] STORE PDU IN DAR BUFFER SN=%03d VR(UR)=%03d VR(UX)=%03d VR(UH)=%03d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, snP, rlc_pP->vr_ur, @@ -813,11 +846,12 @@ inline signed int rlc_um_in_window(rlc_um_entity_t *rlc_pP, frame_t frameP, rlc_ if ( lower_boundP > snP) { #ifdef TRACE_RLC_UM_RX - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] %d not in WINDOW[%03d:%03d] (SN<LOWER BOUND)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] %d not in WINDOW[%03d:%03d] (SN<LOWER BOUND)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn, lower_bound, @@ -827,11 +861,12 @@ inline signed int rlc_um_in_window(rlc_um_entity_t *rlc_pP, frame_t frameP, rlc_ } if ( higher_boundP < snP) { #ifdef TRACE_RLC_UM_RX - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] %d not in WINDOW[%03d:%03d] (SN>HIGHER BOUND) <=> %d not in WINDOW[%03d:%03d]\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] %d not in WINDOW[%03d:%03d] (SN>HIGHER BOUND) <=> %d not in WINDOW[%03d:%03d]\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn, lower_bound, @@ -845,11 +880,12 @@ inline signed int rlc_um_in_window(rlc_um_entity_t *rlc_pP, frame_t frameP, rlc_ if ( lower_boundP == snP) { if ( higher_boundP == snP) { #ifdef TRACE_RLC_UM_RX - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] %d in WINDOW[%03d:%03d] (SN=HIGHER BOUND=LOWER BOUND)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] %d in WINDOW[%03d:%03d] (SN=HIGHER BOUND=LOWER BOUND)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn, lower_bound, @@ -858,11 +894,12 @@ inline signed int rlc_um_in_window(rlc_um_entity_t *rlc_pP, frame_t frameP, rlc_ return 3; } #ifdef TRACE_RLC_UM_RX - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] %d in WINDOW[%03d:%03d] (SN=LOWER BOUND)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] %d in WINDOW[%03d:%03d] (SN=LOWER BOUND)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn, lower_bound, @@ -872,11 +909,12 @@ inline signed int rlc_um_in_window(rlc_um_entity_t *rlc_pP, frame_t frameP, rlc_ } if ( higher_boundP == snP) { #ifdef TRACE_RLC_UM_RX - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] %d in WINDOW[%03d:%03d] (SN=HIGHER BOUND)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] %d in WINDOW[%03d:%03d] (SN=HIGHER BOUND)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn, lower_bound, @@ -891,17 +929,18 @@ inline signed int rlc_um_in_window(rlc_um_entity_t *rlc_pP, frame_t frameP, rlc_ inline signed int rlc_um_in_reordering_window(rlc_um_entity_t *rlc_pP, frame_t frameP, rlc_sn_t snP) { //----------------------------------------------------------------------------- rlc_sn_t modulus = (signed int)rlc_pP->vr_uh - rlc_pP->rx_um_window_size; - + rlc_sn_t sn = snP; snP = (snP - modulus) % rlc_pP->rx_sn_modulo; if ( 0 <= snP) { if (snP < rlc_pP->rx_um_window_size) { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] %d IN REORDERING WINDOW[%03d:%03d[ SN %d IN [%03d:%03d[ VR(UR)=%03d VR(UH)=%03d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] %d IN REORDERING WINDOW[%03d:%03d[ SN %d IN [%03d:%03d[ VR(UR)=%03d VR(UH)=%03d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, snP, 0, @@ -917,11 +956,12 @@ inline signed int rlc_um_in_reordering_window(rlc_um_entity_t *rlc_pP, frame_t f } #if defined (TRACE_RLC_UM_DAR) if (modulus < 0) { - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] %d NOT IN REORDERING WINDOW[%03d:%03d[ SN %d NOT IN [%03d:%03d[ VR(UR)=%03d VR(UH)=%03d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] %d NOT IN REORDERING WINDOW[%03d:%03d[ SN %d NOT IN [%03d:%03d[ VR(UR)=%03d VR(UH)=%03d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, snP, modulus + 1024, @@ -932,11 +972,12 @@ inline signed int rlc_um_in_reordering_window(rlc_um_entity_t *rlc_pP, frame_t f rlc_pP->vr_ur, rlc_pP->vr_uh); } else { - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] %d NOT IN REORDERING WINDOW[%03d:%03d[ SN %d NOT IN [%03d:%03d[ VR(UR)=%03d VR(UH)=%03d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] %d NOT IN REORDERING WINDOW[%03d:%03d[ SN %d NOT IN [%03d:%03d[ VR(UR)=%03d VR(UH)=%03d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, snP, modulus, @@ -997,11 +1038,12 @@ rlc_um_receive_process_dar (rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t // rlc_um_in_window() returns 3 if higher_bound == sn == lower_bound if ((in_window == 1) || (in_window == 0)){ #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] RX PDU VR(UH) – UM_Window_Size) <= SN %d < VR(UR) -> GARBAGE\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] RX PDU VR(UH) – UM_Window_Size) <= SN %d < VR(UR) -> GARBAGE\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn); #endif @@ -1015,11 +1057,12 @@ rlc_um_receive_process_dar (rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t in_window = rlc_um_in_window(rlc_pP, frameP, rlc_pP->vr_ur, sn, rlc_pP->vr_uh); if (in_window == 0){ #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] RX PDU VR(UR) < SN %d < VR(UH) and RECEIVED BEFORE-> GARBAGE\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] RX PDU VR(UR) < SN %d < VR(UH) and RECEIVED BEFORE-> GARBAGE\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn); #endif @@ -1034,11 +1077,12 @@ rlc_um_receive_process_dar (rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t rlc_pP->stat_rx_data_pdus_duplicate += 1; rlc_pP->stat_rx_data_bytes_duplicate += tb_sizeP; #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] RX PDU SN %03d REMOVE OLD PDU BEFORE STORING NEW PDU\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] RX PDU SN %03d REMOVE OLD PDU BEFORE STORING NEW PDU\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn); #endif @@ -1059,11 +1103,12 @@ rlc_um_receive_process_dar (rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t // -set VR(UR) to (VR(UH) – UM_Window_Size); if (rlc_um_in_reordering_window(rlc_pP, frameP, sn) < 0) { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] RX PDU SN %d OUTSIDE REORDERING WINDOW VR(UH)=%d UM_Window_Size=%d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] RX PDU SN %d OUTSIDE REORDERING WINDOW VR(UH)=%d UM_Window_Size=%d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sn, rlc_pP->vr_uh, @@ -1083,11 +1128,12 @@ rlc_um_receive_process_dar (rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t if (rlc_um_in_reordering_window(rlc_pP, frameP, rlc_pP->vr_ur) < 0) { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] VR(UR) %d OUTSIDE REORDERING WINDOW SET TO VR(UH) – UM_Window_Size = %d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] VR(UR) %d OUTSIDE REORDERING WINDOW SET TO VR(UH) – UM_Window_Size = %d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->vr_ur, in_window); @@ -1120,11 +1166,12 @@ rlc_um_receive_process_dar (rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t in_window = rlc_um_in_reordering_window(rlc_pP, frameP, rlc_pP->vr_ux); if (in_window < 0) { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] STOP and RESET t-Reordering because VR(UX) falls outside of the reordering window and VR(UX)=%d is not equal to VR(UH)=%d -or- VR(UX) <= VR(UR)\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] STOP and RESET t-Reordering because VR(UX) falls outside of the reordering window and VR(UX)=%d is not equal to VR(UH)=%d -or- VR(UX) <= VR(UR)\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->vr_ux, rlc_pP->vr_uh); @@ -1137,11 +1184,12 @@ rlc_um_receive_process_dar (rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t in_window = rlc_um_in_window(rlc_pP, frameP, rlc_pP->vr_ur, rlc_pP->vr_ux, rlc_pP->vr_uh); if ((in_window == -2) || (in_window == 1)) { #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] STOP and RESET t-Reordering because VR(UX) falls outside of the reordering window and VR(UX)=%d is not equal to VR(UH)=%d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] STOP and RESET t-Reordering because VR(UX) falls outside of the reordering window and VR(UX)=%d is not equal to VR(UH)=%d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->vr_ux, rlc_pP->vr_uh); @@ -1160,11 +1208,12 @@ rlc_um_receive_process_dar (rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t rlc_um_start_timer_reordering(rlc_pP, frameP); rlc_pP->vr_ux = rlc_pP->vr_uh; #if defined (TRACE_RLC_UM_DAR) - LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][RB %u] RESTART t-Reordering set VR(UX) to VR(UH) =%d\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] RESTART t-Reordering set VR(UX) to VR(UH) =%d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->vr_ux); #endif diff --git a/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_reassembly.c b/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_reassembly.c index d2e7d6f8a3..ba02bf724f 100755 --- a/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_reassembly.c +++ b/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_reassembly.c @@ -61,11 +61,12 @@ rlc_um_reassembly (uint8_t * src_pP, int32_t lengthP, rlc_um_entity_t *rlc_pP, f //----------------------------------------------------------------------------- sdu_size_t sdu_max_size; - LOG_D(RLC, "[FRAME %5u][%s][RLC_UM][MOD %u/%u][RB %u][REASSEMBLY] reassembly() %d bytes %d bytes already reassemblied\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u][REASSEMBLY] reassembly() %d bytes %d bytes already reassemblied\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, lengthP, rlc_pP->output_sdu_size_to_write); @@ -93,46 +94,51 @@ rlc_um_reassembly (uint8_t * src_pP, int32_t lengthP, rlc_um_entity_t *rlc_pP, f rlc_pP->output_sdu_size_to_write += lengthP; #ifdef TRACE_RLC_UM_DISPLAY_ASCII_DATA rlc_pP->output_sdu_in_construction->data[rlc_pP->output_sdu_size_to_write] = 0; - LOG_T(RLC, "[FRAME %5u][%s][RLC_UM][MOD %u/%u][RB %u][REASSEMBLY] DATA :", + LOG_T(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u][REASSEMBLY] DATA :", frameP (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); rlc_util_print_hex_octets(RLC, (unsigned char*)rlc_pP->output_sdu_in_construction->data, rlc_pP->output_sdu_size_to_write); #endif } else { #if defined(STOP_ON_IP_TRAFFIC_OVERLOAD) - AssertFatal(0, "[FRAME %5u][%s][RLC_UM][MOD %u/%u][RB %u] RLC_UM_DATA_IND, SDU TOO BIG, DROPPED\n", + AssertFatal(0, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] RLC_UM_DATA_IND, SDU TOO BIG, DROPPED\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif - LOG_E(RLC, "[FRAME %5u][%s][RLC_UM][MOD %u/%u][RB %u][REASSEMBLY] [max_sdu size %d] ERROR SDU SIZE OVERFLOW SDU GARBAGED\n", + LOG_E(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u][REASSEMBLY] [max_sdu size %d] ERROR SDU SIZE OVERFLOW SDU GARBAGED\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, sdu_max_size); // erase SDU rlc_pP->output_sdu_size_to_write = 0; } } else { - LOG_E(RLC, "[FRAME %5u][%s][RLC_UM][MOD %u/%u][RB %u][REASSEMBLY]ERROR OUTPUT SDU IS NULL\n", + LOG_E(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u][REASSEMBLY]ERROR OUTPUT SDU IS NULL\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #if defined(STOP_ON_IP_TRAFFIC_OVERLOAD) - AssertFatal(0, "[FRAME %5u][%s][RLC_UM][MOD %u/%u][RB %u] RLC_UM_DATA_IND, SDU DROPPED, OUT OF MEMORY\n", + AssertFatal(0, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] RLC_UM_DATA_IND, SDU DROPPED, OUT OF MEMORY\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); #endif } @@ -145,11 +151,12 @@ rlc_um_send_sdu (rlc_um_entity_t *rlc_pP,frame_t frameP, eNB_flag_t eNB_flagP) //----------------------------------------------------------------------------- if ((rlc_pP->output_sdu_in_construction)) { - LOG_D(RLC, "[FRAME %5u][%s][RLC_UM][MOD %u/%u][RB %u] SEND_SDU to upper layers %d bytes sdu %p\n", + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] SEND_SDU to upper layers %d bytes sdu %p\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->output_sdu_size_to_write, rlc_pP->output_sdu_in_construction); @@ -160,11 +167,12 @@ rlc_um_send_sdu (rlc_um_entity_t *rlc_pP,frame_t frameP, eNB_flag_t eNB_flagP) #ifdef TEST_RLC_UM #ifdef TRACE_RLC_UM_DISPLAY_ASCII_DATA rlc_pP->output_sdu_in_construction->data[rlc_pP->output_sdu_size_to_write] = 0; - LOG_T(RLC, "[FRAME %5u][%s][RLC_UM][MOD %u/%u][RB %u][SEND_SDU] DATA :", + LOG_T(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u][SEND_SDU] DATA :", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); rlc_util_print_hex_octets(RLC, rlc_pP->output_sdu_in_construction->data, rlc_pP->output_sdu_size_to_write); #endif @@ -184,11 +192,12 @@ rlc_um_send_sdu (rlc_um_entity_t *rlc_pP,frame_t frameP, eNB_flag_t eNB_flagP) #endif rlc_pP->output_sdu_in_construction = NULL; } else { - LOG_E(RLC, "[FRAME %5u][%s][RLC_UM][MOD %u/%u][RB %u][SEND_SDU] ERROR SIZE <= 0 ... DO NOTHING, SET SDU SIZE TO 0\n", + LOG_E(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u][SEND_SDU] ERROR SIZE <= 0 ... DO NOTHING, SET SDU SIZE TO 0\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id); } rlc_pP->output_sdu_size_to_write = 0; diff --git a/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_receiver.c b/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_receiver.c index 02f3b9849e..f8f2e6188b 100755 --- a/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_receiver.c +++ b/openair2/LAYER2/RLC/UM_v9.3.0/rlc_um_receiver.c @@ -39,38 +39,12 @@ #include "MAC_INTERFACE/extern.h" #include "UTIL/LOG/log.h" -#define DEBUG_RLC_UM_DISPLAY_TB_DATA -#define DEBUG_RLC_UM_RX +//#define DEBUG_RLC_UM_RX 1 //----------------------------------------------------------------------------- void rlc_um_display_rx_window(rlc_um_entity_t *rlc_pP) //----------------------------------------------------------------------------- { -/* - * - * #define RLC_FG_COLOR_BLACK "\e[0;30m30:" -#define RLC_FG_COLOR_RED "\e[0;31m31:" -#define RLC_FG_COLOR_GREEN "\e[0;32m32:" -#define RLC_FG_COLOR_ORANGE "\e[0;33m33:" -#define RLC_FG_COLOR_BLUE "\e[0;34m34:" -#define RLC_FG_COLOR_MAGENTA "\e[0;35m35:" -#define RLC_FG_COLOR_CYAN "\e[0;36m36:" -#define RLC_FG_COLOR_GRAY_BLACK "\e[0;37m37:" -#define RLC_FG_COLOR_DEFAULT "\e[0;39m39:" -#define RLC_FG_BRIGHT_COLOR_DARK_GRAY "\e[1;30m30:" -#define RLC_FG_BRIGHT_COLOR_RED "\e[1;31m31:" -#define RLC_FG_BRIGHT_COLOR_GREEN "\e[1;32m32:" -#define RLC_FG_BRIGHT_COLOR_YELLOW "\e[1;33m33:" -#define RLC_FG_BRIGHT_COLOR_BLUE "\e[1;34m34:" -#define RLC_FG_BRIGHT_COLOR_MAGENTA "\e[1;35m35:" -#define RLC_FG_BRIGHT_COLOR_CYAN "\e[1;36m36:" -#define RLC_FG_BRIGHT_COLOR_WHITE "\e[1;37m37:" -#define RLC_FG_BRIGHT_COLOR_DEFAULT "\e[0;39m39:" -#define RLC_REVERSE_VIDEO "\e[7m" -#define RLC_NORMAL_VIDEO "\e[27m]" - - * - */ unsigned long sn = 0; unsigned long end_sn = 0; char str[4]; @@ -163,16 +137,19 @@ rlc_um_receive (rlc_um_entity_t *rlc_pP, frame_t frameP, eNB_flag_t eNB_flagP, s if (tb_size_in_bytes > 0) { rlc_um_receive_process_dar (rlc_pP, frameP, eNB_flagP, tb_p, (rlc_um_pdu_sn_10_t *)first_byte_p, tb_size_in_bytes); - LOG_D(RLC, "[FRAME %05d][%s][RLC_UM][MOD %u/%u][RB %u] VR(UR)=%03d VR(UX)=%03d VR(UH)=%03d\n", +#if defined(DEBUG_RLC_UM_RX) + LOG_D(RLC, "[FRAME %05u][%s][RLC_UM][MOD %u/%u][%s %u] VR(UR)=%03d VR(UX)=%03d VR(UH)=%03d\n", frameP, (rlc_pP->is_enb) ? "eNB" : "UE", rlc_pP->enb_module_id, rlc_pP->ue_module_id, + (rlc_pP->is_data_plane) ? "DRB" : "SRB", rlc_pP->rb_id, rlc_pP->vr_ur, rlc_pP->vr_ux, rlc_pP->vr_uh); - rlc_um_display_rx_window(rlc_pP); + //rlc_um_display_rx_window(rlc_pP); comented because bad display +#endif } } } -- GitLab