osmocom
/
libosmo-gprs
mirror of https://gerrit.osmocom.org/libosmo-gprs
11
0
Fork 0
Code Releases Wiki Activity

rlcmac: Implement T3182 

Related: OS#550
Change-Id: I4fe9523af1b53c826ccfdd8700bab2a9e1413662
This commit is contained in:
Pau Espin 2023-02-21 19:36:34 +01:00
parent 6f87373fc0
commit 294b886be6
5 changed files with 161 additions and 1 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
src/rlcmac/rlcmac.c
View File

@ -48,6 +48,7 @@ static struct osmo_tdef T_defs_rlcmac[] = {
{ .T=3166, .default_val=5, .unit = OSMO_TDEF_S, .desc="Wait for Packet Uplink ACK/NACK after sending of first data block (s)" },
/* T3168: dynamically updated with what's received in BCCH SI13 */
{ .T=3168, .default_val=5000, .unit = OSMO_TDEF_MS, .desc="Wait for PACKET UPLINK ASSIGNMENT (updated by BCCH SI13) (ms)" },
{ .T=3182, .default_val=5, .unit = OSMO_TDEF_S, .desc="Wait for Acknowledgement (s)" },
{ 0 } /* empty item at the end */
};

34
src/rlcmac/tbf_ul_fsm.c
View File

@ -91,6 +91,27 @@ static void reinit_pkt_acces_procedure(struct gprs_rlcmac_tbf_ul_fsm_ctx *ctx)
gprs_rlcmac_ul_tbf_free(ctx->ul_tbf);
}
/* 9.3.3.3.2: Upon each retransmission of the last block with CV=0, the mobile station shall restart timer T3182 for the TBF.
* Slight impl deviation from spec: If tbf is still in contention resolution, keep using T3166, otherwise start T3182
*/
static void arm_T3182_if_needed(struct gprs_rlcmac_tbf_ul_fsm_ctx *ctx)
{
struct osmo_fsm_inst *fi = ctx->fi;
unsigned long val_sec;
if (gprs_rlcmac_ul_tbf_in_contention_resolution(ctx->ul_tbf)) {
OSMO_ASSERT(fi->T == 3166);
OSMO_ASSERT(osmo_timer_pending(&fi->timer));
} else {
OSMO_ASSERT(!osmo_timer_pending(&fi->timer) ||
(osmo_timer_pending(&fi->timer) && fi->T == 3182));
LOGPFSML(ctx->fi, LOGL_INFO, "Last UL block sent (CV=0), start T3182\n");
fi->T = 3182;
val_sec = osmo_tdef_get(g_ctx->T_defs, fi->T, OSMO_TDEF_S, -1);
osmo_timer_schedule(&fi->timer, val_sec, 0);
}
}
/* This one is triggered when packet access procedure fails, which can happen
* either in WAIT_IMM_ASS (ImmAss timeout), FLOW (T3164) or FINISHED (T3164, T3166) */
static void st_new_on_enter(struct osmo_fsm_inst *fi, uint32_t prev_state)
@ -164,6 +185,7 @@ static void st_flow(struct osmo_fsm_inst *fi, uint32_t event, void *data)
* sent last data (FSM would be in FINISHED state then) */
break;
case GPRS_RLCMAC_TBF_UL_EV_LAST_UL_DATA_SENT:
arm_T3182_if_needed(ctx);
tbf_ul_fsm_state_chg(fi, GPRS_RLCMAC_TBF_UL_ST_FINISHED);
break;
default:
@ -187,6 +209,14 @@ static void st_finished(struct osmo_fsm_inst *fi, uint32_t event, void *data)
OSMO_ASSERT(fi->T == 3166);
osmo_timer_del(&fi->timer);
fi->T = 0;
} else if (fi->T == 3182 && osmo_timer_pending(&fi->timer)) {
/* 9.3.3.3.2 "Upon reception of a PACKET UPLINK ACK/NACK message for this TBF
* the mobile station shall stop timer T3182 for the TBF".
* In our case we only use T3128 once we are out of contention resolution (T3166)
*/
LOGPFSML(ctx->fi, LOGL_DEBUG, "Rx Pkt UL ACK/NACK, stop T3182\n");
osmo_timer_del(&fi->timer);
fi->T = 0;
}
if (ctx_ul_ack_nack->final_ack) {
LOGPFSML(ctx->fi, LOGL_DEBUG, "Final ACK received\n");
@ -201,6 +231,7 @@ static void st_finished(struct osmo_fsm_inst *fi, uint32_t event, void *data)
*/
ctx->last_data_block_retrans_attempts++;
LOGPFSML(ctx->fi, LOGL_INFO, "Data block with CV=0 retransmit attempts=%u\n", ctx->last_data_block_retrans_attempts);
arm_T3182_if_needed(ctx);
if (ctx->last_data_block_retrans_attempts == 4) {
LOGPFSML(ctx->fi, LOGL_NOTICE, "TBF establishment failure (Data block with CV=0 retransmit attempts=%u)\n",
ctx->last_data_block_retrans_attempts);
@ -306,6 +337,9 @@ static int tbf_ul_fsm_timer_cb(struct osmo_fsm_inst *fi)
}
reinit_pkt_acces_procedure(ctx);
break;
case 3182:
gprs_rlcmac_ul_tbf_free(ctx->ul_tbf);
break;
default:
OSMO_ASSERT(0);
}

