added uplink latseq points for latency measurement

executables/nr-ru.c

@@ -51,6 +51,7 @@
 
 #include "common/utils/LOG/log.h"
 #include "common/utils/LOG/vcd_signal_dumper.h"
+#include "common/utils/LATSEQ/latseq.h"
 
 #include <executables/softmodem-common.h>
 
@@ -726,6 +727,7 @@ void rx_rf(RU_t *ru,int *frame,int *slot) {
   }
 
   stop_meas(&ru->rx_fhaul);
+  LATSEQ_P("U phy.SOUTHend--phy.dft","samplesslot%u::fm%u.sl%u", samples_per_slot, *frame, *slot);
 }
 
 static radio_tx_gpio_flag_t get_gpio_flags(RU_t *ru, int slot)
@@ -1254,6 +1256,7 @@ void *ru_thread( void *param ) {
     // synchronization on input FH interface, acquire signals/data and block
     LOG_D(PHY,"[RU_thread] read data: frame_rx = %d, tti_rx = %d\n", frame, slot);
 
+    LATSEQ_P("U phy.SOUTHstart--phy.SOUTHend","::fm%u.sl%u", frame, slot);
     if (ru->fh_south_in) ru->fh_south_in(ru,&frame,&slot);
     else AssertFatal(1==0, "No fronthaul interface at south port");
 
@@ -1299,6 +1302,7 @@ void *ru_thread( void *param ) {
     if (slot_type == NR_UPLINK_SLOT || slot_type == NR_MIXED_SLOT) {
       if (ru->feprx) {
         ru->feprx(ru,proc->tti_rx);
+        LATSEQ_P("U phy.dft--phy.prachpucch","::fm%u.sl%u", frame, slot);
         clock_gettime(CLOCK_MONOTONIC,&ru->rt_ru_profiling.return_RU_feprx[rt_prof_idx]);
         //LOG_M("rxdata.m","rxs",ru->common.rxdata[0],1228800,1,1);
         LOG_D(PHY,"RU proc: frame_rx = %d, tti_rx = %d\n", proc->frame_rx, proc->tti_rx);

openair1/PHY/NR_TRANSPORT/nr_ulsch_demodulation.c

@@ -10,6 +10,7 @@
 #include "common/utils/nr/nr_common.h"
 #include <openair1/PHY/TOOLS/phy_scope_interface.h>
 #include "PHY/sse_intrin.h"
+#include "common/utils/LATSEQ/latseq.h"
 
 //#define DEBUG_CH_COMP
 //#define DEBUG_RB_EXT
@@ -1620,6 +1621,7 @@ void nr_rx_pusch(PHY_VARS_gNB *gNB,
   //--------------------- Channel estimation ---------------------
   //----------------------------------------------------------
   start_meas(&gNB->ulsch_channel_estimation_stats);
+  LATSEQ_P("U phy.prachpucch--phy.CHest", "::fm%u.sl%u.hqpid%u.rnti%u.qammod%u.hqround%u", frame, slot, harq_pid, rel15_ul->rnti, rel15_ul->qam_mod_order, ulsch->harq_process->round);
   int max_ch = 0;
   uint32_t nvar = 0;
   for(uint8_t symbol = rel15_ul->start_symbol_index; symbol < (rel15_ul->start_symbol_index + rel15_ul->nr_of_symbols); symbol++) {
@@ -1690,6 +1692,7 @@ void nr_rx_pusch(PHY_VARS_gNB *gNB,
     pusch_vars->dmrs_symbol =
         get_next_dmrs_symbol_in_slot(rel15_ul->ul_dmrs_symb_pos, rel15_ul->start_symbol_index, rel15_ul->nr_of_symbols);
   }
+  LATSEQ_P("U phy.CHest--phy.CHrbscacompllr", "::fm%u.sl%u.hqpid%u.nbantrx%u.rnti%u", frame, slot, harq_pid, frame_parms->nb_antennas_rx, rel15_ul->rnti);
   stop_meas(&gNB->ulsch_channel_estimation_stats);
 
   int off = ((rel15_ul->rb_size&1) == 1)? 4:0;
@@ -1832,7 +1835,6 @@ void nr_rx_pusch(PHY_VARS_gNB *gNB,
                               nb_re_pusch,
                               nvar);
       }
-
       stop_meas(&gNB->ulsch_mrc_stats);
 
       if (rel15_ul->transform_precoding == transformPrecoder_enabled) {
@@ -1913,6 +1915,7 @@ void nr_rx_pusch(PHY_VARS_gNB *gNB,
       rxdataF_ext_offset += pusch_vars->ul_valid_re_per_slot[symbol];
     }
   } // symbol loop
+  LATSEQ_P("U phy.CHrbscacompllr--phy.layerdemapped", "::fm%u.sl%u.hqpid%u.rnti%u.nbsymbols%u", frame, slot, harq_pid, rel15_ul->rnti, rel15_ul->nr_of_symbols);
   if (!(frame % 128)) {
     int num_llr = num_re_total*rel15_ul->qam_mod_order;
     GnbScopeUpdate(gNB, puschLLRe, num_llr);

openair1/SCHED_NR/phy_procedures_nr_gNB.c

@@ -39,6 +39,7 @@
 #include "executables/softmodem-common.h"
 #include "nfapi/oai_integration/vendor_ext.h"
 #include "NR_SRS-ResourceSet.h"
+#include "common/utils/LATSEQ/latseq.h"
 
 #include "assertions.h"
 
@@ -253,6 +254,7 @@ static void nr_postDecode(PHY_VARS_gNB *gNB, notifiedFIFO_elt_t *req)
         ulsch_harq->processedSegments,
         rdata->nbSegments);
   if (decodeSuccess) {
+    LATSEQ_P("U mac.CBdec--mac.TBdec","::fm%u.sl%u.hqpid%u.ldpciter%u.segmentnb%u.rnti%u", ulsch->frame, ulsch->slot, rdata->harq_pid, rdata->decodeIterations, r, pusch_pdu->rnti);
     memcpy(ulsch_harq->b + rdata->offset, ulsch_harq->c[r], rdata->Kr_bytes - (ulsch_harq->F >> 3) - ((ulsch_harq->C > 1) ? 3 : 0));
 
   } else {
@@ -289,6 +291,7 @@ static void nr_postDecode(PHY_VARS_gNB *gNB, notifiedFIFO_elt_t *req)
             ulsch_harq->TBS,
             rdata->decodeIterations);
       ulsch->active = false;
+      LATSEQ_P("U mac.TBdec--mac.demuxed", "::fm%u.sl%u.hqpid%u.hqround%u.rnti%u.CBbits%u.Fbits%u.TBS%u", ulsch->frame, ulsch->slot, rdata->harq_pid, ulsch_harq->round, pusch_pdu->rnti, ulsch_harq->K, ulsch_harq->F, ulsch_harq->TBS);
       ulsch_harq->round = 0;
       LOG_D(PHY, "ULSCH received ok \n");
       nr_fill_indication(gNB, ulsch->frame, ulsch->slot, rdata->ulsch_id, rdata->harq_pid, 0, 0);
@@ -312,8 +315,15 @@ static void nr_postDecode(PHY_VARS_gNB *gNB, notifiedFIFO_elt_t *req)
       ulsch->handled = 1;
       LOG_D(PHY, "ULSCH %d in error\n",rdata->ulsch_id);
       nr_fill_indication(gNB, ulsch->frame, ulsch->slot, rdata->ulsch_id, rdata->harq_pid, 1, 0);
+      if (ulsch_harq->round == 3) {
+        LATSEQ_P("U mac.CBdec--mac.retxdrop","::fm%u.sl%u.hqpid%u.segmentnb%u.rnti%u", ulsch->frame, ulsch->slot, rdata->harq_pid, r, pusch_pdu->rnti);
+      } else {
+        LATSEQ_P("U mac.CBdec--mac.retxdecfail","::fm%u.sl%u.hqpid%u.segmentnb%u.rnti%u", ulsch->frame, ulsch->slot, rdata->harq_pid, r, pusch_pdu->rnti, ulsch_harq->round);
+        LATSEQ_P("U mac.retxdecfail--phy.prachpucch","::hqpid%u.rnti%u", rdata->harq_pid, pusch_pdu->rnti);
+      }
       //      dumpsig=1;
     }
+    
     ulsch->last_iteration_cnt = rdata->decodeIterations;
     /*
         if (ulsch_harq->ulsch_pdu.mcs_index == 0 && dumpsig==1) {
@@ -403,12 +413,14 @@ static int nr_ulsch_procedures(PHY_VARS_gNB *gNB, int frame_rx, int slot_rx, int
                            pusch_pdu->qam_mod_order,
                            G,
                            gNB->pusch_vars[ULSCH_id].llr_layers);
+  LATSEQ_P("U phy.layerdemapped--phy.unscrambled", "::fm%u.sl%u.hqpid%u.rnti%u", frame_rx, slot_rx, harq_pid, pusch_pdu->rnti);
 
   //----------------------------------------------------------
   //------------------- ULSCH unscrambling -------------------
   //----------------------------------------------------------
   start_meas(&gNB->ulsch_unscrambling_stats);
   nr_ulsch_unscrambling(gNB->pusch_vars[ULSCH_id].llr, G, pusch_pdu->data_scrambling_id, pusch_pdu->rnti);
+  LATSEQ_P("U phy.unscrambled--mac.CBdec", "::fm%u.sl%u.hqpid%u.rnti%u.mcs%u", frame_rx, slot_rx, harq_pid, pusch_pdu->rnti, pusch_pdu->mcs_index);
   stop_meas(&gNB->ulsch_unscrambling_stats);
   //----------------------------------------------------------
   //--------------------- ULSCH decoding ---------------------
@@ -928,6 +940,12 @@ int phy_procedures_gNB_uespec_RX(PHY_VARS_gNB *gNB, int frame_rx, int slot_rx)
              Therefore, we don't yet call nr_fill_indication, it will be called later */
           nr_fill_indication(gNB, frame_rx, slot_rx, ULSCH_id, ulsch->harq_pid, 1, 1);
           pusch_DTX++;
+          if (ulsch_harq->round == 3) {
+            LATSEQ_P("U mac.CBdec--mac.retxdrop","::fm%u.sl%u.hqpid%u", frame_rx, slot_rx, ulsch->harq_pid);
+          } else {
+            LATSEQ_P("U mac.CBdec--mac.retxhighnoise","::fm%u.sl%u.hqpid%u.hqround%u.rnti%u", frame_rx, slot_rx, ulsch->harq_pid, ulsch_harq->round, ulsch->rnti);
+            LATSEQ_P("U mac.retxhighnoise--phy.prachpucch","::hqpid%u.rnti%u", ulsch->harq_pid, ulsch->rnti);
+          }
           continue;
         }
       } else {

openair2/LAYER2/NR_MAC_gNB/gNB_scheduler_ulsch.c

@@ -36,6 +36,7 @@
 #include <openair2/UTIL/OPT/opt.h>
 #include "LAYER2/NR_MAC_COMMON/nr_mac_extern.h"
 #include "LAYER2/nr_rlc/nr_rlc_oai_api.h"
+#include "common/utils/LATSEQ/latseq.h"
 
 //#define SRS_IND_DEBUG
 
@@ -409,6 +410,7 @@ static int nr_process_mac_pdu(instance_t module_idP,
               mac_len);
         UE->mac_stats.ul.lc_bytes[rx_lcid] += mac_len;
 
+        LATSEQ_P("U mac.demuxed--rlc.decoded", "len%u::fm%u.sl%u.hqpid%u.MRbuf%u.rnti%u", mac_len, frameP, slot, harq_pid, pduP+mac_subheader_len, UE->rnti);
         mac_rlc_data_ind(module_idP,
                          UE->rnti,
                          module_idP,

openair2/LAYER2/nr_pdcp/nr_pdcp_entity.c

@@ -31,6 +31,7 @@
 #include "nr_pdcp_sdu.h"
 
 #include "LOG/log.h"
+#include "common/utils/LATSEQ/latseq.h"
 
 static void nr_pdcp_entity_recv_pdu(nr_pdcp_entity_t *entity,
                                     char *_buffer, int size)
@@ -88,6 +89,7 @@ static void nr_pdcp_entity_recv_pdu(nr_pdcp_entity_t *entity,
     entity->stats.rxpdu_dd_pkts++;
     entity->stats.rxpdu_dd_bytes += size;
 
+    LATSEQ_P("U pdcp.decoded--pdcp.discarded.badpdusize", "::sn%u", rcvd_sn);
 
     return;
   }
@@ -120,6 +122,7 @@ static void nr_pdcp_entity_recv_pdu(nr_pdcp_entity_t *entity,
       entity->stats.rxpdu_dd_pkts++;
       entity->stats.rxpdu_dd_bytes += size;
 
+      LATSEQ_P("U pdcp.decoded--pdcp.discarded.integrityfailed", "::sn%u", rcvd_sn);
 
     }
   }
@@ -130,6 +133,7 @@ static void nr_pdcp_entity_recv_pdu(nr_pdcp_entity_t *entity,
     entity->stats.rxpdu_dd_pkts++;
     entity->stats.rxpdu_dd_bytes += size;
 
+    LATSEQ_P("U pdcp.decoded--pdcp.discarded.rcvdsmallerdeliv", "::sn%u", rcvd_sn);
 
     return;
   }
@@ -151,8 +155,9 @@ static void nr_pdcp_entity_recv_pdu(nr_pdcp_entity_t *entity,
     uint32_t count = entity->rx_deliv;
     while (entity->rx_list != NULL && count == entity->rx_list->count) {
       nr_pdcp_sdu_t *cur = entity->rx_list;
+      LATSEQ_P("U pdcp.decoded--sdap.sdu", "len%u::sn%u", cur->size, rcvd_sn);
       entity->deliver_sdu(entity->deliver_sdu_data, entity,
-                          cur->buffer, cur->size);
+                          cur->buffer, cur->size, rcvd_sn);
       entity->rx_list = cur->next;
       entity->rx_size -= cur->size;
       entity->stats.txsdu_pkts++;
@@ -335,8 +340,10 @@ static void check_t_reordering(nr_pdcp_entity_t *entity)
   /* deliver all SDUs with count < rx_reord */
   while (entity->rx_list != NULL && entity->rx_list->count < entity->rx_reord) {
     nr_pdcp_sdu_t *cur = entity->rx_list;
+    LATSEQ_P("U pdcp.decoded--pdcp.outoforderdeliv", "len%u::sn%u", cur->size, cur->count);
+    LATSEQ_P("U pdcp.outoforderdeliv--sdap.sdu", "len%u::sn%u", cur->size, cur->count);
     entity->deliver_sdu(entity->deliver_sdu_data, entity,
-                        cur->buffer, cur->size);
+                        cur->buffer, cur->size, cur->count);
     entity->rx_list = cur->next;
     entity->rx_size -= cur->size;
     nr_pdcp_free_sdu(cur);
@@ -346,8 +353,10 @@ static void check_t_reordering(nr_pdcp_entity_t *entity)
   count = entity->rx_reord;
   while (entity->rx_list != NULL && count == entity->rx_list->count) {
     nr_pdcp_sdu_t *cur = entity->rx_list;
+    LATSEQ_P("U pdcp.decoded--pdcp.reorderdeliv", "len%u::sn%u", cur->size, cur->count);
+    LATSEQ_P("U pdcp.reorderdeliv--sdap.sdu", "len%u::sn%u", cur->size, cur->count);
     entity->deliver_sdu(entity->deliver_sdu_data, entity,
-                        cur->buffer, cur->size);
+                        cur->buffer, cur->size, cur->count);
     entity->rx_list = cur->next;
     entity->rx_size -= cur->size;
     nr_pdcp_free_sdu(cur);
@@ -399,7 +408,7 @@ nr_pdcp_entity_t *new_nr_pdcp_entity(
     bool has_sdap_rx,
     bool has_sdap_tx,
     void (*deliver_sdu)(void *deliver_sdu_data, struct nr_pdcp_entity_t *entity,
-                        char *buf, int size),
+                        char *buf, int size, int sn_latseq),
     void *deliver_sdu_data,
     void (*deliver_pdu)(void *deliver_pdu_data, ue_id_t ue_id, int rb_id,
                         char *buf, int size, int sdu_id),

openair2/LAYER2/nr_pdcp/nr_pdcp_entity.h

@@ -93,7 +93,7 @@ typedef struct nr_pdcp_entity_t {
 
   /* callbacks provided to the PDCP module */
   void (*deliver_sdu)(void *deliver_sdu_data, struct nr_pdcp_entity_t *entity,
-                      char *buf, int size);
+                      char *buf, int size, int sn_latseq);
   void *deliver_sdu_data;
   void (*deliver_pdu)(void *deliver_pdu_data, ue_id_t ue_id, int rb_id,
                       char *buf, int size, int sdu_id);
@@ -174,7 +174,7 @@ nr_pdcp_entity_t *new_nr_pdcp_entity(
     bool has_sdap_rx,
     bool has_sdap_tx,
     void (*deliver_sdu)(void *deliver_sdu_data, struct nr_pdcp_entity_t *entity,
-                        char *buf, int size),
+                        char *buf, int size, int sn_latseq),
     void *deliver_sdu_data,
     void (*deliver_pdu)(void *deliver_pdu_data, ue_id_t ue_id, int rb_id,
                         char *buf, int size, int sdu_id),

openair2/LAYER2/nr_pdcp/nr_pdcp_oai_api.c

@@ -42,6 +42,7 @@
 #include "nr_pdcp_e1_api.h"
 #include "gnb_config.h"
 #include "executables/softmodem-common.h"
+#include "common/utils/LATSEQ/latseq.h"
 
 #define TODO do { \
     printf("%s:%d:%s: todo\n", __FILE__, __LINE__, __FUNCTION__); \
@@ -625,7 +626,7 @@ uint64_t nr_pdcp_module_init(uint64_t _pdcp_optmask, int id)
 }
 
 static void deliver_sdu_drb(void *_ue, nr_pdcp_entity_t *entity,
-                            char *buf, int size)
+                            char *buf, int size, int sn_latseq)
 {
   nr_pdcp_ue_t *ue = _ue;
   int rb_id;
@@ -635,7 +636,7 @@ static void deliver_sdu_drb(void *_ue, nr_pdcp_entity_t *entity,
     LOG_D(PDCP, "IP packet received with size %d, to be sent to SDAP interface, UE ID/RNTI: %ld\n", size, ue->rntiMaybeUEid);
     // in NoS1 mode: the SDAP should write() packets to an FD (TUN interface),
     // so below, set is_gnb == 0 to do that
-    sdap_data_ind(entity->rb_id, 0, entity->has_sdap_rx, entity->pdusession_id, ue->rntiMaybeUEid, buf, size);
+    sdap_data_ind(entity->rb_id, 0, entity->has_sdap_rx, entity->pdusession_id, ue->rntiMaybeUEid, buf, size, sn_latseq);
   }
   else{
     for (i = 0; i < MAX_DRBS_PER_UE; i++) {
@@ -651,7 +652,7 @@ static void deliver_sdu_drb(void *_ue, nr_pdcp_entity_t *entity,
     rb_found:
     {
       LOG_D(PDCP, "%s() (drb %d) sending message to SDAP size %d\n", __func__, rb_id, size);
-      sdap_data_ind(rb_id, ue->drb[rb_id - 1]->is_gnb, ue->drb[rb_id - 1]->has_sdap_rx, ue->drb[rb_id - 1]->pdusession_id, ue->rntiMaybeUEid, buf, size);
+      sdap_data_ind(rb_id, ue->drb[rb_id - 1]->is_gnb, ue->drb[rb_id - 1]->has_sdap_rx, ue->drb[rb_id - 1]->pdusession_id, ue->rntiMaybeUEid, buf, size, sn_latseq);
     }
   }
 }
@@ -702,7 +703,7 @@ static void deliver_pdu_drb_gnb(void *deliver_pdu_data, ue_id_t ue_id, int rb_id
 }
 
 static void deliver_sdu_srb(void *_ue, nr_pdcp_entity_t *entity,
-                            char *buf, int size)
+                            char *buf, int size, int sn_latseq)
 {
   nr_pdcp_ue_t *ue = _ue;
   int srb_id;

openair2/LAYER2/nr_rlc/nr_rlc_entity_am.c

@@ -28,6 +28,7 @@
 
 #include "LOG/log.h"
 #include "common/utils/time_stat.h"
+#include "common/utils/LATSEQ/latseq.h"
 
 /* for a given SDU/SDU segment, computes the corresponding PDU header size */
 static int compute_pdu_header_size(nr_rlc_entity_am_t *entity,
@@ -219,6 +220,7 @@ static void reassemble_and_deliver(nr_rlc_entity_am_t *entity, int sn)
     return;
 
   /* deliver */
+  LATSEQ_P("U rlc.reassembled--pdcp.decoded", "len%u::sn%u", so, sn);
   entity->common.deliver_sdu(entity->common.deliver_sdu_data,
                              (nr_rlc_entity_t *)entity,
                              sdu, so);
@@ -794,6 +796,7 @@ void nr_rlc_entity_am_recv_pdu(nr_rlc_entity_t *_entity,
   }
 
   data_size = size - decoder.byte;
+  LATSEQ_P("U rlc.decoded--rlc.reassembled", "len%u::MRbuf%u.si%u.sn%u.so%u", data_size, buffer, si, sn, so);
 
   /* dicard PDU if no data */
   if (data_size <= 0) {

openair2/SDAP/nr_sdap/nr_sdap.c

@@ -68,7 +68,8 @@ void sdap_data_ind(rb_id_t pdcp_entity,
                    int pdusession_id,
                    ue_id_t ue_id,
                    char *buf,
-                   int size) {
+                   int size,
+                   int sn_latseq) {
   nr_sdap_entity_t *sdap_entity;
   sdap_entity = nr_sdap_get_entity(ue_id, pdusession_id);
 
@@ -84,7 +85,8 @@ void sdap_data_ind(rb_id_t pdcp_entity,
                          pdusession_id,
                          ue_id,
                          buf,
-                         size);
+                         size,
+                         sn_latseq);
 }
 
 void set_qfi_pduid(uint8_t qfi, uint8_t pduid){

openair2/SDAP/nr_sdap/nr_sdap.h

@@ -59,7 +59,8 @@ void sdap_data_ind(rb_id_t pdcp_entity,
                    int pdusession_id,
                    ue_id_t ue_id,
                    char *buf,
-                   int size);
+                   int size,
+                   int sn_latseq);
 
 void set_qfi_pduid(uint8_t qfi, uint8_t pduid);
 

openair2/SDAP/nr_sdap/nr_sdap_entity.c

@@ -28,6 +28,7 @@
 #include <stdlib.h>
 #include <string.h>
 #include <pthread.h>
+#include "common/utils/LATSEQ/latseq.h"
 
 typedef struct {
   nr_sdap_entity_t *sdap_entity_llist;
@@ -184,7 +185,8 @@ static void nr_sdap_rx_entity(nr_sdap_entity_t *entity,
                               int pdusession_id,
                               ue_id_t ue_id,
                               char *buf,
-                              int size) {
+                              int size,
+                              int sn_latseq) {
   /* The offset of the SDAP header, it might be 0 if has_sdap_rx is not true in the pdcp entity. */
   int offset=0;
 
@@ -225,6 +227,7 @@ static void nr_sdap_rx_entity(nr_sdap_entity_t *entity,
     LOG_D(SDAP, "%s()  sending message to gtp size %d\n", __func__,  size-offset);
     // very very dirty hack gloabl var N3GTPUInst
     itti_send_msg_to_task(TASK_GTPV1_U, *N3GTPUInst, message_p);
+    LATSEQ_P("U sdap.sdu--gtp.out", "len%u::sn%u.ueid%u", size-offset, sn_latseq, ue_id);
   } else { //nrUE
     /*
      * TS 37.324 5.2 Data transfer

openair2/SDAP/nr_sdap/nr_sdap_entity.h

@@ -111,7 +111,8 @@ typedef struct nr_sdap_entity_s {
                     int pdusession_id,
                     ue_id_t ue_id,
                     char *buf,
-                    int size);
+                    int size,
+                    int sn_latseq);
 
   /* List of entities */
   struct nr_sdap_entity_s *next_entity;