Remove rlc traces and add new ones into tti run functions both in the enb and ue.

lib/src/upper/rlc_am_lte.cc

@@ -1075,8 +1075,6 @@ void rlc_am_lte::rlc_am_lte_tx::handle_control_pdu(uint8_t* payload, uint32_t no
 
   std::unique_lock<std::mutex> lock(mutex);
 
-  trace_complete_event("rlc_am::handle_control_pdu", "total time");
-
   logger.info(payload, nof_bytes, "%s Rx control PDU", RB_NAME);
 
   rlc_status_pdu_t status;
@@ -1169,7 +1167,6 @@ void rlc_am_lte::rlc_am_lte_tx::handle_control_pdu(uint8_t* payload, uint32_t no
 
   if (not notify_info_vec.empty()) {
     // Remove all SDUs that were fully acked
-    trace_complete_event("rlc_am::handle_control_pdu", "remove acked sdus");
     for (uint32_t acked_pdcp_sn : notify_info_vec) {
       logger.debug("Erasing SDU info: PDCP_SN=%d", acked_pdcp_sn);
       if (not undelivered_sdu_info_queue.has_pdcp_sn(acked_pdcp_sn)) {
@@ -1185,7 +1182,6 @@ void rlc_am_lte::rlc_am_lte_tx::handle_control_pdu(uint8_t* payload, uint32_t no
 
   // Notify PDCP without holding Tx mutex
   if (not notify_info_vec.empty()) {
-    trace_complete_event("rlc_am::handle_control_pdu", "notify_delivery");
     parent->pdcp->notify_delivery(parent->lcid, notify_info_vec);
   }
   notify_info_vec.clear();

srsenb/src/stack/enb_stack_lte.cc

@@ -14,6 +14,7 @@
 #include "srsenb/hdr/enb.h"
 #include "srslte/common/network_utils.h"
 #include "srslte/interfaces/enb_metrics_interface.h"
+#include "srslte/srslog/event_trace.h"
 
 using namespace srslte;
 
@@ -166,6 +167,7 @@ void enb_stack_lte::tti_clock()
 
 void enb_stack_lte::tti_clock_impl()
 {
+  trace_complete_event("enb_stack_lte::tti_clock_impl", "total_time");
   task_sched.tic();
   rrc.tti_clock();
 }

srsenb/src/stack/mac/mac.cc

@@ -20,6 +20,7 @@
 #include "srslte/interfaces/enb_phy_interfaces.h"
 #include "srslte/interfaces/enb_rlc_interfaces.h"
 #include "srslte/interfaces/enb_rrc_interfaces.h"
+#include "srslte/srslog/event_trace.h"
 
 // #define WRITE_SIB_PCAP
 using namespace asn1::rrc;
@@ -575,6 +576,7 @@ int mac::get_dl_sched(uint32_t tti_tx_dl, dl_sched_list_t& dl_sched_res_list)
     return 0;
   }
 
+  trace_complete_event("mac::get_dl_sched", "total_time");
   logger.set_context(TTI_SUB(tti_tx_dl, FDD_HARQ_DELAY_UL_MS));
   log_h->step(TTI_SUB(tti_tx_dl, FDD_HARQ_DELAY_UL_MS));
 

srsue/hdr/ue.h

@@ -62,6 +62,8 @@ typedef struct {
   bool        metrics_csv_append;
   int         metrics_csv_flush_period_sec;
   std::string metrics_csv_filename;
+  bool        tracing_enable;
+  std::string tracing_filename;
 } general_args_t;
 
 typedef struct {

srsue/src/main.cc

@@ -17,6 +17,7 @@
 #include "srslte/common/logmap.h"
 #include "srslte/common/metrics_hub.h"
 #include "srslte/common/signal_handler.h"
+#include "srslte/srslog/event_trace.h"
 #include "srslte/srslog/srslog.h"
 #include "srslte/srslte.h"
 #include "srslte/version.h"
@@ -419,6 +420,14 @@ static int parse_args(all_args_t* args, int argc, char* argv[])
            bpo::value<int>(&args->general.metrics_csv_flush_period_sec)->default_value(-1),
            "Periodicity in s to flush CSV file to disk (-1 for auto)")
 
+    ("general.tracing_enable",
+           bpo::value<bool>(&args->general.tracing_enable)->default_value(false),
+           "Events tracing")
+
+    ("general.tracing_filename",
+           bpo::value<string>(&args->general.tracing_filename)->default_value("/tmp/ue_tracing.log"),
+           "Tracing events filename")
+
     ("stack.have_tti_time_stats",
         bpo::value<bool>(&args->stack.have_tti_time_stats)->default_value(true),
         "Calculate TTI execution statistics")
@@ -642,6 +651,14 @@ int main(int argc, char* argv[])
   srslte::srslog_wrapper log_wrapper(*chan);
   srslog::set_default_sink(*log_sink);
 
+#ifdef ENABLE_SRSLOG_EVENT_TRACE
+  if (args.general.tracing_enable) {
+    srslog::sink&        tracing_sink = srslog::fetch_file_sink(args.general.tracing_filename);
+    srslog::log_channel& c            = srslog::fetch_log_channel("tracing", tracing_sink, {"TRACE", '\0', false});
+    srslog::event_trace_init(c);
+  }
+#endif
+
   // Start the log backend.
   srslog::init();
 

srsue/src/stack/ue_stack_lte.cc

@@ -13,7 +13,7 @@
 #include "srsue/hdr/stack/ue_stack_lte.h"
 #include "srslte/common/logmap.h"
 #include "srslte/interfaces/ue_phy_interfaces.h"
-
+#include "srslte/srslog/event_trace.h"
 #include <algorithm>
 #include <chrono>
 #include <numeric>
@@ -401,6 +401,9 @@ void ue_stack_lte::run_tti_impl(uint32_t tti, uint32_t tti_jump)
   if (args.have_tti_time_stats) {
     tti_tprof.start();
   }
+
+  trace_complete_event("ue_stack_lte::run_tti_impl", "total time");
+
   current_tti = tti_point{tti};
 
   // perform tasks for the received TTI range

srsue/ue.conf.example

@@ -381,7 +381,9 @@ enable = false
 #
 #####################################################################
 [general]
-#metrics_csv_enable  = false
-#metrics_period_secs = 1
+#metrics_csv_enable   = false
+#metrics_period_secs  = 1
 #metrics_csv_filename = /tmp/ue_metrics.csv
-#have_tti_time_stats = true
+#have_tti_time_stats  = true
+#tracing_enable       = true
+#tracing_filename     = /tmp/ue_tracing.log