diff --git a/common/utils/time_meas.c b/common/utils/time_meas.c index df2bfd64de..9d1215b5e5 100644 --- a/common/utils/time_meas.c +++ b/common/utils/time_meas.c @@ -111,13 +111,15 @@ void print_meas(time_stats_t *ts, } } -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) { - 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", - name, - (ts->diff/ts->trials/cpu_freq_GHz/1000.0), - ts->trials, - ts->max/cpu_freq_GHz/1000.0); + 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->trials, + 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", - 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->trials); + 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->trials); } } - return stroff; + return output - begin; } double get_time_meas_us(time_stats_t *ts) diff --git a/common/utils/time_meas.h b/common/utils/time_meas.h index 382dd7455a..fded7f1a9c 100644 --- a/common/utils/time_meas.h +++ b/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); diff --git a/executables/nr-gnb.c b/executables/nr-gnb.c index 66d5c549e7..e6c739dec3 100644 --- a/executables/nr-gnb.c +++ b/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); diff --git a/executables/nr-ue.c b/executables/nr-ue.c index 6e1864f290..01e6c62138 100644 --- a/executables/nr-ue.c +++ b/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) diff --git a/openair2/LAYER2/NR_MAC_gNB/main.c b/openair2/LAYER2/NR_MAC_gNB/main.c index 168d0d15ed..9b9fd4e76c 100644 --- a/openair2/LAYER2/NR_MAC_gNB/main.c +++ b/openair2/LAYER2/NR_MAC_gNB/main.c @@ -52,18 +52,19 @@ void *nrmac_stats_thread(void *arg) { gNB_MAC_INST *gNB = (gNB_MAC_INST *)arg; 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) { - size_t stroff = 0; - stroff += dump_mac_stats(gNB, output, MACSTATSSTRLEN, false); - stroff += snprintf(output + stroff, MACSTATSSTRLEN - stroff, "\n"); - stroff += print_meas_log(&gNB->eNB_scheduler, "DL & UL scheduling timing", NULL, NULL, output + stroff); - stroff += print_meas_log(&gNB->schedule_dlsch, "dlsch scheduler", NULL, NULL, output + stroff); - stroff += print_meas_log(&gNB->rlc_data_req, "rlc_data_req", NULL, NULL, output + stroff); - stroff += print_meas_log(&gNB->rlc_status_ind, "rlc_status_ind", NULL, NULL, output + stroff); - fwrite(output, stroff, 1, file); + 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);