From 8fd4ba7486ddfc57145114dda556740aa7ed9ea2 Mon Sep 17 00:00:00 2001 From: Ismael Gomez Date: Wed, 20 Sep 2017 19:57:43 +0200 Subject: [PATCH] added per-thread PHY logging --- srsue/hdr/phy/phch_common.h | 4 ++-- srsue/hdr/phy/phch_worker.h | 3 ++- srsue/hdr/phy/phy.h | 5 +++-- srsue/hdr/ue.h | 2 +- srsue/src/phy/phch_worker.cc | 24 +++++++++++++----------- srsue/src/phy/phy.cc | 9 +++++---- srsue/src/ue.cc | 20 ++++++++++++++++---- srsue/test/mac/mac_test.cc | 36 ++++++++++++++++++++++-------------- 8 files changed, 64 insertions(+), 39 deletions(-) diff --git a/srsue/hdr/phy/phch_common.h b/srsue/hdr/phy/phch_common.h index 7f0075e33..04102fded 100644 --- a/srsue/hdr/phy/phch_common.h +++ b/srsue/hdr/phy/phch_common.h @@ -48,7 +48,6 @@ namespace srsue { /* Common variables used by all phy workers */ phy_interface_rrc::phy_cfg_t *config; phy_args_t *args; - srslte::log *log_h; mac_interface_phy *mac; srslte_ue_ul_t ue_ul; @@ -116,7 +115,8 @@ namespace srsue { bool is_first_of_burst; srslte::radio *radio_h; float cfo; - + srslte::log *log_h; + bool ul_rnti_active(uint32_t tti); bool dl_rnti_active(uint32_t tti); diff --git a/srsue/hdr/phy/phch_worker.h b/srsue/hdr/phy/phch_worker.h index e6fce4f02..307cea0f0 100644 --- a/srsue/hdr/phy/phch_worker.h +++ b/srsue/hdr/phy/phch_worker.h @@ -45,7 +45,7 @@ public: ~phch_worker(); void reset(); void set_common(phch_common *phy); - bool init(uint32_t max_prb); + bool init(uint32_t max_prb, srslte::log *log); bool set_cell(srslte_cell_t cell); @@ -113,6 +113,7 @@ private: /* Common objects */ phch_common *phy; + srslte::log *log_h; srslte_cell_t cell; bool mem_initiated; bool cell_initiated; diff --git a/srsue/hdr/phy/phy.h b/srsue/hdr/phy/phy.h index 2df93b07b..0c77360b2 100644 --- a/srsue/hdr/phy/phy.h +++ b/srsue/hdr/phy/phy.h @@ -52,8 +52,8 @@ public: phy(); bool init(srslte::radio_multi *radio_handler, mac_interface_phy *mac, - rrc_interface_phy *rrc, - srslte::log *log_h, + rrc_interface_phy *rrc, + std::vector log_vec, phy_args_t *args = NULL); void stop(); @@ -148,6 +148,7 @@ private: const static int WORKERS_THREAD_PRIO = 0; srslte::radio_multi *radio_handler; + std::vector log_vec; srslte::log *log_h; srsue::mac_interface_phy *mac; srsue::rrc_interface_phy *rrc; diff --git a/srsue/hdr/ue.h b/srsue/hdr/ue.h index 2bdb0f0ff..473e01e0e 100644 --- a/srsue/hdr/ue.h +++ b/srsue/hdr/ue.h @@ -103,7 +103,7 @@ private: srslte::logger_file logger; #endif // rf_log is on ue_base - srslte::log_filter phy_log; + std::vector phy_log; srslte::log_filter mac_log; srslte::log_filter rlc_log; srslte::log_filter pdcp_log; diff --git a/srsue/src/phy/phch_worker.cc b/srsue/src/phy/phch_worker.cc index f1dff5f8d..b4b1169ed 100644 --- a/srsue/src/phy/phch_worker.cc +++ b/srsue/src/phy/phch_worker.cc @@ -30,10 +30,10 @@ #include "srslte/interfaces/ue_interfaces.h" #include "srslte/asn1/liblte_rrc.h" -#define Error(fmt, ...) if (SRSLTE_DEBUG_ENABLED) phy->log_h->error_line(__FILE__, __LINE__, fmt, ##__VA_ARGS__) -#define Warning(fmt, ...) if (SRSLTE_DEBUG_ENABLED) phy->log_h->warning_line(__FILE__, __LINE__, fmt, ##__VA_ARGS__) -#define Info(fmt, ...) if (SRSLTE_DEBUG_ENABLED) phy->log_h->info_line(__FILE__, __LINE__, fmt, ##__VA_ARGS__) -#define Debug(fmt, ...) if (SRSLTE_DEBUG_ENABLED) phy->log_h->debug_line(__FILE__, __LINE__, fmt, ##__VA_ARGS__) +#define Error(fmt, ...) if (SRSLTE_DEBUG_ENABLED) log_h->error_line(__FILE__, __LINE__, fmt, ##__VA_ARGS__) +#define Warning(fmt, ...) if (SRSLTE_DEBUG_ENABLED) log_h->warning_line(__FILE__, __LINE__, fmt, ##__VA_ARGS__) +#define Info(fmt, ...) if (SRSLTE_DEBUG_ENABLED) log_h->info_line(__FILE__, __LINE__, fmt, ##__VA_ARGS__) +#define Debug(fmt, ...) if (SRSLTE_DEBUG_ENABLED) log_h->debug_line(__FILE__, __LINE__, fmt, ##__VA_ARGS__) /* This is to visualize the channel response */ @@ -106,8 +106,9 @@ void phch_worker::set_common(phch_common* phy_) phy = phy_; } -bool phch_worker::init(uint32_t max_prb) +bool phch_worker::init(uint32_t max_prb, srslte::log *log_h) { + this->log_h = log_h; // ue_sync in phy.cc requires a buffer for 3 subframes for (uint32_t i=0;iargs->nof_rx_ant;i++) { signal_buffer[i] = (cf_t*) srslte_vec_malloc(3 * sizeof(cf_t) * SRSLTE_SF_LEN_PRB(max_prb)); @@ -166,6 +167,7 @@ void phch_worker::set_tti(uint32_t tti_, uint32_t tx_tti_) { tti = tti_; tx_tti = tx_tti_; + log_h->step(tti); } void phch_worker::set_cfo(float cfo_) @@ -477,7 +479,7 @@ bool phch_worker::decode_pdcch_dl(srsue::mac_interface_phy::mac_grant_t* grant) char hexstr[16]; hexstr[0]='\0'; - if (phy->log_h->get_level() >= srslte::LOG_LEVEL_INFO) { + if (log_h->get_level() >= srslte::LOG_LEVEL_INFO) { srslte_vec_sprint_hex(hexstr, dci_msg.data, dci_msg.nof_bits); } Info("PDCCH: DL DCI %s cce_index=%2d, L=%d, n_data_bits=%d, hex=%s\n", srslte_dci_format_string(dci_msg.format), @@ -678,7 +680,7 @@ bool phch_worker::decode_pdcch_ul(mac_interface_phy::mac_grant_t* grant) char hexstr[16]; hexstr[0]='\0'; - if (phy->log_h->get_level() >= srslte::LOG_LEVEL_INFO) { + if (log_h->get_level() >= srslte::LOG_LEVEL_INFO) { srslte_vec_sprint_hex(hexstr, dci_msg.data, dci_msg.nof_bits); } // Change to last_location_ul @@ -783,7 +785,7 @@ void phch_worker::set_uci_periodic_cqi() cqi_report.type = SRSLTE_CQI_TYPE_SUBBAND; cqi_report.subband.subband_cqi = srslte_cqi_from_snr(phy->avg_snr_db); cqi_report.subband.subband_label = 0; - phy->log_h->console("Warning: Subband CQI periodic reports not implemented\n"); + log_h->console("Warning: Subband CQI periodic reports not implemented\n"); Info("PUCCH: Periodic CQI=%d, SNR=%.1f dB\n", cqi_report.subband.subband_cqi, phy->avg_snr_db); } else { cqi_report.type = SRSLTE_CQI_TYPE_WIDEBAND; @@ -1118,13 +1120,13 @@ void phch_worker::start_plot() { #ifdef ENABLE_GUI if (plot_worker_id == -1) { plot_worker_id = get_id(); - phy->log_h->console("Starting plot for worker_id=%d\n", plot_worker_id); + log_h->console("Starting plot for worker_id=%d\n", plot_worker_id); init_plots(this); } else { - phy->log_h->console("Trying to start a plot but already started by worker_id=%d\n", plot_worker_id); + log_h->console("Trying to start a plot but already started by worker_id=%d\n", plot_worker_id); } #else - phy->log_h->console("Trying to start a plot but plots are disabled (ENABLE_GUI constant in phch_worker.cc)\n"); + log_h->console("Trying to start a plot but plots are disabled (ENABLE_GUI constant in phch_worker.cc)\n"); #endif } diff --git a/srsue/src/phy/phy.cc b/srsue/src/phy/phy.cc index afce102b3..44b548c4e 100644 --- a/srsue/src/phy/phy.cc +++ b/srsue/src/phy/phy.cc @@ -96,12 +96,13 @@ bool phy::check_args(phy_args_t *args) } bool phy::init(srslte::radio_multi* radio_handler, mac_interface_phy *mac, rrc_interface_phy *rrc, - srslte::log *log_h, phy_args_t *phy_args) { + std::vector log_vec, phy_args_t *phy_args) { mlockall(MCL_CURRENT | MCL_FUTURE); n_ta = 0; - this->log_h = log_h; + this->log_vec = log_vec; + this->log_h = (srslte::log*) log_vec[0]; this->radio_handler = radio_handler; this->mac = mac; this->rrc = rrc; @@ -128,12 +129,12 @@ bool phy::init(srslte::radio_multi* radio_handler, mac_interface_phy *mac, rrc_i void phy::run_thread() { prach_buffer.init(&config.common.prach_cnfg, SRSLTE_MAX_PRB, args, log_h); - workers_common.init(&config, args, log_h, radio_handler, mac); + workers_common.init(&config, args, (srslte::log*) log_vec[0], radio_handler, mac); // Add workers to workers pool and start threads for (uint32_t i=0;iworker_cpu_mask); } diff --git a/srsue/src/ue.cc b/srsue/src/ue.cc index 4619b43ce..aab6bbc08 100644 --- a/srsue/src/ue.cc +++ b/srsue/src/ue.cc @@ -56,7 +56,15 @@ bool ue::init(all_args_t *args_) logger.init(args->log.filename); #endif rf_log.init("RF ", &logger); - phy_log.init("PHY ", &logger, true); + // Create array of pointers to phy_logs + for (int i=0;iexpert.phy.nof_phy_threads;i++) { + srslte::log_filter *mylog = new srslte::log_filter; + char tmp[16]; + sprintf(tmp, "PHY%d",i); + mylog->init(tmp, &logger, true); + phy_log.push_back((void*) mylog); + } + mac_log.init("MAC ", &logger, true); rlc_log.init("RLC ", &logger); pdcp_log.init("PDCP", &logger); @@ -70,7 +78,9 @@ bool ue::init(all_args_t *args_) logger.log("\n\n"); #endif rf_log.set_level(srslte::LOG_LEVEL_INFO); - phy_log.set_level(level(args->log.phy_level)); + for (int i=0;iexpert.phy.nof_phy_threads;i++) { + ((srslte::log_filter*) phy_log[i])->set_level(level(args->log.phy_level)); + } mac_log.set_level(level(args->log.mac_level)); rlc_log.set_level(level(args->log.rlc_level)); pdcp_log.set_level(level(args->log.pdcp_level)); @@ -79,7 +89,9 @@ bool ue::init(all_args_t *args_) gw_log.set_level(level(args->log.gw_level)); usim_log.set_level(level(args->log.usim_level)); - phy_log.set_hex_limit(args->log.phy_hex_limit); + for (int i=0;iexpert.phy.nof_phy_threads;i++) { + ((srslte::log_filter*) phy_log[i])->set_hex_limit(args->log.phy_hex_limit); + } mac_log.set_hex_limit(args->log.mac_hex_limit); rlc_log.set_hex_limit(args->log.rlc_hex_limit); pdcp_log.set_hex_limit(args->log.pdcp_hex_limit); @@ -104,7 +116,7 @@ bool ue::init(all_args_t *args_) // PHY initis in background, start before radio args->expert.phy.nof_rx_ant = args->rf.nof_rx_ant; - phy.init(&radio, &mac, &rrc, &phy_log, &args->expert.phy); + phy.init(&radio, &mac, &rrc, phy_log, &args->expert.phy); /* Start Radio */ char *dev_name = NULL; diff --git a/srsue/test/mac/mac_test.cc b/srsue/test/mac/mac_test.cc index 368a7f35e..4cb47e9f8 100644 --- a/srsue/test/mac/mac_test.cc +++ b/srsue/test/mac/mac_test.cc @@ -427,22 +427,11 @@ private: int main(int argc, char *argv[]) { - srslte::log_filter mac_log("MAC"), phy_log("PHY"); + srslte::log_filter mac_log("MAC"); rlctest my_rlc; parse_args(&prog_args, argc, argv); - switch (prog_args.verbose) { - case 1: - mac_log.set_level(srslte::LOG_LEVEL_INFO); - phy_log.set_level(srslte::LOG_LEVEL_INFO); - break; - case 2: - mac_log.set_level(srslte::LOG_LEVEL_DEBUG); - phy_log.set_level(srslte::LOG_LEVEL_DEBUG); - break; - } - - // Capture SIGINT to write traces + // Capture SIGINT to write traces if (prog_args.do_trace) { signal(SIGINT, sig_int_handler); //radio.start_trace(); @@ -461,7 +450,26 @@ int main(int argc, char *argv[]) if (!radio.init()) { exit(1); } - phy.init(&radio, &mac, NULL, &phy_log); + + std::vector phy_log; + + srslte::log_filter *mylog = new srslte::log_filter("PHY"); + char tmp[16]; + sprintf(tmp, "PHY%d",0); + phy_log.push_back((void*) mylog); + + switch (prog_args.verbose) { + case 1: + mac_log.set_level(srslte::LOG_LEVEL_INFO); + mylog->set_level(srslte::LOG_LEVEL_INFO); + break; + case 2: + mac_log.set_level(srslte::LOG_LEVEL_DEBUG); + mylog->set_level(srslte::LOG_LEVEL_DEBUG); + break; + } + + phy.init(&radio, &mac, NULL, phy_log); if (prog_args.rf_rx_gain > 0 && prog_args.rf_tx_gain > 0) { radio.set_rx_gain(prog_args.rf_rx_gain); radio.set_tx_gain(prog_args.rf_tx_gain);