rlcmac: ul_tbf: Implement T3180

Related: OS#6209
Change-Id: I350b277532d36ed7928b33ee3b77d98d083a3179

6 files changed, 155 insertions, 3 deletions

diff --git a/include/osmocom/gprs/rlcmac/tbf_ul.h b/include/osmocom/gprs/rlcmac/tbf_ul.h
index 1abde9a..bb0231e 100644
--- a/include/osmocom/gprs/rlcmac/tbf_ul.h
+++ b/include/osmocom/gprs/rlcmac/tbf_ul.h
@@ -47,6 +47,8 @@ struct gprs_rlcmac_ul_tbf {
 		uint8_t cv;
 		struct gprs_rlcmac_llc_queue *llc_queue;
 	} countdown_proc;
+
+	struct osmo_timer_list t3180;
 };
 
 struct gprs_rlcmac_ul_tbf *gprs_rlcmac_ul_tbf_alloc(struct gprs_rlcmac_entity *gre);
@@ -66,7 +68,7 @@ bool gprs_rlcmac_ul_tbf_data_rts(const struct gprs_rlcmac_ul_tbf *ul_tbf, const
 bool gprs_rlcmac_ul_tbf_dummy_rts(const struct gprs_rlcmac_ul_tbf *ul_tbf, const struct gprs_rlcmac_rts_block_ind *bi);
 
 struct msgb *gprs_rlcmac_ul_tbf_data_create(struct gprs_rlcmac_ul_tbf *ul_tbf, const struct gprs_rlcmac_rts_block_ind *bi);
-struct msgb *gprs_rlcmac_ul_tbf_dummy_create(const struct gprs_rlcmac_ul_tbf *ul_tbf);
+struct msgb *gprs_rlcmac_ul_tbf_dummy_create(struct gprs_rlcmac_ul_tbf *ul_tbf);
 
 int gprs_rlcmac_ul_tbf_handle_pkt_ul_ack_nack(struct gprs_rlcmac_ul_tbf *ul_tbf,
 					      const RlcMacDownlink_t *dl_block);
diff --git a/src/rlcmac/rlcmac.c b/src/rlcmac/rlcmac.c
index 2c809ec..ac168c2 100644
--- a/src/rlcmac/rlcmac.c
+++ b/src/rlcmac/rlcmac.c
@@ -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=3180, .default_val=5,	.unit = OSMO_TDEF_S,	.desc="Wait for Uplink State Flag After Data Block (s)" },
 	{ .T=3182, .default_val=5,	.unit = OSMO_TDEF_S,	.desc="Wait for Acknowledgement (s)" },
 	{ .T=3190, .default_val=5,	.unit = OSMO_TDEF_S,	.desc="Wait for Valid Downlink Data Received from the Network (s)" },
 	{ .T=3192, .default_val=0,	.unit = OSMO_TDEF_MS,	.desc="Wait for release of the TBF after reception of the final block (ms)" },
diff --git a/src/rlcmac/tbf_ul.c b/src/rlcmac/tbf_ul.c
index d96891f..34268ee 100644
--- a/src/rlcmac/tbf_ul.c
+++ b/src/rlcmac/tbf_ul.c
@@ -29,6 +29,8 @@
 #include <osmocom/gprs/rlcmac/rlc_window_ul.h>
 #include <osmocom/gprs/rlcmac/rlc.h>
 
