- Port time related classes to srslog.

- Adapt tti_point_test to srslog.
master
faluco 4 years ago committed by faluco
parent 1a5799a6ca
commit b014233662

@ -252,7 +252,7 @@ private:
} \ } \
} while (0) } while (0)
#define TESTASSERT(cond) CONDERROR((not(cond)), "[%s][Line %d] Fail at \"%s\"\n", __FUNCTION__, __LINE__, (#cond)) #define TESTASSERT(cond) CONDERROR((not(cond)), "[%s][Line %d] Fail at \"%s\"", __FUNCTION__, __LINE__, (#cond))
#else // if C #else // if C

@ -48,8 +48,7 @@ class tprof
public: public:
template <typename... Args> template <typename... Args>
explicit tprof(Args&&... args) : prof(std::forward<Args>(args)...) explicit tprof(Args&&... args) : prof(std::forward<Args>(args)...)
{ {}
}
void start() { meas.start(); } void start() { meas.start(); }
@ -71,8 +70,7 @@ class tprof<Prof, false>
public: public:
template <typename... Args> template <typename... Args>
explicit tprof(Args&&... args) explicit tprof(Args&&... args)
{ {}
}
void start() {} void start() {}
@ -106,8 +104,7 @@ struct mutexed_tprof {
template <typename... Args> template <typename... Args>
explicit mutexed_tprof(Args&&... args) : prof(std::forward<Args>(args)...) explicit mutexed_tprof(Args&&... args) : prof(std::forward<Args>(args)...)
{ {}
}
measure start() { return measure{this}; } measure start() { return measure{this}; }
Prof prof; Prof prof;
@ -126,8 +123,7 @@ struct mutexed_tprof<Prof, false> {
template <typename... Args> template <typename... Args>
explicit mutexed_tprof(Args&&... args) explicit mutexed_tprof(Args&&... args)
{ {}
}
measure start() { return measure{}; } measure start() { return measure{}; }
}; };
@ -135,11 +131,11 @@ struct avg_time_stats {
avg_time_stats(const char* name_, const char* logname, size_t print_period_); avg_time_stats(const char* name_, const char* logname, size_t print_period_);
void operator()(std::chrono::nanoseconds duration); void operator()(std::chrono::nanoseconds duration);
srslte::log_ref log_ptr; srslog::basic_logger& logger;
std::string name; std::string name;
double avg_val = 1; double avg_val = 1;
long count = 0, max_val = 0, min_val = std::numeric_limits<long>::max(); long count = 0, max_val = 0, min_val = std::numeric_limits<long>::max();
long print_period = 0; long print_period = 0;
}; };
template <typename TUnit> template <typename TUnit>
@ -149,7 +145,7 @@ public:
sliding_window_stats(const char* name_, const char* logname, size_t print_period_ = 10); sliding_window_stats(const char* name_, const char* logname, size_t print_period_ = 10);
void operator()(std::chrono::nanoseconds duration); void operator()(std::chrono::nanoseconds duration);
srslte::log_ref log_ptr; srslog::basic_logger& logger;
std::string name; std::string name;
std::vector<std::chrono::nanoseconds> sliding_window; std::vector<std::chrono::nanoseconds> sliding_window;
size_t window_idx = 0; size_t window_idx = 0;

