From 7b94edd81f7ebc385cf4bb833055b1909cb3e469 Mon Sep 17 00:00:00 2001 From: Cedric Roux <cedric.roux@eurecom.fr> Date: Fri, 22 May 2015 13:48:16 +0000 Subject: [PATCH] Adding CC_id to LOG_* messages wherever it seemed pertinent. git-svn-id: http://svn.eurecom.fr/openair4G/trunk@7464 818b1a75-f10b-46b9-bf7c-635c3b92a50f --- openair2/LAYER2/MAC/eNB_scheduler_RA.c | 28 +++--- openair2/LAYER2/MAC/eNB_scheduler_bch.c | 10 +- openair2/LAYER2/MAC/eNB_scheduler_dlsch.c | 99 +++++++++++-------- openair2/LAYER2/MAC/eNB_scheduler_mch.c | 63 ++++++------ .../LAYER2/MAC/eNB_scheduler_primitives.c | 2 +- openair2/LAYER2/MAC/eNB_scheduler_ulsch.c | 75 +++++++------- openair2/LAYER2/MAC/main.c | 2 +- openair2/LAYER2/MAC/rar_tools.c | 7 +- 8 files changed, 155 insertions(+), 131 deletions(-) diff --git a/openair2/LAYER2/MAC/eNB_scheduler_RA.c b/openair2/LAYER2/MAC/eNB_scheduler_RA.c index 1c8f316e4c7..bdcbae6b7fd 100644 --- a/openair2/LAYER2/MAC/eNB_scheduler_RA.c +++ b/openair2/LAYER2/MAC/eNB_scheduler_RA.c @@ -93,8 +93,8 @@ void schedule_RA(module_id_t module_idP,frame_t frameP, sub_frame_t subframeP,un if (RA_template[i].RA_active == TRUE) { - LOG_D(MAC,"[eNB %d][RAPROC] RA %d is active (generate RAR %d, generate_Msg4 %d, wait_ack_Msg4 %d, rnti %x)\n", - module_idP,i,RA_template[i].generate_rar,RA_template[i].generate_Msg4,RA_template[i].wait_ack_Msg4, RA_template[i].rnti); + LOG_D(MAC,"[eNB %d][RAPROC] CC_id %d RA %d is active (generate RAR %d, generate_Msg4 %d, wait_ack_Msg4 %d, rnti %x)\n", + module_idP,CC_id,i,RA_template[i].generate_rar,RA_template[i].generate_Msg4,RA_template[i].wait_ack_Msg4, RA_template[i].rnti); if (RA_template[i].generate_rar == 1) { nprb[CC_id]= nprb[CC_id] + 3; @@ -126,12 +126,12 @@ void schedule_RA(module_id_t module_idP,frame_t frameP, sub_frame_t subframeP,un } } - LOG_D(MAC,"[eNB %d][RAPROC] Frame %d, subframeP %d: UE_id %d, Is_rrc_registered %d, rrc_sdu_length %d\n", - module_idP,frameP, subframeP,UE_id, Is_rrc_registered,rrc_sdu_length); + LOG_D(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d, subframeP %d: UE_id %d, Is_rrc_registered %d, rrc_sdu_length %d\n", + module_idP, CC_id, frameP, subframeP,UE_id, Is_rrc_registered,rrc_sdu_length); if (rrc_sdu_length>0) { - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d, subframeP %d: Generating Msg4 with RRC Piggyback (RA proc %d, RNTI %x)\n", - module_idP,frameP, subframeP,i,RA_template[i].rnti); + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d, subframeP %d: Generating Msg4 with RRC Piggyback (RA proc %d, RNTI %x)\n", + module_idP, CC_id, frameP, subframeP,i,RA_template[i].rnti); //msg("[MAC][eNB %d][RAPROC] Frame %d, subframeP %d: Received %d bytes for Msg4: \n",module_idP,frameP,subframeP,rrc_sdu_length); // for (j=0;j<rrc_sdu_length;j++) @@ -369,8 +369,8 @@ void schedule_RA(module_id_t module_idP,frame_t frameP, sub_frame_t subframeP,un msg4_post_padding = TBsize - rrc_sdu_length - msg4_header -1; } - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d subframeP %d Msg4 : TBS %d, sdu_len %d, msg4_header %d, msg4_padding %d, msg4_post_padding %d\n", - module_idP,frameP,subframeP,TBsize,rrc_sdu_length,msg4_header,msg4_padding,msg4_post_padding); + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d subframeP %d Msg4 : TBS %d, sdu_len %d, msg4_header %d, msg4_padding %d, msg4_post_padding %d\n", + module_idP,CC_id,frameP,subframeP,TBsize,rrc_sdu_length,msg4_header,msg4_padding,msg4_post_padding); DevAssert( UE_id != UE_INDEX_INVALID ); // FIXME not sure how to gracefully return offset = generate_dlsch_header((unsigned char*)eNB->UE_list.DLSCH_pdu[CC_id][0][(unsigned char)UE_id].payload[0], 1, //num_sdus @@ -390,8 +390,8 @@ void schedule_RA(module_id_t module_idP,frame_t frameP, sub_frame_t subframeP,un trace_pdu(1, (uint8_t *)eNB->UE_list.DLSCH_pdu[CC_id][0][(unsigned char)UE_id].payload[0], rrc_sdu_length, UE_id, 3, UE_RNTI(module_idP, UE_id), eNB->subframe,0,0); - LOG_D(OPT,"[eNB %d][DLSCH] Frame %d trace pdu for rnti %x with size %d\n", - module_idP, frameP, UE_RNTI(module_idP,UE_id), rrc_sdu_length); + LOG_D(OPT,"[eNB %d][DLSCH] CC_id %d Frame %d trace pdu for rnti %x with size %d\n", + module_idP, CC_id, frameP, UE_RNTI(module_idP,UE_id), rrc_sdu_length); } nprb[CC_id]= nprb[CC_id] + 3; @@ -427,7 +427,7 @@ void initiate_ra_proc(module_id_t module_idP, int CC_id,frame_t frameP, uint16_t uint8_t i; RA_TEMPLATE *RA_template = (RA_TEMPLATE *)&eNB_mac_inst[module_idP].common_channels[CC_id].RA_template[0]; - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d Initiating RA procedure for preamble index %d\n",module_idP,frameP,preamble_index); + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d Initiating RA procedure for preamble index %d\n",module_idP,CC_id,frameP,preamble_index); for (i=0; i<NB_RA_PROC_MAX; i++) { if (RA_template[i].RA_active==FALSE) { @@ -440,8 +440,8 @@ void initiate_ra_proc(module_id_t module_idP, int CC_id,frame_t frameP, uint16_t RA_template[i].rnti = taus(); RA_template[i].RA_rnti = 1+subframeP+(10*f_id); RA_template[i].preamble_index = preamble_index; - LOG_D(MAC,"[eNB %d][RAPROC] Frame %d Activating RAR generation for process %d, rnti %x, RA_active %d\n", - module_idP,frameP,i,RA_template[i].rnti, + LOG_D(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d Activating RAR generation for process %d, rnti %x, RA_active %d\n", + module_idP,CC_id,frameP,i,RA_template[i].rnti, RA_template[i].RA_active); return; @@ -455,7 +455,7 @@ void cancel_ra_proc(module_id_t module_idP, int CC_id, frame_t frameP, rnti_t rn RA_TEMPLATE *RA_template = (RA_TEMPLATE *)&eNB_mac_inst[module_idP].common_channels[CC_id].RA_template[0]; MSC_LOG_EVENT(MSC_PHY_ENB, "RA Cancelling procedure ue %"PRIx16" ", rnti); - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d Cancelling RA procedure for UE rnti %x\n",module_idP,frameP,rnti); + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d Cancelling RA procedure for UE rnti %x\n",module_idP,CC_id,frameP,rnti); for (i=0; i<NB_RA_PROC_MAX; i++) { if (rnti == RA_template[i].rnti) { diff --git a/openair2/LAYER2/MAC/eNB_scheduler_bch.c b/openair2/LAYER2/MAC/eNB_scheduler_bch.c index 9adb5692bc4..2e8e80cea08 100644 --- a/openair2/LAYER2/MAC/eNB_scheduler_bch.c +++ b/openair2/LAYER2/MAC/eNB_scheduler_bch.c @@ -175,18 +175,20 @@ schedule_SI( eNB->subframe, 0, 0); - LOG_D(OPT,"[eNB %d][BCH] Frame %d trace pdu for rnti %x with size %d\n", - module_idP, frameP, 0xffff, bcch_sdu_length); + LOG_D(OPT,"[eNB %d][BCH] Frame %d trace pdu for CC_id %d rnti %x with size %d\n", + module_idP, frameP, CC_id, 0xffff, bcch_sdu_length); } if (PHY_vars_eNB_g[module_idP][CC_id]->lte_frame_parms.frame_type == TDD) { - LOG_D(MAC,"[eNB] Frame %d : Scheduling BCCH->DLSCH (TDD) for SI %d bytes (mcs %d, rb 3, TBS %d)\n", + LOG_D(MAC,"[eNB] Frame %d : Scheduling BCCH->DLSCH (TDD) for CC_id %d SI %d bytes (mcs %d, rb 3, TBS %d)\n", frameP, + CC_id, bcch_sdu_length, mcs, mac_xface->get_TBS_DL(mcs,3)); } else { - LOG_D(MAC,"[eNB] Frame %d : Scheduling BCCH->DLSCH (FDD) for SI %d bytes (mcs %d, rb 3, TBS %d)\n", + LOG_D(MAC,"[eNB] Frame %d : Scheduling BCCH->DLSCH (FDD) for CC_id %d SI %d bytes (mcs %d, rb 3, TBS %d)\n", frameP, + CC_id, bcch_sdu_length, mcs, mac_xface->get_TBS_DL(mcs,3)); diff --git a/openair2/LAYER2/MAC/eNB_scheduler_dlsch.c b/openair2/LAYER2/MAC/eNB_scheduler_dlsch.c index dbc410bbe20..4dd14342610 100644 --- a/openair2/LAYER2/MAC/eNB_scheduler_dlsch.c +++ b/openair2/LAYER2/MAC/eNB_scheduler_dlsch.c @@ -333,7 +333,7 @@ set_ul_DAI( if (frame_parms[CC_idP]->frame_type == TDD) { DAI = (UE_list->UE_template[CC_idP][UE_idP].DAI-1)&3; - LOG_D(MAC,"[eNB %d] Frame %d, subframe %d: DAI %d for UE %d\n",module_idP,frameP,subframeP,DAI,UE_idP); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d, subframe %d: DAI %d for UE %d\n",module_idP,CC_idP,frameP,subframeP,DAI,UE_idP); // Save DAI for Format 0 DCI switch (frame_parms[CC_idP]->tdd_config) { @@ -604,8 +604,8 @@ schedule_ue_spec( if (frame_parms[CC_id]->frame_type == TDD) { UE_list->UE_template[CC_id][UE_id].DAI++; update_ul_dci(module_idP,CC_id,rnti,UE_list->UE_template[CC_id][UE_id].DAI); - LOG_D(MAC,"DAI update: subframeP %d: UE %d, DAI %d\n", - subframeP,UE_id,UE_list->UE_template[CC_id][UE_id].DAI); + LOG_D(MAC,"DAI update: CC_id %d subframeP %d: UE %d, DAI %d\n", + CC_id,subframeP,UE_id,UE_list->UE_template[CC_id][UE_id].DAI); } // get freq_allocation @@ -662,13 +662,15 @@ schedule_ue_spec( ((DCI1_1_5MHz_TDD_t*)DLSCH_dci)->harq_pid = harq_pid; ((DCI1_1_5MHz_TDD_t*)DLSCH_dci)->rv = round&3; ((DCI1_1_5MHz_TDD_t*)DLSCH_dci)->dai = (UE_list->UE_template[CC_id][UE_id].DAI-1)&3; - LOG_D(MAC,"[eNB %d] Retransmission : harq_pid %d, round %d, dai %d, mcs %d\n",module_idP,harq_pid,round,(UE_list->UE_template[CC_id][UE_id].DAI-1), + LOG_D(MAC,"[eNB %d] Retransmission CC_id %d : harq_pid %d, round %d, dai %d, mcs %d\n", + module_idP,CC_id,harq_pid,round,(UE_list->UE_template[CC_id][UE_id].DAI-1), ((DCI1_1_5MHz_TDD_t*)DLSCH_dci)->mcs); } else { // ((DCI1_1_5MHz_FDD_t*)DLSCH_dci)->ndi = 0; ((DCI1_1_5MHz_FDD_t*)DLSCH_dci)->harq_pid = harq_pid; ((DCI1_1_5MHz_FDD_t*)DLSCH_dci)->rv = round&3; - LOG_D(MAC,"[eNB %d] Retransmission : harq_pid %d, round %d, mcs %d\n",module_idP,harq_pid,round,((DCI1_1_5MHz_FDD_t*)DLSCH_dci)->mcs); + LOG_D(MAC,"[eNB %d] Retransmission CC_id %d : harq_pid %d, round %d, mcs %d\n", + module_idP,CC_id,harq_pid,round,((DCI1_1_5MHz_FDD_t*)DLSCH_dci)->mcs); } @@ -680,13 +682,15 @@ schedule_ue_spec( ((DCI1_5MHz_TDD_t*)DLSCH_dci)->harq_pid = harq_pid; ((DCI1_5MHz_TDD_t*)DLSCH_dci)->rv = round&3; ((DCI1_5MHz_TDD_t*)DLSCH_dci)->dai = (UE_list->UE_template[CC_id][UE_id].DAI-1)&3; - LOG_D(MAC,"[eNB %d] Retransmission : harq_pid %d, round %d, dai %d, mcs %d\n",module_idP,harq_pid,round,(UE_list->UE_template[CC_id][UE_id].DAI-1), + LOG_D(MAC,"[eNB %d] Retransmission CC_id %d : harq_pid %d, round %d, dai %d, mcs %d\n", + module_idP,CC_id,harq_pid,round,(UE_list->UE_template[CC_id][UE_id].DAI-1), ((DCI1_5MHz_TDD_t*)DLSCH_dci)->mcs); } else { // ((DCI1_5MHz_FDD_t*)DLSCH_dci)->ndi = 0; ((DCI1_5MHz_FDD_t*)DLSCH_dci)->harq_pid = harq_pid; ((DCI1_5MHz_FDD_t*)DLSCH_dci)->rv = round&3; - LOG_D(MAC,"[eNB %d] Retransmission : harq_pid %d, round %d, mcs %d\n",module_idP,harq_pid,round,((DCI1_5MHz_FDD_t*)DLSCH_dci)->mcs); + LOG_D(MAC,"[eNB %d] Retransmission CC_id %d : harq_pid %d, round %d, mcs %d\n", + module_idP,CC_id,harq_pid,round,((DCI1_5MHz_FDD_t*)DLSCH_dci)->mcs); } @@ -698,13 +702,15 @@ schedule_ue_spec( ((DCI1_10MHz_TDD_t*)DLSCH_dci)->harq_pid = harq_pid; ((DCI1_10MHz_TDD_t*)DLSCH_dci)->rv = round&3; ((DCI1_10MHz_TDD_t*)DLSCH_dci)->dai = (UE_list->UE_template[CC_id][UE_id].DAI-1)&3; - LOG_D(MAC,"[eNB %d] Retransmission : harq_pid %d, round %d, dai %d, mcs %d\n",module_idP,harq_pid,round,(UE_list->UE_template[CC_id][UE_id].DAI-1), + LOG_D(MAC,"[eNB %d] Retransmission CC_id %d : harq_pid %d, round %d, dai %d, mcs %d\n", + module_idP,CC_id,harq_pid,round,(UE_list->UE_template[CC_id][UE_id].DAI-1), ((DCI1_10MHz_TDD_t*)DLSCH_dci)->mcs); } else { // ((DCI1_10MHz_FDD_t*)DLSCH_dci)->ndi = 0; ((DCI1_10MHz_FDD_t*)DLSCH_dci)->harq_pid = harq_pid; ((DCI1_10MHz_FDD_t*)DLSCH_dci)->rv = round&3; - LOG_D(MAC,"[eNB %d] Retransmission : harq_pid %d, round %d, mcs %d\n",module_idP,harq_pid,round,((DCI1_10MHz_FDD_t*)DLSCH_dci)->mcs); + LOG_D(MAC,"[eNB %d] Retransmission CC_id %d : harq_pid %d, round %d, mcs %d\n", + module_idP,CC_id,harq_pid,round,((DCI1_10MHz_FDD_t*)DLSCH_dci)->mcs); } @@ -716,13 +722,15 @@ schedule_ue_spec( ((DCI1_20MHz_TDD_t*)DLSCH_dci)->harq_pid = harq_pid; ((DCI1_20MHz_TDD_t*)DLSCH_dci)->rv = round&3; ((DCI1_20MHz_TDD_t*)DLSCH_dci)->dai = (UE_list->UE_template[CC_id][UE_id].DAI-1)&3; - LOG_D(MAC,"[eNB %d] Retransmission : harq_pid %d, round %d, dai %d, mcs %d\n",module_idP,harq_pid,round,(UE_list->UE_template[CC_id][UE_id].DAI-1), + LOG_D(MAC,"[eNB %d] Retransmission CC_id %d : harq_pid %d, round %d, dai %d, mcs %d\n", + module_idP,CC_id,harq_pid,round,(UE_list->UE_template[CC_id][UE_id].DAI-1), ((DCI1_20MHz_TDD_t*)DLSCH_dci)->mcs); } else { // ((DCI1_20MHz_FDD_t*)DLSCH_dci)->ndi = 0; ((DCI1_20MHz_FDD_t*)DLSCH_dci)->harq_pid = harq_pid; ((DCI1_20MHz_FDD_t*)DLSCH_dci)->rv = round&3; - LOG_D(MAC,"[eNB %d] Retransmission : harq_pid %d, round %d, mcs %d\n",module_idP,harq_pid,round,((DCI1_20MHz_FDD_t*)DLSCH_dci)->mcs); + LOG_D(MAC,"[eNB %d] Retransmission CC_id %d : harq_pid %d, round %d, mcs %d\n", + module_idP,CC_id,harq_pid,round,((DCI1_20MHz_FDD_t*)DLSCH_dci)->mcs); } @@ -784,7 +792,8 @@ schedule_ue_spec( UE_list->eNB_UE_stats[CC_id][UE_id].dlsch_mcs1=eNB_UE_stats->dlsch_mcs1; UE_list->eNB_UE_stats[CC_id][UE_id].dlsch_mcs2=eNB_UE_stats->dlsch_mcs1; } else { - LOG_D(MAC,"[eNB %d] Frame %d : don't schedule UE %d, its retransmission takes more resources than we have\n", module_idP, frameP, UE_id); + LOG_D(MAC,"[eNB %d] Frame %d CC_id %d : don't schedule UE %d, its retransmission takes more resources than we have\n", + module_idP, frameP, CC_id, UE_id); } } else { /* This is a potentially new SDU opportunity */ @@ -839,7 +848,8 @@ schedule_ue_spec( sdu_lengths[0]=0; if (rlc_status.bytes_in_buffer > 0) { // There is DCCH to transmit - LOG_D(MAC,"[eNB %d] Frame %d, DL-DCCH->DLSCH, Requesting %d bytes from RLC (RRC message)\n",module_idP,frameP,TBS-header_len_dcch); + LOG_D(MAC,"[eNB %d] Frame %d, DL-DCCH->DLSCH CC_id %d, Requesting %d bytes from RLC (RRC message)\n", + module_idP,frameP,CC_id,TBS-header_len_dcch); sdu_lengths[0] += mac_rlc_data_req( module_idP, rnti, @@ -850,14 +860,14 @@ schedule_ue_spec( DCCH, (char *)&dlsch_buffer[sdu_lengths[0]]); - LOG_D(MAC,"[eNB %d][DCCH] Got %d bytes from RLC\n",module_idP,sdu_lengths[0]); + LOG_D(MAC,"[eNB %d][DCCH] CC_id %d Got %d bytes from RLC\n",module_idP,CC_id,sdu_lengths[0]); sdu_length_total = sdu_lengths[0]; sdu_lcids[0] = DCCH; UE_list->eNB_UE_stats[CC_id][UE_id].num_pdu_tx[DCCH]+=1; UE_list->eNB_UE_stats[CC_id][UE_id].num_bytes_tx[DCCH]+=sdu_lengths[0]; num_sdus = 1; #ifdef DEBUG_eNB_SCHEDULER - LOG_T(MAC,"[eNB %d][DCCH] Got %d bytes :",module_idP,sdu_lengths[0]); + LOG_T(MAC,"[eNB %d][DCCH] CC_id %d Got %d bytes :",module_idP,CC_id,sdu_lengths[0]); for (j=0; j<sdu_lengths[0]; j++) { LOG_T(MAC,"%x ",dlsch_buffer[j]); @@ -885,8 +895,8 @@ schedule_ue_spec( // DCCH SDU if (rlc_status.bytes_in_buffer > 0) { - LOG_D(MAC,"[eNB %d], Frame %d, DCCH1->DLSCH, Requesting %d bytes from RLC (RRC message)\n", - module_idP,frameP,TBS-header_len_dcch-sdu_length_total); + LOG_D(MAC,"[eNB %d], Frame %d, DCCH1->DLSCH, CC_id %d, Requesting %d bytes from RLC (RRC message)\n", + module_idP,frameP,CC_id,TBS-header_len_dcch-sdu_length_total); sdu_lengths[num_sdus] += mac_rlc_data_req( module_idP, rnti, @@ -903,7 +913,7 @@ schedule_ue_spec( UE_list->eNB_UE_stats[CC_id][UE_id].num_pdu_tx[DCCH1]+=1; UE_list->eNB_UE_stats[CC_id][UE_id].num_bytes_tx[DCCH1]+=sdu_lengths[num_sdus]; num_sdus++; - LOG_D(MAC,"[eNB %d] Got %d bytes for DCCH from RLC\n",module_idP,sdu_lengths[0]); + LOG_D(MAC,"[eNB %d] CC_id %d Got %d bytes for DCCH from RLC\n",module_idP,CC_id,sdu_lengths[0]); } } @@ -912,8 +922,8 @@ schedule_ue_spec( header_len_dtch = 3; // 3 bytes DTCH SDU subheader - LOG_D(MAC,"[eNB %d], Frame %d, DTCH->DLSCH, Checking RLC status (rab %d, tbs %d, len %d)\n", - module_idP,frameP,DTCH,TBS, + LOG_D(MAC,"[eNB %d], Frame %d, DTCH->DLSCH, CC_id %d, Checking RLC status (rab %d, tbs %d, len %d)\n", + module_idP,frameP,CC_id,DTCH,TBS, TBS-ta_len-header_len_dcch-sdu_length_total-header_len_dtch); if (TBS-ta_len-header_len_dcch-sdu_length_total-header_len_dtch > 0 ) { @@ -929,8 +939,8 @@ schedule_ue_spec( if (rlc_status.bytes_in_buffer > 0) { - LOG_D(MAC,"[eNB %d][USER-PLANE DEFAULT DRB], Frame %d, DTCH->DLSCH, Requesting %d bytes from RLC (hdr len dtch %d)\n", - module_idP,frameP,TBS-header_len_dcch-sdu_length_total-header_len_dtch,header_len_dtch); + LOG_D(MAC,"[eNB %d][USER-PLANE DEFAULT DRB], Frame %d, DTCH->DLSCH, CC_id %d, Requesting %d bytes from RLC (hdr len dtch %d)\n", + module_idP,frameP,CC_id,TBS-header_len_dcch-sdu_length_total-header_len_dtch,header_len_dtch); sdu_lengths[num_sdus] = mac_rlc_data_req( module_idP, rnti, @@ -941,7 +951,8 @@ schedule_ue_spec( DTCH, (char*)&dlsch_buffer[sdu_length_total]); - LOG_D(MAC,"[eNB %d][USER-PLANE DEFAULT DRB] Got %d bytes for DTCH %d \n",module_idP,sdu_lengths[num_sdus],DTCH); + LOG_D(MAC,"[eNB %d][USER-PLANE DEFAULT DRB] CC_id %d Got %d bytes for DTCH %d \n", + module_idP,CC_id,sdu_lengths[num_sdus],DTCH); sdu_lcids[num_sdus] = DTCH; sdu_length_total += sdu_lengths[num_sdus]; UE_list->eNB_UE_stats[CC_id][UE_id].num_pdu_tx[DTCH]+=1; @@ -1045,8 +1056,8 @@ schedule_ue_spec( LOG_D(MAC,"dlsch_mcs before and after the rate matching = (%d, %d)\n",eNB_UE_stats->dlsch_mcs1, mcs); #ifdef DEBUG_eNB_SCHEDULER - LOG_D(MAC,"[eNB %d] Generated DLSCH header (mcs %d, TBS %d, nb_rb %d)\n", - module_idP,mcs,TBS,nb_rb); + LOG_D(MAC,"[eNB %d] CC_id %d Generated DLSCH header (mcs %d, TBS %d, nb_rb %d)\n", + module_idP,CC_id,mcs,TBS,nb_rb); // msg("[MAC][eNB ] Reminder of DLSCH with random data %d %d %d %d \n", // TBS, sdu_length_total, offset, TBS-sdu_length_total-offset); #endif @@ -1116,8 +1127,8 @@ schedule_ue_spec( trace_pdu(1, (uint8_t *)UE_list->DLSCH_pdu[CC_id][0][UE_id].payload[0], TBS, module_idP, 3, UE_RNTI(module_idP,UE_id), eNB->subframe,0,0); - LOG_D(OPT,"[eNB %d][DLSCH] Frame %d rnti %x with size %d\n", - module_idP, frameP, UE_RNTI(module_idP,UE_id), TBS); + LOG_D(OPT,"[eNB %d][DLSCH] CC_id %d Frame %d rnti %x with size %d\n", + module_idP, CC_id, frameP, UE_RNTI(module_idP,UE_id), TBS); } aggregation = process_ue_cqi(module_idP,UE_id); @@ -1413,7 +1424,8 @@ schedule_ue_spec( } // Toggle NDI for next time - LOG_D(MAC,"Frame %d, subframeP %d: Toggling Format1 NDI for UE %d (rnti %x/%d) oldNDI %d\n",frameP,subframeP,UE_id, + LOG_D(MAC,"CC_id %d Frame %d, subframeP %d: Toggling Format1 NDI for UE %d (rnti %x/%d) oldNDI %d\n", + CC_id, frameP,subframeP,UE_id, UE_list->UE_template[CC_id][UE_id].rnti,harq_pid,UE_list->UE_template[CC_id][UE_id].oldNDI[harq_pid]); UE_list->UE_template[CC_id][UE_id].oldNDI[harq_pid]=1-UE_list->UE_template[CC_id][UE_id].oldNDI[harq_pid]; } else { // There is no data from RLC or MAC header, so don't schedule @@ -1489,7 +1501,7 @@ fill_DLSCH_dci( // printf("BCCH check\n"); if (eNB->common_channels[CC_id].bcch_active == 1) { eNB->common_channels[CC_id].bcch_active = 0; - LOG_D(MAC,"[eNB %d] Frame %d subframeP %d: BCCH active\n", module_idP, frameP, subframeP); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d subframeP %d: BCCH active\n", module_idP, CC_id, frameP, subframeP); // randomize frequency allocation for SI first_rb = 10;//(unsigned char)(taus()%(PHY_vars_eNB_g[module_idP][CC_id]->lte_frame_parms.N_RB_DL-4)); @@ -1683,8 +1695,8 @@ fill_DLSCH_dci( //FK: postponed to fill_rar //RA_template->generate_rar = 0; - LOG_D(MAC,"[eNB %d] Frame %d, subframeP %d: Generating RAR DCI (proc %d), RA_active %d format 1A (%d,%d))\n", - module_idP,frameP, subframeP,i, + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d, subframeP %d: Generating RAR DCI (proc %d), RA_active %d format 1A (%d,%d))\n", + module_idP, CC_id, frameP, subframeP,i, RA_template->RA_active, RA_template->RA_dci_fmt1, RA_template->RA_dci_size_bits1); @@ -1848,8 +1860,8 @@ fill_DLSCH_dci( - LOG_D(MAC,"[eNB %d] Frame %d: Adding common dci for RA%d (RAR) RA_active %d\n",module_idP,frameP,i, - RA_template->RA_active); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d: Adding common dci for RA%d (RAR) RA_active %d\n", + module_idP,CC_id,frameP,i, RA_template->RA_active); } if (RA_template->generate_Msg4_dci == 1) { @@ -2000,14 +2012,14 @@ fill_DLSCH_dci( RA_template->RA_dci_size_bits2, RA_template->RA_dci_fmt2, 0); - LOG_D(MAC,"[eNB %d][RAPROC] Frame %d, subframeP %d: Adding ue specific dci (rnti %x) for Msg4\n", - module_idP,frameP,subframeP,RA_template->rnti); + LOG_D(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d, subframeP %d: Adding ue specific dci (rnti %x) for Msg4\n", + module_idP,CC_id,frameP,subframeP,RA_template->rnti); RA_template->generate_Msg4_dci=0; } else if (RA_template->wait_ack_Msg4==1) { // check HARQ status and retransmit if necessary - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d, subframeP %d: Checking if Msg4 was acknowledged: \n", - module_idP,frameP,subframeP); + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d, subframeP %d: Checking if Msg4 was acknowledged: \n", + module_idP,CC_id,frameP,subframeP); // Get candidate harq_pid from PHY mac_xface->get_ue_active_harq_pid(module_idP,CC_id,RA_template->rnti,frameP,subframeP,&harq_pid,&round,0); @@ -2051,15 +2063,15 @@ fill_DLSCH_dci( RA_template->RA_dci_size_bits2, RA_template->RA_dci_fmt2, 0); - LOG_W(MAC,"[eNB %d][RAPROC] Frame %d, subframeP %d: Msg4 not acknowledged, adding ue specific dci (rnti %x) for RA (Msg4 Retransmission)\n", - module_idP,frameP,subframeP,RA_template->rnti); + LOG_W(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d, subframeP %d: Msg4 not acknowledged, adding ue specific dci (rnti %x) for RA (Msg4 Retransmission)\n", + module_idP,CC_id,frameP,subframeP,RA_template->rnti); } else { /* msg4 not received if ((round == 0) && (RA_template->wait_ack_Msg4>1){ remove UE instance across all the layers: mac_xface->cancel_RA(); } */ - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d, subframeP %d : Msg4 acknowledged\n",module_idP,frameP,subframeP); + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d, subframeP %d : Msg4 acknowledged\n",module_idP,CC_id,frameP,subframeP); RA_template->wait_ack_Msg4=0; RA_template->RA_active=FALSE; UE_id = find_UE_id(module_idP,RA_template->rnti); @@ -2103,7 +2115,7 @@ fill_DLSCH_dci( case 1: case 2: - LOG_D(MAC,"[eNB %d] Adding UE %d spec DCI for %d PRBS (rb alloc: %x) \n",module_idP, UE_id, nb_rb,rballoc); + LOG_D(MAC,"[eNB %d] CC_id %d Adding UE %d spec DCI for %d PRBS (rb alloc: %x) \n",module_idP, CC_id, UE_id, nb_rb,rballoc); if (PHY_vars_eNB_g[module_idP][CC_id]->lte_frame_parms.frame_type == TDD) { switch (PHY_vars_eNB_g[module_idP][CC_id]->lte_frame_parms.N_RB_DL) { @@ -2195,7 +2207,8 @@ fill_DLSCH_dci( break; case 3: - LOG_D(MAC,"[eNB %d] Adding Format 2A UE %d spec DCI for %d PRBS (rb alloc: %x) \n",module_idP, UE_id, nb_rb,rballoc); + LOG_D(MAC,"[eNB %d] CC_id %d Adding Format 2A UE %d spec DCI for %d PRBS (rb alloc: %x) \n", + module_idP, CC_id, UE_id, nb_rb,rballoc); if (PHY_vars_eNB_g[module_idP][CC_id]->lte_frame_parms.frame_type == TDD) { switch (PHY_vars_eNB_g[module_idP][CC_id]->lte_frame_parms.N_RB_DL) { @@ -2367,7 +2380,7 @@ get_dlsch_sdu( eNB_MAC_INST *eNB=&eNB_mac_inst[module_idP]; if (rntiP==SI_RNTI) { - LOG_D(MAC,"[eNB %d] Frame %d Get DLSCH sdu for BCCH \n",module_idP,frameP); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d Get DLSCH sdu for BCCH \n", module_idP, CC_id, frameP); return((unsigned char *)&eNB->common_channels[CC_id].BCCH_pdu.payload[0]); } diff --git a/openair2/LAYER2/MAC/eNB_scheduler_mch.c b/openair2/LAYER2/MAC/eNB_scheduler_mch.c index a9e9e9a1b8d..ce3386b2cd0 100644 --- a/openair2/LAYER2/MAC/eNB_scheduler_mch.c +++ b/openair2/LAYER2/MAC/eNB_scheduler_mch.c @@ -74,12 +74,12 @@ int8_t get_mbsfn_sf_alloction (module_id_t module_idP, uint8_t CC_id, uint8_t mb { // currently there is one-to-one mapping between sf allocation pattern and sync area if (mbsfn_sync_area > MAX_MBSFN_AREA) { - LOG_W(MAC,"[eNB %d] MBSFN synchronization area %d out of range\n ", module_idP, mbsfn_sync_area); + LOG_W(MAC,"[eNB %d] CC_id %d MBSFN synchronization area %d out of range\n ", module_idP, CC_id, mbsfn_sync_area); return -1; } else if (eNB_mac_inst[module_idP].common_channels[CC_id].mbsfn_SubframeConfig[mbsfn_sync_area] != NULL) { return mbsfn_sync_area; } else { - LOG_W(MAC,"[eNB %d] MBSFN Subframe Config pattern %d not found \n ", module_idP, mbsfn_sync_area); + LOG_W(MAC,"[eNB %d] CC_id %d MBSFN Subframe Config pattern %d not found \n ", module_idP, CC_id, mbsfn_sync_area); return -1; } } @@ -117,8 +117,8 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra mcch_period = 32<<(eNB_mac_inst[module_idP].common_channels[CC_id].mbsfn_AreaInfo[i]->mcch_Config_r9.mcch_RepetitionPeriod_r9); msi_pos=0; ii=0; - LOG_D(MAC,"[eNB %d] Frame %d subframeP %d : Checking MBSFN Sync Area %d/%d with SF allocation %d/%d for MCCH and MTCH (mbsfn period %d, mcch period %d)\n", - module_idP,frameP, subframeP,i,eNB_mac_inst[module_idP].common_channels[CC_id].num_active_mbsfn_area, + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d subframeP %d : Checking MBSFN Sync Area %d/%d with SF allocation %d/%d for MCCH and MTCH (mbsfn period %d, mcch period %d)\n", + module_idP, CC_id, frameP, subframeP,i,eNB_mac_inst[module_idP].common_channels[CC_id].num_active_mbsfn_area, j,eNB_mac_inst[module_idP].common_channels[CC_id].num_sf_allocation_pattern,mbsfn_period,mcch_period); @@ -151,7 +151,8 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra msi_pos++; } - LOG_D(MAC,"[eNB %d] Frame %d subframeP %d : sync area %d sf allocation pattern %d sf alloc %x msi pos is %d \n", module_idP,frameP, subframeP,i,j, + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d subframeP %d : sync area %d sf allocation pattern %d sf alloc %x msi pos is %d \n", + module_idP, CC_id, frameP, subframeP,i,j, eNB_mac_inst[module_idP].common_channels[CC_id].mbsfn_SubframeConfig[j]->subframeAllocation.choice.oneFrame.buf[0], msi_pos); } @@ -343,8 +344,8 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra // sf allocation is non-overlapping if ((msi_flag==1) || (mcch_flag==1) || (mtch_flag==1)) { - LOG_D(MAC,"[eNB %d] Frame %d Subframe %d: sync area %d SF alloc %d: msi flag %d, mcch flag %d, mtch flag %d\n", - module_idP, frameP, subframeP,i,j,msi_flag,mcch_flag,mtch_flag); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d Subframe %d: sync area %d SF alloc %d: msi flag %d, mcch flag %d, mtch flag %d\n", + module_idP, CC_id, frameP, subframeP,i,j,msi_flag,mcch_flag,mtch_flag); break; } } else { // four-frameP format @@ -402,7 +403,8 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra header_len_msi = 3; } - LOG_D(MAC,"[eNB %d] Frame %d : MSI->MCH, length of MSI is %d bytes \n",module_idP,frameP,msi_length); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d : MSI->MCH, length of MSI is %d bytes \n", + module_idP,CC_id,frameP,msi_length); //LOG_D(MAC,"Scheduler: MSI is transmitted in this subframeP \n" ); // LOG_D(MAC,"Scheduler: MSI length is %d bytes\n",msi_length); @@ -414,15 +416,15 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra sdu_lcids[num_sdus] = MCH_SCHDL_INFO; sdu_lengths[num_sdus] = msi_length; sdu_length_total += sdu_lengths[num_sdus]; - LOG_I(MAC,"[eNB %d] Create %d bytes for MSI\n",module_idP,sdu_lengths[num_sdus]); + LOG_I(MAC,"[eNB %d] CC_id %d Create %d bytes for MSI\n", module_idP, CC_id, sdu_lengths[num_sdus]); num_sdus++; eNB_mac_inst[module_idP].common_channels[CC_id].msi_active=1; } // there is MCCH if (mcch_flag == 1) { - LOG_D(MAC,"[eNB %d] Frame %d Subframe %d: Schedule MCCH MESSAGE (area %d, sfAlloc %d)\n", - module_idP,frameP, subframeP, i, j); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d Subframe %d: Schedule MCCH MESSAGE (area %d, sfAlloc %d)\n", + module_idP, CC_id, frameP, subframeP, i, j); mcch_sdu_length = mac_rrc_data_req(module_idP, CC_id, @@ -434,19 +436,20 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra i); // this is the mbsfn sync area index if (mcch_sdu_length > 0) { - LOG_D(MAC,"[eNB %d] Frame %d subframeP %d : MCCH->MCH, Received %d bytes from RRC \n",module_idP,frameP,subframeP,mcch_sdu_length); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d subframeP %d : MCCH->MCH, Received %d bytes from RRC \n", + module_idP,CC_id,frameP,subframeP,mcch_sdu_length); header_len_mcch = 2; if (mac_xface->lte_frame_parms->frame_type == TDD) { - LOG_D(MAC,"[eNB %d] Frame %d subframeP %d: Scheduling MCCH->MCH (TDD) for MCCH message %d bytes (mcs %d )\n", - module_idP, + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d subframeP %d: Scheduling MCCH->MCH (TDD) for MCCH message %d bytes (mcs %d )\n", + module_idP, CC_id, frameP,subframeP, mcch_sdu_length, mcch_mcs); } else { - LOG_I(MAC,"[eNB %d] Frame %d subframeP %d: Scheduling MCCH->MCH (FDD) for MCCH message %d bytes (mcs %d)\n", - module_idP, + LOG_I(MAC,"[eNB %d] CC_id %d Frame %d subframeP %d: Scheduling MCCH->MCH (FDD) for MCCH message %d bytes (mcs %d)\n", + module_idP, CC_id, frameP, subframeP, mcch_sdu_length, mcch_mcs); @@ -465,7 +468,7 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra } sdu_length_total += sdu_lengths[num_sdus]; - LOG_D(MAC,"[eNB %d] Got %d bytes for MCCH from RRC \n",module_idP,sdu_lengths[num_sdus]); + LOG_D(MAC,"[eNB %d] CC_id %d Got %d bytes for MCCH from RRC \n",module_idP,CC_id,sdu_lengths[num_sdus]); num_sdus++; } } @@ -488,11 +491,11 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra } // get MTCH data from RLC (like for DTCH) - LOG_D(MAC,"[eNB %d] Frame %d subframe %d: Schedule MTCH (area %d, sfAlloc %d)\n",Mod_id,frame,subframe,i,j); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d subframe %d: Schedule MTCH (area %d, sfAlloc %d)\n",Mod_id,CC_id,frame,subframe,i,j); header_len_mtch = 3; - LOG_D(MAC,"[eNB %d], Frame %d, MTCH->MCH, Checking RLC status (rab %d, tbs %d, len %d)\n", - Mod_id,frame,MTCH,TBS, + LOG_D(MAC,"[eNB %d], CC_id %d, Frame %d, MTCH->MCH, Checking RLC status (rab %d, tbs %d, len %d)\n", + Mod_id,CC_id,frame,MTCH,TBS, TBS-header_len_mcch-header_len_msi-sdu_length_total-header_len_mtch); rlc_status = mac_rlc_status_ind(Mod_id,frame,1,RLC_MBMS_YES,MTCH+ (maxDRB + 3) * MAX_MOBILES_PER_RG, @@ -502,11 +505,11 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra */ // get MTCH data from RLC (like for DTCH) - LOG_D(MAC,"[eNB %d] Frame %d subframeP %d: Schedule MTCH (area %d, sfAlloc %d)\n",module_idP,frameP,subframeP,i,j); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d subframeP %d: Schedule MTCH (area %d, sfAlloc %d)\n",module_idP,CC_id,frameP,subframeP,i,j); header_len_mtch = 3; - LOG_D(MAC,"[eNB %d], Frame %d, MTCH->MCH, Checking RLC status (rab %d, tbs %d, len %d)\n", - module_idP,frameP,MTCH,TBS, + LOG_D(MAC,"[eNB %d], CC_id %d, Frame %d, MTCH->MCH, Checking RLC status (rab %d, tbs %d, len %d)\n", + module_idP,CC_id,frameP,MTCH,TBS, TBS-header_len_mcch-header_len_msi-sdu_length_total-header_len_mtch); rlc_status = mac_rlc_status_ind(module_idP,0,frameP,module_idP,ENB_FLAG_YES,MBMS_FLAG_YES,MTCH, @@ -515,8 +518,8 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra MTCH,frameP,subframeP, rlc_status.bytes_in_buffer); if (rlc_status.bytes_in_buffer >0) { - LOG_I(MAC,"[eNB %d][MBMS USER-PLANE], Frame %d, MTCH->MCH, Requesting %d bytes from RLC (header len mtch %d)\n", - module_idP,frameP,TBS-header_len_mcch-header_len_msi-sdu_length_total-header_len_mtch,header_len_mtch); + LOG_I(MAC,"[eNB %d][MBMS USER-PLANE], CC_id %d, Frame %d, MTCH->MCH, Requesting %d bytes from RLC (header len mtch %d)\n", + module_idP,CC_id,frameP,TBS-header_len_mcch-header_len_msi-sdu_length_total-header_len_mtch,header_len_mtch); sdu_lengths[num_sdus] = mac_rlc_data_req( module_idP, @@ -528,7 +531,7 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra MTCH, (char*)&mch_buffer[sdu_length_total]); //sdu_lengths[num_sdus] = mac_rlc_data_req(module_idP,frameP, MBMS_FLAG_NO, MTCH+(MAX_NUM_RB*(NUMBER_OF_UE_MAX+1)), (char*)&mch_buffer[sdu_length_total]); - LOG_I(MAC,"[eNB %d][MBMS USER-PLANE] Got %d bytes for MTCH %d\n",module_idP,sdu_lengths[num_sdus],MTCH); + LOG_I(MAC,"[eNB %d][MBMS USER-PLANE] CC_id %d Got %d bytes for MTCH %d\n",module_idP,CC_id,sdu_lengths[num_sdus],MTCH); eNB_mac_inst[module_idP].common_channels[CC_id].mtch_active=1; sdu_lcids[num_sdus] = MTCH; sdu_length_total += sdu_lengths[num_sdus]; @@ -611,8 +614,8 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra LOG_D(MAC," MCS for this sf is %d (mcch active %d, mtch active %d)\n", eNB_mac_inst[module_idP].common_channels[CC_id].MCH_pdu.mcs, eNB_mac_inst[module_idP].common_channels[CC_id].MCH_pdu.mcch_active,eNB_mac_inst[module_idP].common_channels[CC_id].MCH_pdu.mtch_active ); LOG_I(MAC, - "[eNB %d][MBMS USER-PLANE ] Generate header : sdu_length_total %d, num_sdus %d, sdu_lengths[0] %d, sdu_lcids[0] %d => payload offset %d,padding %d,post_padding %d (mcs %d, TBS %d), header MTCH %d, header MCCH %d, header MSI %d\n", - module_idP,sdu_length_total,num_sdus,sdu_lengths[0],sdu_lcids[0],offset,padding,post_padding,eNB_mac_inst[module_idP].common_channels[CC_id].MCH_pdu.mcs,TBS, + "[eNB %d][MBMS USER-PLANE ] CC_id %d Generate header : sdu_length_total %d, num_sdus %d, sdu_lengths[0] %d, sdu_lcids[0] %d => payload offset %d,padding %d,post_padding %d (mcs %d, TBS %d), header MTCH %d, header MCCH %d, header MSI %d\n", + module_idP,CC_id,sdu_length_total,num_sdus,sdu_lengths[0],sdu_lcids[0],offset,padding,post_padding,eNB_mac_inst[module_idP].common_channels[CC_id].MCH_pdu.mcs,TBS, header_len_mtch, header_len_mcch, header_len_msi); // copy SDU to mch_pdu after the MAC Header memcpy(&eNB_mac_inst[module_idP].common_channels[CC_id].MCH_pdu.payload[offset],mch_buffer,sdu_length_total); @@ -627,8 +630,8 @@ int schedule_MBMS(module_id_t module_idP, uint8_t CC_id, frame_t frameP, sub_fra trace_pdu(1, (uint8_t *)eNB_mac_inst[module_idP].common_channels[CC_id].MCH_pdu.payload, TBS, module_idP, 6, 0xffff, // M_RNTI = 6 in wirehsark eNB_mac_inst[module_idP].subframe,0,0); - LOG_D(OPT,"[eNB %d][MCH] Frame %d : MAC PDU with size %d\n", - module_idP, frameP, TBS); + LOG_D(OPT,"[eNB %d][MCH] CC_id %d Frame %d : MAC PDU with size %d\n", + module_idP, CC_id, frameP, TBS); } /* diff --git a/openair2/LAYER2/MAC/eNB_scheduler_primitives.c b/openair2/LAYER2/MAC/eNB_scheduler_primitives.c index 2254c857256..d5415e0413d 100644 --- a/openair2/LAYER2/MAC/eNB_scheduler_primitives.c +++ b/openair2/LAYER2/MAC/eNB_scheduler_primitives.c @@ -542,7 +542,7 @@ void SR_indication(module_id_t mod_idP, int cc_idP, frame_t frameP, rnti_t rntiP } else { // AssertFatal(0, "find_UE_id(%u,rnti %d) not found", enb_mod_idP, rntiP); // AssertError(0, 0, "Frame %d: find_UE_id(%u,rnti %d) not found\n", frameP, enb_mod_idP, rntiP); - LOG_D(MAC,"[eNB %d][SR %x] Frame %d subframeP %d Signaling SR for UE %d (unknown UEid) \n",mod_idP,rntiP,frameP,subframeP, UE_id); + LOG_D(MAC,"[eNB %d][SR %x] Frame %d subframeP %d Signaling SR for UE %d (unknown UEid) on CC_id %d\n",mod_idP,rntiP,frameP,subframeP, UE_id,cc_idP); } } diff --git a/openair2/LAYER2/MAC/eNB_scheduler_ulsch.c b/openair2/LAYER2/MAC/eNB_scheduler_ulsch.c index d86c5c5c4c9..0191317e6ee 100644 --- a/openair2/LAYER2/MAC/eNB_scheduler_ulsch.c +++ b/openair2/LAYER2/MAC/eNB_scheduler_ulsch.c @@ -97,7 +97,7 @@ void rx_sdu( VCD_SIGNAL_DUMPER_DUMP_FUNCTION_BY_NAME(VCD_SIGNAL_DUMPER_FUNCTIONS_RX_SDU,1); - LOG_D(MAC,"[eNB %d] Received ULSCH sdu from PHY (rnti %x, UE_id %d), parsing header\n",enb_mod_idP,rntiP,UE_id); + LOG_D(MAC,"[eNB %d] CC_id %d Received ULSCH sdu from PHY (rnti %x, UE_id %d), parsing header\n",enb_mod_idP,CC_idP,rntiP,UE_id); payload_ptr = parse_ulsch_header(sduP,&num_ce,&num_sdu,rx_ces,rx_lcids,rx_lengths,sdu_lenP); // control element @@ -107,7 +107,8 @@ void rx_sdu( case POWER_HEADROOM: if (UE_id != -1) { UE_list->UE_template[CC_idP][UE_id].phr_info = (payload_ptr[0] & 0x3f) - PHR_MAPPING_OFFSET; - LOG_D(MAC, "[eNB] MAC CE_LCID %d : Received PHR PH = %d (db)\n", rx_ces[i], UE_list->UE_template[CC_idP][UE_id].phr_info); + LOG_D(MAC, "[eNB %d] CC_id %d MAC CE_LCID %d : Received PHR PH = %d (db)\n", + enb_mod_idP, CC_idP, rx_ces[i], UE_list->UE_template[CC_idP][UE_id].phr_info); UE_list->UE_template[CC_idP][UE_id].phr_info_configured=1; } @@ -115,7 +116,8 @@ void rx_sdu( break; case CRNTI: - LOG_D(MAC, "[eNB] MAC CE_LCID %d : Received CRNTI %d \n", rx_ces[i], payload_ptr[0]); + LOG_D(MAC, "[eNB %d] CC_id %d MAC CE_LCID %d : Received CRNTI %d \n", + enb_mod_idP, CC_idP, rx_ces[i], payload_ptr[0]); payload_ptr+=1; break; @@ -124,8 +126,8 @@ void rx_sdu( if (UE_id != -1) { uint8_t lcgid; lcgid = (payload_ptr[0] >> 6); - LOG_D(MAC, "[eNB] MAC CE_LCID %d : Received short BSR LCGID = %u bsr = %d\n", - rx_ces[i], lcgid, payload_ptr[0] & 0x3f); + LOG_D(MAC, "[eNB %d] CC_id %d MAC CE_LCID %d : Received short BSR LCGID = %u bsr = %d\n", + enb_mod_idP, CC_idP, rx_ces[i], lcgid, payload_ptr[0] & 0x3f); UE_list->UE_template[CC_idP][UE_id].bsr_info[lcgid] = (payload_ptr[0] & 0x3f); if (UE_list->UE_template[CC_idP][UE_id].ul_buffer_creation_time[lcgid] == 0 ) { @@ -145,8 +147,9 @@ void rx_sdu( UE_list->UE_template[CC_idP][UE_id].bsr_info[LCGID2] = ((payload_ptr[1] & 0x0F) << 2) | ((payload_ptr[2] & 0xC0) >> 6); UE_list->UE_template[CC_idP][UE_id].bsr_info[LCGID3] = (payload_ptr[2] & 0x3F); - LOG_D(MAC, "[eNB] MAC CE_LCID %d: Received long BSR LCGID0 = %u LCGID1 = " + LOG_D(MAC, "[eNB %d] CC_id %d MAC CE_LCID %d: Received long BSR LCGID0 = %u LCGID1 = " "%u LCGID2 = %u LCGID3 = %u\n", + enb_mod_idP, CC_idP, rx_ces[i], UE_list->UE_template[CC_idP][UE_id].bsr_info[LCGID0], UE_list->UE_template[CC_idP][UE_id].bsr_info[LCGID1], @@ -183,7 +186,7 @@ void rx_sdu( break; default: - LOG_E(MAC, "[eNB] Received unknown MAC header (0x%02x)\n", rx_ces[i]); + LOG_E(MAC, "[eNB %d] CC_id %d Received unknown MAC header (0x%02x)\n", enb_mod_idP, CC_idP, rx_ces[i]); break; } } @@ -193,12 +196,13 @@ void rx_sdu( switch (rx_lcids[i]) { case CCCH : - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d, Received CCCH: %x.%x.%x.%x.%x.%x, Terminating RA procedure for UE rnti %x\n", - enb_mod_idP,frameP, + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d, Received CCCH: %x.%x.%x.%x.%x.%x, Terminating RA procedure for UE rnti %x\n", + enb_mod_idP,CC_idP,frameP, payload_ptr[0],payload_ptr[1],payload_ptr[2],payload_ptr[3],payload_ptr[4], payload_ptr[5], rntiP); for (ii=0; ii<NB_RA_PROC_MAX; ii++) { - LOG_D(MAC,"[RAPROC] Checking proc %d : rnti (%x, %x), active %d\n",ii, + LOG_D(MAC,"[eNB %d][RAPROC] CC_id %p Checking proc %d : rnti (%x, %x), active %d\n", + enb_mod_idP, CC_idP, ii, eNB->common_channels[CC_idP].RA_template[ii].rnti, rntiP, eNB->common_channels[CC_idP].RA_template[ii].RA_active); @@ -209,17 +213,17 @@ void rx_sdu( if (UE_id < 0) { memcpy(&eNB->common_channels[CC_idP].RA_template[ii].cont_res_id[0],payload_ptr,6); - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d CCCH: Received RRCConnectionRequest: length %d, offset %d\n", - enb_mod_idP,frameP,rx_lengths[ii],payload_ptr-sduP); + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d CCCH: Received RRCConnectionRequest: length %d, offset %d\n", + enb_mod_idP,CC_idP,frameP,rx_lengths[ii],payload_ptr-sduP); if ((UE_id=add_new_ue(enb_mod_idP,CC_idP,eNB->common_channels[CC_idP].RA_template[ii].rnti,harq_pidP)) == -1 ) { mac_xface->macphy_exit("[MAC][eNB] Max user count reached\n"); } else - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d Added user with rnti %x => UE %d\n", - enb_mod_idP,frameP,eNB->common_channels[CC_idP].RA_template[ii].rnti,UE_id); + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d Added user with rnti %x => UE %d\n", + enb_mod_idP,CC_idP,frameP,eNB->common_channels[CC_idP].RA_template[ii].rnti,UE_id); } else { - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d CCCH: Received RRCConnectionReestablishment from UE %d: length %d, offset %d\n", - enb_mod_idP,frameP,UE_id,rx_lengths[ii],payload_ptr-sduP); + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d CCCH: Received RRCConnectionReestablishment from UE %d: length %d, offset %d\n", + enb_mod_idP,CC_idP,frameP,UE_id,rx_lengths[ii],payload_ptr-sduP); } if (Is_rrc_registered == 1) @@ -266,8 +270,8 @@ void rx_sdu( // This check is just to make sure we didn't get a bogus SDU length, to be removed ... if (rx_lengths[i]<CCCH_PAYLOAD_SIZE_MAX) { - LOG_D(MAC,"[eNB %d] Frame %d : ULSCH -> UL-DCCH, received %d bytes form UE %d on LCID %d \n", - enb_mod_idP,frameP, rx_lengths[i], UE_id, rx_lcids[i]); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d : ULSCH -> UL-DCCH, received %d bytes form UE %d on LCID %d \n", + enb_mod_idP,CC_idP,frameP, rx_lengths[i], UE_id, rx_lcids[i]); mac_rlc_data_ind( enb_mod_idP, @@ -302,8 +306,8 @@ void rx_sdu( LOG_T(MAC,"\n"); #endif - LOG_D(MAC,"[eNB %d] Frame %d : ULSCH -> UL-DTCH, received %d bytes from UE %d for lcid %d\n", - enb_mod_idP,frameP, rx_lengths[i], UE_id,rx_lcids[i]); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d : ULSCH -> UL-DTCH, received %d bytes from UE %d for lcid %d\n", + enb_mod_idP,CC_idP,frameP, rx_lengths[i], UE_id,rx_lcids[i]); if ((rx_lengths[i] <SCH_PAYLOAD_SIZE_MAX) && (rx_lengths[i] > 0) ) { // MAX SIZE OF transport block mac_rlc_data_ind( @@ -327,7 +331,8 @@ void rx_sdu( default : //if (rx_lcids[i] >= DTCH) { UE_list->eNB_UE_stats[CC_idP][UE_id].num_errors_rx+=1; - LOG_E(MAC,"[eNB %d] Frame %d : received unsupported or unknown LCID %d from UE %d ", enb_mod_idP, frameP, rx_lcids[i], UE_id); + LOG_E(MAC,"[eNB %d] CC_id %d Frame %d : received unsupported or unknown LCID %d from UE %d ", + enb_mod_idP, CC_idP, frameP, rx_lcids[i], UE_id); break; } @@ -341,7 +346,7 @@ void rx_sdu( if (msg3_flagP != NULL) { if( *msg3_flagP == 1 ) { - LOG_N(MAC,"[eNB %d] frame %d : false msg3 detection: signal phy to canceling RA and remove the UE\n", enb_mod_idP, frameP); + LOG_N(MAC,"[eNB %d] CC_id %d frame %d : false msg3 detection: signal phy to canceling RA and remove the UE\n", enb_mod_idP, CC_idP, frameP); *msg3_flagP=0; } } @@ -672,7 +677,7 @@ void schedule_ulsch_rnti(module_id_t module_idP, rnti = UE_RNTI(module_idP,UE_id); if (rnti==NOT_A_RNTI) { - LOG_W(MAC,"[eNB %d] frame %d subfarme %d, UE %d CC %d: no RNTI \n", module_idP,frameP,subframeP,UE_id,CC_id); + LOG_W(MAC,"[eNB %d] frame %d subfarme %d, UE %d: no RNTI \n", module_idP,frameP,subframeP,UE_id); continue; } @@ -700,7 +705,7 @@ void schedule_ulsch_rnti(module_id_t module_idP, UE_template = &UE_list->UE_template[CC_id][UE_id]; if (mac_xface->get_ue_active_harq_pid(module_idP,CC_id,rnti,frameP,subframeP,&harq_pid,&round,1) == -1 ) { - LOG_W(MAC,"[eNB %d] Scheduler Frame %d, subframeP: candidate harq_pid from PHY for UE %d CC %d RNTI %x\n", + LOG_W(MAC,"[eNB %d] Scheduler Frame %d, subframeP %d: candidate harq_pid from PHY for UE %d CC %d RNTI %x\n", module_idP,frameP,subframeP, UE_id, CC_id, rnti); // NN --> RK: Don't schedule UE if we cannot get harq pid //should we continue or set harq_pid to 0? @@ -786,8 +791,8 @@ void schedule_ulsch_rnti(module_id_t module_idP, //store for possible retransmission UE_template->nb_rb_ul[harq_pid] = rb_table[rb_table_index]; - LOG_D(MAC,"[eNB %d][PUSCH %d/%x] Frame %d subframeP %d Scheduled UE %d (mcs %d, first rb %d, nb_rb %d, rb_table_index %d, TBS %d, harq_pid %d)\n", - module_idP,harq_pid,rnti,frameP,subframeP,UE_id,mcs, + LOG_D(MAC,"[eNB %d][PUSCH %d/%x] CC_id %d Frame %d subframeP %d Scheduled UE %d (mcs %d, first rb %d, nb_rb %d, rb_table_index %d, TBS %d, harq_pid %d)\n", + module_idP,harq_pid,rnti,CC_id,frameP,subframeP,UE_id,mcs, first_rb[CC_id],rb_table[rb_table_index], rb_table_index,TBS,harq_pid); // Adjust BSR entries for LCGIDs @@ -806,8 +811,8 @@ void schedule_ulsch_rnti(module_id_t module_idP, } - LOG_D(MAC,"[eNB %d][PUSCH %d/%x] Frame %d subframeP %d Scheduled UE retransmission (mcs %d, first rb %d, nb_rb %d, TBS %d, harq_pid %d, round %d)\n", - module_idP,UE_id,rnti,frameP,subframeP,mcs, + LOG_D(MAC,"[eNB %d][PUSCH %d/%x] CC_id %d Frame %d subframeP %d Scheduled UE retransmission (mcs %d, first rb %d, nb_rb %d, TBS %d, harq_pid %d, round %d)\n", + module_idP,UE_id,rnti,CC_id,frameP,subframeP,mcs, first_rb[CC_id],UE_template->nb_rb_ul[harq_pid], TBS,//mac_xface->get_TBS_UL(mcs,UE_template->nb_rb_ul[harq_pid]), harq_pid, round); @@ -1037,7 +1042,7 @@ void schedule_ulsch_rnti(module_id_t module_idP, nCCE[CC_id] = nCCE[CC_id] + (1<<aggregation); nCCE_available[CC_id] = mac_xface->get_nCCE_max(module_idP,CC_id) - nCCE[CC_id]; - LOG_D(MAC,"[eNB %d] Frame %d, subframeP %d: Generated ULSCH DCI for next UE_id %d, format 0\n", module_idP,frameP,subframeP,UE_id); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d, subframeP %d: Generated ULSCH DCI for next UE_id %d, format 0\n", module_idP,CC_id,frameP,subframeP,UE_id); #ifdef DEBUG dump_dci(frame_parms, &DCI_pdu->dci_alloc[DCI_pdu->Num_common_dci+DCI_pdu->Num_ue_spec_dci-1]); #endif @@ -1225,8 +1230,8 @@ void schedule_ulsch_cba_rnti(module_id_t module_idP, unsigned char cooperation_f for (cba_group=0; cba_group<total_groups; cba_group++) { LOG_N(MAC, - "[eNB %d] Frame %d, subframe %d: cba group %d active_ues %d total groups %d mcs %d, available/required rb (%d/%d), num resources %d, ncce (%d/%d required %d \n", - module_idP, frameP, subframeP, cba_group,active_UEs[cba_group],total_groups, + "[eNB %d] CC_id %d Frame %d, subframe %d: cba group %d active_ues %d total groups %d mcs %d, available/required rb (%d/%d), num resources %d, ncce (%d/%d required %d \n", + module_idP, CC_id, frameP, subframeP, cba_group,active_UEs[cba_group],total_groups, mcs[cba_group], available_rbs,required_rbs[cba_group], num_cba_resources[cba_group], nCCE[CC_id],nCCE_available[CC_id],(1<<aggregation) * num_cba_resources[cba_group]); @@ -1255,8 +1260,8 @@ void schedule_ulsch_cba_rnti(module_id_t module_idP, unsigned char cooperation_f first_rb[CC_id]+=rb_table[rb_table_index]; LOG_N(MAC, - "[eNB %d] Frame %d, subframeP %d: schedule CBA access %d rnti %x, total/required/allocated/remaining rbs (%d/%d/%d/%d), mcs %d, rballoc %d, nCCE (%d/%d)\n", - module_idP, frameP, subframeP, cba_group,eNB_mac_inst[module_idP].common_channels[CC_id].cba_rnti[cba_group], + "[eNB %d] CC_id %d Frame %d, subframeP %d: schedule CBA access %d rnti %x, total/required/allocated/remaining rbs (%d/%d/%d/%d), mcs %d, rballoc %d, nCCE (%d/%d)\n", + module_idP, CC_id, frameP, subframeP, cba_group,eNB_mac_inst[module_idP].common_channels[CC_id].cba_rnti[cba_group], available_rbs, required_rbs[cba_group], allocated_rbs, remaining_rbs, mcs[cba_group],rballoc,nCCE_available[CC_id],nCCE[CC_id]); @@ -1311,7 +1316,7 @@ void schedule_ulsch_cba_rnti(module_id_t module_idP, unsigned char cooperation_f 0); } - LOG_D(MAC,"[eNB %d] Frame %d, subframeP %d: Generated ULSCH DCI for CBA group %d, RB 25 format 0\n", module_idP,frameP,subframeP,cba_group); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d, subframeP %d: Generated ULSCH DCI for CBA group %d, RB 25 format 0\n", module_idP,CC_id,frameP,subframeP,cba_group); break; case 50: @@ -1360,7 +1365,7 @@ void schedule_ulsch_cba_rnti(module_id_t module_idP, unsigned char cooperation_f 0); } - LOG_D(MAC,"[eNB %d] Frame %d, subframeP %d: Generated ULSCH DCI for CBA group %d, RB 50 format 0\n", module_idP,frameP,subframeP,cba_group); + LOG_D(MAC,"[eNB %d] CC_id %d Frame %d, subframeP %d: Generated ULSCH DCI for CBA group %d, RB 50 format 0\n", module_idP,CC_id,frameP,subframeP,cba_group); break; case 100: diff --git a/openair2/LAYER2/MAC/main.c b/openair2/LAYER2/MAC/main.c index 1a549d14428..54c8f4ec99a 100644 --- a/openair2/LAYER2/MAC/main.c +++ b/openair2/LAYER2/MAC/main.c @@ -218,7 +218,7 @@ int mac_top_init(int eMBMS_active, char *uecap_xer, uint8_t cba_group_active, ui for (i=0; i<NB_eNB_INST; i++) for (CC_id=0; CC_id<MAX_NUM_CCs; CC_id++) { - LOG_D(MAC,"[MAIN][eNB %d] initializing RA_template\n",i); + LOG_D(MAC,"[MAIN][eNB %d] CC_id %d initializing RA_template\n",i, CC_id); LOG_D(MAC, "[MSC_NEW][FRAME 00000][MAC_eNB][MOD %02d][]\n", i); RA_template = (RA_TEMPLATE *)&eNB_mac_inst[i].common_channels[CC_id].RA_template[0]; diff --git a/openair2/LAYER2/MAC/rar_tools.c b/openair2/LAYER2/MAC/rar_tools.c index b8397845458..3b960c2cca2 100644 --- a/openair2/LAYER2/MAC/rar_tools.c +++ b/openair2/LAYER2/MAC/rar_tools.c @@ -115,7 +115,8 @@ unsigned short fill_rar( rar[2] |= ((mcs&0x8)>>3); // mcs 10 rar[3] = (((mcs&0x7)<<5)) | ((TPC&7)<<2) | ((ULdelay&1)<<1) | (cqireq&1); - LOG_I(MAC,"[eNB %d][RAPROC] Frame %d Generating RAR (%02x|%02x.%02x.%02x.%02x.%02x.%02x) for ra_idx %d, CRNTI %x,preamble %d/%d,TIMING OFFSET %d\n",module_idP, + LOG_I(MAC,"[eNB %d][RAPROC] CC_id %d Frame %d Generating RAR (%02x|%02x.%02x.%02x.%02x.%02x.%02x) for ra_idx %d, CRNTI %x,preamble %d/%d,TIMING OFFSET %d\n", + module_idP, CC_id, frameP, *(uint8_t*)rarh,rar[0],rar[1],rar[2],rar[3],rar[4],rar[5], ra_idx, @@ -127,8 +128,8 @@ unsigned short fill_rar( if (oai_emulation.info.opt_enabled) { trace_pdu(1, dlsch_buffer, input_buffer_length, module_idP, 2, 1, eNB_mac_inst[module_idP].subframe, 0, 0); - LOG_D(OPT,"[eNB %d][RAPROC] RAR Frame %d trace pdu for rnti %x and rapid %d size %d\n", - module_idP, frameP, eNB_mac_inst[module_idP].common_channels[CC_id].RA_template[ra_idx].rnti, + LOG_D(OPT,"[eNB %d][RAPROC] CC_id %d RAR Frame %d trace pdu for rnti %x and rapid %d size %d\n", + module_idP, CC_id, frameP, eNB_mac_inst[module_idP].common_channels[CC_id].RA_template[ra_idx].rnti, rarh->RAPID, input_buffer_length); } -- GitLab