tests: rlcmac: Reproduce bug encoding 2 llc frames in 1 rlc block

Bug will be fixed in a follow-up patch.

Related: OS#6351
Change-Id: I2f654bcefd6a2f192b9742873b8cb70a63bbfbd1

3 files changed, 148 insertions, 0 deletions

diff --git a/tests/rlcmac/rlcmac_prim_test.c b/tests/rlcmac/rlcmac_prim_test.c
index bfc491f..0697abf 100644
--- a/tests/rlcmac/rlcmac_prim_test.c
+++ b/tests/rlcmac/rlcmac_prim_test.c
@@ -69,6 +69,19 @@ static uint8_t pdu_llc_gmm_att_req[] = {
 	0x11, 0xe5, 0x10, 0x00, 0xe2, 0x18, 0xf2
 };
 
+/* GMM Attach Compl */
+static uint8_t pdu_llc_gmm_att_compl[] = { 0x01, 0xc0, 0x0d, 0x08, 0x03, 0x55, 0x1c, 0xea };
+
+/* SM Activate PDP Context Request */
+static uint8_t pdu_llc_sm_act_pdp_ctx_req[] = {
+	0x01, 0xc0, 0x11, 0x8a, 0x41, 0x06, 0x03, 0x0e,
+	0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
+	0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x02, 0x01,
+	0x21, 0x28, 0x09, 0x08, 0x69, 0x6e, 0x74, 0x65,
+	0x72, 0x6e, 0x65, 0x74, 0x9e, 0x49, 0x7a
+};
+
+
 /**
 GSM CCCH - Immediate Assignment
 	L2 Pseudo Length
@@ -1280,6 +1293,77 @@ static void test_ccch_pag_req1(void)
 	cleanup_test();
 }
 
+
+/* Validate 2 LLC frames (GMM Attach Compl + SM Act PDP Context Req) in the tx
+ * queue are transmitted in 1 UL TBF in CS4 (OS#6351): */
+static void test_ul_tbf_2_llc_blocks_in_1_cs4_rlc_block(void)
+{
+	struct osmo_gprs_rlcmac_prim *rlcmac_prim;
+	int rc;
+
+	printf("=== %s start ===\n", __func__);
+	prepare_test();
+	uint32_t tlli = 0x2342;
+	uint8_t ts_nr = 7;
+	uint8_t usf = 0;
+	uint32_t rts_fn = 4;
+	uint8_t bs_cv_max = 15;
+	struct msgb *llc_msg = msgb_alloc(200, "llc_msg");
+	uint8_t imm_ass[sizeof(ccch_imm_ass_pkt_ul_tbf_normal)];
+
+	/* Submit an SI13 with bs_cv_max: */
+	rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_l1ctl_ccch_data_ind(0, create_si13(bs_cv_max));
+	rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
+	OSMO_ASSERT(rc == 0);
+
+
+	/* Submit LLC bytes containing GMM ATTACH COMPL */
+	memcpy(msgb_put(llc_msg, sizeof(pdu_llc_gmm_att_compl)),
+			pdu_llc_gmm_att_compl,
+			sizeof(pdu_llc_gmm_att_compl));
+	rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_grr_unitdata_req(tlli, msgb_data(llc_msg), msgb_length(llc_msg));
+	rlcmac_prim->grr.unitdata_req.sapi = OSMO_GPRS_RLCMAC_LLC_SAPI_GMM;
+	rlcmac_prim->grr.unitdata_req.radio_prio = 1;
+	rc = osmo_gprs_rlcmac_prim_upper_down(rlcmac_prim);
+	OSMO_ASSERT(rc == 0);
+
+	/* Submit LLC bytes containing SM ACT PDP CTX REQ */
+	msgb_trim(llc_msg, 0);
+	memcpy(msgb_put(llc_msg, sizeof(pdu_llc_sm_act_pdp_ctx_req)),
+			pdu_llc_sm_act_pdp_ctx_req,
+			sizeof(pdu_llc_sm_act_pdp_ctx_req));
+	/* -4: The scenario where this was seen is actually reproduced by having
+	 * a DL TBF sending GMM Attach Accept, and MS requesting a UL TBF through
+	 * DL AKC/NACK and getting it assigned over PACCH. As a result, no
+	 * contention resolution is needed and the UL TBF block doesn't contain
+	 * TLLI. Since it's far easy writing here a test by directlly allocating
+	 * the UL TBF, we simply account for the extra TLLI added in the RLC block
+	 * by discounting 4 bytes from the upper LLC layer payload to end up with
+	 * the same packet size as the one reproduced in the real case scenario.
+	 */
+	rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_grr_unitdata_req(tlli, msgb_data(llc_msg), msgb_length(llc_msg) - 4);
+	rlcmac_prim->grr.unitdata_req.sapi = OSMO_GPRS_RLCMAC_LLC_SAPI_GMM;
+	rlcmac_prim->grr.unitdata_req.radio_prio = 1;
+	rc = osmo_gprs_rlcmac_prim_upper_down(rlcmac_prim);
+	OSMO_ASSERT(rc == 0);
+
+	memcpy(imm_ass, ccch_imm_ass_pkt_ul_tbf_normal, sizeof(imm_ass));
+	imm_ass[7] = last_rach_req_ra; /* Update RA to match */
+	imm_ass[14] = 0x70; /* Set CS4 */
+	rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_l1ctl_ccch_data_ind(0, imm_ass);
+	rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
+	OSMO_ASSERT(rc == 0);
+
+	/* Trigger transmission of LLC data (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);
+
+	printf("=== %s end ===\n", __func__);
+	msgb_free(llc_msg);
+	cleanup_test();
+}
+
 static const struct log_info_cat test_log_categories[] = { };
 static const struct log_info test_log_info = {
 	.cat = test_log_categories,
@@ -1317,6 +1401,7 @@ int main(int argc, char *argv[])
 	test_dl_tbf_ccch_assign();
 	test_dl_tbf_ccch_assign_requests_ul_tbf_pacch();
 	test_ccch_pag_req1();
+	test_ul_tbf_2_llc_blocks_in_1_cs4_rlc_block();
 
 	talloc_free(tall_ctx);
 }
diff --git a/tests/rlcmac/rlcmac_prim_test.err b/tests/rlcmac/rlcmac_prim_test.err
index 554b6d0..1a1644e 100644
--- a/tests/rlcmac/rlcmac_prim_test.err
+++ b/tests/rlcmac/rlcmac_prim_test.err
@@ -1102,3 +1102,56 @@ DLGLOBAL INFO DL_TBF_ASS{IDLE}: Allocated
 DLGLOBAL DEBUG Rx from lower layers: L1CTL-CCCH_DATA.indication
 DLGLOBAL INFO Rx Paging Request Type 1
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: Deallocated
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-CCCH_DATA.indication
+DLGLOBAL DEBUG Rx SI13 from lower layers
+DLGLOBAL INFO Rx from upper layers: GRR-UNITDATA.request
+DLGLOBAL INFO TLLI=0x00002342 not found, creating entity on the fly
+DLGLOBAL INFO DL_TBF_ASS{IDLE}: Allocated
+DLGLOBAL DEBUG GRE(00002342) Enqueueing LLC-PDU len=8 SAPI=GMM radio_prio=1
+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}: Requesting one-phase packet access using CCCH
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-RACH.request
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: state_chg to WAIT_CCCH_IMM_ASS
+DLGLOBAL INFO Rx from upper layers: GRR-UNITDATA.request
+DLGLOBAL DEBUG GRE(00002342) Enqueueing LLC-PDU len=35 SAPI=GMM radio_prio=1
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-CCCH_DATA.indication
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
+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 TFI=0 initCS=CS-4 cur_tn=7 cur_fn=0 start_fn=0
+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 TBF(UL:NR-0:TLLI-00002342) Send L1CTL-CFG_UL_TBF.req ul_tbf_nr=0 ul_slotmask=0x80 tbf_starting_time(present=0 fn=0)
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-CFG_UL_TBF.request
+DLGLOBAL INFO UL_TBF{ASSIGN}: state_chg to FLOW
+DLGLOBAL INFO UL_TBF_ASS{COMPLETED}: state_chg to IDLE
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG Rx RTS.ind (fn=4, ts=7, usf=0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 0, CS=CS-4
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Entering Countdown procedure CV=0
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Dequeue next LLC (len=8)
+DLGLOBAL DEBUG -- Chunk with length 8 is less than remaining space (46): 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) Dequeue next LLC (len=35)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=0, CS-4, CV=0): 21 00 00 23 42 01 c0 0d 08 03 55 1c ea 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 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 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 CV=0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-4): 00 01 00 21 00 00 23 42 01 c0 0d 08 03 55 1c ea 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 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 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 INFO UL_TBF{FLOW}: Received Event LAST_UL_DATA_SENT
+DLGLOBAL INFO UL_TBF{FLOW}: state_chg to FINISHED
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (1)
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL INFO DL_TBF_ASS{IDLE}: Deallocated
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: Deallocated
+DLGLOBAL INFO UL_TBF{FINISHED}: Send L1CTL-CFG_UL_TBF.req ul_tbf_nr=0 (release)
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-CFG_UL_TBF.request
+DLGLOBAL INFO UL_TBF{FINISHED}: Deallocated
diff --git a/tests/rlcmac/rlcmac_prim_test.ok b/tests/rlcmac/rlcmac_prim_test.ok
index b9f18d2..1b0f626 100644
--- a/tests/rlcmac/rlcmac_prim_test.ok
+++ b/tests/rlcmac/rlcmac_prim_test.ok
@@ -229,3 +229,13 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=
 sys={0.000000}, mono={0.000000}: clock_override_set
 test_rlcmac_prim_up_cb(): Rx GMMRR-PAGE.indication TLLI=0x00000001
 === test_ccch_pag_req1 end ===
+=== test_ul_tbf_2_llc_blocks_in_1_cs4_rlc_block start ===
+sys={0.000000}, mono={0.000000}: clock_override_set
+test_rlcmac_prim_down_cb(): Rx L1CTL-RACH.request ra=0x78
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
+test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
+test_rlcmac_prim_up_cb(): Rx GMMRR-LLC_TRANSMITTED.indication TLLI=0x00002342
+test_rlcmac_prim_up_cb(): Rx GMMRR-LLC_TRANSMITTED.indication TLLI=0x00002342
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=4 ts=7 data_len=54 data=[00 01 00 21 00 00 23 42 01 c0 0d 08 03 55 1c ea 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00 ]
+=== test_ul_tbf_2_llc_blocks_in_1_cs4_rlc_block end ===
+test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x00