modifications to enable phy lib logging

lib/examples/pdsch_enodeb.c

@@ -700,7 +700,7 @@ int main(int argc, char **argv) {
   uint32_t sfn; 
   srslte_refsignal_t csr_refs;
   srslte_refsignal_t mbsfn_refs;
-  srslte_is_example = 1;
+
   srslte_debug_handle_crash(argc, argv);
 
 #ifdef DISABLE_RF

lib/examples/pdsch_ue.c

@@ -352,7 +352,7 @@ int main(int argc, char **argv) {
   uint8_t bch_payload[SRSLTE_BCH_PAYLOAD_LEN];
   int sfn_offset;
   float cfo = 0; 
-  srslte_is_example = 1;
+
   srslte_debug_handle_crash(argc, argv);
 
   parse_args(&prog_args, argc, argv);

lib/include/srslte/common/log.h

@@ -112,9 +112,9 @@ public:
   virtual void warning_line(std::string file, int line, std::string message, ...){error("warning_line not implemented.\n");}
   virtual void info_line(std::string file, int line, std::string message, ...){error("info_line not implemented.\n");}
   virtual void debug_line(std::string file, int line, std::string message, ...){error("debug_line not implemented.\n");}
-
-protected:
   std::string get_service_name() { return service_name; }
+protected:
+  
   uint32_t        tti;
   LOG_LEVEL_ENUM  level;
   int             hex_limit;

lib/include/srslte/phy/utils/debug.h

@@ -48,7 +48,7 @@ SRSLTE_API void get_time_interval(struct timeval * tdata);
 #define SRSLTE_DEBUG_ENABLED 1
 
 SRSLTE_API extern int srslte_verbose;
-SRSLTE_API extern int srslte_is_example;
+SRSLTE_API extern int handler_registered;
 
 #define SRSLTE_VERBOSE_ISINFO() (srslte_verbose>=SRSLTE_VERBOSE_INFO)
 #define SRSLTE_VERBOSE_ISDEBUG() (srslte_verbose>=SRSLTE_VERBOSE_DEBUG)
@@ -58,21 +58,21 @@ SRSLTE_API extern int srslte_is_example;
 #define PRINT_INFO srslte_verbose=SRSLTE_VERBOSE_INFO
 #define PRINT_NONE srslte_verbose=SRSLTE_VERBOSE_NONE
 
-#define DEBUG(_fmt, ...) if (SRSLTE_DEBUG_ENABLED && srslte_verbose >= SRSLTE_VERBOSE_DEBUG && srslte_is_example)\
+#define DEBUG(_fmt, ...) if (SRSLTE_DEBUG_ENABLED && srslte_verbose >= SRSLTE_VERBOSE_DEBUG && !handler_registered)\
         {  fprintf(stdout, "[DEBUG]: " _fmt, ##__VA_ARGS__);  }\
-        else{  srslte_phy_log_print(LOG_LEVEL_DEBUG, _fmt, ##__VA_ARGS__);  }
+        else{  srslte_phy_log_print(LOG_LEVEL_DEBUG, _fmt, ##__VA_ARGS__); }
 
-#define INFO(_fmt, ...) if (SRSLTE_DEBUG_ENABLED && ((srslte_verbose >= SRSLTE_VERBOSE_INFO)) && srslte_is_example)\
+#define INFO(_fmt, ...) if (SRSLTE_DEBUG_ENABLED && srslte_verbose >= SRSLTE_VERBOSE_INFO   && !handler_registered) \
         {  fprintf(stdout, "[INFO]: " _fmt, ##__VA_ARGS__);  }\
         else{  srslte_phy_log_print(LOG_LEVEL_INFO, _fmt, ##__VA_ARGS__); }
 
 #if CMAKE_BUILD_TYPE==Debug
 /* In debug mode, it prints out the  */
-#define ERROR(_fmt, ...) if (srslte_is_example)\
+#define ERROR(_fmt, ...) if (!handler_registered)\
     {   fprintf(stderr, "\e[31m%s.%d: " _fmt "\e[0m\n", __FILE__, __LINE__, ##__VA_ARGS__);}\
         else {srslte_phy_log_print(LOG_LEVEL_ERROR, _fmt, ##__VA_ARGS__);} // 
 #else
-#define ERROR(_fmt, ...) if (srslte_is_example)\
+#define ERROR(_fmt, ...) if (!handler_registered)\
         {   fprintf(stderr, "[ERROR in %s]:" _fmt "\n", __FUNCTION__, ##__VA_ARGS__);}\
         else{srslte_phy_log_print(LOG_LEVEL_ERROR, _fmt, ##__VA_ARGS__);} // 
 #endif /* CMAKE_BUILD_TYPE==Debug */

lib/src/phy/utils/debug.c

@@ -34,7 +34,7 @@
 #include "srslte/version.h"
 
 int srslte_verbose = 0;
-int srslte_is_example = 0;
+int handler_registered = 0;
 
 void get_time_interval(struct timeval * tdata) {
 

srsue/hdr/phy/phch_recv.h

@@ -52,13 +52,13 @@ public:
   ~phch_recv();
   void init(srslte::radio_multi* radio_handler, mac_interface_phy *mac,rrc_interface_phy *rrc,
             prach *prach_buffer, srslte::thread_pool *_workers_pool,
-            phch_common *_worker_com, srslte::log* _log_h, uint32_t nof_rx_antennas, uint32_t prio, int sync_cpu_affinity = -1);
+            phch_common *_worker_com, srslte::log* _log_h, srslte::log *_log_phy_lib_h, uint32_t nof_rx_antennas, uint32_t prio, int sync_cpu_affinity = -1);
   void stop();
   void set_agc_enable(bool enable);
 
   void    set_earfcn(std::vector<uint32_t> earfcn);
   void    force_freq(float dl_freq, float ul_freq);
-  void    srslte_phy_logger(phy_logger_level_t log_level, char *str);
+  
   void    reset_sync();
   void    cell_search_start();
   void    cell_search_stop();
@@ -275,6 +275,7 @@ private:
   mac_interface_phy    *mac;
   rrc_interface_phy    *rrc;
   srslte::log          *log_h;
+  srslte::log          *log_phy_lib_h;
   srslte::thread_pool  *workers_pool;
   srslte::radio_multi  *radio_h;
   phch_common          *worker_com;

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, srslte::log *log, chest_feedback_itf *chest_loop);
+  bool  init(uint32_t max_prb, srslte::log *log, srslte::log *log_phy_lib_h, chest_feedback_itf *chest_loop);
 
   bool  set_cell(srslte_cell_t cell);
 
@@ -117,6 +117,7 @@ private:
   /* Common objects */  
   phch_common    *phy;
   srslte::log    *log_h;
+  srslte::log    *log_phy_lib_h;
   chest_feedback_itf *chest_loop;
   srslte_cell_t  cell;
   bool           mem_initiated;

srsue/hdr/phy/phy.h

@@ -64,7 +64,7 @@ public:
   void set_agc_enable(bool enabled);
 
   void get_metrics(phy_metrics_t &m);
-  
+  void srslte_phy_logger(phy_logger_level_t log_level, char *str);
   
   
   static uint32_t tti_to_SFN(uint32_t tti);
@@ -160,6 +160,7 @@ private:
   srslte::radio_multi      *radio_handler;
   std::vector<void*>        log_vec;
   srslte::log              *log_h;
+  srslte::log              *log_phy_lib_h;
   srsue::mac_interface_phy *mac;
   srsue::rrc_interface_phy *rrc;
 

srsue/hdr/ue_base.h

@@ -81,6 +81,7 @@ typedef struct {
 
 typedef struct {
   std::string   phy_level;
+  std::string   phy_lib_level;
   std::string   mac_level;
   std::string   rlc_level;
   std::string   pdcp_level;

srsue/src/main.cc

@@ -98,6 +98,7 @@ void parse_args(all_args_t *args, int argc, char *argv[]) {
     ("gui.enable", bpo::value<bool>(&args->gui.enable)->default_value(false), "Enable GUI plots")
 
     ("log.phy_level", bpo::value<string>(&args->log.phy_level), "PHY log level")
+    ("log.phy_lib_level", bpo::value<string>(&args->log.phy_lib_level), "PHY lib log level")
     ("log.phy_hex_limit", bpo::value<int>(&args->log.phy_hex_limit), "PHY log hex dump limit")
     ("log.mac_level", bpo::value<string>(&args->log.mac_level), "MAC log level")
     ("log.mac_hex_limit", bpo::value<int>(&args->log.mac_hex_limit), "MAC log hex dump limit")
@@ -327,6 +328,9 @@ void parse_args(all_args_t *args, int argc, char *argv[]) {
     if (!vm.count("log.phy_level")) {
       args->log.phy_level = args->log.all_level;
     }
+    if (!vm.count("log.phy_lib_level")) {
+      args->log.phy_lib_level = args->log.all_level;
+    }
     if (!vm.count("log.mac_level")) {
       args->log.mac_level = args->log.all_level;
     }

srsue/src/phy/phch_recv.cc

@@ -46,30 +46,7 @@ double callback_set_rx_gain(void *h, double gain) {
   return ((phch_recv*) h)->set_rx_gain(gain);
 }
 
-static void srslte_phy_handler(phy_logger_level_t log_level, void *ctx, char *str) {
-  phch_recv *r = (phch_recv *) ctx;
-  r->srslte_phy_logger(log_level, str);
-}
 
-void phch_recv::srslte_phy_logger(phy_logger_level_t log_level, char *str) {
-  if (log_h) {
-    switch(log_level){
-      case LOG_LEVEL_INFO:
-        log_h->info("[PHY_LAYER]: %s", str);
-        break;
-      case LOG_LEVEL_DEBUG:
-        log_h->debug("[PHY_LAYER]: %s", str);
-        break;
-      case LOG_LEVEL_ERROR:
-        log_h->error("[PHY_LAYER]: %s", str);
-        break;
-      default:
-        break;
-    }
-  } else {
-    printf("[PHY_LAYER]: %s\n", str);
-  }
-}
 
 phch_recv::phch_recv() {
   dl_freq = -1;
@@ -81,11 +58,12 @@ phch_recv::phch_recv() {
 
 void phch_recv::init(srslte::radio_multi *_radio_handler, mac_interface_phy *_mac, rrc_interface_phy *_rrc,
                      prach *_prach_buffer, srslte::thread_pool *_workers_pool,
-                     phch_common *_worker_com, srslte::log *_log_h, uint32_t nof_rx_antennas_, uint32_t prio,
+                     phch_common *_worker_com, srslte::log *_log_h, srslte::log *_log_phy_lib_h, uint32_t nof_rx_antennas_, uint32_t prio,
                      int sync_cpu_affinity)
 {
   radio_h = _radio_handler;
   log_h   = _log_h;
+  log_phy_lib_h = _log_phy_lib_h;
   mac     = _mac;
   rrc     = _rrc;
   workers_pool    = _workers_pool;
@@ -118,7 +96,7 @@ void phch_recv::init(srslte::radio_multi *_radio_handler, mac_interface_phy *_ma
   intra_freq_meas.init(worker_com, rrc, log_h);
 
   reset();
-  srslte_phy_log_register_handler(this, srslte_phy_handler);
+  
   // Start main thread
   if (sync_cpu_affinity < 0) {
     start(prio);
@@ -585,6 +563,8 @@ void phch_recv::run_thread()
     }
 
     log_h->step(tti);
+    log_phy_lib_h->step(tti);
+    
     sf_idx = tti%10;
 
     switch (phy_state) {

srsue/src/phy/phch_worker.cc

@@ -107,9 +107,10 @@ void phch_worker::set_common(phch_common* phy_)
   phy = phy_;   
 }
 
-bool phch_worker::init(uint32_t max_prb, srslte::log *log_h, chest_feedback_itf *chest_loop)
+bool phch_worker::init(uint32_t max_prb, srslte::log *log_h, srslte::log *log_phy_lib_h , chest_feedback_itf *chest_loop)
 {
   this->log_h = log_h;
+  this->log_phy_lib_h =  log_phy_lib_h;
   this->chest_loop = chest_loop;
 
   // ue_sync in phy.cc requires a buffer for 3 subframes
@@ -173,6 +174,11 @@ void phch_worker::set_tti(uint32_t tti_, uint32_t tx_tti_)
   tti    = tti_; 
   tx_tti = tx_tti_;
   log_h->step(tti);
+  printf("tti\n");
+  printf("out : %s", log_phy_lib_h->get_service_name());
+  log_phy_lib_h->step(tti);
+  
+  
 }
 
 void phch_worker::set_cfo(float cfo_)

srsue/src/phy/phy.cc

@@ -56,6 +56,31 @@ phy::phy() : workers_pool(MAX_WORKERS),
 {
 }
 
+static void srslte_phy_handler(phy_logger_level_t log_level, void *ctx, char *str) {
+  phy *r = (phy *) ctx;
+  r->srslte_phy_logger(log_level, str);
+}
+
+void phy::srslte_phy_logger(phy_logger_level_t log_level, char *str) {
+  if (log_phy_lib_h) {
+    switch(log_level){
+      case LOG_LEVEL_INFO:
+        log_phy_lib_h->info(" %s", str);
+        break;
+      case LOG_LEVEL_DEBUG:
+        log_phy_lib_h->debug(" %s", str);
+        break;
+      case LOG_LEVEL_ERROR:
+        log_phy_lib_h->error(" %s", str);
+        break;
+      default:
+        break;
+    }
+  } else {
+    printf("[PHY_LIB]: %s\n", str);
+  }
+}
+
 void phy::set_default_args(phy_args_t *args)
 {
   args->nof_rx_ant          = 1;
@@ -105,7 +130,9 @@ bool phy::init(srslte::radio_multi* radio_handler, mac_interface_phy *mac, rrc_i
   this->radio_handler = radio_handler;
   this->mac           = mac;
   this->rrc           = rrc;
-
+  
+  
+  
   if (!phy_args) {
     args = &default_args;
     set_default_args(args);
@@ -118,7 +145,11 @@ bool phy::init(srslte::radio_multi* radio_handler, mac_interface_phy *mac, rrc_i
   }
 
   nof_workers = args->nof_phy_threads;
-
+  
+  this->log_phy_lib_h = (srslte::log*) log_vec[nof_workers];
+  srslte_phy_log_register_handler(this, srslte_phy_handler);
+  
+  
   initiated = false;
   start();
   return true;
@@ -133,12 +164,12 @@ void phy::run_thread() {
   // Add workers to workers pool and start threads
   for (uint32_t i=0;i<nof_workers;i++) {
     workers[i].set_common(&workers_common);
-    workers[i].init(SRSLTE_MAX_PRB, (srslte::log*) log_vec[i], &sf_recv);
+    workers[i].init(SRSLTE_MAX_PRB, (srslte::log*) log_vec[i], (srslte::log*) log_vec[nof_workers], &sf_recv);
     workers_pool.init_worker(i, &workers[i], WORKERS_THREAD_PRIO, args->worker_cpu_mask);
   }
 
   // Warning this must be initialized after all workers have been added to the pool
-  sf_recv.init(radio_handler, mac, rrc, &prach_buffer, &workers_pool, &workers_common, log_h, args->nof_rx_ant, SF_RECV_THREAD_PRIO, args->sync_cpu_affinity);
+  sf_recv.init(radio_handler, mac, rrc, &prach_buffer, &workers_pool, &workers_common, log_h, log_phy_lib_h, args->nof_rx_ant, SF_RECV_THREAD_PRIO, args->sync_cpu_affinity);
 
   // Disable UL signal pregeneration until the attachment 
   enable_pregen_signals(false);

srsue/src/ue.cc

@@ -84,6 +84,16 @@ bool ue::init(all_args_t *args_)
   for (int i=0;i<args->expert.phy.nof_phy_threads;i++) {
     ((srslte::log_filter*) phy_log[i])->set_level(level(args->log.phy_level));
   }
+  
+  /* here we add a log layer to handle logging from the phy library*/
+  srslte::log_filter *lib_log = new srslte::log_filter;
+  char tmp[16];
+  sprintf(tmp, "PHY_LIB");
+  lib_log->init(tmp, logger, true);
+  phy_log.push_back((void*) lib_log);
+  ((srslte::log_filter*) phy_log[args->expert.phy.nof_phy_threads])->set_level(level(args->log.phy_lib_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));
@@ -92,7 +102,7 @@ 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));
 
-  for (int i=0;i<args->expert.phy.nof_phy_threads;i++) {
+  for (int i=0;i<args->expert.phy.nof_phy_threads + 1;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);

srsue/ue.conf.example

@@ -73,6 +73,7 @@ nas_filename = /tmp/nas.pcap
 #####################################################################
 [log]
 all_level = info
+phy_lib_level = none
 all_hex_limit = 32
 filename = /tmp/ue.log