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.

master
Pedro Alvarez 3 years ago
parent 74d847efe9
commit b687072815

@ -104,11 +104,9 @@ public:
protected: protected:
// Common variables needed/provided by parent class // Common variables needed/provided by parent class
srslog::basic_logger& logger;
srsran::timer_handler* timers = nullptr; srsran::timer_handler* timers = nullptr;
uint32_t lcid = 0; uint32_t lcid = 0;
rlc_config_t cfg = {}; 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 static const int poll_periodicity = 8; // After how many data PDUs a status PDU shall be requested

@ -34,6 +34,11 @@ namespace srsran {
#define RLC_MAX_SDU_SIZE ((1 << 11) - 1) // Length of LI field is 11bits #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 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 { typedef enum {
RLC_FI_FIELD_START_AND_END_ALIGNED = 0, RLC_FI_FIELD_START_AND_END_ALIGNED = 0,
RLC_FI_FIELD_NOT_END_ALIGNED, RLC_FI_FIELD_NOT_END_ALIGNED,
@ -188,6 +193,7 @@ typedef std::function<void(uint32_t, uint32_t, uint32_t)> bsr_callback_t;
class rlc_common class rlc_common
{ {
public: public:
explicit rlc_common(srslog::basic_logger& logger_) : logger(logger_) {}
virtual ~rlc_common() = default; virtual ~rlc_common() = default;
virtual bool configure(const rlc_config_t& cnfg) = 0; virtual bool configure(const rlc_config_t& cnfg) = 0;
virtual void stop() = 0; virtual void stop() = 0;
@ -265,6 +271,10 @@ public:
void* operator new(size_t sz) { return allocate_rlc_bearer(sz); } void* operator new(size_t sz) { return allocate_rlc_bearer(sz); }
void operator delete(void* p) { return deallocate_rlc_bearer(p); } void operator delete(void* p) { return deallocate_rlc_bearer(p); }
protected:
std::string rb_name = {};
srslog::basic_logger& logger;
private: private:
bool suspended = false; bool suspended = false;

@ -62,7 +62,6 @@ public:
private: private:
byte_buffer_pool* pool = nullptr; byte_buffer_pool* pool = nullptr;
srslog::basic_logger& logger;
uint32_t lcid = 0; uint32_t lcid = 0;
srsue::pdcp_interface_rlc* pdcp = nullptr; srsue::pdcp_interface_rlc* pdcp = nullptr;
srsue::rrc_interface_rlc* rrc = nullptr; srsue::rrc_interface_rlc* rrc = nullptr;

@ -154,14 +154,12 @@ protected:
}; };
// Common variables needed by parent class // Common variables needed by parent class
srsue::rrc_interface_rlc* rrc = nullptr; srsue::rrc_interface_rlc* rrc = nullptr;
srsue::pdcp_interface_rlc* pdcp = nullptr; srsue::pdcp_interface_rlc* pdcp = nullptr;
srslog::basic_logger& logger;
srsran::timer_handler* timers = nullptr; srsran::timer_handler* timers = nullptr;
uint32_t lcid = 0; uint32_t lcid = 0;
rlc_config_t cfg = {}; 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); std::string get_rb_name(srsue::rrc_interface_rlc* rrc, uint32_t lcid, bool is_mrb);
// Rx and Tx objects // Rx and Tx objects

@ -38,7 +38,7 @@ rlc_am::rlc_am(srsran_rat_t rat,
srsue::pdcp_interface_rlc* pdcp_, srsue::pdcp_interface_rlc* pdcp_,
srsue::rrc_interface_rlc* rrc_, srsue::rrc_interface_rlc* rrc_,
srsran::timer_handler* timers_) : 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) { if (rat == srsran_rat_t::lte) {
rlc_am_lte_tx* tx = new rlc_am_lte_tx(this); 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); tx->set_rx(rx);
rx->set_tx(tx); rx->set_tx(tx);
} else { } else {
logger.error("Invalid RAT at entity initialization"); RlcError("Invalid RAT at entity initialization");
} }
} }
bool rlc_am::configure(const rlc_config_t& cfg_) bool rlc_am::configure(const rlc_config_t& cfg_)
{ {
// determine bearer name and configure rx/tx objects // determine bearer name and configure rx/tx objects
@ -67,37 +68,36 @@ bool rlc_am::configure(const rlc_config_t& cfg_)
cfg = cfg_; cfg = cfg_;
if (not rx_base->configure(cfg)) { if (not rx_base->configure(cfg)) {
logger.error("Error configuring bearer (RX)"); RlcError("Error configuring bearer (RX)");
return false; return false;
} }
if (not tx_base->configure(cfg)) { if (not tx_base->configure(cfg)) {
logger.error("Error configuring bearer (TX)"); RlcError("Error configuring bearer (TX)");
return false; return false;
} }
logger.info("%s configured: t_poll_retx=%d, poll_pdu=%d, poll_byte=%d, max_retx_thresh=%d, " RlcInfo("configured - t_poll_retx=%d, poll_pdu=%d, poll_byte=%d, max_retx_thresh=%d, "
"t_reordering=%d, t_status_prohibit=%d", "t_reordering=%d, t_status_prohibit=%d",
rb_name.c_str(), cfg.am.t_poll_retx,
cfg.am.t_poll_retx, cfg.am.poll_pdu,
cfg.am.poll_pdu, cfg.am.poll_byte,
cfg.am.poll_byte, cfg.am.max_retx_thresh,
cfg.am.max_retx_thresh, cfg.am.t_reordering,
cfg.am.t_reordering, cfg.am.t_status_prohibit);
cfg.am.t_status_prohibit);
return true; return true;
} }
void rlc_am::stop() void rlc_am::stop()
{ {
logger.debug("Stopped bearer %s", rb_name.c_str()); RlcDebug("Stopped bearer %s", rb_name.c_str());
tx_base->stop(); tx_base->stop();
rx_base->stop(); rx_base->stop();
} }
void rlc_am::reestablish() 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 tx_base->reestablish(); // calls stop and enables tx again
rx_base->reestablish(); // calls only stop rx_base->reestablish(); // calls only stop
} }

