From 8a54aef89d37d0c52ab29d11cc9eb2263e8c0214 Mon Sep 17 00:00:00 2001 From: Francisco Paisana Date: Mon, 16 Mar 2020 11:06:36 +0000 Subject: [PATCH] created a better/more composable design for time measures --- lib/include/srslte/common/time_prof.h | 128 +++++++++----------------- srsenb/src/stack/mac/mac.cc | 15 +-- 2 files changed, 53 insertions(+), 90 deletions(-) diff --git a/lib/include/srslte/common/time_prof.h b/lib/include/srslte/common/time_prof.h index b9ee34da3..6b32f02ac 100644 --- a/lib/include/srslte/common/time_prof.h +++ b/lib/include/srslte/common/time_prof.h @@ -29,125 +29,87 @@ namespace srslte { -template -class mutexed_tprof_measure -{ - using tpoint = std::chrono::time_point; +struct tprof_handler { + explicit tprof_handler(const char* name_) : name(name_) { log_ptr->set_level(LOG_LEVEL_INFO); } + virtual void process(long sample) = 0; -public: - template - explicit mutexed_tprof_measure(Args&&... args) : c(std::forward(args)...) - { - srslte::logmap::get("TPROF")->set_level(LOG_LEVEL_INFO); - } + std::mutex mutex; + srslte::log_ref log_ptr = srslte::logmap::get("TPROF"); + std::string name; +}; - uint8_t start() - { - auto t1 = std::chrono::high_resolution_clock::now(); - std::lock_guard lock(mutex); - auto ret = start_tpoints.insert(std::make_pair(next_id++, t1)); - return ret.first->first; - } +struct avg_tprof : public tprof_handler { + avg_tprof(const char* name_, size_t print_period_) : tprof_handler(name_), print_period(print_period_) {} - void stop(uint8_t id) + void process(long duration) final { - auto t2 = std::chrono::high_resolution_clock::now(); - std::lock_guard lock(mutex); - auto& t1 = start_tpoints[id]; - c.process(std::chrono::duration_cast(t2 - t1).count()); - start_tpoints.erase(id); + count++; + avg_val = avg_val * (count - 1) / count + static_cast(duration) / count; + max_val = std::max(max_val, duration); + min_val = std::min(min_val, duration); + if (count % print_period == 0) { + log_ptr->info("%s: Mean=%0.1fusec, Max=%ldusec, Min=%ldusec, nof_samples=%ld", + name.c_str(), + avg_val / 1e3, + max_val / 1000, + min_val / 1000, + count); + } } -private: - std::mutex mutex; - Callable c; - std::unordered_map start_tpoints; - uint8_t next_id = 0; + double avg_val = 1; + long count = 0, max_val = 0, min_val = std::numeric_limits::max(); + long print_period; }; -template -class tprof_measure -{ +struct tprof_measure { using tpoint = std::chrono::time_point; -public: - template - explicit tprof_measure(Args&&... args) : c(std::forward(args)...) - { - srslte::logmap::get("TPROF")->set_level(LOG_LEVEL_INFO); - } + explicit tprof_measure(tprof_handler* h_) : h(h_) {} void start() { t1 = std::chrono::high_resolution_clock::now(); } void stop() { - auto t2 = std::chrono::high_resolution_clock::now(); - c.process(std::chrono::duration_cast(t2 - t1).count()); + auto t2 = std::chrono::high_resolution_clock::now(); + std::lock_guard lock(h->mutex); + h->process(std::chrono::duration_cast(t2 - t1).count()); } private: - Callable c; - tpoint t1; + tprof_handler* h; + tpoint t1; }; -struct avg_tprof { - avg_tprof(const char* name_, size_t print_period_) : name(name_), print_period(print_period_) {} +struct tprof_measure_guard { + tprof_measure_guard(tprof_handler* h_) : tmeas(h_) { tmeas.start(); } + ~tprof_measure_guard() { tmeas.stop(); } + tprof_measure_guard(const tprof_measure_guard&) = delete; + tprof_measure_guard& operator=(const tprof_measure_guard&) = delete; - void process(long duration) - { - count++; - avg_val = avg_val * (count - 1) / count + static_cast(duration) / count; - max_val = std::max(max_val, duration); - min_val = std::min(min_val, duration); - if (count % print_period == 0) { - log_ptr->info("%s: Mean=%0.1fusec, Max=%ldusec, Min=%ldusec, nof_samples=%ld", - name.c_str(), - avg_val / 1e3, - max_val / 1000, - min_val / 1000, - count); - } - } - - srslte::log_ref log_ptr = srslte::logmap::get("TPROF"); - std::string name; - double avg_val = 1; - long count = 0, max_val = 0, min_val = std::numeric_limits::max(); - long print_period; +private: + tprof_measure tmeas; }; #else namespace srslte { -template -class mutexed_tprof_measure -{ -public: - template - explicit mutexed_tprof_measure(Args&&... c) - { - } - uint8_t start() { return 0; } - void stop(uint8_t id) {} +struct tprof_handler { +}; + +struct avg_tprof : public tprof_handler { + avg_tprof(const char*, size_t) {} }; -template class tprof_measure { public: - template - explicit tprof_measure(Args&&... c) - { - } + explicit tprof_measure(tprof_handler* h_) {} void start() {} void stop() {} }; -struct avg_tprof { - avg_tprof(const char*, size_t) {} -}; - #endif } // namespace srslte diff --git a/srsenb/src/stack/mac/mac.cc b/srsenb/src/stack/mac/mac.cc index 3e0d53324..6168ddcba 100644 --- a/srsenb/src/stack/mac/mac.cc +++ b/srsenb/src/stack/mac/mac.cc @@ -445,10 +445,11 @@ int mac::sr_detected(uint32_t tti, uint16_t rnti) void mac::rach_detected(uint32_t tti, uint32_t enb_cc_idx, uint32_t preamble_idx, uint32_t time_adv) { - static srslte::mutexed_tprof_measure rach_tprof("RACH", 1); + static srslte::avg_tprof rach_tprof("RACH", 1); log_h->step(tti); - uint16_t rnti; - uint8_t tprof_id = rach_tprof.start(); + uint16_t rnti; + srslte::tprof_measure tprof_meas{&rach_tprof}; + tprof_meas.start(); { srslte::rwlock_write_guard lock(rwlock); @@ -472,7 +473,7 @@ void mac::rach_detected(uint32_t tti, uint32_t enb_cc_idx, uint32_t preamble_idx } } - stack_task_queue.push([this, rnti, tti, enb_cc_idx, preamble_idx, time_adv, tprof_id]() mutable { + stack_task_queue.push([this, rnti, tti, enb_cc_idx, preamble_idx, time_adv, tprof_meas]() mutable { // Generate RAR data sched_interface::dl_sched_rar_info_t rar_info = {}; rar_info.preamble_idx = preamble_idx; @@ -490,7 +491,7 @@ void mac::rach_detected(uint32_t tti, uint32_t enb_cc_idx, uint32_t preamble_idx ue_cfg.dl_cfg.tm = SRSLTE_TM1; if (scheduler.ue_cfg(rnti, ue_cfg) != SRSLTE_SUCCESS) { Error("Registering new user rnti=0x%x to SCHED\n", rnti); - rach_tprof.stop(tprof_id); + tprof_meas.stop(); return; } @@ -500,14 +501,14 @@ void mac::rach_detected(uint32_t tti, uint32_t enb_cc_idx, uint32_t preamble_idx // Add temporal rnti to the PHY if (phy_h->add_rnti(rnti, enb_cc_idx, true) != SRSLTE_SUCCESS) { Error("Registering temporal-rnti=0x%x to PHY\n", rnti); - rach_tprof.stop(tprof_id); + tprof_meas.stop(); return; } // Trigger scheduler RACH scheduler.dl_rach_info(enb_cc_idx, rar_info); - rach_tprof.stop(tprof_id); + tprof_meas.stop(); log_h->info("RACH: tti=%d, preamble=%d, offset=%d, temp_crnti=0x%x\n", tti, preamble_idx, time_adv, rnti); log_h->console("RACH: tti=%d, preamble=%d, offset=%d, temp_crnti=0x%x\n", tti, preamble_idx, time_adv, rnti);