56
tests/rlcmac/rlcmac_prim_test.c
View File

@ -709,6 +709,61 @@ static void test_ul_tbf_n3104_timeout(void)
cleanup_test();
}
static void test_ul_tbf_t3182_timeout(void)
{
struct osmo_gprs_rlcmac_prim *rlcmac_prim;
int rc;
printf("=== %s start ===\n", __func__);
prepare_test();
uint32_t tlli = 0x2342;
uint8_t ul_tfi = 0;
uint8_t ts_nr = 7;
uint8_t usf = 0;
uint32_t rts_fn = 4;
RlcMacDownlink_t dl_block;
Ack_Nack_Description_t *ack_desc = &dl_block.u.Packet_Uplink_Ack_Nack.u.PU_AckNack_GPRS_Struct.Ack_Nack_Description;
/* Submit 14 bytes to fit in 1 RLCMAC block to shorten test and end up in FINISHED state quickly: */
rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_grr_unitdata_req(tlli, pdu_llc_gmm_att_req,
sizeof(pdu_llc_gmm_att_req));
rlcmac_prim->grr.unitdata_req.sapi = OSMO_GPRS_RLCMAC_LLC_SAPI_GMM;
rc = osmo_gprs_rlcmac_prim_upper_down(rlcmac_prim);
ccch_imm_ass_pkt_ul_tbf_normal[7] = last_rach_req_ra; /* Update RA to match */
rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_l1ctl_ccch_data_ind(0, ccch_imm_ass_pkt_ul_tbf_normal);
rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
OSMO_ASSERT(rc == 0);
/* Trigger transmission of LLC data (GMM Attach) (first part) */
rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_l1ctl_pdch_rts_ind(ts_nr, rts_fn, usf);
rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
OSMO_ASSERT(rc == 0);
/* PCU acks it: */
ul_ack_nack_init(&dl_block, ul_tfi, GPRS_RLCMAC_CS_2);
ack_desc->STARTING_SEQUENCE_NUMBER = 1;
ack_desc->FINAL_ACK_INDICATION = 0;
ul_ack_nack_mark(ack_desc, 0, true);
rlcmac_prim = create_dl_ctrl_block(&dl_block, ts_nr, rts_fn);
rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
OSMO_ASSERT(rc == 0);
/* Trigger transmission of LLC data (GMM Attach) (second part, CV=0) */
rts_fn = fn_next_block(rts_fn);
rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_l1ctl_pdch_rts_ind(ts_nr, rts_fn, usf);
rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
OSMO_ASSERT(rc == 0);
/* increase time 5 seconds, timeout should trigger */
clock_override_add(5, 0);
clock_debug("Expect T3182 timeout");
osmo_select_main(0);
printf("=== %s end ===\n", __func__);
cleanup_test();
}
/* 9.3.3.3.2: The block with CV=0 shall not be retransmitted more than four times. */
static void test_ul_tbf_last_data_cv0_retrans_max(void)
{
@ -840,6 +895,7 @@ int main(int argc, char *argv[])
test_ul_tbf_t3164_timeout();
test_ul_tbf_t3166_timeout();
test_ul_tbf_n3104_timeout();
test_ul_tbf_t3182_timeout();
test_ul_tbf_last_data_cv0_retrans_max();
test_ul_tbf_request_another_ul_tbf();
test_dl_tbf_ccch_assign();

60
tests/rlcmac/rlcmac_prim_test.err
View File

@ -430,6 +430,62 @@ DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: Last UL block sent (CV=0), start T3182
DLGLOBAL INFO UL_TBF{FLOW}: state_chg to FINISHED
DLGLOBAL INFO UL_TBF{FINISHED}: Timeout of T3182
DLGLOBAL INFO UL_TBF_ASS{IDLE}: Deallocated
DLGLOBAL INFO UL_TBF{FINISHED}: Deallocated
DLGLOBAL INFO Rx from upper layers: GRR-UNITDATA.request
DLGLOBAL INFO TLLI=0x00002342 not found, creating entity on the fly
DLGLOBAL INFO UL_TBF{NEW}: Allocated
DLGLOBAL INFO UL_TBF_ASS{IDLE}: Allocated
DLGLOBAL INFO UL_TBF_ASS{IDLE}: Received Event START
DLGLOBAL INFO UL_TBF{NEW}: Received Event UL_ASS_START
DLGLOBAL INFO UL_TBF{NEW}: state_chg to ASSIGN
DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x7b
DLGLOBAL INFO UL_TBF_ASS{IDLE}: state_chg to WAIT_CCCH_IMM_ASS
DLGLOBAL INFO Rx from lower layers: L1CTL-CCCH_DATA.indication
DLGLOBAL INFO UL_TBF_ASS{WAIT_CCCH_IMM_ASS}: Received Event RX_CCCH_IMM_ASS
DLGLOBAL INFO UL_TBF_ASS{WAIT_CCCH_IMM_ASS}: ImmAss initial CS=CS-2
DLGLOBAL INFO UL_TBF_ASS{WAIT_CCCH_IMM_ASS}: ImmAss DynamicAlloc (1phase access) ts_nr=7 usf=0
DLGLOBAL INFO UL_TBF_ASS{WAIT_CCCH_IMM_ASS}: state_chg to COMPLETED
DLGLOBAL INFO UL_TBF{ASSIGN}: Received Event UL_ASS_COMPL
DLGLOBAL INFO UL_TBF{ASSIGN}: Send L1CTL-CF_UL_TBF.req ul_slotmask=0x80
DLGLOBAL INFO UL_TBF{ASSIGN}: state_chg to FLOW
DLGLOBAL INFO UL_TBF_ASS{COMPLETED}: state_chg to IDLE
DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 0, CS=CS-2
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Dequeue next LLC (len=33)
DLGLOBAL DEBUG -- Chunk with length 33 larger than space (26) left in block: copy only remaining space, and we are done
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 0, CS-2): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 00 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent (1 phase access), start T3166
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (1)
DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_DATA.indication
DLGLOBAL INFO TS=7 FN=4 Rx Pkt UL ACK/NACK
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Got GPRS UL ACK bitmap: SSN: 1, BSN 0 to 1 - 1 (1 blocks), "R"
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) ack: (BSN=0)"R"(BSN=0) R=ACK I=NACK
DLGLOBAL DEBUG - got ack for BSN=0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) V(B): (V(A)=1)""(V(S)-1=0) A=Acked N=Nacked U=Unacked X=Resend-Unacked I=Invalid
DLGLOBAL INFO UL_TBF{FLOW}: Received Event RX_UL_ACK_NACK
DLGLOBAL INFO UL_TBF{FLOW}: Contention resolution succeeded, stop T3166
DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 1, CS=CS-2
DLGLOBAL DEBUG -- Chunk with length 7 is less than remaining space (30): add length header to delimit LLC frame
DLGLOBAL DEBUG -- Final block, so we done.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Complete UL frame, len=0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 1, CS-2): 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: Last UL block sent (CV=0), start T3182
DLGLOBAL INFO UL_TBF{FLOW}: state_chg to FINISHED
DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Restarting at BSN 1, because all blocks have been transmitted.
@ -440,6 +496,7 @@ DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=1
DLGLOBAL INFO UL_TBF{FINISHED}: Last UL block sent (CV=0), start T3182
DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Restarting at BSN 1, because all blocks have been transmitted.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
@ -449,6 +506,7 @@ DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=2
DLGLOBAL INFO UL_TBF{FINISHED}: Last UL block sent (CV=0), start T3182
DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Restarting at BSN 1, because all blocks have been transmitted.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
@ -458,6 +516,7 @@ DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=3
DLGLOBAL INFO UL_TBF{FINISHED}: Last UL block sent (CV=0), start T3182
DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Restarting at BSN 1, because all blocks have been transmitted.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
@ -467,6 +526,7 @@ DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=4
DLGLOBAL INFO UL_TBF{FINISHED}: Last UL block sent (CV=0), start T3182
DLGLOBAL NOTICE UL_TBF{FINISHED}: TBF establishment failure (Data block with CV=0 retransmit attempts=4)
DLGLOBAL INFO UL_TBF_ASS{IDLE}: Deallocated
DLGLOBAL INFO UL_TBF{FINISHED}: Deallocated