@ -64,11 +64,11 @@ class timer_handler
bool set(uint32_t duration_) bool set(uint32_t duration_)
{ {
if (duration_ > MAX_TIMER_DURATION) { if (duration_ > MAX_TIMER_DURATION) {
ERROR("Error: timer durations above %u are not supported\n", MAX_TIMER_DURATION); ERROR("Error: timer durations above %u are not supported", MAX_TIMER_DURATION);
return false; return false;
} }
if (not active) { if (not active) {
ERROR("Error: setting inactive timer id=%d\n", id()); ERROR("Error: setting inactive timer id=%d", id());
return false; return false;
} }
duration = duration_; duration = duration_;
@ -92,7 +92,7 @@ class timer_handler
{ {
std::unique_lock<std::mutex> lock(parent->mutex); std::unique_lock<std::mutex> lock(parent->mutex);
if (not active) { if (not active) {
ERROR("Error: calling run() for inactive timer id=%d\n", id()); ERROR("Error: calling run() for inactive timer id=%d", id());
return; return;
} }
timeout = parent->cur_time + duration; timeout = parent->cur_time + duration;

@ -30,7 +30,7 @@ struct tti_point {
if (diff < 10240) { if (diff < 10240) {
tti_val = 10240 - diff - 1; tti_val = 10240 - diff - 1;
} else { } else {
srslte::logmap::get("COMMON")->error("Invalid TTI point assigned\n"); srslog::fetch_basic_logger("COMMON").error("Invalid TTI point assigned");
} }
} }
} }

@ -21,21 +21,21 @@ class dummy_radio
private: private:
static const int radio_delay_us = 200; static const int radio_delay_us = 200;
srslte::log_filter* log_h = nullptr; srslog::basic_logger& logger;
std::mutex mutex; std::mutex mutex;
uint32_t last_tti = 0; uint32_t last_tti = 0;
bool first = true; bool first = true;
bool late = false; bool late = false;
public: public:
dummy_radio(srslte::log_filter& log_h_) : log_h(&log_h_) { log_h->info("Dummy radio created\n"); } explicit dummy_radio(srslog::basic_logger& logger) : logger(logger) { logger.info("Dummy radio created"); }
void tx(uint32_t tti) void tx(uint32_t tti)
{ {
std::lock_guard<std::mutex> lock(mutex); std::lock_guard<std::mutex> lock(mutex);
log_h->info("Transmitting TTI %d\n", tti); logger.info("Transmitting TTI %d", tti);
// Exit if TTI was advanced // Exit if TTI was advanced
if (!first && tti <= last_tti) { if (!first && tti <= last_tti) {
@ -59,8 +59,8 @@ private:
static const int sleep_time_min_us = 50; static const int sleep_time_min_us = 50;
static const int sleep_time_max_us = 2000; static const int sleep_time_max_us = 2000;
srslog::basic_logger& logger;
srslte::tti_semaphore<uint32_t>* tti_semaphore = nullptr; srslte::tti_semaphore<uint32_t>* tti_semaphore = nullptr;
srslte::log_filter* log_h = nullptr;
dummy_radio* radio = nullptr; dummy_radio* radio = nullptr;
srslte_random_t random_gen = nullptr; srslte_random_t random_gen = nullptr;
uint32_t tti = 0; uint32_t tti = 0;
@ -68,14 +68,14 @@ private:
public: public:
dummy_worker(uint32_t id, dummy_worker(uint32_t id,
srslte::tti_semaphore<uint32_t>* tti_semaphore_, srslte::tti_semaphore<uint32_t>* tti_semaphore_,
srslte::log_filter* log_h_, srslog::basic_logger& logger,
dummy_radio* radio_) dummy_radio* radio_) :
logger(logger)
{ {
tti_semaphore = tti_semaphore_; tti_semaphore = tti_semaphore_;
log_h = log_h_;
radio = radio_; radio = radio_;
random_gen = srslte_random_init(id); random_gen = srslte_random_init(id);
log_h->info("Dummy worker created\n"); logger.info("Dummy worker created");
} }
~dummy_worker() { srslte_random_free(random_gen); } ~dummy_worker() { srslte_random_free(random_gen); }
@ -91,9 +91,9 @@ protected:
// Inform // Inform
// Actual work ;) // Actual work ;)
log_h->info("Start working for %d us.\n", sleep_time_us); logger.info("Start working for %d us.", sleep_time_us);
usleep(sleep_time_us); usleep(sleep_time_us);
log_h->info("Stopped working\n"); logger.info("Stopped working");
// Wait for green light // Wait for green light
tti_semaphore->wait(tti); tti_semaphore->wait(tti);
@ -121,28 +121,15 @@ int main(int argc, char** argv)
std::vector<std::unique_ptr<dummy_worker> > workers; std::vector<std::unique_ptr<dummy_worker> > workers;
srslte::tti_semaphore<uint32_t> tti_semaphore; srslte::tti_semaphore<uint32_t> tti_semaphore;
// Setup logging. // Loggers.
srslog::sink* s = srslog::create_stdout_sink(); auto& radio_logger = srslog::fetch_basic_logger("radio", false);
if (!s) { radio_logger.set_level(srslog::basic_levels::none);
return SRSLTE_ERROR;
}
srslog::log_channel* chan = srslog::create_log_channel("main_channel", *s);
if (!chan) {
return SRSLTE_ERROR;
}
srslte::srslog_wrapper logger(*chan);
// Start the log backend. // Start the log backend.
srslog::init(); srslog::init();
// Loggers
srslte::log_filter radio_log("radio", &logger);
std::vector<std::unique_ptr<srslte::log_filter> > worker_logs;
radio_log.set_level("none");
// Radio // Radio
dummy_radio radio(radio_log); dummy_radio radio(radio_logger);
// Create workers // Create workers
for (uint32_t i = 0; i < nof_workers; i++) { for (uint32_t i = 0; i < nof_workers; i++) {
@ -150,15 +137,13 @@ int main(int argc, char** argv)
char log_name[32] = {}; char log_name[32] = {};
snprintf(log_name, sizeof(log_name), "PHY%d", i); snprintf(log_name, sizeof(log_name), "PHY%d", i);
// Create log filter auto& logger = srslog::fetch_basic_logger(log_name, false);
srslte::log_filter* log_filter = new srslte::log_filter(log_name, &logger); logger.set_level(srslog::basic_levels::none);
log_filter->set_level("none");
// Create worker // Create worker
auto* worker = new dummy_worker(i, &tti_semaphore, log_filter, &radio); auto* worker = new dummy_worker(i, &tti_semaphore, logger, &radio);
// Push back objects // Push back objects
worker_logs.push_back(std::unique_ptr<srslte::log_filter>(log_filter));
workers.push_back(std::unique_ptr<dummy_worker>(worker)); workers.push_back(std::unique_ptr<dummy_worker>(worker));
// Init worker in pool // Init worker in pool

@ -59,7 +59,7 @@ bool threads_new_rt_cpu(pthread_t* thread, void* (*start_routine)(void*), void*
} }
if (pthread_attr_setschedparam(&attr, &param)) { if (pthread_attr_setschedparam(&attr, &param)) {
perror("pthread_attr_setschedparam"); perror("pthread_attr_setschedparam");
ERROR("Error not enough privileges to set Scheduling priority\n"); ERROR("Error not enough privileges to set Scheduling priority");
} }
attr_enable = true; attr_enable = true;
} else if (prio_offset == -1) { } else if (prio_offset == -1) {
@ -73,7 +73,7 @@ bool threads_new_rt_cpu(pthread_t* thread, void* (*start_routine)(void*), void*
} }
if (pthread_attr_setschedparam(&attr, &param)) { if (pthread_attr_setschedparam(&attr, &param)) {
perror("pthread_attr_setschedparam"); perror("pthread_attr_setschedparam");
ERROR("Error not enough privileges to set Scheduling priority\n"); ERROR("Error not enough privileges to set Scheduling priority");
} }
attr_enable = true; attr_enable = true;
} else if (prio_offset == -2) { } else if (prio_offset == -2) {

@ -54,11 +54,8 @@ const char* get_tunit_str<std::chrono::minutes>()
// tprof stats // tprof stats
avg_time_stats::avg_time_stats(const char* name_, const char* logname, size_t print_period_) : avg_time_stats::avg_time_stats(const char* name_, const char* logname, size_t print_period_) :
name(name_), name(name_), logger(srslog::fetch_basic_logger(logname)), print_period(print_period_)
log_ptr(srslte::logmap::get(logname)), {}
print_period(print_period_)
{
}
void avg_time_stats::operator()(nanoseconds duration) void avg_time_stats::operator()(nanoseconds duration)
{ {
@ -67,22 +64,19 @@ void avg_time_stats::operator()(nanoseconds duration)
max_val = std::max<long>(max_val, duration.count()); max_val = std::max<long>(max_val, duration.count());
min_val = std::min<long>(min_val, duration.count()); min_val = std::min<long>(min_val, duration.count());
if (count % print_period == 0) { if (count % print_period == 0) {
log_ptr->info("%s: {mean, max, min}={%0.1f, %ld, %ld} usec, nof_samples=%ld", logger.info("%s: {mean, max, min}={%0.1f, %ld, %ld} usec, nof_samples=%ld",
name.c_str(), name.c_str(),
avg_val / 1e3, avg_val / 1e3,
max_val / 1000, max_val / 1000,
min_val / 1000, min_val / 1000,
count); count);
} }
} }
template <typename TUnit> template <typename TUnit>
sliding_window_stats<TUnit>::sliding_window_stats(const char* name_, const char* logname, size_t print_period_) : sliding_window_stats<TUnit>::sliding_window_stats(const char* name_, const char* logname, size_t print_period_) :
name(name_), name(name_), logger(srslog::fetch_basic_logger(logname)), sliding_window(print_period_)
log_ptr(srslte::logmap::get(logname)), {}
sliding_window(print_period_)
{
}
template <typename TUnit> template <typename TUnit>
void sliding_window_stats<TUnit>::operator()(nanoseconds duration) void sliding_window_stats<TUnit>::operator()(nanoseconds duration)
@ -91,7 +85,7 @@ void sliding_window_stats<TUnit>::operator()(nanoseconds duration)
const char* unit_str = get_tunit_str<TUnit>(); const char* unit_str = get_tunit_str<TUnit>();
TUnit dur = std::chrono::duration_cast<TUnit>(duration); TUnit dur = std::chrono::duration_cast<TUnit>(duration);
log_ptr->debug("%s: duration=%" PRId64 " %s\n", name.c_str(), dur.count(), unit_str); logger.debug("%s: duration=%" PRId64 " %s", name.c_str(), dur.count(), unit_str);
sliding_window[window_idx++] = duration; sliding_window[window_idx++] = duration;
if (window_idx == sliding_window.size()) { if (window_idx == sliding_window.size()) {
@ -100,12 +94,12 @@ void sliding_window_stats<TUnit>::operator()(nanoseconds duration)
nanoseconds tmin = *std::min_element(sliding_window.begin(), sliding_window.end()); nanoseconds tmin = *std::min_element(sliding_window.begin(), sliding_window.end());
double tmean = static_cast<double>(duration_cast<TUnit>(tsum).count()) / sliding_window.size(); double tmean = static_cast<double>(duration_cast<TUnit>(tsum).count()) / sliding_window.size();
log_ptr->info("%s: {mean, max, min} = {%0.2f, %" PRId64 ", %" PRId64 "} %s\n", logger.info("%s: {mean, max, min} = {%0.2f, %" PRId64 ", %" PRId64 "} %s",
name.c_str(), name.c_str(),
tmean, tmean,
duration_cast<TUnit>(tmax).count(), duration_cast<TUnit>(tmax).count(),
duration_cast<TUnit>(tmin).count(), duration_cast<TUnit>(tmin).count(),
unit_str); unit_str);
window_idx = 0; window_idx = 0;
} }
} }

@ -68,6 +68,7 @@ int test_tti_type()
int main() int main()
{ {
srslog::init();
TESTASSERT(test_tti_type() == SRSLTE_SUCCESS); TESTASSERT(test_tti_type() == SRSLTE_SUCCESS);
return 0; return 0;
} }

Loading…
Cancel
Save