+static void gprs_rlcmac_ul_tbf_t3180_timer_cb(void *data);
+
 struct gprs_rlcmac_ul_tbf *gprs_rlcmac_ul_tbf_alloc(struct gprs_rlcmac_entity *gre)
 {
 	struct gprs_rlcmac_ul_tbf *ul_tbf;
@@ -57,6 +59,8 @@ struct gprs_rlcmac_ul_tbf *gprs_rlcmac_ul_tbf_alloc(struct gprs_rlcmac_entity *g
 	ul_tbf->blkst = gprs_rlcmac_rlc_block_store_alloc(ul_tbf);
 	OSMO_ASSERT(ul_tbf->blkst);
 
+	osmo_timer_setup(&ul_tbf->t3180, gprs_rlcmac_ul_tbf_t3180_timer_cb, ul_tbf);
+
 	return ul_tbf;
 
 err_state_fsm_destruct:
@@ -78,6 +82,8 @@ void gprs_rlcmac_ul_tbf_free(struct gprs_rlcmac_ul_tbf *ul_tbf)
 	tbf = ul_tbf_as_tbf(ul_tbf);
 	gre = tbf->gre;
 
+	osmo_timer_del(&ul_tbf->t3180);
+
 	if (ul_tbf->countdown_proc.llc_queue) {
 		gprs_rlcmac_llc_queue_merge_prepend(gre->llc_queue,
 						    ul_tbf->countdown_proc.llc_queue);
@@ -102,6 +108,22 @@ void gprs_rlcmac_ul_tbf_free(struct gprs_rlcmac_ul_tbf *ul_tbf)
 	gprs_rlcmac_entity_ul_tbf_freed(gre, ul_tbf);
 }
 
+static void gprs_rlcmac_ul_tbf_t3180_timer_cb(void *data)
+{
+	struct gprs_rlcmac_ul_tbf *ul_tbf = data;
+
+	LOGPTBFUL(ul_tbf, LOGL_NOTICE, "Timeout of T3180\n");
+
+	gprs_rlcmac_ul_tbf_free(ul_tbf);
+}
+
+static void gprs_rlcmac_ul_tbf_t3180_start(struct gprs_rlcmac_ul_tbf *ul_tbf)
+{
+	unsigned long val_sec;
+	val_sec = osmo_tdef_get(g_rlcmac_ctx->T_defs, 3180, OSMO_TDEF_S, -1);
+	osmo_timer_schedule(&ul_tbf->t3180, val_sec, 0);
+}
+
 int gprs_rlcmac_ul_tbf_submit_configure_req(const struct gprs_rlcmac_ul_tbf *ul_tbf,
 					    const struct gprs_rlcmac_ul_tbf_allocation *alloc,
 					    bool starting_time_present, uint32_t starting_time_fn)
@@ -344,7 +366,7 @@ int gprs_rlcmac_ul_tbf_handle_pkt_ul_ass(struct gprs_rlcmac_ul_tbf *ul_tbf,
 	return rc;
 }
 
-struct msgb *gprs_rlcmac_ul_tbf_dummy_create(const struct gprs_rlcmac_ul_tbf *ul_tbf)
+struct msgb *gprs_rlcmac_ul_tbf_dummy_create(struct gprs_rlcmac_ul_tbf *ul_tbf)
 {
 	struct msgb *msg;
 	struct bitvec bv;
@@ -371,6 +393,7 @@ struct msgb *gprs_rlcmac_ul_tbf_dummy_create(const struct gprs_rlcmac_ul_tbf *ul
 		goto free_ret;
 	}
 
+	gprs_rlcmac_ul_tbf_t3180_start(ul_tbf);
 	return msg;
 
 free_ret:
@@ -1183,6 +1206,7 @@ struct msgb *gprs_rlcmac_ul_tbf_data_create(struct gprs_rlcmac_ul_tbf *ul_tbf, c
 	int bsn;
 	int bsn2 = -1;
 	bool may_combine;
+	struct msgb *msg;
 
 	bsn = take_next_bsn(ul_tbf, bi, -1, &may_combine);
 	if (bsn < 0)
@@ -1191,5 +1215,9 @@ struct msgb *gprs_rlcmac_ul_tbf_data_create(struct gprs_rlcmac_ul_tbf *ul_tbf, c
 	if (may_combine)
 		bsn2 = take_next_bsn(ul_tbf, bi, bsn, &may_combine);
 
-	return create_ul_acked_block(ul_tbf, bi, bsn, bsn2);
+	msg = create_ul_acked_block(ul_tbf, bi, bsn, bsn2);
+	if (!msg)
+		return NULL;
+	gprs_rlcmac_ul_tbf_t3180_start(ul_tbf);
+	return msg;
 }
diff --git a/tests/rlcmac/rlcmac_prim_test.c b/tests/rlcmac/rlcmac_prim_test.c
index 5b27bd2..179888a 100644
--- a/tests/rlcmac/rlcmac_prim_test.c
+++ b/tests/rlcmac/rlcmac_prim_test.c
@@ -779,6 +779,49 @@ static void test_ul_tbf_t3166_timeout(void)
 	cleanup_test();
 }
 
+static void test_ul_tbf_t3180_timeout(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;
+
+	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;
+	rlcmac_prim->grr.unitdata_req.radio_prio = 1;
+	rc = osmo_gprs_rlcmac_prim_upper_down(rlcmac_prim);
+
+	OSMO_ASSERT(sizeof(ccch_imm_ass_pkt_ul_tbf_normal) == GSM_MACBLOCK_LEN);
+	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);
+
+	/* 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);
+
+	/* Transmit another block */
+	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, T3180 timeout should trigger */
+	clock_override_add(5, 0);
+	clock_debug("Expect T3180 timeout");
+	osmo_select_main(0);
+
+	printf("=== %s end ===\n", __func__);
+	cleanup_test();
+}
+
 static void test_ul_tbf_n3104_timeout(void)
 {
 	struct osmo_gprs_rlcmac_prim *rlcmac_prim;
@@ -1256,6 +1299,7 @@ int main(int argc, char *argv[])
 	test_ul_tbf_attach();
 	test_ul_tbf_t3164_timeout();
 	test_ul_tbf_t3166_timeout();
+	test_ul_tbf_t3180_timeout();
 	test_ul_tbf_n3104_timeout();
 	test_ul_tbf_t3182_timeout(true);
 #if 0
diff --git a/tests/rlcmac/rlcmac_prim_test.err b/tests/rlcmac/rlcmac_prim_test.err
index 5027ca8..c6c4ebc 100644
--- a/tests/rlcmac/rlcmac_prim_test.err
+++ b/tests/rlcmac/rlcmac_prim_test.err
@@ -386,6 +386,68 @@ DLGLOBAL INFO UL_TBF{FINISHED}: Deallocated
 DLGLOBAL INFO Tx L1CTL-PDCH_REL.req
 DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_RELEASE.request
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: Deallocated
+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=33 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 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-2 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-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, CV=15): 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 CV=15)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 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 DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG Rx RTS.ind (fn=8, ts=7, usf=0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 1, CS=CS-2
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Entering Countdown procedure CV=0
+DLGLOBAL DEBUG -- Chunk with length 7 is less than remaining space (26): 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, CV=0): 1d 00 00 23 42 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 
+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 CV=0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 01 02 1d 00 00 23 42 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 00 
+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 (2)
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL NOTICE TBF(UL:NR-0:TLLI-00002342) Timeout of T3180
+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
+DLGLOBAL INFO Tx L1CTL-PDCH_REL.req
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_RELEASE.request
+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
diff --git a/tests/rlcmac/rlcmac_prim_test.ok b/tests/rlcmac/rlcmac_prim_test.ok
index 571f918..70d0939 100644
--- a/tests/rlcmac/rlcmac_prim_test.ok
+++ b/tests/rlcmac/rlcmac_prim_test.ok
@@ -91,6 +91,21 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=
 sys={20.027690}, mono={20.027690}: clock_override_add
 sys={20.027690}, mono={20.027690}: Expect defer_pkt_idle_timer timeout
 test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_RELEASE.request
+=== test_ul_tbf_t3180_timeout 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_down_cb(): Rx L1CTL-PDCH_DATA.request fn=4 ts=7 data_len=34 data=[3c 01 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 01 02 1d 00 00 23 42 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 00 ]
+sys={5.000000}, mono={5.000000}: clock_override_add
+sys={5.000000}, mono={5.000000}: Expect T3180 timeout
+test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x00
+=== test_ul_tbf_t3180_timeout end ===
+sys={5.027690}, mono={5.027690}: clock_override_add
+sys={5.027690}, mono={5.027690}: Expect defer_pkt_idle_timer timeout
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_RELEASE.request
 === test_ul_tbf_n3104_timeout start ===
 sys={0.000000}, mono={0.000000}: clock_override_set
 test_rlcmac_prim_down_cb(): Rx L1CTL-RACH.request ra=0x78