[srsran-users] RAR scheduling with mbsfn enabled release 2021_10

Wed Nov 17 16:35:00 UTC 2021

Hi

So after a little more digging I think I found the problem, It has to do 
with when the epc is started.

Even though the enb will keep trying to connect to the epc if it is not 
there initially then the call
to "stack->set_sched_dl_tti_mask(mch_table, nof_sfs)" will not be made, 
leaving all sf in play.

patch attached to provide logs below.

run with epc started first...

[jgiovatto at patty src]$ ./srsenb ./enb.conf.zmq_mbsfn | grep XXX 2<&1
XXX in phy_common configure_mbsfn
XXX in phy_common init
XXX in phy_common init mcch_configured
XXX MCH 
|0|1|1|1|0|0|1|1|1|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|
XXX set_dl_tti_mask : |0|1|1|1|0|0|1|1|1|0|
XXX MCCH |0|1|0|0|0|0|0|0|0|0|
XXX RAR dl_sched tti_tx_dl 0
XXX RAR dl_sched tti_tx_dl 4
XXX RAR dl_sched tti_tx_dl 5
XXX RAR dl_sched tti_tx_dl 9
XXX RAR dl_sched tti_tx_dl 0
XXX RAR dl_sched tti_tx_dl 4
XXX RAR dl_sched tti_tx_dl 5
XXX RAR dl_sched tti_tx_dl 9

run with epc started after enb...

[jgiovatto at patty src]$ ./srsenb ./enb.conf.zmq_mbsfn | grep XXX 2<&1
connect(): Connection refused
XXX in phy_common init
XXX in phy_common configure_mbsfn
XXX RAR dl_sched tti_tx_dl 0
XXX RAR dl_sched tti_tx_dl 1
XXX RAR dl_sched tti_tx_dl 2
XXX RAR dl_sched tti_tx_dl 3
XXX RAR dl_sched tti_tx_dl 4
XXX RAR dl_sched tti_tx_dl 5
XXX RAR dl_sched tti_tx_dl 6
XXX RAR dl_sched tti_tx_dl 7
XXX RAR dl_sched tti_tx_dl 8
XXX RAR dl_sched tti_tx_dl 9
XXX RAR dl_sched tti_tx_dl 0

Joe