@ -21,7 +21,7 @@ rlc_tm::rlc_tm(srslog::basic_logger& logger,
uint32_t lcid_, uint32_t lcid_,
srsue::pdcp_interface_rlc* pdcp_, srsue::pdcp_interface_rlc* pdcp_,
srsue::rrc_interface_rlc* rrc_) : 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(); pool = byte_buffer_pool::get_instance();
} }
@ -34,7 +34,7 @@ rlc_tm::~rlc_tm()
bool rlc_tm::configure(const rlc_config_t& cnfg) 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; return true;
} }
@ -96,7 +96,7 @@ void rlc_tm::write_sdu(unique_byte_buffer_t sdu)
} }
} else { } 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) { if (!tx_enabled) {
return; 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() 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(); uint32_t pdu_size = ul_queue.size_tail_bytes();
if (pdu_size > nof_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; return 0;
} }
unique_byte_buffer_t buf; unique_byte_buffer_t buf;
if (ul_queue.try_read(&buf)) { if (ul_queue.try_read(&buf)) {
pdu_size = buf->N_bytes; pdu_size = buf->N_bytes;
memcpy(payload, buf->msg, buf->N_bytes); memcpy(payload, buf->msg, buf->N_bytes);
logger.debug("%s Complete SDU scheduled for tx. Stack latency: %" PRIu64 " us", RlcDebug("Complete SDU scheduled for tx. Stack latency: %" PRIu64 " us", (uint64_t)buf->get_latency_us().count());
rrc->get_rb_name(lcid),
(uint64_t)buf->get_latency_us().count());
logger.info(payload, logger.info(payload,
pdu_size, pdu_size,
"%s Tx %s PDU, queue size=%d, bytes=%d", "%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<std::mutex> lock(metrics_mutex); std::lock_guard<std::mutex> lock(metrics_mutex);
metrics.num_tx_pdu_bytes += pdu_size; metrics.num_tx_pdu_bytes += pdu_size;
return 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) 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)); pdcp->write_pdu(lcid, std::move(buf));
} }
} else { } 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().");
} }
} }

@ -21,7 +21,7 @@ rlc_um_base::rlc_um_base(srslog::basic_logger& logger,
srsue::pdcp_interface_rlc* pdcp_, srsue::pdcp_interface_rlc* pdcp_,
srsue::rrc_interface_rlc* rrc_, srsue::rrc_interface_rlc* rrc_,
srsran::timer_handler* timers_) : 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() {} 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) void rlc_um_base::write_sdu(unique_byte_buffer_t sdu)
{ {
if (not tx_enabled || not tx) { 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<std::mutex> lock(metrics_mutex); std::lock_guard<std::mutex> lock(metrics_mutex);
metrics.num_lost_sdus++; metrics.num_lost_sdus++;
return; 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) void rlc_um_base::discard_sdu(uint32_t discard_sn)
{ {
if (not tx_enabled || not tx) { 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; return;
} }
tx->discard_sdu(discard_sn); 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.size());
tx_sdu_queue.write(std::move(sdu)); tx_sdu_queue.write(std::move(sdu));
} else { } 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()); tx_sdu_queue.size());
} }
} else { } else {
logger.warning("NULL SDU pointer in write_sdu()"); RlcWarning("NULL SDU pointer in write_sdu()");
} }
return SRSRAN_ERROR; return SRSRAN_ERROR;
} }
void rlc_um_base::rlc_um_base_tx::discard_sdu(uint32_t discard_sn) 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() 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; unique_byte_buffer_t pdu;
{ {
std::lock_guard<std::mutex> lock(mutex); std::lock_guard<std::mutex> 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()) { 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; return 0;
} }
pdu = make_byte_buffer(); pdu = make_byte_buffer();
if (!pdu || pdu->N_bytes != 0) { if (!pdu || pdu->N_bytes != 0) {
logger.error("Failed to allocate PDU buffer"); RlcError("Failed to allocate PDU buffer");
return 0; return 0;
} }
} }

Loading…
Cancel
Save