Merge remote-tracking branch 'origin/fix-test-caracal' into integration_2022_wk23

ci-scripts/conf_files/gnb.band78.tm1.106PRB.usrpn300.conf

@@ -219,7 +219,7 @@ RUs = (
          ## beamforming 4x4 matrix:
          #bf_weights = [0x00007fff, 0x0000, 0x0000, 0x0000, 0x00000000, 0x00007fff, 0x0000, 0x0000, 0x0000, 0x0000, 0x00007fff, 0x0000, 0x0000, 0x0000, 0x0000, 0x00007fff];
 
-         sdr_addrs = "addr=192.168.10.2,second_addr=192.168.20.2,mgmt_addr=192.168.18.85";
+         sdr_addrs = "addr=192.168.10.2,second_addr=192.168.20.2";
     }
 );  
 

ci-scripts/datalog_rt_stats.2x2.yaml

@@ -16,7 +16,7 @@ Ref :
   L1 Rx processing : 175.0
   PUSCH inner-receiver : 100.0
   PUSCH decoding : 180.0 
-  DL & UL scheduling timing stats : 37.0
+  DL & UL scheduling timing : 37.0
   UL Indication : 38.0
 Threshold :
   feprx : 1.25
@@ -28,5 +28,5 @@ Threshold :
   L1 Rx processing : 1.25
   PUSCH inner-receiver : 1.25
   PUSCH decoding : 1.25
-  DL & UL scheduling timing stats : 1.25
+  DL & UL scheduling timing : 1.25
   UL Indication : 1.25

ci-scripts/datalog_rt_stats.default.yaml

@@ -17,7 +17,7 @@ Ref :
   PUSCH inner-receiver : 100.0
   #PUSCH decoding : 180.0
   PUSCH decoding : 240.0
-  DL & UL scheduling timing stats : 37.0
+  DL & UL scheduling timing : 37.0
   UL Indication : 38.0
 Threshold :
   feprx : 1.25
@@ -29,5 +29,5 @@ Threshold :
   L1 Rx processing : 1.25
   PUSCH inner-receiver : 1.25
   PUSCH decoding : 1.25
-  DL & UL scheduling timing stats : 1.25
+  DL & UL scheduling timing : 1.25
   UL Indication : 1.25

ci-scripts/stats_monitor_conf.yaml

@@ -25,7 +25,7 @@ gnb :
     L1 Rx processing:
     PUSCH inner-receiver:
     PUSCH decoding:
-    DL & UL scheduling timing stats:
+    DL & UL scheduling timing:
     UL Indication:
   graph : 
     page1:
@@ -45,5 +45,5 @@ gnb :
     page4:
       rt.PUSCH inner-receiver:
       rt.PUSCH decoding:
-      rt.DL & UL scheduling timing stats:
+      rt.DL & UL scheduling timing:
       rt.UL Indication:

common/utils/time_meas.c

@@ -111,13 +111,15 @@ void print_meas(time_stats_t *ts,
   }
 }
 