11
tests/rlcmac/rlcmac_prim_test.ok
View File

@ -80,12 +80,21 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-RACH.request ra=0x7b
test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=43 ts=7 data_len=34 data=[3c 00 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00 ]
test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
=== test_ul_tbf_n3104_timeout end ===
=== test_ul_tbf_last_data_cv0_retrans_max start ===
=== test_ul_tbf_t3182_timeout start ===
sys={0.000000}, mono={0.000000}: clock_override_set
test_rlcmac_prim_down_cb(): Rx L1CTL-RACH.request ra=0x7a
test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=4 ts=7 data_len=34 data=[3c 00 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00 ]
test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=8 ts=7 data_len=34 data=[00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00 ]
sys={5.000000}, mono={5.000000}: clock_override_add
sys={5.000000}, mono={5.000000}: Expect T3182 timeout
=== test_ul_tbf_t3182_timeout end ===
=== test_ul_tbf_last_data_cv0_retrans_max start ===
sys={0.000000}, mono={0.000000}: clock_override_set
test_rlcmac_prim_down_cb(): Rx L1CTL-RACH.request ra=0x7b
test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=4 ts=7 data_len=34 data=[3c 00 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00 ]
test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=8 ts=7 data_len=34 data=[00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00 ]
RTS 0: FN=13
test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=13 ts=7 data_len=34 data=[00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00 ]
RTS 1: FN=17