On 11/15/21 13:17, Justin Tallon wrote:
> Hey Joe,
>
> Nice work on the investigation!
>
> Just to clarify, is this with the HEAD of the release or at the commit 
> I previously recommended.
>
> In any case, the subframe allocation works as follows:
>
> Subframes 1,2,3 6,7,8 are possible for mbms.
>
> The number provided is a bit mask for these subframes, so 63 is 111 
> 111 meaning all 6 possible subframes are scheduled for mbms.
>
> 33 would be 100001 so only 1 and 8 are scheduled for mbms.
>
> It's likley that the RAR is in subframes 2,3 6 or 7 and thats why 
> freeing them up fixed the issues, try using a prach config that would 
> result in the RAR landing on a non mbms subframe ie 0, 4, 5 or 9 and 
> try again with 63.
>
>
> Regards,
> Justin
>
>
>
>
>
> On Mon, 15 Nov 2021, 18:25 J Giovatto, <jgiovatto at adjacentlink.com> wrote:
>
>     Hi Folks,
>
>     In our emulation environment I have seen some issue where the ue's
>     can not connect. It is random but reproducible
>
>     only in our emulation environment and not using zmq, though all of
>     the config is essentially the same and in line with what is in the
>     release, with 1 excpetion is we use 1 phythread.
>
>     With the default sib mbsn subframe allocation default setting of
>     63, we will see illustrated below (log changes attached) where the
>     enb will schedule
>
>     what I believe is the RAR (rnti 0x2) on an mbsfn subframe.
>
>     Below is a 2 ue connect snapshot ...
>
>     17:00:30.392495 [MAC    ] [I] [  901] SCHED: Added user rnti=0x46
>
>     17:00:30.392501 [MAC    ] [I] [  901] SCHED: rnti=0x46, new lcid
>     configuration: [{lcid=0, mode=bi-dir, prio=1, lcg=0}]
>     17:00:30.392502 [MAC    ] [I] [  901] SCHED: Resetting rnti=0x46,
>     cc=0 HARQs and feedback state
>     17:00:30.392502 [MAC    ] [I] [  901] SCHED: rnti=0x46 PCell is
>     now enb_cc_idx=0
>     17:00:30.392549 [RRC    ] [I] Setting RLF timer for rnti=0x46 to
>     4000ms
>     17:00:30.392559 [RLC    ] [I] Added LTE radio bearer with LCID 0
>     in Transparent Mode
>     17:00:30.392562 [RRC    ] [I] Added new user rnti=0x46
>     17:00:30.392563 [MAC    ] [I] [  902] SCHED: New PRACH tti=901,
>     preamble=18, temp_crnti=0x46, ta_cmd=0, msg3_size=7
>     17:00:30.392563 [MAC    ] [I] [  902] RACH:  tti=901, cc=0,
>     preamble=18, offset=0, temp_crnti=0x46
>     17:00:30.392570 [MAC    ] [I] [  902] rach_tprof: {mean, max,
>     min}={343.2, 343, 343} usec, nof_samples=1
>     17:00:30.393051 [MAC    ] [I] [  903] SCHED: RAR, ra-rnti=2,
>     rbgs=[0, 1), dci=(2,0), msg3 grants=[{c-rnti=0x46, rba=103, mcs=0}]
>     17:00:30.393068 [PHY    ] [I] [  904] PDCCH:enb_dl_put_dl_pdcch_i:
>     cc=0, cellId 1, rnti 0x2, pdcch_seqnum 1338, type DL
>     17:00:30.393076 [PHY0   ] [I] [  903] PDCCH_DL: cc=0, f=1A, cce=
>     0, L=2, riv=100, pid=0, mcs={1}, ndi={0}, tpc_pucch=0, tti_tx_dl=907
>     17:00:30.393090 [PHY    ] [I] [  904] PDSCH:enb_dl_put_dl_pdsch_i:
>     cc=0, cellId 1, rnti 0x2, pdsch_seqnum 1338
>     17:00:30.393093 [PHY0   ] [I] [  903] PDSCH: cc=0, rnti=0x2,
>     nof_prb=3, nof_re=450, tbs={11}, mod={2}, rv={0}, tti_tx_dl=907
>     17:00:30.395050 [MAC    ] [I] [  905] SCHED: Msg3 tx rnti=0x46,
>     cc=0, pid=1, dci=(0,0), prb=[3, 6), n_rtx=0, cfi=1, tbs=7, bsr=0 (0-7)
>
>     ue-02/var/log/ue.log:17:00:30.392178 [PHY0   ] [W] [ 902]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.393170 [PHY0   ] [W] [ 903]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.396182 [PHY0   ] [W] [ 906]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.397505 [PHY0   ] [W] [ 907]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.398182 [PHY0   ] [W] [ 908]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.401166 [PHY0   ] [W] [ 911]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.402172 [PHY0   ] [W] [ 912]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.403175 [PHY0   ] [W] [ 913]
>     work_dl_mbsfn calling decode_pdcch_dl
>
>
>
>     17:00:30.411465 [MAC    ] [I] [  921] SCHED: Added user rnti=0x47
>     17:00:30.411471 [MAC    ] [I] [  921] SCHED: rnti=0x47, new lcid
>     configuration: [{lcid=0, mode=bi-dir, prio=1, lcg=0}]
>     17:00:30.411472 [MAC    ] [I] [  921] SCHED: Resetting rnti=0x47,
>     cc=0 HARQs and feedback state
>     17:00:30.411472 [MAC    ] [I] [  921] SCHED: rnti=0x47 PCell is
>     now enb_cc_idx=0
>     17:00:30.411496 [RRC    ] [I] Setting RLF timer for rnti=0x47 to
>     4000ms
>     17:00:30.411505 [RLC    ] [I] Added LTE radio bearer with LCID 0
>     in Transparent Mode
>     17:00:30.411508 [RRC    ] [I] Added new user rnti=0x47
>     17:00:30.411509 [MAC    ] [I] [  921] SCHED: New PRACH tti=921,
>     preamble=21, temp_crnti=0x47, ta_cmd=0, msg3_size=7
>     17:00:30.411509 [MAC    ] [I] [  921] RACH:  tti=921, cc=0,
>     preamble=21, offset=0, temp_crnti=0x47
>     17:00:30.411514 [MAC    ] [I] [  921] rach_tprof: {mean, max,
>     min}={282.2, 343, 221} usec, nof_samples=2
>     17:00:30.412053 [MAC    ] [I] [  922] SCHED: RAR, ra-rnti=2,
>     rbgs=[0, 1), dci=(2,0), msg3 grants=[{c-rnti=0x47, rba=103, mcs=0}]
>     17:00:30.412072 [PHY    ] [I] [  923] PDCCH:enb_dl_put_dl_pdcch_i:
>     cc=0, cellId 1, rnti 0x2, pdcch_seqnum 1341, type DL
>     17:00:30.412076 [PHY0   ] [I] [  922] PDCCH_DL: cc=0, f=1A, cce=
>     0, L=2, riv=100, pid=0, mcs={1}, ndi={0}, tpc_pucch=0,tti_tx_dl=926
>     17:00:30.412086 [PHY    ] [I] [  923] PDSCH:enb_dl_put_dl_pdsch_i:
>     cc=0, cellId 1, rnti 0x2, pdsch_seqnum 1340
>     17:00:30.412088 [PHY0   ] [I] [  922] PDSCH: cc=0, rnti=0x2,
>     nof_prb=3, nof_re=450, tbs={11}, mod={2}, rv={0}, tti_tx_dl=926
>     17:00:30.414046 [MAC    ] [I] [  924] SCHED: Msg3 tx rnti=0x47,
>     cc=0, pid=4, dci=(0,0), prb=[3, 6), n_rtx=0, cfi=1, tbs=7, bsr=0 (0-7)
>
>
>     ue-02/var/log/ue.log:17:00:30.408188 [PHY0   ] [W] [ 918]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.411181 [PHY0   ] [W] [ 921]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.412181 [PHY0   ] [W] [ 922]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.413166 [PHY0   ] [W] [ 923]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.416494 [PHY0   ] [W] [ 926]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.417181 [PHY0   ] [W] [ 927]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.418170 [PHY0   ] [W] [ 928]
>     work_dl_mbsfn calling decode_pdcch_dl
>     ue-02/var/log/ue.log:17:00:30.421175 [PHY0   ] [W] [ 931]
>     work_dl_mbsfn calling decode_pdcch_dl
>
>     If I change the subframe allocation to say (33) the problem goes
>     away as far as I can tell.
>
>     Can you guide to where the decision of the subframe is done and/or
>     provide some suggestions ?
>
>     Thanks
>
>     Joe
>
>     _______________________________________________
>     srsran-users mailing list
>     srsran-users at lists.srsran.com
>     https://lists.srsran.com/mailman/listinfo/srsran-users
>     <https://lists.srsran.com/mailman/listinfo/srsran-users>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.srsran.com/pipermail/srsran-users/attachments/20211117/a005ba9d/attachment-0001.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: msbfn_config_logs.patch
Type: text/x-patch
Size: 2999 bytes
Desc: not available
URL: <https://lists.srsran.com/pipermail/srsran-users/attachments/20211117/a005ba9d/attachment-0001.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature
Type: application/pgp-signature
Size: 840 bytes
Desc: OpenPGP digital signature
URL: <https://lists.srsran.com/pipermail/srsran-users/attachments/20211117/a005ba9d/attachment-0001.sig>