-int print_meas_log(time_stats_t *ts,
+size_t print_meas_log(time_stats_t *ts,
                       const char *name,
                       time_stats_t *total_exec_time,
                       time_stats_t *sf_exec_time,
-                char *output)
+                      char *output,
+                      size_t outputlen)
 {
-  int stroff = 0;
+  const char *begin = output;
+  const char *end = output + outputlen;
   static int first_time = 0;
   static double cpu_freq_GHz = 0.0;
 
@@ -128,30 +130,49 @@ int print_meas_log(time_stats_t *ts,
     first_time=1;
 
     if ((total_exec_time == NULL) || (sf_exec_time== NULL))
-      stroff += sprintf(output, "%25s  %25s  %25s  %25s %25s %6f\n","Name","Total","Per Trials",   "Num Trials","CPU_F_GHz", cpu_freq_GHz);
+      output += snprintf(output,
+                         end - output,
+                         "%25s  %25s  %25s  %25s %25s %6f\n",
+                         "Name",
+                         "Total",
+                         "Per Trials",
+                         "Num Trials",
+                         "CPU_F_GHz",
+                         cpu_freq_GHz);
     else
-      stroff += sprintf(output+stroff, "%25s  %25s  %25s  %20s %15s %6f\n","Name","Total","Average/Frame","Trials",    "CPU_F_GHz", cpu_freq_GHz);
+      output += snprintf(output,
+                         end - output,
+                         "%25s  %25s  %25s  %20s %15s %6f\n",
+                         "Name",
+                         "Total",
+                         "Average/Frame",
+                         "Trials",
+                         "CPU_F_GHz",
+                         cpu_freq_GHz);
   }
 
   if (ts->trials>0) {
-    //printf("%20s: total: %10.3f ms, average: %10.3f us (%10d trials)\n", name, ts->diff/cpu_freq_GHz/1000000.0, ts->diff/ts->trials/cpu_freq_GHz/1000.0, ts->trials);
     if ((total_exec_time == NULL) || (sf_exec_time== NULL)) {
-      stroff += sprintf(output+stroff, "%25s:  %15.3f us; %15d; %15.3f us;\n",
+      output += snprintf(output,
+                         end - output,
+                         "%25s:  %15.3f us; %15d; %15.3f us;\n",
                          name,
-              (ts->diff/ts->trials/cpu_freq_GHz/1000.0),
+                         ts->diff / ts->trials / cpu_freq_GHz / 1000.0,
                          ts->trials,
-              ts->max/cpu_freq_GHz/1000.0);
+                         ts->max / cpu_freq_GHz / 1000.0);
     } else {
-      stroff += sprintf(output+stroff, "%25s:  %15.3f ms (%5.2f%%); %15.3f us (%5.2f%%); %15d;\n",
+      output += snprintf(output,
+                         end - output,
+                         "%25s:  %15.3f ms (%5.2f%%); %15.3f us (%5.2f%%); %15d;\n",
                          name,
-              (ts->diff/cpu_freq_GHz/1000000.0),
-              ((ts->diff/cpu_freq_GHz/1000000.0)/(total_exec_time->diff/cpu_freq_GHz/1000000.0))*100,  // percentage
-              (ts->diff/ts->trials/cpu_freq_GHz/1000.0),
-              ((ts->diff/ts->trials/cpu_freq_GHz/1000.0)/(sf_exec_time->diff/sf_exec_time->trials/cpu_freq_GHz/1000.0))*100,  // percentage
+                         ts->diff / cpu_freq_GHz / 1000000.0,
+                         ((ts->diff / cpu_freq_GHz / 1000000.0) / (total_exec_time->diff / cpu_freq_GHz / 1000000.0))*100,  // percentage
+                         ts->diff / ts->trials / cpu_freq_GHz / 1000.0,
+                         ((ts->diff / ts->trials / cpu_freq_GHz / 1000.0) / (sf_exec_time->diff / sf_exec_time->trials / cpu_freq_GHz / 1000.0)) * 100,  // percentage
                          ts->trials);
     }
   }
-  return stroff;
+  return output - begin;
 }
 
 double get_time_meas_us(time_stats_t *ts)

common/utils/time_meas.h

@@ -83,7 +83,12 @@ static inline void stop_meas(time_stats_t *ts) __attribute__((always_inline));
 
 void print_meas_now(time_stats_t *ts, const char *name, FILE *file_name);
 void print_meas(time_stats_t *ts, const char *name, time_stats_t *total_exec_time, time_stats_t *sf_exec_time);
-int print_meas_log(time_stats_t *ts, const char *name, time_stats_t *total_exec_time, time_stats_t *sf_exec_time, char *output);
+size_t print_meas_log(time_stats_t *ts,
+                      const char *name,
+                      time_stats_t *total_exec_time,
+                      time_stats_t *sf_exec_time,
+                      char *output,
+                      size_t outputlen);
 double get_time_meas_us(time_stats_t *ts);
 double get_cpu_freq_GHz(void);
 

executables/nr-gnb.c

@@ -304,32 +304,36 @@ void rx_func(void *param) {
        );
 #endif
 }
