Avoid losing DL-TBF during MS merge

It is desired to free pending DL-TBF under some scenarios, which somehow
are related to those where we call the ms_merge() procedure since it's at
time an MS can be identified when coming from packet-idle state.

Until now, the freeing of those DL-TBFs happen because the ms_merge()
procedure doesn't migrate DL-TBF from "old_ms" to "ms". This was done
manually under the cases where it was deemed necessary before calling
the ms_merge() procedure 8because old_ms and its tbfs are gone after
returning from it).
This logic, though convinient for the specific cases at hand, is quite
confusing for readers and program execution since one would expect the
ms merge to, well, merge everything.

Therefore, this patch changes the ms_merge() logic to always merge the
DL-TBF, and only under the specific cases where it makes sense to free
it, do so explicitly after MS merge, where all the info has been updated
and united.
2 code paths are now explicitly freeing the existing DL-TBF when needed:
- TBF_EV_FIRST_UL_DATA_RECVD: 1st data (containing TLLI) is
  received from MS, hence identifyng the MS and potentially having been
  merged with some old MS which used to have a DL-TBF, most probably in
  process of being assigned through CCCH (PCH). This event is triggered
  during MS using 1phase-access, and we should drop the exsitng DL-TBF
  because MS just came from packet-idle mode (CCCH).
- rcv_resource_request(): PktResourceRequest is received at an scheduled
  SBA, meaning the MS is doing 2phase-access, meaning MS also came from
  packet-idle mode (CCCH), so previous DL-TBF can be dropped.

Related: OS#5700
Change-Id: I29f4ffa904d79d58275c6596cc5ef6790b6e68c6

5 files changed, 81 insertions, 26 deletions

diff --git a/src/gprs_ms.c b/src/gprs_ms.c
index 10d761d0..f233967d 100644
--- a/src/gprs_ms.c
+++ b/src/gprs_ms.c
@@ -452,6 +452,14 @@ void ms_merge_and_clear_ms(struct GprsMs *ms, struct GprsMs *old_ms)
 
 	llc_queue_move_and_merge(&ms->llc_queue, &old_ms->llc_queue);
 
+	if (!ms_dl_tbf(ms) && ms_dl_tbf(old_ms)) {
+		struct gprs_rlcmac_dl_tbf *dl_tbf = ms_dl_tbf(old_ms);
+		LOGPTBFDL(dl_tbf, LOGL_NOTICE,
+			  "Merge MS: Move DL TBF: %s => %s\n",
+			  old_ms_name, ms_name(ms));
+		/* Move the DL TBF to the new MS */
+		tbf_set_ms(dl_tbf_as_tbf(dl_tbf), ms);
+	}
 
 	/* Clean up the old MS object */
 	/* TODO: Use timer? */
