From 9bd368e0a9151fea3d945e2f366bc1d5f1cdbe62 Mon Sep 17 00:00:00 2001 From: Pedro Alvarez Date: Fri, 14 Jan 2022 11:38:39 +0000 Subject: [PATCH] lib,rlc: changed back status and header logging helpers to log directly. Make sure RB name is automatically logged. --- lib/include/srsran/rlc/rlc_am_lte_packing.h | 63 ++++++++++++++++++++- lib/src/rlc/rlc_am_lte.cc | 15 +++-- lib/src/rlc/rlc_am_lte_packing.cc | 46 --------------- 3 files changed, 68 insertions(+), 56 deletions(-) diff --git a/lib/include/srsran/rlc/rlc_am_lte_packing.h b/lib/include/srsran/rlc/rlc_am_lte_packing.h index 1ddb16b6a..ea866bde8 100644 --- a/lib/include/srsran/rlc/rlc_am_lte_packing.h +++ b/lib/include/srsran/rlc/rlc_am_lte_packing.h @@ -62,8 +62,67 @@ bool rlc_am_is_unaligned(const uint8_t fi); bool rlc_am_not_start_aligned(const uint8_t fi); std::string rlc_am_undelivered_sdu_info_to_string(const std::map >& info_queue); -std::string rlc_amd_pdu_header_to_string(const rlc_amd_pdu_header_t& header); -std::string rlc_am_status_pdu_to_string(rlc_status_pdu_t* status); + +template +void log_rlc_amd_pdu_header_to_string(srslog::log_channel& log_ch, + const std::string& rb_name, + const char* fmt_str, + const rlc_amd_pdu_header_t& header, + Args&&... args) +{ + if (not log_ch.enabled()) { + return; + } + + fmt::memory_buffer buffer; + fmt::format_to(buffer, + "{}: [{}, RF={}, P={}, FI={}, SN={}, LSF={}, SO={}, N_li={}", + rb_name, + rlc_dc_field_text[header.dc], + (header.rf ? "1" : "0"), + (header.p ? "1" : "0"), + (header.fi ? "1" : "0"), + header.sn, + (header.lsf ? "1" : "0"), + header.so, + header.N_li); + if (header.N_li > 0) { + fmt::format_to(buffer, " ({}", header.li[0]); + for (uint32_t i = 1; i < header.N_li; ++i) { + fmt::format_to(buffer, ", {}", header.li[i]); + } + fmt::format_to(buffer, ")"); + } + fmt::format_to(buffer, "]"); + + log_ch(fmt_str, std::forward(args)..., to_c_str(buffer)); +} + +template +void log_rlc_am_status_pdu_to_string(srslog::log_channel& log_ch, + const std::string& rb_name, + const char* fmt_str, + rlc_status_pdu_t* status, + Args&&... args) +{ + if (not log_ch.enabled()) { + return; + } + fmt::memory_buffer buffer; + fmt::format_to(buffer, "{}: ACK_SN = {}, N_nack = {}", rb_name, status->ack_sn, status->N_nack); + if (status->N_nack > 0) { + fmt::format_to(buffer, ", NACK_SN = "); + for (uint32_t i = 0; i < status->N_nack; ++i) { + if (status->nacks[i].has_so) { + fmt::format_to( + buffer, "[{} {}:{}]", status->nacks[i].nack_sn, status->nacks[i].so_start, status->nacks[i].so_end); + } else { + fmt::format_to(buffer, "[{}]", status->nacks[i].nack_sn); + } + } + } + log_ch(fmt_str, std::forward(args)..., to_c_str(buffer)); +} } // namespace srsran #endif // SRSRAN_RLC_AM_LTE_PACKING_H diff --git a/lib/src/rlc/rlc_am_lte.cc b/lib/src/rlc/rlc_am_lte.cc index 057a2a15c..fba47da00 100644 --- a/lib/src/rlc/rlc_am_lte.cc +++ b/lib/src/rlc/rlc_am_lte.cc @@ -438,7 +438,7 @@ int rlc_am_lte_tx::build_status_pdu(uint8_t* payload, uint32_t nof_bytes) RlcDebug("Deferred Status PDU. Cause: Failed to acquire Rx lock"); pdu_len = 0; } else if (pdu_len > 0 && nof_bytes >= static_cast(pdu_len)) { - RlcInfo("Tx status PDU - %s", rlc_am_status_pdu_to_string(&tx_status)); + log_rlc_am_status_pdu_to_string(logger.info, rb_name, "Tx status PDU - %s", &tx_status); if (cfg.t_status_prohibit > 0 && status_prohibit_timer.is_valid()) { // re-arm timer status_prohibit_timer.run(); @@ -528,7 +528,7 @@ int rlc_am_lte_tx::build_retx_pdu(uint8_t* payload, uint32_t nof_bytes) tx_window[retx.sn].buf->N_bytes, tx_window[retx.sn].retx_count + 1, cfg.max_retx_thresh); - RlcDebug("%s", rlc_amd_pdu_header_to_string(new_header)); + log_rlc_amd_pdu_header_to_string(logger.debug, rb_name, "Tx PDU - %s", new_header); debug_state(); return (ptr - payload) + tx_window[retx.sn].buf->N_bytes; @@ -551,8 +551,7 @@ int rlc_am_lte_tx::build_segment(uint8_t* payload, uint32_t nof_bytes, rlc_amd_r pdu_without_poll++; byte_without_poll += (tx_window[retx.sn].buf->N_bytes + rlc_am_packed_length(&new_header)); - RlcInfo("pdu_without_poll: %d", pdu_without_poll); - RlcInfo("byte_without_poll: %d", byte_without_poll); + RlcInfo("pdu_without_poll: %d, byte_without_poll: %d", pdu_without_poll, byte_without_poll); new_header.dc = RLC_DC_FIELD_DATA_PDU; new_header.rf = 1; @@ -909,7 +908,7 @@ int rlc_am_lte_tx::build_data_pdu(uint8_t* payload, uint32_t nof_bytes) memcpy(ptr, buffer_ptr->msg, buffer_ptr->N_bytes); int total_len = (ptr - payload) + buffer_ptr->N_bytes; RlcHexInfo(payload, total_len, "Tx PDU SN=%d (%d B)", header.sn, total_len); - RlcDebug("%s", rlc_amd_pdu_header_to_string(header)); + log_rlc_amd_pdu_header_to_string(logger.debug, rb_name, "%s", header); debug_state(); return total_len; @@ -933,7 +932,7 @@ void rlc_am_lte_tx::handle_control_pdu(uint8_t* payload, uint32_t nof_bytes) rlc_am_read_status_pdu(payload, nof_bytes, &status); - RlcInfo("Rx Status PDU %s", rlc_am_status_pdu_to_string(&status)); + log_rlc_am_status_pdu_to_string(logger.info, rb_name, "Rx Status PDU %s", &status); // make sure ACK_SN is within our Tx window if (((MOD + status.ack_sn - vt_a) % MOD > RLC_AM_WINDOW_SIZE) || @@ -1268,7 +1267,7 @@ void rlc_am_lte_rx::handle_data_pdu_full(uint8_t* payload, uint32_t nof_bytes, r std::map::iterator it; RlcHexInfo(payload, nof_bytes, "Rx data PDU SN=%d (%d B)", header.sn, nof_bytes); - RlcDebug("%s", rlc_amd_pdu_header_to_string(header)); + log_rlc_amd_pdu_header_to_string(logger.debug, rb_name, "%s", header); // sanity check for segments not exceeding PDU length if (header.N_li > 0) { @@ -1387,7 +1386,7 @@ void rlc_am_lte_rx::handle_data_pdu_segment(uint8_t* payload, uint32_t nof_bytes nof_bytes, header.so, header.N_li); - RlcDebug("%s", rlc_amd_pdu_header_to_string(header)); + log_rlc_amd_pdu_header_to_string(logger.debug, rb_name, "Rx data PDU segment %s", header); // Check inside rx window if (!inside_rx_window(header.sn)) { diff --git a/lib/src/rlc/rlc_am_lte_packing.cc b/lib/src/rlc/rlc_am_lte_packing.cc index e6a451a56..b83e5bb8e 100644 --- a/lib/src/rlc/rlc_am_lte_packing.cc +++ b/lib/src/rlc/rlc_am_lte_packing.cc @@ -309,50 +309,4 @@ bool rlc_am_not_start_aligned(const uint8_t fi) return (fi == RLC_FI_FIELD_NOT_START_ALIGNED || fi == RLC_FI_FIELD_NOT_START_OR_END_ALIGNED); } -/** - * Logging helpers - */ -std::string rlc_amd_pdu_header_to_string(const rlc_amd_pdu_header_t& header) -{ - fmt::memory_buffer buffer; - fmt::format_to(buffer, - "[{}, RF={}, P={}, FI={}, SN={}, LSF={}, SO={}, N_li={}", - rlc_dc_field_text[header.dc], - (header.rf ? "1" : "0"), - (header.p ? "1" : "0"), - (header.fi ? "1" : "0"), - header.sn, - (header.lsf ? "1" : "0"), - header.so, - header.N_li); - if (header.N_li > 0) { - fmt::format_to(buffer, " ({}", header.li[0]); - for (uint32_t i = 1; i < header.N_li; ++i) { - fmt::format_to(buffer, ", {}", header.li[i]); - } - fmt::format_to(buffer, ")"); - } - fmt::format_to(buffer, "]"); - - return fmt::to_string(buffer); -} - -std::string rlc_am_status_pdu_to_string(rlc_status_pdu_t* status) -{ - fmt::memory_buffer buffer; - fmt::format_to(buffer, "ACK_SN = {}, N_nack = {}", status->ack_sn, status->N_nack); - if (status->N_nack > 0) { - fmt::format_to(buffer, ", NACK_SN = "); - for (uint32_t i = 0; i < status->N_nack; ++i) { - if (status->nacks[i].has_so) { - fmt::format_to( - buffer, "[{} {}:{}]", status->nacks[i].nack_sn, status->nacks[i].so_start, status->nacks[i].so_end); - } else { - fmt::format_to(buffer, "[{}]", status->nacks[i].nack_sn); - } - } - } - return fmt::to_string(buffer); -} - } // namespace srsran