-static void dump_L1_meas_stats(PHY_VARS_gNB *gNB, RU_t *ru, char *output) {
-  int stroff = 0;
-  stroff += print_meas_log(&gNB->phy_proc_tx, "L1 Tx processing", NULL, NULL, output);
-  stroff += print_meas_log(&gNB->dlsch_encoding_stats, "DLSCH encoding", NULL, NULL, output+stroff);
-  stroff += print_meas_log(&gNB->phy_proc_rx, "L1 Rx processing", NULL, NULL, output+stroff);
-  stroff += print_meas_log(&gNB->ul_indication_stats, "UL Indication", NULL, NULL, output+stroff);
-  stroff += print_meas_log(&gNB->rx_pusch_stats, "PUSCH inner-receiver", NULL, NULL, output+stroff);
-  stroff += print_meas_log(&gNB->ulsch_decoding_stats, "PUSCH decoding", NULL, NULL, output+stroff);
-  stroff += print_meas_log(&gNB->schedule_response_stats, "Schedule Response",NULL,NULL, output+stroff);
-  if (ru->feprx) stroff += print_meas_log(&ru->ofdm_demod_stats,"feprx",NULL,NULL, output+stroff);
+static size_t dump_L1_meas_stats(PHY_VARS_gNB *gNB, RU_t *ru, char *output, size_t outputlen) {
+  const char *begin = output;
+  const char *end = output + outputlen;
+  output += print_meas_log(&gNB->phy_proc_tx, "L1 Tx processing", NULL, NULL, output, end - output);
+  output += print_meas_log(&gNB->dlsch_encoding_stats, "DLSCH encoding", NULL, NULL, output, end - output);
+  output += print_meas_log(&gNB->phy_proc_rx, "L1 Rx processing", NULL, NULL, output, end - output);
+  output += print_meas_log(&gNB->ul_indication_stats, "UL Indication", NULL, NULL, output, end - output);
+  output += print_meas_log(&gNB->rx_pusch_stats, "PUSCH inner-receiver", NULL, NULL, output, end - output);
+  output += print_meas_log(&gNB->ulsch_decoding_stats, "PUSCH decoding", NULL, NULL, output, end - output);
+  output += print_meas_log(&gNB->schedule_response_stats, "Schedule Response", NULL, NULL, output, end - output);
+  if (ru->feprx)
+    output += print_meas_log(&ru->ofdm_demod_stats, "feprx", NULL, NULL, output, end - output);
 
   if (ru->feptx_ofdm) {
-    stroff += print_meas_log(&ru->precoding_stats,"feptx_prec",NULL,NULL, output+stroff);
-    stroff += print_meas_log(&ru->txdataF_copy_stats,"txdataF_copy",NULL,NULL, output+stroff);
-    stroff += print_meas_log(&ru->ofdm_mod_stats,"feptx_ofdm",NULL,NULL, output+stroff);
-    stroff += print_meas_log(&ru->ofdm_total_stats,"feptx_total",NULL,NULL, output+stroff);
+    output += print_meas_log(&ru->precoding_stats,"feptx_prec",NULL,NULL, output, end - output);
+    output += print_meas_log(&ru->txdataF_copy_stats,"txdataF_copy",NULL,NULL, output, end - output);
+    output += print_meas_log(&ru->ofdm_mod_stats,"feptx_ofdm",NULL,NULL, output, end - output);
+    output += print_meas_log(&ru->ofdm_total_stats,"feptx_total",NULL,NULL, output, end - output);
   }
 
-  if (ru->fh_north_asynch_in) stroff += print_meas_log(&ru->rx_fhaul,"rx_fhaul",NULL,NULL, output+stroff);
+  if (ru->fh_north_asynch_in)
+    output += print_meas_log(&ru->rx_fhaul,"rx_fhaul",NULL,NULL, output, end - output);
 
-  stroff += print_meas_log(&ru->tx_fhaul,"tx_fhaul",NULL,NULL, output+stroff);
+  output += print_meas_log(&ru->tx_fhaul,"tx_fhaul",NULL,NULL, output, end - output);
 
   if (ru->fh_north_out) {
-    stroff += print_meas_log(&ru->compression,"compression",NULL,NULL, output+stroff);
-    stroff += print_meas_log(&ru->transport,"transport",NULL,NULL, output+stroff);
+    output += print_meas_log(&ru->compression,"compression",NULL,NULL, output, end - output);
+    output += print_meas_log(&ru->transport,"transport",NULL,NULL, output, end - output);
   }
+  return output - begin;
 }
 
 void *nrL1_stats_thread(void *param) {
@@ -355,7 +359,7 @@ void *nrL1_stats_thread(void *param) {
     dump_nr_I0_stats(fd,gNB);
     dump_pdsch_stats(fd,gNB);
     dump_pusch_stats(fd,gNB);
-    dump_L1_meas_stats(gNB, ru, output);
+    dump_L1_meas_stats(gNB, ru, output, L1STATSSTRLEN);
     fprintf(fd,"%s\n",output);
     fflush(fd);
     fseek(fd,0,SEEK_SET);
@@ -380,7 +384,7 @@ void *tx_reorder_thread(void* param) {
     if (resL1Reserve) {
        resL1=resL1Reserve;
        if (((processingData_L1tx_t *)NotifiedFifoData(resL1))->slot != next_tx_slot) {
-         LOG_E(PHY,"order mistake");
+         LOG_E(PHY,"order mistake\n");
 	 resL1Reserve=NULL;
 	 resL1 = pullTpool(gNB->L1_tx_out, gNB->threadPool);
        }

executables/nr-ue.c

@@ -106,23 +106,24 @@ queue_t nr_rach_ind_queue;
 
 static void *NRUE_phy_stub_standalone_pnf_task(void *arg);
 
-static int dump_L1_UE_meas_stats(PHY_VARS_NR_UE *ue, char *output, int max_len)
+static size_t dump_L1_UE_meas_stats(PHY_VARS_NR_UE *ue, char *output, size_t max_len)
 {
-  int stroff = 0;
-  stroff += print_meas_log(&ue->phy_proc_tx, "L1 TX processing", NULL, NULL, output);
-  stroff += print_meas_log(&ue->ulsch_encoding_stats, "ULSCH encoding", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->phy_proc_rx[0], "L1 RX processing t0", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->phy_proc_rx[1], "L1 RX processing t1", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->ue_ul_indication_stats, "UL Indication", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->rx_pdsch_stats, "PDSCH receiver", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->dlsch_decoding_stats[0], "PDSCH decoding t0", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->dlsch_decoding_stats[1], "PDSCH decoding t1", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->dlsch_deinterleaving_stats, " -> Deinterleive", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->dlsch_rate_unmatching_stats, " -> Rate Unmatch", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->dlsch_ldpc_decoding_stats, " ->  LDPC Decode", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->dlsch_unscrambling_stats, "PDSCH unscrambling", NULL, NULL, output + stroff);
-  stroff += print_meas_log(&ue->dlsch_rx_pdcch_stats, "PDCCH handling", NULL, NULL, output + stroff);
-  return stroff;
+  const char *begin = output;
+  const char *end = output + max_len;
+  output += print_meas_log(&ue->phy_proc_tx, "L1 TX processing", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->ulsch_encoding_stats, "ULSCH encoding", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->phy_proc_rx[0], "L1 RX processing t0", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->phy_proc_rx[1], "L1 RX processing t1", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->ue_ul_indication_stats, "UL Indication", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->rx_pdsch_stats, "PDSCH receiver", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->dlsch_decoding_stats[0], "PDSCH decoding t0", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->dlsch_decoding_stats[1], "PDSCH decoding t1", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->dlsch_deinterleaving_stats, " -> Deinterleive", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->dlsch_rate_unmatching_stats, " -> Rate Unmatch", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->dlsch_ldpc_decoding_stats, " ->  LDPC Decode", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->dlsch_unscrambling_stats, "PDSCH unscrambling", NULL, NULL, output, end - output);
+  output += print_meas_log(&ue->dlsch_rx_pdcch_stats, "PDCCH handling", NULL, NULL, output, end - output);
+  return output - begin;
 }
 
 static void *nrL1_UE_stats_thread(void *param)

openair1/SCHED_NR/phy_procedures_nr_gNB.c

@@ -793,10 +793,14 @@ int phy_procedures_gNB_uespec_RX(PHY_VARS_gNB *gNB, int frame_rx, int slot_rx) {
                    dB_fixed_x10(gNB->pusch_vars[ULSCH_id]->ulsch_power_tot),
                    dB_fixed_x10(gNB->pusch_vars[ULSCH_id]->ulsch_noise_power_tot),gNB->pusch_thres);
              gNB->pusch_vars[ULSCH_id]->ulsch_power_tot = gNB->pusch_vars[ULSCH_id]->ulsch_noise_power_tot;
-             nr_fill_indication(gNB,frame_rx, slot_rx, ULSCH_id, harq_pid, 1,1);
              gNB->pusch_vars[ULSCH_id]->DTX=1;
              if (stats) stats->DTX++;
+             if (!get_softmodem_params()->phy_test) {
+               /* in case of phy_test mode, we still want to decode to measure execution time. 
+                  Therefore, we don't yet call nr_fill_indication, it will be called later */
+               nr_fill_indication(gNB,frame_rx, slot_rx, ULSCH_id, harq_pid, 1,1);
                return 1;
+             }
           } else {
             LOG_D(PHY, "PUSCH detected in %d.%d (%d,%d,%d)\n",frame_rx,slot_rx,
                   dB_fixed_x10(gNB->pusch_vars[ULSCH_id]->ulsch_power_tot),
@@ -856,10 +860,6 @@ int phy_procedures_gNB_uespec_RX(PHY_VARS_gNB *gNB, int frame_rx, int slot_rx) {
   }
 
   stop_meas(&gNB->phy_proc_rx);
-  // figure out a better way to choose slot_rx, 19 is ok for a particular TDD configuration with 30kHz SCS
-  if ((frame_rx&127) == 0 && slot_rx==19) {
-    LOG_I(NR_PHY, "Number of bad PUCCH received: %lu\n", gNB->bad_pucch);
-  }
 
   if (pucch_decode_done || pusch_decode_done) {
     T(T_GNB_PHY_PUCCH_PUSCH_IQ, T_INT(frame_rx), T_INT(slot_rx), T_BUFFER(&gNB->common_vars.rxdataF[0][0], gNB->frame_parms.symbols_per_slot * gNB->frame_parms.ofdm_symbol_size * 4));

openair2/LAYER2/NR_MAC_gNB/gNB_scheduler.c

@@ -117,8 +117,6 @@ void gNB_dlsch_ulsch_scheduler(module_id_t module_idP,
   protocol_ctxt_t   ctxt={0};
   PROTOCOL_CTXT_SET_BY_MODULE_ID(&ctxt, module_idP, ENB_FLAG_YES, NOT_A_RNTI, frame, slot,module_idP);
 
-  char stats_output[16384];
-
   gNB_MAC_INST *gNB = RC.nrmac[module_idP];
   NR_COMMON_channels_t *cc = gNB->common_channels;
   NR_ServingCellConfigCommon_t        *scc     = cc->ServingCellConfigCommon;
@@ -180,9 +178,10 @@ void gNB_dlsch_ulsch_scheduler(module_id_t module_idP,
 
 
   if ((slot == 0) && (frame & 127) == 0) {
-     stats_output[0]='\0';
-     dump_mac_stats(RC.nrmac[module_idP],stats_output,16384,true);
-     LOG_I(NR_MAC,"Frame.Slot %d.%d\n%s\n",frame,slot,stats_output);
+    char stats_output[16384];
+    stats_output[0] = '\0';
+    dump_mac_stats(RC.nrmac[module_idP], stats_output, sizeof(stats_output), true);
+    LOG_I(NR_MAC, "Frame.Slot %d.%d\n%s\n", frame, slot, stats_output);
   }
 
   nr_mac_update_timers(module_idP, frame, slot);

openair2/LAYER2/NR_MAC_gNB/gNB_scheduler_phytest.c

@@ -310,6 +310,7 @@ void nr_preprocessor_phytest(module_id_t module_id,
   sched_pdsch->rbSize = rbSize;
 
   sched_pdsch->mcs = target_dl_mcs;
+  sched_ctrl->dl_bler_stats.mcs = target_dl_mcs; /* for logging output */
   sched_pdsch->Qm = nr_get_Qm_dl(sched_pdsch->mcs, ps->mcsTableIdx);
   sched_pdsch->R = nr_get_code_rate_dl(sched_pdsch->mcs, ps->mcsTableIdx);
   sched_pdsch->tb_size = nr_compute_tbs(sched_pdsch->Qm,
@@ -461,6 +462,7 @@ bool nr_ul_preprocessor_phytest(module_id_t module_id, frame_t frame, sub_frame_
   const int mcs = target_ul_mcs;
   NR_sched_pusch_t *sched_pusch = &sched_ctrl->sched_pusch;
   sched_pusch->mcs = mcs;
+  sched_ctrl->ul_bler_stats.mcs = mcs; /* for logging output */
   sched_pusch->rbStart = rbStart;
   sched_pusch->rbSize = rbSize;
   /* get the PID of a HARQ process awaiting retransmission, or -1 for "any new" */

openair2/LAYER2/NR_MAC_gNB/mac_proto.h

@@ -534,7 +534,7 @@ int get_mcs_from_bler(const NR_bler_options_t *bler_options,
 
 void nr_sr_reporting(gNB_MAC_INST *nrmac, frame_t frameP, sub_frame_t slotP);
 
-void dump_mac_stats(gNB_MAC_INST *gNB, char *output, int strlen, bool reset_rsrp);
+size_t dump_mac_stats(gNB_MAC_INST *gNB, char *output, size_t strlen, bool reset_rsrp);
 
 void process_CellGroup(NR_CellGroupConfig_t *CellGroup, NR_UE_sched_ctrl_t *sched_ctrl);
 

openair2/LAYER2/NR_MAC_gNB/main.c

@@ -45,25 +45,31 @@
 extern RAN_CONTEXT_t RC;
 
 
-#define MACSTATSSTRLEN 16384
+#define MACSTATSSTRLEN 65536
 
 void *nrmac_stats_thread(void *arg) {
 
   gNB_MAC_INST *gNB = (gNB_MAC_INST *)arg;
 
-  char output[MACSTATSSTRLEN];
-  memset(output,0,MACSTATSSTRLEN);
-  FILE *fd=fopen("nrMAC_stats.log","w");
-  AssertFatal(fd!=NULL,"Cannot open nrMAC_stats.log, error %s\n",strerror(errno));
+  char output[MACSTATSSTRLEN] = {0};
+  const char *end = output + MACSTATSSTRLEN;
+  FILE *file = fopen("nrMAC_stats.log","w");
+  AssertFatal(file!=NULL,"Cannot open nrMAC_stats.log, error %s\n",strerror(errno));
 
   while (oai_exit == 0) {
-    dump_mac_stats(gNB,output,MACSTATSSTRLEN,false);
-     fprintf(fd,"%s\n",output);
-     fflush(fd);
-     usleep(200000);
-     fseek(fd,0,SEEK_SET);
+    char *p = output;
+    p += dump_mac_stats(gNB, p, end - p, false);
+    p += snprintf(p, end - p, "\n");
+    p += print_meas_log(&gNB->eNB_scheduler, "DL & UL scheduling timing", NULL, NULL, p, end - p);
+    p += print_meas_log(&gNB->schedule_dlsch, "dlsch scheduler", NULL, NULL, p, end - p);
+    p += print_meas_log(&gNB->rlc_data_req, "rlc_data_req", NULL, NULL, p, end - p);
+    p += print_meas_log(&gNB->rlc_status_ind, "rlc_status_ind", NULL, NULL, p, end - p);
+    fwrite(output, p - output, 1, file);
+    fflush(file);
+    sleep(1);
+    fseek(file,0,SEEK_SET);
   }
-  fclose(fd);
+  fclose(file);
   return NULL;
 }
 
@@ -73,11 +79,12 @@ void clear_mac_stats(gNB_MAC_INST *gNB) {
   }
 }
 
-void dump_mac_stats(gNB_MAC_INST *gNB, char *output, int strlen, bool reset_rsrp)
+size_t dump_mac_stats(gNB_MAC_INST *gNB, char *output, size_t strlen, bool reset_rsrp)
 {
   int num = 1;
+  const char *begin = output;
+  const char *end = output + strlen;
  
-  int stroff=0;
   pthread_mutex_lock(&gNB->UE_info.mutex);
   UE_iterator(gNB->UE_info.list, UE) {
     NR_UE_sched_ctrl_t *sched_ctrl = &UE->UE_sched_ctrl;
@@ -85,23 +92,28 @@ void dump_mac_stats(gNB_MAC_INST *gNB, char *output, int strlen, bool reset_rsrp
     const int avg_rsrp = stats->num_rsrp_meas > 0 ? stats->cumul_rsrp / stats->num_rsrp_meas : 0;
 
 
-    stroff+=sprintf(output+stroff,"UE RNTI %04x (%d) PH %d dB PCMAX %d dBm, average RSRP %d (%d meas)\n",
+    output += snprintf(output,
+                       end - output,
+                       "UE RNTI %04x (%d) PH %d dB PCMAX %d dBm, average RSRP %d (%d meas)\n",
                        UE->rnti,
                        num++,
                        sched_ctrl->ph,
                        sched_ctrl->pcmax,
                        avg_rsrp,
                        stats->num_rsrp_meas);
-    stroff+=sprintf(output+stroff,"UE %04x: CQI %d, RI %d, PMI (%d,%d)\n",
+    output += snprintf(output,
+                       end - output,
+                       "UE %04x: CQI %d, RI %d, PMI (%d,%d)\n",
                        UE->rnti,
                        UE->UE_sched_ctrl.CSI_report.cri_ri_li_pmi_cqi_report.wb_cqi_1tb,
                        UE->UE_sched_ctrl.CSI_report.cri_ri_li_pmi_cqi_report.ri+1,
                        UE->UE_sched_ctrl.CSI_report.cri_ri_li_pmi_cqi_report.pmi_x1,
                        UE->UE_sched_ctrl.CSI_report.cri_ri_li_pmi_cqi_report.pmi_x2);
 
-    stroff+=sprintf(output+stroff,"UE %04x: dlsch_rounds %"PRIu64"/%"PRIu64"/%"PRIu64"/%"PRIu64", dlsch_errors %"PRIu64", pucch0_DTX %d, BLER %.5f MCS %d\n",
+    output += snprintf(output,
+                       end - output,
+                       "UE %04x: dlsch_rounds %"PRIu64"/%"PRIu64"/%"PRIu64"/%"PRIu64", dlsch_errors %"PRIu64", pucch0_DTX %d, BLER %.5f MCS %d\n",
                        UE->rnti,
-
                        stats->dl.rounds[0], stats->dl.rounds[1],
                        stats->dl.rounds[2], stats->dl.rounds[3],
                        stats->dl.errors,
@@ -112,8 +124,14 @@ void dump_mac_stats(gNB_MAC_INST *gNB, char *output, int strlen, bool reset_rsrp
       stats->num_rsrp_meas = 0;
       stats->cumul_rsrp = 0;
     }
-    stroff+=sprintf(output+stroff,"UE %04x: dlsch_total_bytes %"PRIu64"\n", UE->rnti, stats->dl.total_bytes);
-    stroff+=sprintf(output+stroff,"UE %04x: ulsch_rounds %"PRIu64"/%"PRIu64"/%"PRIu64"/%"PRIu64", ulsch_DTX %d, ulsch_errors %"PRIu64", BLER %.5f MCS %d\n",
+    output += snprintf(output,
+                       end - output,
+                       "UE %04x: dlsch_total_bytes %"PRIu64"\n",
+                       UE->rnti,
+                       stats->dl.total_bytes);
+    output += snprintf(output,
+                       end - output,
+                       "UE %04x: ulsch_rounds %"PRIu64"/%"PRIu64"/%"PRIu64"/%"PRIu64", ulsch_DTX %d, ulsch_errors %"PRIu64", BLER %.5f MCS %d\n",
                        UE->rnti,
                        stats->ul.rounds[0], stats->ul.rounds[1],
                        stats->ul.rounds[2], stats->ul.rounds[3],
@@ -121,27 +139,30 @@ void dump_mac_stats(gNB_MAC_INST *gNB, char *output, int strlen, bool reset_rsrp
                        stats->ul.errors,
                        sched_ctrl->ul_bler_stats.bler,
                        sched_ctrl->ul_bler_stats.mcs);
-    stroff+=sprintf(output+stroff,
+    output += snprintf(output,
+                       end - output,
                       "UE %04x: ulsch_total_bytes_scheduled %"PRIu64", ulsch_total_bytes_received %"PRIu64"\n",
                       UE->rnti,
                       stats->ulsch_total_bytes_scheduled, stats->ul.total_bytes);
     for (int lc_id = 0; lc_id < 63; lc_id++) {
-      if (stats->dl.lc_bytes[lc_id] > 0) {
-        stroff+=sprintf(output+stroff, "UE %04x: LCID %d: %"PRIu64" bytes TX\n", UE->rnti, lc_id, stats->dl.lc_bytes[lc_id]);
-	LOG_D(NR_MAC, "UE %04x: LCID %d: %"PRIu64" bytes TX\n", UE->rnti, lc_id, stats->dl.lc_bytes[lc_id]);
-      }
-      if (stats->ul.lc_bytes[lc_id] > 0) {
-        stroff+=sprintf(output+stroff, "UE %04x: LCID %d: %"PRIu64" bytes RX\n", UE->rnti, lc_id, stats->ul.lc_bytes[lc_id]);
-	LOG_D(NR_MAC, "UE %04x: LCID %d: %"PRIu64" bytes RX\n", UE->rnti, lc_id, stats->ul.lc_bytes[lc_id]);
-
-      }
+      if (stats->dl.lc_bytes[lc_id] > 0)
+        output += snprintf(output,
+                           end - output,
+                           "UE %04x: LCID %d: %"PRIu64" bytes TX\n",
+                           UE->rnti,
+                           lc_id,
+                           stats->dl.lc_bytes[lc_id]);
+      if (stats->ul.lc_bytes[lc_id] > 0)
+        output += snprintf(output,
+                           end - output,
+                           "UE %04x: LCID %d: %"PRIu64" bytes RX\n",
+                           UE->rnti,
+                           lc_id,
+                           stats->ul.lc_bytes[lc_id]);
     }
   }
   pthread_mutex_unlock(&gNB->UE_info.mutex);
-  print_meas(&gNB->eNB_scheduler, "DL & UL scheduling timing stats", NULL, NULL);
-  print_meas(&gNB->schedule_dlsch,"dlsch scheduler",NULL,NULL);
-  print_meas(&gNB->rlc_data_req, "rlc_data_req",NULL,NULL);
-  print_meas(&gNB->rlc_status_ind,"rlc_status_ind",NULL,NULL);
+  return output - begin;
 }