From 50c70bc31646fe780729885677a67a7918fed93d Mon Sep 17 00:00:00 2001
From: Raymond Knopp <raymond.knopp@eurecom.fr>
Date: Tue, 12 Jan 2021 13:51:04 +0100
Subject: [PATCH] writing L1/L2 stats to files rather than screen

---
 openair1/PHY/LTE_TRANSPORT/pucch.c           | 17 +++++---
 openair1/PHY/LTE_TRANSPORT/transport_proto.h |  4 +-
 openair1/PHY/LTE_TRANSPORT/ulsch_decoding.c  | 19 ++++----
 openair1/PHY/defs_eNB.h                      |  2 +
 openair1/SCHED/phy_procedures_lte_eNb.c      |  6 ---
 openair2/LAYER2/MAC/eNB_scheduler.c          | 21 ---------
 openair2/LAYER2/MAC/mac.h                    |  2 +
 openair2/LAYER2/MAC/main.c                   | 46 ++++++++++++++++++++
 targets/RT/USER/lte-enb.c                    | 15 +++++++
 9 files changed, 89 insertions(+), 43 deletions(-)

diff --git a/openair1/PHY/LTE_TRANSPORT/pucch.c b/openair1/PHY/LTE_TRANSPORT/pucch.c
index fd7e7bad76..9418ace334 100644
--- a/openair1/PHY/LTE_TRANSPORT/pucch.c
+++ b/openair1/PHY/LTE_TRANSPORT/pucch.c
@@ -65,21 +65,24 @@ int16_t cfo_pucch_ep[24*6] = {24278,-22005,29621,-14010,32412,-4808,32412,4807,2
 
 
 
-void dump_uci_stats(PHY_VARS_eNB *eNB,int frame) {
+void dump_uci_stats(FILE *fd,PHY_VARS_eNB *eNB,int frame) {
 
-  for (int i=0;i<NUMBER_OF_SCH_STATS_MAX;i++)
+  int strpos=0;
+  char output[16384];
+
+  for (int i=0;i<NUMBER_OF_SCH_STATS_MAX;i++){
     if (eNB->uci_stats[i].rnti>0) {
       eNB_UCI_STATS_t *uci_stats = &eNB->uci_stats[i];
-      LOG_I(PHY,"UCI RNTI %x: pucch1_trials %d, pucch1_thres %d dB, current pucch1_stat %d dB,positive SR count %d\n",
+      strpos+=sprintf(output+strpos,"UCI RNTI %x: pucch1_trials %d, pucch1_thres %d dB, current pucch1_stat %d dB,positive SR count %d\n",
 	uci_stats->rnti,uci_stats->pucch1_trials,uci_stats->pucch1_thres,dB_fixed(uci_stats->current_pucch1_stat),uci_stats->pucch1_positive_SR);
-      LOG_I(PHY,"UCI RNTI %x: pucch1_low (%d,%d)dB pucch1_high (%d,%d)dB\n",
+      strpos+=sprintf(output+strpos,"UCI RNTI %x: pucch1_low (%d,%d)dB pucch1_high (%d,%d)dB\n",
 	    uci_stats->rnti,
             dB_fixed(uci_stats->pucch1_low_stat[0]),
             dB_fixed(uci_stats->pucch1_low_stat[1]),
             dB_fixed(uci_stats->pucch1_high_stat[0]),
             dB_fixed(uci_stats->pucch1_high_stat[1]));
       
-      LOG_I(PHY,"UCI RNTI %x: pucch1a_trials %d, pucch1a_stat (%d,%d), pucch1b_trials %d, pucch1b_stat (%d,%d) pucch1ab_DTX %d\n",
+      strpos+=sprintf(output+strpos,"UCI RNTI %x: pucch1a_trials %d, pucch1a_stat (%d,%d), pucch1b_trials %d, pucch1b_stat (%d,%d) pucch1ab_DTX %d\n",
             uci_stats->rnti,
             uci_stats->pucch1a_trials,
             uci_stats->current_pucch1a_stat_re,
@@ -89,7 +92,9 @@ void dump_uci_stats(PHY_VARS_eNB *eNB,int frame) {
 	    uci_stats->current_pucch1b_stat_im,
             uci_stats->pucch1ab_DTX);
     }
-
+  }
+  if (fd) fprintf(fd,"%s",output);
+  else    printf("%s",output);  
 }
 /* PUCCH format3 >> */
 /* SubCarrier Demap */
diff --git a/openair1/PHY/LTE_TRANSPORT/transport_proto.h b/openair1/PHY/LTE_TRANSPORT/transport_proto.h
index 786aaca6e3..3caa1df05a 100644
--- a/openair1/PHY/LTE_TRANSPORT/transport_proto.h
+++ b/openair1/PHY/LTE_TRANSPORT/transport_proto.h
@@ -520,8 +520,8 @@ int generate_eNB_ulsch_params_from_dci(PHY_VARS_eNB *PHY_vars_eNB,
 
 void dump_ulsch(PHY_VARS_eNB *phy_vars_eNB,int frame, int subframe, uint8_t UE_id,int round);
 
-void dump_ulsch_stats(PHY_VARS_eNB *eNB,int frame);
-void dump_uci_stats(PHY_VARS_eNB *eNB,int frame);
+void dump_ulsch_stats(FILE *fd,PHY_VARS_eNB *eNB,int frame);
+void dump_uci_stats(FILE *fd,PHY_VARS_eNB *eNB,int frame);
 
 
 
diff --git a/openair1/PHY/LTE_TRANSPORT/ulsch_decoding.c b/openair1/PHY/LTE_TRANSPORT/ulsch_decoding.c
index 17f95f31ce..137ffcb219 100644
--- a/openair1/PHY/LTE_TRANSPORT/ulsch_decoding.c
+++ b/openair1/PHY/LTE_TRANSPORT/ulsch_decoding.c
@@ -1116,16 +1116,18 @@ unsigned int  ulsch_decoding(PHY_VARS_eNB *eNB,
   return(ret);
 }
 
+#define STATSTRLEN 16384
+void dump_ulsch_stats(FILE *fd,PHY_VARS_eNB *eNB,int frame) {
 
-void dump_ulsch_stats(PHY_VARS_eNB *eNB,int frame) {
-
+  char output[16384];
+  int stroff=0;
   for (int i=0;i<NUMBER_OF_ULSCH_MAX;i++)
     if (eNB->ulsch_stats[i].rnti>0) { 
-      for (int aa=0;aa<eNB->frame_parms.nb_antennas_rx;aa++)
-        LOG_I(PHY,"ULSCH RNTI %x: ulsch_power[%d] %d, ulsch_noise_power[%d] %d\n", 
+      for (int aa=0;aa<eNB->frame_parms.nb_antennas_rx;aa++) 
+        stroff+=sprintf(output+stroff,"ULSCH RNTI %x: ulsch_power[%d] %d, ulsch_noise_power[%d] %d\n", 
               eNB->ulsch_stats[i].rnti, aa,eNB->ulsch_stats[i].ulsch_power[aa],aa,eNB->ulsch_stats[i].ulsch_noise_power[aa]);
-
-      LOG_I(PHY,"ULSCH RNTI %x: round_trials %d(%1.1e):%d(%1.1e):%d(%1.1e):%d\n",
+      AssertFatal(stroff<(STATSTRLEN-1000),"Increase STATSTRLEN\n");
+      stroff+=sprintf(output+stroff,"ULSCH RNTI %x: round_trials %d(%1.1e):%d(%1.1e):%d(%1.1e):%d\n",
             eNB->ulsch_stats[i].rnti,
             eNB->ulsch_stats[i].round_trials[0],
             (double)eNB->ulsch_stats[i].round_trials[1]/eNB->ulsch_stats[i].round_trials[0],
@@ -1134,7 +1136,7 @@ void dump_ulsch_stats(PHY_VARS_eNB *eNB,int frame) {
             eNB->ulsch_stats[i].round_trials[2],
            (double)eNB->ulsch_stats[i].round_trials[3]/eNB->ulsch_stats[i].round_trials[0],
             eNB->ulsch_stats[i].round_trials[3]);
-      LOG_I(PHY,"ULSCH RNTI %x:  current_Qm %d, current_G %d, current_TBS %d, current_rate %f,current_RI %d, timing_offset %d, total_bytes RX/SCHED %d/%d\n",
+      stroff+=sprintf(output+stroff,"ULSCH RNTI %x:  current_Qm %d, current_G %d, current_TBS %d, current_rate %f,current_RI %d, timing_offset %d, total_bytes RX/SCHED %d/%d\n",
             eNB->ulsch_stats[i].rnti,
             eNB->ulsch_stats[i].current_Qm,
 	    eNB->ulsch_stats[i].current_G,
@@ -1145,7 +1147,8 @@ void dump_ulsch_stats(PHY_VARS_eNB *eNB,int frame) {
             eNB->ulsch_stats[i].total_bytes_rx,
             eNB->ulsch_stats[i].total_bytes_tx);
     }
-  
+  if (fd) fprintf(fd,"%s",output);
+  else    printf("%s",output);  
 }
 
 void clear_ulsch_stats(PHY_VARS_eNB *eNB) {
diff --git a/openair1/PHY/defs_eNB.h b/openair1/PHY/defs_eNB.h
index a2caba8dfd..bae072d532 100644
--- a/openair1/PHY/defs_eNB.h
+++ b/openair1/PHY/defs_eNB.h
@@ -362,6 +362,8 @@ typedef struct L1_proc_t_s {
   L1_rxtx_proc_t L1_proc,L1_proc_tx;
   /// stats thread pthread descriptor
   pthread_t process_stats_thread;
+  /// L1 stats pthread descriptor
+  pthread_t L1_stats_thread;
   /// for waking up tx procedure
   RU_proc_t *ru_proc;
   struct PHY_VARS_eNB_s *eNB;
diff --git a/openair1/SCHED/phy_procedures_lte_eNb.c b/openair1/SCHED/phy_procedures_lte_eNb.c
index 89b3dea7d6..898dfb62aa 100644
--- a/openair1/SCHED/phy_procedures_lte_eNb.c
+++ b/openair1/SCHED/phy_procedures_lte_eNb.c
@@ -2182,12 +2182,6 @@ void phy_procedures_eNB_uespec_RX(PHY_VARS_eNB *eNB,L1_rxtx_proc_t *proc) {
     LOG_I (PHY, "max_I0 %d (rb %d), min_I0 %d (rb %d), avg I0 %d\n", max_I0, amax, min_I0, amin, eNB->measurements.n0_subband_power_avg_dB);
   }
 
-  // figure out a better way to choose slot_rx, 19 is ok for a particular TDD configuration with 30kHz SCS
-  if ((frame&127) == 0 && subframe==3) {
-       dump_ulsch_stats(eNB,frame);
-       dump_uci_stats(eNB,frame);
-  }
-
   // clear unused statistics after 2 seconds
   for (int i=0;i<NUMBER_OF_SCH_STATS_MAX;i++) {
      if (eNB->ulsch_stats[i].frame <= frame) {
diff --git a/openair2/LAYER2/MAC/eNB_scheduler.c b/openair2/LAYER2/MAC/eNB_scheduler.c
index 86704c816a..492bbbddf2 100644
--- a/openair2/LAYER2/MAC/eNB_scheduler.c
+++ b/openair2/LAYER2/MAC/eNB_scheduler.c
@@ -595,27 +595,6 @@ eNB_dlsch_ulsch_scheduler(module_id_t module_idP,
       CC_id = UE_PCCID(module_idP, UE_id);
       UE_scheduling_control = &(UE_info->UE_sched_ctrl[UE_id]);
 
-      if (((frameP & 127) == 0) && (subframeP == 0)) {
-        LOG_I(MAC,"UE  rnti %x : %s, PHR %d dB DL CQI %d PUSCH SNR %d (TPC accum %d)  PUCCH SNR %d (TPC accum %d)\n",
-              rnti,
-              UE_scheduling_control->ul_out_of_sync == 0 ? "in synch" : "out of sync",
-              UE_info->UE_template[CC_id][UE_id].phr_info,
-              UE_scheduling_control->dl_cqi[CC_id],
-              (5 * UE_scheduling_control->pusch_snr[CC_id] - 640) / 10, UE_scheduling_control->pucch_tpc_accumulated[CC_id],
-              (5 * UE_scheduling_control->pucch1_snr[CC_id] - 640) / 10, UE_scheduling_control->pusch_tpc_accumulated[CC_id]);
-        LOG_I(MAC,"              ULSCH rounds %d/%d/%d/%d, DLSCH rounds %d/%d/%d/%d, ULSCH errors %d, DLSCH errors %d\n",
-              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_rounds[0],
-              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_rounds[1],
-              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_rounds[2],
-              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_rounds[3],
-              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_rounds[0],
-              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_rounds[1],
-              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_rounds[2],
-              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_rounds[3],
-              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_errors,
-              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_errors);
-      }
-
       RC.eNB[module_idP][CC_id]->pusch_stats_bsr[UE_id][(frameP * 10) + subframeP] = -63;
 
       if (UE_id == UE_info->list.head) {
diff --git a/openair2/LAYER2/MAC/mac.h b/openair2/LAYER2/MAC/mac.h
index bf8db987d3..160d84e1c0 100644
--- a/openair2/LAYER2/MAC/mac.h
+++ b/openair2/LAYER2/MAC/mac.h
@@ -1433,6 +1433,8 @@ typedef struct eNB_MAC_INST_s {
 
   int32_t puSch10xSnr;
   int32_t puCch10xSnr;
+
+  pthread_t mac_stats_thread;
 } eNB_MAC_INST;
 
 /*
diff --git a/openair2/LAYER2/MAC/main.c b/openair2/LAYER2/MAC/main.c
index af6d1a7ac3..86f2bf0af1 100644
--- a/openair2/LAYER2/MAC/main.c
+++ b/openair2/LAYER2/MAC/main.c
@@ -40,8 +40,51 @@
 #include "RRC/L2_INTERFACE/openair_rrc_L2_interface.h"
 #include "common/ran_context.h"
 #include "intertask_interface.h"
+#include <pthread.h>
 
 extern RAN_CONTEXT_t RC;
+extern int oai_exit;
+
+void *mac_stats_thread(void *param) {
+  eNB_MAC_INST     *mac      = (eNB_MAC_INST *)param;
+  FILE *fd;
+  UE_info_t        *UE_info  = &(mac->UE_info);
+
+  while (!oai_exit) {
+    sleep(1);
+    fd=fopen("MAC_stats.log","w+");
+    AssertFatal(fd!=NULL,"Cannot open MAC_stats.log\n");
+
+    for (int UE_id = 0; UE_id < MAX_MOBILES_PER_ENB; UE_id++) {
+      if (UE_info->active[UE_id]) {
+        int rnti = UE_RNTI(mac->Mod_id, UE_id);
+        int CC_id = UE_PCCID(mac->Mod_id, UE_id);
+        UE_sched_ctrl_t *UE_scheduling_control = &(UE_info->UE_sched_ctrl[UE_id]);
+
+      fprintf(fd,"UE  rnti %x : %s, PHR %d dB DL CQI %d PUSCH SNR %d (TPC accum %d)  PUCCH SNR %d (TPC accum %d)\n",
+              rnti,
+              UE_scheduling_control->ul_out_of_sync == 0 ? "in synch" : "out of sync",
+              UE_info->UE_template[CC_id][UE_id].phr_info,
+              UE_scheduling_control->dl_cqi[CC_id],
+              (5 * UE_scheduling_control->pusch_snr[CC_id] - 640) / 10, UE_scheduling_control->pucch_tpc_accumulated[CC_id],
+              (5 * UE_scheduling_control->pucch1_snr[CC_id] - 640) / 10, UE_scheduling_control->pusch_tpc_accumulated[CC_id]);
+      fprintf(fd,"              ULSCH rounds %d/%d/%d/%d, DLSCH rounds %d/%d/%d/%d, ULSCH errors %d, DLSCH errors %d\n",
+              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_rounds[0],
+              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_rounds[1],
+              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_rounds[2],
+              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_rounds[3],
+              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_rounds[0],
+              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_rounds[1],
+              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_rounds[2],
+              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_rounds[3],
+              UE_info->eNB_UE_stats[CC_id][UE_id].ulsch_errors,
+              UE_info->eNB_UE_stats[CC_id][UE_id].dlsch_errors);
+      }
+    }
+    fclose(fd);
+  }
+  return(NULL);
+}
 
 void init_UE_info(UE_info_t *UE_info)
 {
@@ -128,6 +171,9 @@ void mac_top_init_eNB(void)
   pdcp_layer_init();
 
   rrc_init_global_param();
+
+  for (i=0;i<RC.nb_macrlc_inst; i++) pthread_create(&mac[i]->mac_stats_thread,NULL,mac_stats_thread,(void*)mac[i]);
+
 }
 
 void mac_init_cell_params(int Mod_idP, int CC_idP)
diff --git a/targets/RT/USER/lte-enb.c b/targets/RT/USER/lte-enb.c
index 03ef480131..208e8fba2d 100644
--- a/targets/RT/USER/lte-enb.c
+++ b/targets/RT/USER/lte-enb.c
@@ -846,6 +846,20 @@ static void *process_stats_thread(void *param) {
   return(NULL);
 }
 
+void *L1_stats_thread(void *param) {
+  PHY_VARS_eNB     *eNB      = (PHY_VARS_eNB *)param;
+  wait_sync("L1_stats_thread");
+  FILE *fd;
+  while (!oai_exit) {
+    sleep(1);
+    fd=fopen("L1_stats.log","w");
+    AssertFatal(fd!=NULL,"Cannot open L1_stats.log\n");
+    dump_ulsch_stats(fd,eNB,eNB->proc.L1_proc_tx.frame_tx);
+    dump_uci_stats(fd,eNB,eNB->proc.L1_proc_tx.frame_tx);
+    fclose(fd);
+  }
+  return(NULL);
+}
 
 void init_eNB_proc(int inst) {
   /*int i=0;*/
@@ -940,6 +954,7 @@ void init_eNB_proc(int inst) {
     AssertFatal(proc->instance_cnt_prach == -1,"instance_cnt_prach = %d\n",proc->instance_cnt_prach);
 
     if (opp_enabled == 1) pthread_create(&proc->process_stats_thread,NULL,process_stats_thread,(void *)eNB);
+    pthread_create(&proc->L1_stats_thread,NULL,L1_stats_thread,(void*)eNB);
   }
 
   //for multiple CCs: setup master and slaves
-- 
2.26.2