UE not triggering new RA procedure
After gNB dropping the UE connection the UE doesn't trigger new RA. But when I try to stop the UE by pressing ctrl+C, I see the message saying SR counter reached sr_MaxTransmissions and it triggers the new RA before stopping. So there is an issue with update of the counter or somewhere.
UE logs:
[NR_PHY] [UE 0] RSRP = -37 dBm
[NR_PHY] [UE 0] RSRP = -40 dBm
[NR_PHY] [UE 0] RSRP = -37 dBm
[NR_PHY] [UE 0] RSRP = -40 dBm
[NR_PHY] [UE 0] RSRP = -38 dBm
[NR_PHY] ============================================
[NR_PHY] [UE 0] Harq round stats for Downlink: 147/2/0
[NR_PHY] ============================================
[NR_PHY] [UE 0] RSRP = -37 dBm
[NR_PHY] [UE 0] RSRP = -39 dBm
[NR_PHY] [UE 0] RSRP = -37 dBm
[NR_PHY] [UE 0] RSRP = -40 dBm
[NR_PHY] [UE 0] RSRP = -37 dBm
[NR_PHY] [UE 0] RSRP = -40 dBm
[NR_PHY] [UE 0] RSRP = -37 dBm
^CPress ^C again to trigger immediate shutdown
[NAS] [UE 0] Received NAS_DEREGISTRATION_REQ
mac 6f 1a 7 28
[NR_PHY] [UE 0] RSRP = -39 dBm
[NR_PHY] ============================================
[NR_PHY] [UE 0] Harq round stats for Downlink: 147/2/0
[NR_PHY] ============================================
[NR_PHY] [UE 0] RSRP = -38 dBm
[NR_PHY] [UE 0] RSRP = -37 dBm
[NR_PHY] [UE 0] RSRP = -39 dBm
[NR_MAC] [UE 0] SR not served! SR counter 64 reached sr_MaxTransmissions 64
[NR_MAC] Triggering new RA procedure for UE with RNTI 4174
[NR_MAC] Initialization of 4-step contention-based random access procedure
[NR_MAC] PRACH scheduler: Selected RO Frame 359, Slot 19, Symbol 0, Fdm 0
[PHY] PRACH [UE 0] in frame.slot 359.19, placing PRACH in position 1804, msg1 frequency start 0 (k1 0), preamble_offset 0, first_nonzero_root_idx 0
[NR_MAC] [UE 0][RAPROC][RA-RNTI 0005] Got BI RAR subPDU 267 ms
[NR_MAC] [UE 0][RAPROC][RA-RNTI 010b] Got RAPID RAR subPDU
[NR_MAC] [UE 0][RAPROC][360.7] Found RAR with the intended RAPID 3
[MAC] received TA command 31
[PHY] RAR-Msg2 decoded
[NR_MAC] [RAPROC][360.17] RA-Msg3 transmitted
[NR_PHY] ============================================
[NR_PHY] [UE 0] Harq round stats for Downlink: 148/2/0
[NR_PHY] ============================================
[NR_PHY] ============================================
[NR_PHY] [UE 0] Harq round stats for Downlink: 148/2/0
[NR_PHY] ============================================
[NR_PHY] ============================================
[NR_PHY] [UE 0] Harq round stats for Downlink: 148/2/0
[NR_PHY] ============================================
[NR_PHY] ============================================
[NR_PHY] [UE 0] Harq round stats for Downlink: 148/2/0
[NR_PHY] ============================================
[NR_PHY] ============================================
[NR_PHY] [UE 0] Harq round stats for Downlink: 148/2/0
[NR_PHY] ============================================
[NR_PHY] ============================================
[NR_PHY] [UE 0] Harq round stats for Downlink: 148/2/0
[NR_PHY] ============================================
[NR_PHY] ============================================
[NR_PHY] [UE 0] Harq round stats for Downlink: 148/2/0
[NR_PHY] ============================================
Returned from ITTI signal handler
oai_exit=1
[HW] releasing USRP
[HW] [recv] received 8163 samples out of 23040
D[HW] Time: 252.594 s
Fragmentation offset: 60364
ERROR_CODE_OVERFLOW (Out of sequence error)To reproduce
I see this when I run with USRPs and sometime the gNB machine has real-time issues which causes the UE to skip some PUSCH orders. When it happens the gNB drops the UE and the UE won't trigger RA till press ctrl+C. Maybe this can be reproduced with rfsimulator and changing the UL channel SNR via telnet?
Activity
assigned to @francescomani
@velumani Could you help me debug? Could you reproduce by enabling the following log?
LOG_D(NR_MAC, "[UE %d] Frame %d slot %d instruct the physical layer to signal the SR (counter/sr_TransMax %d/%d)\n", mac->ue_id, frame, slot, sr_info->counter, sr_info->maxTransmissions);-
If I test locally, the
sr_TransMaxcounter behaves as expected and the new RA is triggered when the limit is reached[NR_MAC] [UE 0] Frame 498 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 1/64) [NR_MAC] [UE 0] Frame 499 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 2/64) [NR_MAC] [UE 0] Frame 499 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 3/64) [NR_MAC] [UE 0] Frame 500 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 4/64) [NR_MAC] [UE 0] Frame 500 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 5/64) [NR_MAC] [UE 0] Frame 501 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 6/64) [NR_MAC] [UE 0] Frame 501 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 7/64) [NR_MAC] [UE 0] Frame 502 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 8/64) [NR_MAC] [UE 0] Frame 502 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 9/64) [NR_MAC] [UE 0] Frame 503 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 10/64) [NR_MAC] [UE 0] Frame 503 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 11/64) [NR_MAC] [UE 0] Frame 504 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 12/64) [NR_MAC] [UE 0] Frame 504 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 13/64) [NR_MAC] [UE 0] Frame 505 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 14/64) [NR_MAC] [UE 0] Frame 505 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 15/64) [NR_MAC] [UE 0] Frame 506 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 16/64) [NR_MAC] [UE 0] Frame 506 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 17/64) [NR_MAC] [UE 0] Frame 507 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 18/64) [NR_MAC] [UE 0] Frame 507 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 19/64) [NR_MAC] [UE 0] Frame 508 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 20/64) [NR_MAC] [UE 0] Frame 508 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 21/64) [NR_MAC] [UE 0] Frame 509 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 22/64) [NR_MAC] [UE 0] Frame 509 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 23/64) [NR_MAC] [UE 0] Frame 510 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 24/64) [NR_MAC] [UE 0] Frame 510 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 25/64) [NR_MAC] [UE 0] Frame 511 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 26/64) [NR_MAC] [UE 0] Frame 511 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 27/64) [NR_MAC] [UE 0] Frame 512 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 28/64) [NR_MAC] UE 0 stats sfn: 512.8, cumulated bad DCI 0 DL harq: 1/0 Ul harq: 1/0 avg code rate 0.2, avg bit/symbol 2.3, avg per TB: (nb RBs 8.0, nb symbols 3.0) [NR_MAC] [UE 0] Frame 512 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 29/64) [NR_MAC] [UE 0] Frame 513 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 30/64) [NR_MAC] [UE 0] Frame 513 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 31/64) [NR_MAC] [UE 0] Frame 514 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 32/64) [NR_MAC] [UE 0] Frame 514 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 33/64) [NR_MAC] [UE 0] Frame 515 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 34/64) [NR_MAC] [UE 0] Frame 515 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 35/64) [NR_MAC] [UE 0] Frame 516 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 36/64) [NR_MAC] [UE 0] Frame 516 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 37/64) [NR_MAC] [UE 0] Frame 517 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 38/64) [NR_MAC] [UE 0] Frame 517 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 39/64) [NR_MAC] [UE 0] Frame 518 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 40/64) [NR_MAC] [UE 0] Frame 518 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 41/64) [NR_MAC] [UE 0] Frame 519 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 42/64) [NR_MAC] [UE 0] Frame 519 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 43/64) [NR_MAC] [UE 0] Frame 520 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 44/64) [NR_MAC] [UE 0] Frame 520 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 45/64) [NR_MAC] [UE 0] Frame 521 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 46/64) [NR_MAC] [UE 0] Frame 521 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 47/64) [NR_MAC] [UE 0] Frame 522 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 48/64) [NR_MAC] [UE 0] Frame 522 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 49/64) [NR_MAC] [UE 0] Frame 523 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 50/64) [NR_MAC] [UE 0] Frame 523 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 51/64) [NR_MAC] [UE 0] Frame 524 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 52/64) [NR_MAC] [UE 0] Frame 524 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 53/64) [NR_MAC] [UE 0] Frame 525 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 54/64) [NR_MAC] [UE 0] Frame 525 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 55/64) [NR_MAC] [UE 0] Frame 526 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 56/64) [NR_MAC] [UE 0] Frame 526 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 57/64) [NR_MAC] [UE 0] Frame 527 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 58/64) [NR_MAC] [UE 0] Frame 527 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 59/64) [NR_MAC] [UE 0] Frame 528 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 60/64) [NR_MAC] [UE 0] Frame 528 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 61/64) [NR_MAC] [UE 0] Frame 529 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 62/64) [NR_MAC] [UE 0] Frame 529 slot 17 instruct the physical layer to signal the SR (counter/sr_TransMax 63/64) [NR_MAC] [UE 0] Frame 530 slot 7 instruct the physical layer to signal the SR (counter/sr_TransMax 64/64) [NR_MAC] [UE 0] SR not served! SR counter 64 reached sr_MaxTransmissions 64 [NR_MAC] Triggering new RA procedure for UE with RNTI 47aa [MAC] Initialization of 4-Step CBRA procedure [NR_MAC] PRACH scheduler: Selected RO Frame 531, Slot 19, Symbol 0, Fdm 0 [PHY] PRACH [UE 0] in frame.slot 531.19, placing PRACH in position 2828, Msg1/MsgA-Preamble frequency start 0 (k1 0), preamble_offset 0, first_nonzero_root_idx 0, preambleIndex = 2 [NR_MAC] [UE 0][RAPROC][RA-RNTI 0005] Got BI RAR subPDU 267 ms [NR_MAC] [UE 0][RAPROC][RA-RNTI 010b] Got RAPID RAR subPDU [NR_MAC] [UE 0][RAPROC][532.7] Found RAR with the intended RAPID 2 [PHY] RAR-Msg2 decoded [NR_MAC] [RAPROC][532.17] RA-Msg3 transmitted [MAC] [UE 0][533.10][RAPROC] 4-Step RA procedure succeeded. CBRA: Contention Resolution is successful.On the gNB side, the procedure with MAC CE with C-RNTI is correctly run
[NR_PHY] [RAPROC] 531.19 Initiating RA procedure with preamble 2, energy 54.9 dB (I0 0, thres 200), delay 0 start symbol 0 freq index 0 [NR_MAC] 531.19 UE RA-RNTI 010b TC-RNTI 2622: Activating RA process index 0 [NR_MAC] UE 2622: Msg3 scheduled at 532.17 (532.7 TDA 3) [NR_MAC] UE 2622: 532.7 Generating RA-Msg2 DCI, RA RNTI 0x10b, state 1, CoreSetType 0, preamble_index(RAPID) 2, timing_offset = 0 (estimated distance 0.0 [m]) [NR_MAC] 532.7 Send RAR to RA-RNTI 010b [NR_MAC] Adding new UE context with RNTI 0x2622 [NR_MAC] 532.17 PUSCH with TC_RNTI 0x2622 received correctly [NR_MAC] Received UL_SCH_LCID_C_RNTI with C-RNTI 0x47aa, triggering RRC Reconfiguration [NR_MAC] Activating scheduling Msg4 for TC_RNTI 0x47aa (state WAIT_Msg3)So to me there is no issue or at least none that I can reproduce. @velumani unless you have any objection, I would close this issue.
I think I know what might happen : if the gnb does not handle msg3 with c-rnti,the UE will never try to do RA again.
The easiest is to
- Start with F1 (CU/DU), connect UE
- Stop CU (keep DU running)
- Start CU, DU reset UE states (because 38.473 says after F1 setup, all UE contexts should be reinitialized, that's the easiest)
- UE does RA and msg 3 with c rnti, which is dropped by the DU
- UE does not do RA again
Edited by Robert Schmidt-
That scenario should be solved by !3150 (merged) where the failure would trigger backoff timer and then a new RA at the UE (and eventually radio link failure if preambleTransMax is reached).
mentioned in merge request !3150 (merged)
mentioned in issue #910 (closed)
#910 (closed) Can reproduce this intermittently.
-
Can you try !3150 (merged)? It should be fixed. At least the one reported by @schmidtr above which is gNB not receiving MSG3 with C-RNTI.
-
If it is the first MSG3 (the one with Setup Request) then it is a different issue. If I try to run the scenario in #910 (closed) it doesn't hang for me but I get RAR preamble not matching in MSG2 reception.
[PHY] PRACH [UE 0] in frame.slot 743.4, placing PRACH in position 1428, Msg1/MsgA-Preamble frequency start 0 (k1 0), preamble_offset 7, first_nonzero_root_idx 0, preambleIndex = 36 [NR_MAC] [UE 0][RAPROC][RA-RNTI 0005] Got BI RAR subPDU 57 ms [NR_MAC] [UE 0][RAPROC][RA-RNTI 0039] Got RAPID RAR subPDU [NR_MAC] [UE 0][RAPROC][744.2] Received RAR preamble (35) doesn't match the intended RAPID (36) [PHY] RAR-Msg2 decoded [MAC] [UE 0][746:5] RAR reception failed
marked this issue as related to #910 (closed)
mentioned in issue #919 (closed)
mentioned in commit fe52ef28
closed with merge request !3309 (merged)
mentioned in commit 82fb9fcc
Please register or sign in to reply