diff --git a/lib/include/srslte/common/common.h b/lib/include/srslte/common/common.h index b1a195c98..c10ba0c01 100644 --- a/lib/include/srslte/common/common.h +++ b/lib/include/srslte/common/common.h @@ -82,7 +82,7 @@ namespace srslte { -//#define ENABLE_TIMESTAMP +#define ENABLE_TIMESTAMP /****************************************************************************** * Byte and Bit buffers @@ -152,7 +152,7 @@ public: return 0; gettimeofday(×tamp[2], NULL); get_time_interval(timestamp); - return timestamp[0].tv_usec; + return timestamp[0].tv_usec + timestamp[0].tv_sec * 1000000; #else return 0; #endif @@ -263,7 +263,7 @@ typedef std::unique_ptr unique_byte_buffer_t /// Utilities to create a span out of a byte_buffer. /// -using byte_span = span; +using byte_span = span; using const_byte_span = span; inline byte_span make_span(byte_buffer_t& b) diff --git a/lib/include/srslte/upper/rlc_am_lte.h b/lib/include/srslte/upper/rlc_am_lte.h index 74527d1a8..3bf70a27b 100644 --- a/lib/include/srslte/upper/rlc_am_lte.h +++ b/lib/include/srslte/upper/rlc_am_lte.h @@ -13,6 +13,7 @@ #ifndef SRSLTE_RLC_AM_LTE_H #define SRSLTE_RLC_AM_LTE_H +#include "srslte/adt/accumulators.h" #include "srslte/common/buffer_pool.h" #include "srslte/common/common.h" #include "srslte/common/log.h" @@ -182,6 +183,9 @@ private: // Mutexes pthread_mutex_t mutex; + + // Metrics + srslte::rolling_average mean_pdu_latency_us; }; // Receiver sub-class diff --git a/lib/include/srslte/upper/rlc_um_lte.h b/lib/include/srslte/upper/rlc_um_lte.h index 7cb8d4e61..2e9e540e0 100644 --- a/lib/include/srslte/upper/rlc_um_lte.h +++ b/lib/include/srslte/upper/rlc_um_lte.h @@ -13,6 +13,7 @@ #ifndef SRSLTE_RLC_UM_LTE_H #define SRSLTE_RLC_UM_LTE_H +#include "srslte/adt/accumulators.h" #include "srslte/common/buffer_pool.h" #include "srslte/common/common.h" #include "srslte/common/log.h" @@ -63,6 +64,9 @@ private: ***************************************************************************/ uint32_t vt_us = 0; // Send state. SN to be assigned for next PDU. + // Metrics + srslte::rolling_average mean_pdu_latency_us; + void debug_state(); }; diff --git a/lib/src/upper/rlc_am_lte.cc b/lib/src/upper/rlc_am_lte.cc index a04491cf9..7430f29cf 100644 --- a/lib/src/upper/rlc_am_lte.cc +++ b/lib/src/upper/rlc_am_lte.cc @@ -837,7 +837,12 @@ int rlc_am_lte::rlc_am_lte_tx::build_data_pdu(uint8_t* payload, uint32_t nof_byt tx_sdu->N_bytes -= to_move; tx_sdu->msg += to_move; if (tx_sdu->N_bytes == 0) { - log->debug("%s Complete SDU scheduled for tx. Stack latency: %ld us\n", RB_NAME, tx_sdu->get_latency_us()); + long latency_us = tx_sdu->get_latency_us(); + mean_pdu_latency_us.push(latency_us); + log->debug("%s Complete SDU scheduled for tx. Stack latency (last/average): %ld/%ld us\n", + RB_NAME, + latency_us, + (long)mean_pdu_latency_us.value()); tx_sdu.reset(); } if (pdu_space > to_move) { @@ -876,7 +881,12 @@ int rlc_am_lte::rlc_am_lte_tx::build_data_pdu(uint8_t* payload, uint32_t nof_byt tx_sdu->N_bytes -= to_move; tx_sdu->msg += to_move; if (tx_sdu->N_bytes == 0) { - log->debug("%s Complete SDU scheduled for tx. Stack latency: %ld us\n", RB_NAME, tx_sdu->get_latency_us()); + long latency_us = tx_sdu->get_latency_us(); + mean_pdu_latency_us.push(latency_us); + log->debug("%s Complete SDU scheduled for tx. Stack latency (last/average): %ld/%ld us\n", + RB_NAME, + latency_us, + (long)mean_pdu_latency_us.value()); tx_sdu.reset(); } if (pdu_space > to_move) { diff --git a/lib/src/upper/rlc_um_lte.cc b/lib/src/upper/rlc_um_lte.cc index 52262d75b..4ef03b350 100644 --- a/lib/src/upper/rlc_um_lte.cc +++ b/lib/src/upper/rlc_um_lte.cc @@ -23,8 +23,7 @@ rlc_um_lte::rlc_um_lte(srslte::log_ref log_, srsue::rrc_interface_rlc* rrc_, srslte::timer_handler* timers_) : rlc_um_base(log_, lcid_, pdcp_, rrc_, timers_) -{ -} +{} // Warning: must call stop() to properly deallocate all buffers rlc_um_lte::~rlc_um_lte() @@ -146,8 +145,12 @@ int rlc_um_lte::rlc_um_lte_tx::build_data_pdu(unique_byte_buffer_t pdu, uint8_t* tx_sdu->N_bytes -= to_move; tx_sdu->msg += to_move; if (tx_sdu->N_bytes == 0) { - log->debug( - "%s Complete SDU scheduled for tx. Stack latency: %ld us\n", rb_name.c_str(), tx_sdu->get_latency_us()); + long latency_us = tx_sdu->get_latency_us(); + mean_pdu_latency_us.push(latency_us); + log->debug("%s Complete SDU scheduled for tx. Stack latency (last/average): %ld/%ld us\n", + rb_name.c_str(), + latency_us, + (long)mean_pdu_latency_us.value()); tx_sdu.reset(); } @@ -178,8 +181,12 @@ int rlc_um_lte::rlc_um_lte_tx::build_data_pdu(unique_byte_buffer_t pdu, uint8_t* tx_sdu->N_bytes -= to_move; tx_sdu->msg += to_move; if (tx_sdu->N_bytes == 0) { - log->debug( - "%s Complete SDU scheduled for tx. Stack latency: %ld us\n", rb_name.c_str(), tx_sdu->get_latency_us()); + long latency_us = tx_sdu->get_latency_us(); + mean_pdu_latency_us.push(latency_us); + log->debug("%s Complete SDU scheduled for tx. Stack latency (last/average): %ld/%ld us\n", + rb_name.c_str(), + latency_us, + (long)mean_pdu_latency_us.value()); tx_sdu.reset(); } @@ -220,10 +227,8 @@ void rlc_um_lte::rlc_um_lte_tx::reset() ***************************************************************************/ rlc_um_lte::rlc_um_lte_rx::rlc_um_lte_rx(rlc_um_base* parent_) : - rlc_um_base_rx(parent_), - reordering_timer(timers->get_unique_timer()) -{ -} + rlc_um_base_rx(parent_), reordering_timer(timers->get_unique_timer()) +{} rlc_um_lte::rlc_um_lte_rx::~rlc_um_lte_rx() {} diff --git a/srsenb/src/stack/upper/gtpu.cc b/srsenb/src/stack/upper/gtpu.cc index 7a561874f..f803fb18e 100644 --- a/srsenb/src/stack/upper/gtpu.cc +++ b/srsenb/src/stack/upper/gtpu.cc @@ -227,6 +227,7 @@ void gtpu::rem_user(uint16_t rnti) void gtpu::handle_gtpu_s1u_rx_packet(srslte::unique_byte_buffer_t pdu, const sockaddr_in& addr) { gtpu_log->debug("Received %d bytes from S1-U interface\n", pdu->N_bytes); + pdu->set_timestamp(); gtpu_header_t header; if (not gtpu_read_header(pdu.get(), &header, gtpu_log)) {