diff --git a/lib/include/srslte/common/common.h b/lib/include/srslte/common/common.h index c10ba0c01..f9ea6e333 100644 --- a/lib/include/srslte/common/common.h +++ b/lib/include/srslte/common/common.h @@ -18,6 +18,7 @@ *******************************************************************************/ #include "srslte/adt/span.h" +#include #include #include #include @@ -104,9 +105,6 @@ public: byte_buffer_t() : N_bytes(0) { bzero(buffer, SRSLTE_MAX_BUFFER_SIZE_BYTES); -#ifdef ENABLE_TIMESTAMP - timestamp_is_set = false; -#endif msg = &buffer[SRSLTE_BUFFER_HEADER_OFFSET]; next = NULL; #ifdef SRSLTE_BUFFER_POOL_LOG_ENABLED @@ -144,24 +142,23 @@ public: } uint32_t get_headroom() { return msg - buffer; } // Returns the remaining space from what is reported to be the length of msg - uint32_t get_tailroom() { return (sizeof(buffer) - (msg - buffer) - N_bytes); } - long get_latency_us() + uint32_t get_tailroom() { return (sizeof(buffer) - (msg - buffer) - N_bytes); } + std::chrono::microseconds get_latency_us() { #ifdef ENABLE_TIMESTAMP - if (!timestamp_is_set) - return 0; - gettimeofday(×tamp[2], NULL); - get_time_interval(timestamp); - return timestamp[0].tv_usec + timestamp[0].tv_sec * 1000000; + if (!timestamp_is_set) { + return std::chrono::microseconds{0}; + } + return std::chrono::duration_cast(std::chrono::high_resolution_clock::now() - tp); #else - return 0; + return std::chrono::microseconds{0}; #endif } void set_timestamp() { #ifdef ENABLE_TIMESTAMP - gettimeofday(×tamp[1], NULL); + tp = std::chrono::high_resolution_clock::now(); timestamp_is_set = true; #endif } @@ -174,8 +171,8 @@ public: private: #ifdef ENABLE_TIMESTAMP - struct timeval timestamp[3]; - bool timestamp_is_set; + std::chrono::high_resolution_clock::time_point tp; + bool timestamp_is_set = false; #endif byte_buffer_t* next; }; diff --git a/lib/src/upper/rlc_am_lte.cc b/lib/src/upper/rlc_am_lte.cc index 1270288ed..a07c84777 100644 --- a/lib/src/upper/rlc_am_lte.cc +++ b/lib/src/upper/rlc_am_lte.cc @@ -838,7 +838,7 @@ int rlc_am_lte::rlc_am_lte_tx::build_data_pdu(uint8_t* payload, uint32_t nof_byt tx_sdu->msg += to_move; if (tx_sdu->N_bytes == 0) { #ifdef ENABLE_TIMESTAMP - long latency_us = tx_sdu->get_latency_us(); + long latency_us = tx_sdu->get_latency_us().count(); 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, @@ -886,7 +886,7 @@ int rlc_am_lte::rlc_am_lte_tx::build_data_pdu(uint8_t* payload, uint32_t nof_byt tx_sdu->msg += to_move; if (tx_sdu->N_bytes == 0) { #ifdef ENABLE_TIMESTAMP - long latency_us = tx_sdu->get_latency_us(); + long latency_us = tx_sdu->get_latency_us().count(); 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, diff --git a/lib/src/upper/rlc_tm.cc b/lib/src/upper/rlc_tm.cc index ef38f0b56..1f63c6bab 100644 --- a/lib/src/upper/rlc_tm.cc +++ b/lib/src/upper/rlc_tm.cc @@ -142,7 +142,7 @@ int rlc_tm::read_pdu(uint8_t* payload, uint32_t nof_bytes) memcpy(payload, buf->msg, buf->N_bytes); log->debug("%s Complete SDU scheduled for tx. Stack latency: %ld us\n", rrc->get_rb_name(lcid).c_str(), - buf->get_latency_us()); + buf->get_latency_us().count()); log->info_hex(payload, pdu_size, "TX %s, %s PDU, queue size=%d, bytes=%d", diff --git a/lib/src/upper/rlc_um_lte.cc b/lib/src/upper/rlc_um_lte.cc index e3c77054d..0211df507 100644 --- a/lib/src/upper/rlc_um_lte.cc +++ b/lib/src/upper/rlc_um_lte.cc @@ -146,7 +146,7 @@ int rlc_um_lte::rlc_um_lte_tx::build_data_pdu(unique_byte_buffer_t pdu, uint8_t* tx_sdu->msg += to_move; if (tx_sdu->N_bytes == 0) { #ifdef ENABLE_TIMESTAMP - long latency_us = tx_sdu->get_latency_us(); + auto latency_us = tx_sdu->get_latency_us().count(); 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(), @@ -185,7 +185,7 @@ int rlc_um_lte::rlc_um_lte_tx::build_data_pdu(unique_byte_buffer_t pdu, uint8_t* tx_sdu->msg += to_move; if (tx_sdu->N_bytes == 0) { #ifdef ENABLE_TIMESTAMP - long latency_us = tx_sdu->get_latency_us(); + auto latency_us = tx_sdu->get_latency_us().count(); 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(), diff --git a/lib/src/upper/rlc_um_nr.cc b/lib/src/upper/rlc_um_nr.cc index 135cd3275..d5406b7b0 100644 --- a/lib/src/upper/rlc_um_nr.cc +++ b/lib/src/upper/rlc_um_nr.cc @@ -139,8 +139,9 @@ int rlc_um_nr::rlc_um_nr_tx::build_data_pdu(unique_byte_buffer_t pdu, uint8_t* p 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()); + log->debug("%s Complete SDU scheduled for tx. Stack latency: %ld us\n", + rb_name.c_str(), + tx_sdu->get_latency_us().count()); tx_sdu.reset(); header.si = rlc_nr_si_field_t::last_segment; } else { @@ -163,8 +164,9 @@ int rlc_um_nr::rlc_um_nr_tx::build_data_pdu(unique_byte_buffer_t pdu, uint8_t* p 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()); + log->debug("%s Complete SDU scheduled for tx. Stack latency: %ld us\n", + rb_name.c_str(), + tx_sdu->get_latency_us().count()); tx_sdu.reset(); header.si = rlc_nr_si_field_t::full_sdu; } else { diff --git a/srsue/src/stack/upper/gw.cc b/srsue/src/stack/upper/gw.cc index fe306d809..314132c9a 100644 --- a/srsue/src/stack/upper/gw.cc +++ b/srsue/src/stack/upper/gw.cc @@ -113,7 +113,7 @@ void gw::get_metrics(gw_metrics_t& m, const uint32_t nof_tti) *******************************************************************************/ void gw::write_pdu(uint32_t lcid, srslte::unique_byte_buffer_t pdu) { - log.info_hex(pdu->msg, pdu->N_bytes, "RX PDU. Stack latency: %ld us\n", pdu->get_latency_us()); + log.info_hex(pdu->msg, pdu->N_bytes, "RX PDU. Stack latency: %ld us\n", pdu->get_latency_us().count()); dl_tput_bytes += pdu->N_bytes; if (!if_up) { log.warning("TUN/TAP not up - dropping gw RX message\n"); @@ -137,8 +137,11 @@ void gw::write_pdu(uint32_t lcid, srslte::unique_byte_buffer_t pdu) void gw::write_pdu_mch(uint32_t lcid, srslte::unique_byte_buffer_t pdu) { if (pdu->N_bytes > 2) { - log.info_hex( - pdu->msg, pdu->N_bytes, "RX MCH PDU (%d B). Stack latency: %ld us\n", pdu->N_bytes, pdu->get_latency_us()); + log.info_hex(pdu->msg, + pdu->N_bytes, + "RX MCH PDU (%d B). Stack latency: %ld us\n", + pdu->N_bytes, + pdu->get_latency_us().count()); dl_tput_bytes += pdu->N_bytes; // Hack to drop initial 2 bytes