diff --git a/src/pdch.cpp b/src/pdch.cpp
index e979cf05..e9b9852c 100644
--- a/src/pdch.cpp
+++ b/src/pdch.cpp
@@ -657,6 +657,7 @@ void gprs_rlcmac_pdch::rcv_resource_request(Packet_Resource_Request_t *request,
 
 	if (request->ID.UnionType) {
 		struct gprs_rlcmac_ul_tbf *ul_tbf = NULL;
+		struct gprs_rlcmac_dl_tbf *dl_tbf = NULL;
 		uint32_t tlli = request->ID.u.TLLI;
 
 		GprsMs *ms = bts_ms_by_tlli(bts, tlli, GSM_RESERVED_TMSI);
@@ -693,8 +694,17 @@ void gprs_rlcmac_pdch::rcv_resource_request(Packet_Resource_Request_t *request,
 				tbf_free(ul_tbf);
 				ul_tbf = NULL;
 			}
-			/* MS seized the PDCH answering on the SBA: */
-			bts_do_rate_ctr_inc(bts, CTR_IMMEDIATE_ASSIGN_UL_TBF_CONTENTION_RESOLUTION_SUCCESS);
+			/* Similarly, it is for sure not using any DL-TBF. We
+			* still may have some because we were trying to assign a
+			* DL-TBF over CCCH when the MS proactively requested for a
+			* UL-TBF. In that case we'll need to re-assigna new DL-TBF through PACCH when contention resolution is done: */
+			if ((dl_tbf = ms_dl_tbf(ms))) {
+				/* Get rid of previous finished UL TBF before providing a new one */
+				LOGPTBFDL(dl_tbf, LOGL_NOTICE,
+					  "Got PACKET RESOURCE REQ while DL-TBF pending, killing it\n");
+				tbf_free(dl_tbf);
+				dl_tbf = NULL;
+			}
 			break;
 		case PDCH_ULC_NODE_TBF_POLL:
 			if (item->tbf_poll.poll_tbf->direction != GPRS_RLCMAC_UL_TBF) {
diff --git a/src/tbf_dl.cpp b/src/tbf_dl.cpp
index c63af58f..cc809da0 100644
--- a/src/tbf_dl.cpp
+++ b/src/tbf_dl.cpp
@@ -191,7 +191,6 @@ int dl_tbf_handle(struct gprs_rlcmac_bts *bts,
 		  const uint16_t delay_csec,
 		  const uint8_t *data, const uint16_t len)
 {
-	struct gprs_rlcmac_dl_tbf *dl_tbf = NULL;
 	int rc;
 	GprsMs *ms, *ms_old;
 
@@ -208,20 +207,8 @@ int dl_tbf_handle(struct gprs_rlcmac_bts *bts,
 			LOGP(DTBF, LOGL_NOTICE,
 			     "There is a new MS object for the same MS: (0x%08x, '%s') -> (0x%08x, '%s')\n",
 			     ms_tlli(ms_old), ms_imsi(ms_old), ms_tlli(ms), ms_imsi(ms));
-
-			ms_ref(ms_old);
-
-			if (!ms_dl_tbf(ms) && ms_dl_tbf(ms_old)) {
-				LOGP(DTBF, LOGL_NOTICE,
-				     "IMSI %s, old TBF %s: moving DL TBF to new MS object\n",
-				     imsi ? : "unknown", ms_dl_tbf(ms_old)->name());
-				dl_tbf = ms_dl_tbf(ms_old);
-				/* Move the DL TBF to the new MS */
-				dl_tbf->set_ms(ms);
-			}
 			ms_merge_and_clear_ms(ms, ms_old);
-
-			ms_unref(ms_old);
+			/* old_ms may no longer be available here */
 		}
 	}
 
diff --git a/src/tbf_fsm.c b/src/tbf_fsm.c
index b236d27b..9ddbd69f 100644
--- a/src/tbf_fsm.c
+++ b/src/tbf_fsm.c
@@ -208,6 +208,7 @@ static void st_flow(struct osmo_fsm_inst *fi, uint32_t event, void *data)
 {
 	struct tbf_fsm_ctx *ctx = (struct tbf_fsm_ctx *)fi->priv;
 	struct GprsMs *ms = tbf_ms(ctx->tbf);
+	struct gprs_rlcmac_dl_tbf *dl_tbf = NULL;
 
 	switch (event) {
 	case TBF_EV_FIRST_UL_DATA_RECVD:
@@ -217,6 +218,17 @@ static void st_flow(struct osmo_fsm_inst *fi, uint32_t event, void *data)
 		 * comprises the TLLI value that identifies the mobile station and the
 		 * TFI value associated with the TBF." */
 		bts_pch_timer_stop(ms->bts, ms);
+		/* We may still have some DL-TBF waiting for assignment in PCH,
+		 * which clearly won't happen since the MS is on PDCH now. Get rid
+		 * of it, it will be re-assigned on PACCH when contention
+		 * resolution at the MS side is done (1st UL ACK/NACK sent) */
+		if ((dl_tbf = ms_dl_tbf(ms))) {
+			/* Get rid of previous finished UL TBF before providing a new one */
+			LOGPTBFDL(dl_tbf, LOGL_NOTICE,
+					"Got first UL data while DL-TBF pending, killing it\n");
+			tbf_free(dl_tbf_as_tbf(dl_tbf));
+			dl_tbf = NULL;
+		}
 		break;
 	case TBF_EV_DL_ACKNACK_MISS:
 		OSMO_ASSERT(tbf_direction(ctx->tbf) == GPRS_RLCMAC_DL_TBF);
diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err
index 27ed39bf..1124462c 100644
--- a/tests/tbf/TbfTest.err
+++ b/tests/tbf/TbfTest.err
@@ -2314,10 +2314,10 @@ TBF(TFI=1 TLLI=0xf5667788 DIR=UL STATE=FLOW) Frame 1 starts at offset 0, length=
 TBF(TFI=1 TLLI=0xf5667788 DIR=UL STATE=FLOW) No gaps in received block, last block: BSN=0 CV=15
 Old MS: TLLI = 0xf1223344, TA = 7, IMSI = 0011223344, LLC = 0
 There is a new MS object for the same MS: (0xf1223344, '0011223344') -> (0xf5667788, '')
-IMSI 0011223344, old TBF TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED): moving DL TBF to new MS object
+MS(TLLI=0xf5667788, IMSI=, TA=7, 1/0, UL) Merge MS: MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL DL)
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED) Merge MS: Move DL TBF: MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL DL) => MS(TLLI=0xf5667788, IMSI=0011223344, TA=7, 1/0, UL)
 MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL) Detaching TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED)
