diff --git a/lib/src/pdcp/pdcp_entity_nr.cc b/lib/src/pdcp/pdcp_entity_nr.cc index d4510b9e7..306fbac75 100644 --- a/lib/src/pdcp/pdcp_entity_nr.cc +++ b/lib/src/pdcp/pdcp_entity_nr.cc @@ -200,6 +200,15 @@ void pdcp_entity_nr::write_pdu(unique_byte_buffer_t pdu) uint32_t rcvd_sn = read_data_header(pdu); // Calculate RCVD_COUNT + /* + *- if RCVD_SN < SN(RX_DELIV) – Window_Size: + * - RCVD_HFN = HFN(RX_DELIV) + 1. + *- else if RCVD_SN >= SN(RX_DELIV) + Window_Size: + * - RCVD_HFN = HFN(RX_DELIV) – 1. + *- else: + * - RCVD_HFN = HFN(RX_DELIV); + *- RCVD_COUNT = [RCVD_HFN, RCVD_SN]. + */ uint32_t rcvd_hfn, rcvd_count; if ((int64_t)rcvd_sn < (int64_t)SN(rx_deliv) - (int64_t)window_size) { rcvd_hfn = HFN(rx_deliv) + 1; @@ -227,6 +236,7 @@ void pdcp_entity_nr::write_pdu(unique_byte_buffer_t pdu) if (is_srb() || (is_drb() && (integrity_direction == DIRECTION_TX || integrity_direction == DIRECTION_TXRX))) { extract_mac(pdu, mac); } + // TS 38.323, section 5.9: Integrity verification // The data unit that is integrity protected is the PDU header // and the data part of the PDU before ciphering. @@ -245,6 +255,11 @@ void pdcp_entity_nr::write_pdu(unique_byte_buffer_t pdu) discard_data_header(pdu); // Check valid rcvd_count + /* + * - if RCVD_COUNT < RX_DELIV; or + * - if the PDCP Data PDU with COUNT = RCVD_COUNT has been received before: + * - discard the PDCP Data PDU; + */ if (rcvd_count < rx_deliv) { logger.debug("Out-of-order after time-out, duplicate or COUNT wrap-around"); logger.debug("RCVD_COUNT %u, RCVD_COUNT %u", rcvd_count, rx_deliv); @@ -253,6 +268,7 @@ void pdcp_entity_nr::write_pdu(unique_byte_buffer_t pdu) // Check if PDU has been received if (reorder_queue.find(rcvd_count) != reorder_queue.end()) { + logger.debug("Duplicate PDU, dropping."); return; // PDU already present, drop. } @@ -274,12 +290,14 @@ void pdcp_entity_nr::write_pdu(unique_byte_buffer_t pdu) // Handle reordering timers if (reordering_timer.is_running() and rx_deliv >= rx_reord) { reordering_timer.stop(); + logger.debug("Stopped t-Reordering - RX_DELIV=%d, RX_REORD=%ld", rx_deliv, rx_reord); } if (cfg.t_reordering != pdcp_t_reordering_t::infinity) { if (not reordering_timer.is_running() and rx_deliv < rx_next) { rx_reord = rx_next; reordering_timer.run(); + logger.debug("Started t-Reordering - RX_REORD=%ld, RX_DELIV=%ld, RX_NEXT=%ld", rx_reord, rx_deliv, rx_next); } } @@ -333,7 +351,8 @@ void pdcp_entity_nr::deliver_all_consecutive_counts() // Reordering Timer Callback (t-reordering) void pdcp_entity_nr::reordering_callback::operator()(uint32_t timer_id) { - parent->logger.info("Reordering timer expired. Re-order queue size=%d", parent->reorder_queue.size()); + parent->logger.info( + "Reordering timer expired. RX_REORD=%u, re-order queue size=%ld", parent->rx_reord, parent->reorder_queue.size()); // Deliver all PDCP SDU(s) with associated COUNT value(s) < RX_REORD for (std::map::iterator it = parent->reorder_queue.begin(); @@ -347,6 +366,10 @@ void pdcp_entity_nr::reordering_callback::operator()(uint32_t timer_id) parent->deliver_all_consecutive_counts(); if (parent->rx_deliv < parent->rx_next) { + parent->logger.debug("Updating RX_REORD to %ld. Old RX_REORD=%ld, RX_DELIV=%ld", + parent->rx_next, + parent->rx_reord, + parent->rx_deliv); parent->rx_reord = parent->rx_next; parent->reordering_timer.run(); } @@ -355,7 +378,7 @@ void pdcp_entity_nr::reordering_callback::operator()(uint32_t timer_id) // Discard Timer Callback (discardTimer) void pdcp_entity_nr::discard_callback::operator()(uint32_t timer_id) { - parent->logger.debug("Discard timer expired for PDU with SN = %d", discard_sn); + parent->logger.debug("Discard timer expired for PDU with SN=%d", discard_sn); // Notify the RLC of the discard. It's the RLC to actually discard, if no segment was transmitted yet. parent->rlc->discard_sdu(parent->lcid, discard_sn); diff --git a/lib/src/rlc/rlc_am_base.cc b/lib/src/rlc/rlc_am_base.cc index 9c2ee0fb6..9cc277cd0 100644 --- a/lib/src/rlc/rlc_am_base.cc +++ b/lib/src/rlc/rlc_am_base.cc @@ -239,13 +239,19 @@ int rlc_am::rlc_am_base_tx::write_sdu(unique_byte_buffer_t sdu) uint32_t nof_bytes = sdu->N_bytes; srsran::error_type ret = tx_sdu_queue.try_write(std::move(sdu)); if (ret) { - RlcHexInfo(msg_ptr, nof_bytes, "Tx SDU (%d B, tx_sdu_queue_len=%d)", nof_bytes, tx_sdu_queue.size()); + RlcHexInfo(msg_ptr, + nof_bytes, + "Tx SDU (%d B, PDCP_SN=%ld tx_sdu_queue_len=%d)", + nof_bytes, + sdu_pdcp_sn, + tx_sdu_queue.size()); } else { // in case of fail, the try_write returns back the sdu RlcHexWarning(ret.error()->msg, ret.error()->N_bytes, - "[Dropped SDU] Tx SDU (%d B, tx_sdu_queue_len=%d)", + "[Dropped SDU] Tx SDU (%d B, PDCP_SN=%ld, tx_sdu_queue_len=%d)", ret.error()->N_bytes, + sdu_pdcp_sn, tx_sdu_queue.size()); return SRSRAN_ERROR; } diff --git a/lib/src/rlc/rlc_am_nr.cc b/lib/src/rlc/rlc_am_nr.cc index eb0963f61..dda2e66a0 100644 --- a/lib/src/rlc/rlc_am_nr.cc +++ b/lib/src/rlc/rlc_am_nr.cc @@ -183,7 +183,7 @@ uint32_t rlc_am_nr_tx::build_new_pdu(uint8_t* payload, uint32_t nof_bytes) } while (tx_sdu == nullptr && tx_sdu_queue.size() != 0); if (tx_sdu != nullptr) { - RlcDebug("Read RLC SDU - %d bytes", tx_sdu->N_bytes); + RlcDebug("Read RLC SDU - RLC_SN=%d, PDCP_SN=%d, %d bytes", st.tx_next, tx_sdu->md.pdcp_sn, tx_sdu->N_bytes); } else { RlcDebug("No SDUs left in the tx queue."); return 0;