From b687072815cf9d6b08af0603501c1f7c563c8089 Mon Sep 17 00:00:00 2001 From: Pedro Alvarez Date: Tue, 11 Jan 2022 15:04:27 +0000 Subject: [PATCH] lib,rlc: added rb_name and logger to rlc_common. Added macros to help making sure bearer name is always included to the log to rlc_common.h. Started using said macros in TM, UM and AM entities. --- lib/include/srsran/rlc/rlc_am_base.h | 2 -- lib/include/srsran/rlc/rlc_common.h | 10 ++++++++++ lib/include/srsran/rlc/rlc_tm.h | 1 - lib/include/srsran/rlc/rlc_um_base.h | 8 +++----- lib/src/rlc/rlc_am_base.cc | 30 ++++++++++++++-------------- lib/src/rlc/rlc_tm.cc | 28 ++++++++++++-------------- lib/src/rlc/rlc_um_base.cc | 18 ++++++++--------- 7 files changed, 50 insertions(+), 47 deletions(-) diff --git a/lib/include/srsran/rlc/rlc_am_base.h b/lib/include/srsran/rlc/rlc_am_base.h index 32aa7dba2..128eb5abb 100644 --- a/lib/include/srsran/rlc/rlc_am_base.h +++ b/lib/include/srsran/rlc/rlc_am_base.h @@ -104,11 +104,9 @@ public: protected: // Common variables needed/provided by parent class - srslog::basic_logger& logger; srsran::timer_handler* timers = nullptr; uint32_t lcid = 0; rlc_config_t cfg = {}; - std::string rb_name; static const int poll_periodicity = 8; // After how many data PDUs a status PDU shall be requested diff --git a/lib/include/srsran/rlc/rlc_common.h b/lib/include/srsran/rlc/rlc_common.h index 8e62796c5..a67b29609 100644 --- a/lib/include/srsran/rlc/rlc_common.h +++ b/lib/include/srsran/rlc/rlc_common.h @@ -34,6 +34,11 @@ namespace srsran { #define RLC_MAX_SDU_SIZE ((1 << 11) - 1) // Length of LI field is 11bits #define RLC_AM_MIN_DATA_PDU_SIZE (3) // AMD PDU with 10 bit SN (length of LI field is 11 bits) (No LI) +#define RlcDebug(fmt, ...) logger.debug("%s: " fmt, rb_name, ##__VA_ARGS__) +#define RlcInfo(fmt, ...) logger.info("%s: " fmt, rb_name, ##__VA_ARGS__) +#define RlcWarning(fmt, ...) logger.warning("%s: " fmt, rb_name, ##__VA_ARGS__) +#define RlcError(fmt, ...) logger.error("%s: " fmt, rb_name, ##__VA_ARGS__) + typedef enum { RLC_FI_FIELD_START_AND_END_ALIGNED = 0, RLC_FI_FIELD_NOT_END_ALIGNED, @@ -188,6 +193,7 @@ typedef std::function bsr_callback_t; class rlc_common { public: + explicit rlc_common(srslog::basic_logger& logger_) : logger(logger_) {} virtual ~rlc_common() = default; virtual bool configure(const rlc_config_t& cnfg) = 0; virtual void stop() = 0; @@ -265,6 +271,10 @@ public: void* operator new(size_t sz) { return allocate_rlc_bearer(sz); } void operator delete(void* p) { return deallocate_rlc_bearer(p); } +protected: + std::string rb_name = {}; + srslog::basic_logger& logger; + private: bool suspended = false; diff --git a/lib/include/srsran/rlc/rlc_tm.h b/lib/include/srsran/rlc/rlc_tm.h index 849ba9737..f02b860b9 100644 --- a/lib/include/srsran/rlc/rlc_tm.h +++ b/lib/include/srsran/rlc/rlc_tm.h @@ -62,7 +62,6 @@ public: private: byte_buffer_pool* pool = nullptr; - srslog::basic_logger& logger; uint32_t lcid = 0; srsue::pdcp_interface_rlc* pdcp = nullptr; srsue::rrc_interface_rlc* rrc = nullptr; diff --git a/lib/include/srsran/rlc/rlc_um_base.h b/lib/include/srsran/rlc/rlc_um_base.h index 40cfd2768..b824ef628 100644 --- a/lib/include/srsran/rlc/rlc_um_base.h +++ b/lib/include/srsran/rlc/rlc_um_base.h @@ -154,14 +154,12 @@ protected: }; // Common variables needed by parent class - srsue::rrc_interface_rlc* rrc = nullptr; - srsue::pdcp_interface_rlc* pdcp = nullptr; - srslog::basic_logger& logger; + srsue::rrc_interface_rlc* rrc = nullptr; + srsue::pdcp_interface_rlc* pdcp = nullptr; srsran::timer_handler* timers = nullptr; uint32_t lcid = 0; rlc_config_t cfg = {}; - std::string rb_name; - byte_buffer_pool* pool = nullptr; + byte_buffer_pool* pool = nullptr; std::string get_rb_name(srsue::rrc_interface_rlc* rrc, uint32_t lcid, bool is_mrb); // Rx and Tx objects diff --git a/lib/src/rlc/rlc_am_base.cc b/lib/src/rlc/rlc_am_base.cc index 4f6f4eacb..9764994de 100644 --- a/lib/src/rlc/rlc_am_base.cc +++ b/lib/src/rlc/rlc_am_base.cc @@ -38,7 +38,7 @@ rlc_am::rlc_am(srsran_rat_t rat, srsue::pdcp_interface_rlc* pdcp_, srsue::rrc_interface_rlc* rrc_, srsran::timer_handler* timers_) : - logger(logger), rrc(rrc_), pdcp(pdcp_), timers(timers_), lcid(lcid_) + rlc_common(logger), rrc(rrc_), pdcp(pdcp_), timers(timers_), lcid(lcid_) { if (rat == srsran_rat_t::lte) { rlc_am_lte_tx* tx = new rlc_am_lte_tx(this); @@ -55,9 +55,10 @@ rlc_am::rlc_am(srsran_rat_t rat, tx->set_rx(rx); rx->set_tx(tx); } else { - logger.error("Invalid RAT at entity initialization"); + RlcError("Invalid RAT at entity initialization"); } } + bool rlc_am::configure(const rlc_config_t& cfg_) { // determine bearer name and configure rx/tx objects @@ -67,37 +68,36 @@ bool rlc_am::configure(const rlc_config_t& cfg_) cfg = cfg_; if (not rx_base->configure(cfg)) { - logger.error("Error configuring bearer (RX)"); + RlcError("Error configuring bearer (RX)"); return false; } if (not tx_base->configure(cfg)) { - logger.error("Error configuring bearer (TX)"); + RlcError("Error configuring bearer (TX)"); return false; } - logger.info("%s configured: t_poll_retx=%d, poll_pdu=%d, poll_byte=%d, max_retx_thresh=%d, " - "t_reordering=%d, t_status_prohibit=%d", - rb_name.c_str(), - cfg.am.t_poll_retx, - cfg.am.poll_pdu, - cfg.am.poll_byte, - cfg.am.max_retx_thresh, - cfg.am.t_reordering, - cfg.am.t_status_prohibit); + RlcInfo("configured - t_poll_retx=%d, poll_pdu=%d, poll_byte=%d, max_retx_thresh=%d, " + "t_reordering=%d, t_status_prohibit=%d", + cfg.am.t_poll_retx, + cfg.am.poll_pdu, + cfg.am.poll_byte, + cfg.am.max_retx_thresh, + cfg.am.t_reordering, + cfg.am.t_status_prohibit); return true; } void rlc_am::stop() { - logger.debug("Stopped bearer %s", rb_name.c_str()); + RlcDebug("Stopped bearer %s", rb_name.c_str()); tx_base->stop(); rx_base->stop(); } void rlc_am::reestablish() { - logger.debug("Reestablished bearer %s", rb_name.c_str()); + RlcDebug("Reestablished bearer %s", rb_name.c_str()); tx_base->reestablish(); // calls stop and enables tx again rx_base->reestablish(); // calls only stop } diff --git a/lib/src/rlc/rlc_tm.cc b/lib/src/rlc/rlc_tm.cc index 75bc8d0d7..c9870db04 100644 --- a/lib/src/rlc/rlc_tm.cc +++ b/lib/src/rlc/rlc_tm.cc @@ -21,7 +21,7 @@ rlc_tm::rlc_tm(srslog::basic_logger& logger, uint32_t lcid_, srsue::pdcp_interface_rlc* pdcp_, srsue::rrc_interface_rlc* rrc_) : - logger(logger), pdcp(pdcp_), rrc(rrc_), lcid(lcid_) + rlc_common(logger), pdcp(pdcp_), rrc(rrc_), lcid(lcid_) { pool = byte_buffer_pool::get_instance(); } @@ -34,7 +34,7 @@ rlc_tm::~rlc_tm() bool rlc_tm::configure(const rlc_config_t& cnfg) { - logger.error("Attempted to configure TM RLC entity"); + RlcError("Attempted to configure TM RLC entity"); return true; } @@ -96,7 +96,7 @@ void rlc_tm::write_sdu(unique_byte_buffer_t sdu) } } else { - logger.warning("NULL SDU pointer in write_sdu()"); + RlcWarning("NULL SDU pointer in write_sdu()"); } } @@ -105,7 +105,7 @@ void rlc_tm::discard_sdu(uint32_t discard_sn) if (!tx_enabled) { return; } - logger.warning("SDU discard not implemented on RLC TM"); + RlcWarning("SDU discard not implemented on RLC TM"); } bool rlc_tm::sdu_queue_is_full() @@ -153,16 +153,14 @@ uint32_t rlc_tm::read_pdu(uint8_t* payload, uint32_t nof_bytes) { uint32_t pdu_size = ul_queue.size_tail_bytes(); if (pdu_size > nof_bytes) { - logger.info("%s Tx PDU size larger than MAC opportunity (%d > %d)", rrc->get_rb_name(lcid), pdu_size, nof_bytes); + RlcInfo("Tx PDU size larger than MAC opportunity (%d > %d)", pdu_size, nof_bytes); return 0; } unique_byte_buffer_t buf; if (ul_queue.try_read(&buf)) { pdu_size = buf->N_bytes; memcpy(payload, buf->msg, buf->N_bytes); - logger.debug("%s Complete SDU scheduled for tx. Stack latency: %" PRIu64 " us", - rrc->get_rb_name(lcid), - (uint64_t)buf->get_latency_us().count()); + RlcDebug("Complete SDU scheduled for tx. Stack latency: %" PRIu64 " us", (uint64_t)buf->get_latency_us().count()); logger.info(payload, pdu_size, "%s Tx %s PDU, queue size=%d, bytes=%d", @@ -174,13 +172,13 @@ uint32_t rlc_tm::read_pdu(uint8_t* payload, uint32_t nof_bytes) std::lock_guard lock(metrics_mutex); metrics.num_tx_pdu_bytes += pdu_size; return pdu_size; - } else { - if (ul_queue.size_bytes() > 0) { - logger.warning("Corrupted queue: empty but size_bytes > 0. Resetting queue"); - ul_queue.reset(); - } - return 0; } + + if (ul_queue.size_bytes() > 0) { + RlcWarning("Corrupted queue: empty but size_bytes > 0. Resetting queue"); + ul_queue.reset(); + } + return 0; } void rlc_tm::write_pdu(uint8_t* payload, uint32_t nof_bytes) @@ -201,7 +199,7 @@ void rlc_tm::write_pdu(uint8_t* payload, uint32_t nof_bytes) pdcp->write_pdu(lcid, std::move(buf)); } } else { - logger.error("Fatal Error: Couldn't allocate buffer in rlc_tm::write_pdu()."); + RlcError("Fatal Error: Couldn't allocate buffer in rlc_tm::write_pdu()."); } } diff --git a/lib/src/rlc/rlc_um_base.cc b/lib/src/rlc/rlc_um_base.cc index b24ae585c..1fcafaef9 100644 --- a/lib/src/rlc/rlc_um_base.cc +++ b/lib/src/rlc/rlc_um_base.cc @@ -21,7 +21,7 @@ rlc_um_base::rlc_um_base(srslog::basic_logger& logger, srsue::pdcp_interface_rlc* pdcp_, srsue::rrc_interface_rlc* rrc_, srsran::timer_handler* timers_) : - logger(logger), lcid(lcid_), pdcp(pdcp_), rrc(rrc_), timers(timers_), pool(byte_buffer_pool::get_instance()) + rlc_common(logger), lcid(lcid_), pdcp(pdcp_), rrc(rrc_), timers(timers_), pool(byte_buffer_pool::get_instance()) {} rlc_um_base::~rlc_um_base() {} @@ -81,7 +81,7 @@ void rlc_um_base::empty_queue() void rlc_um_base::write_sdu(unique_byte_buffer_t sdu) { if (not tx_enabled || not tx) { - logger.debug("%s is currently deactivated. Dropping SDU (%d B)", rb_name.c_str(), sdu->N_bytes); + RlcDebug("RB is currently deactivated. Dropping SDU (%d B)", sdu->N_bytes); std::lock_guard lock(metrics_mutex); metrics.num_lost_sdus++; return; @@ -101,7 +101,7 @@ void rlc_um_base::write_sdu(unique_byte_buffer_t sdu) void rlc_um_base::discard_sdu(uint32_t discard_sn) { if (not tx_enabled || not tx) { - logger.debug("%s is currently deactivated. Ignoring SDU discard (SN=%u)", rb_name.c_str(), discard_sn); + RlcDebug("RB is currently deactivated. Ignoring SDU discard (SN=%u)", discard_sn); return; } tx->discard_sdu(discard_sn); @@ -274,7 +274,7 @@ void rlc_um_base::rlc_um_base_tx::write_sdu(unique_byte_buffer_t sdu) tx_sdu_queue.size()); tx_sdu_queue.write(std::move(sdu)); } else { - logger.warning("NULL SDU pointer in write_sdu()"); + RlcWarning("NULL SDU pointer in write_sdu()"); } } @@ -297,14 +297,14 @@ int rlc_um_base::rlc_um_base_tx::try_write_sdu(unique_byte_buffer_t sdu) tx_sdu_queue.size()); } } else { - logger.warning("NULL SDU pointer in write_sdu()"); + RlcWarning("NULL SDU pointer in write_sdu()"); } return SRSRAN_ERROR; } void rlc_um_base::rlc_um_base_tx::discard_sdu(uint32_t discard_sn) { - logger.warning("RLC UM: Discard SDU not implemented yet."); + RlcWarning("RLC UM: Discard SDU not implemented yet."); } bool rlc_um_base::rlc_um_base_tx::sdu_queue_is_full() @@ -317,16 +317,16 @@ uint32_t rlc_um_base::rlc_um_base_tx::build_data_pdu(uint8_t* payload, uint32_t unique_byte_buffer_t pdu; { std::lock_guard lock(mutex); - logger.debug("MAC opportunity - %d bytes", nof_bytes); + RlcDebug("MAC opportunity - %d bytes", nof_bytes); if (tx_sdu == nullptr && tx_sdu_queue.is_empty()) { - logger.info("No data available to be sent"); + RlcInfo("No data available to be sent"); return 0; } pdu = make_byte_buffer(); if (!pdu || pdu->N_bytes != 0) { - logger.error("Failed to allocate PDU buffer"); + RlcError("Failed to allocate PDU buffer"); return 0; } }