-MS(TLLI=0xf5667788, IMSI=, TA=7, 1/0, UL) Attaching DL TBF: TBF(TFI=0 TLLI=0xf5667788 DIR=DL STATE=FINISHED)
-MS(TLLI=0xf5667788, IMSI=, TA=7, 1/0, UL DL) Merge MS: MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL)
+MS(TLLI=0xf5667788, IMSI=0011223344, TA=7, 1/0, UL) Attaching DL TBF: TBF(TFI=0 TLLI=0xf5667788 DIR=DL STATE=FINISHED)
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) free
 PDCH(bts=0,trx=0,ts=7) Detaching TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW), 2 TBFs, USFs = 03, TFIs = 00000003.
 MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Detaching TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW)
@@ -2454,8 +2454,16 @@ Detected FN jump! 2654275 -> 2654327 (expected 2654279)
 PDCH(bts=0,trx=0,ts=7) FN=2654327 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++
 PDCH(bts=0,trx=0,ts=7) FN=2654327 ------------------------- RX : Uplink Control Block -------------------------
 PDCH(bts=0,trx=0,ts=7) FN=2654327 PKT RESOURCE REQ: MS requests UL TBF throguh SBA
-MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, DL) ********** UL-TBF starts here **********
-MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, DL) Allocating UL TBF
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) Got PACKET RESOURCE REQ while DL-TBF pending, killing it
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) free
+PDCH(bts=0,trx=0,ts=7) Detaching TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN), 1 TBFs, USFs = 00, TFIs = 00000001.
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Detaching TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN)
+********** DL-TBF ends here **********
+TBF(DL-TFI_0){ASSIGN}: Deallocated
+UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
+DL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) ********** UL-TBF starts here **********
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Allocating UL TBF
 TBF{NEW}: Allocated
 UL_ASS_TBF{NONE}: Allocated
 DL_ASS_TBF{NONE}: Allocated
@@ -2472,7 +2480,7 @@ UL_ACK_TBF{NONE}: Allocated
 PDCH(bts=0,trx=0,ts=7) Attaching TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=NEW), 1 TBFs, USFs = 01, TFIs = 00000001.
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=NEW) Setting Control TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=NEW) Allocated: trx = 0, ul_slots = 80, dl_slots = 00
-MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, DL) Attaching UL TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=NEW)
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Attaching UL TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=NEW)
 TBF(UL-TFI_0){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=NEW) set ass. type PACCH [prev CCCH:0, PACCH:0]
 TBF(UL-TFI_0){NEW}: state_chg to ASSIGN
@@ -2497,6 +2505,32 @@ UL_ASS_TBF(UL-TFI_0){WAIT_ACK}: Received Event RX_ASS_CTRL_ACK
 UL_ASS_TBF(UL-TFI_0){WAIT_ACK}: state_chg to NONE
 TBF(UL-TFI_0){ASSIGN}: Received Event ASSIGN_ACK_PACCH
 TBF(UL-TFI_0){ASSIGN}: state_chg to FLOW
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL) ********** DL-TBF starts here **********
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL) Allocating DL TBF
+TBF{NEW}: Allocated
+UL_ASS_TBF{NONE}: Allocated
+DL_ASS_TBF{NONE}: Allocated
+[DL] algo A <multi> (suggested TRX: 0): Alloc start
+- Skipping TS 0, because not enabled
+- Skipping TS 1, because not enabled
+- Skipping TS 2, because not enabled
+- Skipping TS 3, because not enabled
+- Skipping TS 4, because not enabled
+- Skipping TS 5, because not enabled
+- Skipping TS 6, because not enabled
+[DL] Assign downlink TS=7 TFI=0
+PDCH(bts=0,trx=0,ts=7) Attaching TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=NEW), 1 TBFs, USFs = 01, TFIs = 00000001.
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=NEW) Setting Control TS 7
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=NEW) Allocated: trx = 0, ul_slots = 80, dl_slots = 80
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL) Attaching DL TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=NEW)
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=NEW) [DOWNLINK] START (PACCH)
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=NEW) Send downlink assignment on PACCH, because TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) exists
+DL_ASS_TBF(UL-TFI_0){NONE}: Received Event SCHED_ASS
+DL_ASS_TBF(UL-TFI_0){NONE}: state_chg to SEND_ASS
+TBF(DL-TFI_0){NEW}: Received Event ASSIGN_ADD_PACCH
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=NEW) set ass. type PACCH [prev CCCH:0, PACCH:0]
+TBF(DL-TFI_0){NEW}: state_chg to ASSIGN
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
 Detected FN jump! 2654340 -> 2654331 (expected 2654344)
 PDCH(bts=0,trx=0,ts=7) Got CS-1 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=184
 PDCH(bts=0,trx=0,ts=7) FN=2654331 Rx UL DATA from unexpected TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW)
@@ -2662,16 +2696,20 @@ TBF(TFI=0 TLLI=0xffffffff DIR=UL STATE=FLOW) Decoded premier TLLI=0xf1223344 of
 Modifying MS object, UL TLLI: 0xffffffff -> 0xf1223344, not yet confirmed
 MS(TLLI=0xf1223344, IMSI=, TA=7, 0/0, UL) Merge MS: MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, DL)
 Modifying MS object, TLLI = 0xf1223344, MS class 0 -> 1
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) Merge MS: Move DL TBF: MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, DL) => MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL)
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Detaching TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN)
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL) Attaching DL TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN)
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Clearing MS object
+MS(TLLI=0xffffffff, IMSI=, TA=7, 1/0,) Destroying MS object
+TBF(UL-TFI_0){FLOW}: Received Event FIRST_UL_DATA_RECVD
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) Got first UL data while DL-TBF pending, killing it
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) free
 PDCH(bts=0,trx=0,ts=7) Detaching TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN), 1 TBFs, USFs = 01, TFIs = 00000001.
-MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Detaching TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN)
+MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL) Detaching TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN)
 ********** DL-TBF ends here **********
 TBF(DL-TFI_0){ASSIGN}: Deallocated
 UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
 DL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
-MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Clearing MS object
-MS(TLLI=0xffffffff, IMSI=, TA=7, 1/0,) Destroying MS object
-TBF(UL-TFI_0){FLOW}: Received Event FIRST_UL_DATA_RECVD
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) Assembling frames: (len=20)
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) Frame 1 starts at offset 4, length=16, is_complete=1
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) complete UL frame len=16