tbf_ul_fsm: Delay moving ul_tbf to FLOW

Otherwise the scheduler selects the UL TBF for USF during that time, and
of course no one has that USF assigned yet, so no answer and that ends
up triggering MAX_N3101 on the UL TBF.

This is specially important when PCU is connected to the BSC, since the
amount of time for the ImmAss to be scheduled on the BTS and reach the
MS can be bigger.

Change-Id: I48babd70ca44f11110240cbcfbab43d0e3a0fb59

4 files changed, 81 insertions, 30 deletions

diff --git a/src/tbf_ul_fsm.c b/src/tbf_ul_fsm.c
index a26d1618..49849ba3 100644
--- a/src/tbf_ul_fsm.c
+++ b/src/tbf_ul_fsm.c
@@ -89,7 +89,7 @@ static void st_new(struct osmo_fsm_inst *fi, uint32_t event, void *data)
 	switch (event) {
 	case TBF_EV_ASSIGN_ADD_CCCH:
 		mod_ass_type(ctx, GPRS_RLCMAC_FLAG_CCCH, true);
-		tbf_ul_fsm_state_chg(fi, TBF_ST_FLOW);
+		tbf_ul_fsm_state_chg(fi, TBF_ST_ASSIGN);
 		ul_tbf_contention_resolution_start(ctx->ul_tbf);
 		break;
 	case TBF_EV_ASSIGN_ADD_PACCH:
@@ -126,6 +126,22 @@ static void st_assign_on_enter(struct osmo_fsm_inst *fi, uint32_t prev_state)
 			  "Starting timer T3168 [UL TBF Ass (PACCH)] with %u sec. %u microsec\n",
 			  sec, micro);
 		osmo_timer_schedule(&fi->timer, sec, micro);
+	} else if (ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH)) {
+		/* Wait a bit for the AGCH ImmAss[PktUlAss] sent BSC->BTS to
+		 * arrive at the MS, and for the MS to jump and starting
+		 * listening on USFs in the assigned PDCH.
+		 * Ideally we would first wait for TBF_EV_ASSIGN_PCUIF_CNF to
+		 * account for queueing time, but that's only sent for data on PCH
+		 * so far, while ImmAss for UL TBF is sent on AGCH.
+		 */
+		fi->T = -2002;
+		val = osmo_tdef_get(the_pcu->T_defs, fi->T, OSMO_TDEF_MS, -1);
+		sec = val / 1000;
+		micro = (val % 1000) * 1000;
+		LOGPTBFUL(ctx->ul_tbf, LOGL_DEBUG,
+			  "Starting timer X2002 [assignment (AGCH)] with %u sec. %u microsec\n",
+			  sec, micro);
+		osmo_timer_schedule(&fi->timer, sec, micro);
 	}
 }
 
@@ -152,6 +168,10 @@ static void st_assign(struct osmo_fsm_inst *fi, uint32_t event, void *data)
 		}
 		tbf_ul_fsm_state_chg(fi, TBF_ST_FLOW);
 		break;
+	case TBF_EV_ASSIGN_READY_CCCH:
+		/* change state to FLOW, so scheduler will start requesting USF */
+		tbf_ul_fsm_state_chg(fi, TBF_ST_FLOW);
+		break;
 	default:
 		OSMO_ASSERT(0);
 	}
@@ -259,6 +279,9 @@ static int tbf_ul_fsm_timer_cb(struct osmo_fsm_inst *fi)
 {
 	struct tbf_ul_fsm_ctx *ctx = (struct tbf_ul_fsm_ctx *)fi->priv;
 	switch (fi->T) {
+	case -2002:
+		osmo_fsm_inst_dispatch(fi, TBF_EV_ASSIGN_READY_CCCH, NULL);
+		break;
 	case 3168:
 		LOGPTBFUL(ctx->ul_tbf, LOGL_NOTICE, "Releasing due to UL TBF PACCH assignment timeout\n");
 		/* fall-through */
@@ -286,7 +309,8 @@ static struct osmo_fsm_state tbf_ul_fsm_states[] = {
 		.in_event_mask =
 			X(TBF_EV_ASSIGN_ADD_CCCH) |
 			X(TBF_EV_ASSIGN_ADD_PACCH) |
-			X(TBF_EV_ASSIGN_ACK_PACCH),
+			X(TBF_EV_ASSIGN_ACK_PACCH) |
+			X(TBF_EV_ASSIGN_READY_CCCH),
 		.out_state_mask =
 			X(TBF_ST_FLOW) |
 			X(TBF_ST_FINISHED),
diff --git a/tests/tbf/TbfTest.cpp b/tests/tbf/TbfTest.cpp
index bf308912..0205f2b1 100644
--- a/tests/tbf/TbfTest.cpp
+++ b/tests/tbf/TbfTest.cpp
@@ -650,10 +650,18 @@ static gprs_rlcmac_ul_tbf *establish_ul_tbf_single_phase(struct gprs_rlcmac_bts
 
 	tfi = bts_tfi_find_free(bts, GPRS_RLCMAC_UL_TBF, &pdch->trx->trx_no, -1);
 
+	/* We set X2002 timeout to 0 here to get immediate trigger through osmo_select_main() below */
+	OSMO_ASSERT(osmo_tdef_set(the_pcu->T_defs, -2002, 0, OSMO_TDEF_MS) == 0);
 	bts_handle_rach(bts, 0x03, *fn, qta);
 
 	ul_tbf = bts_ul_tbf_by_tfi(bts, tfi, pdch->trx->trx_no, pdch->ts_no);
 	OSMO_ASSERT(ul_tbf != NULL);
+	OSMO_ASSERT(ul_tbf->state_is(TBF_ST_ASSIGN));
+
+	/* ImmAss has been sent PCU=PCUIF=>BTS. This means UL TBF is in state
+	 * ASSIGN with X2002 armed. It will move to FLOW once it expires. */
+	osmo_select_main(0);
+	OSMO_ASSERT(ul_tbf->state_is(TBF_ST_FLOW));
 
 	OSMO_ASSERT(ul_tbf->ta() == qta / 4);
 
diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err
index 83bf6db0..e582807b 100644
--- a/tests/tbf/TbfTest.err
+++ b/tests/tbf/TbfTest.err
@@ -2271,11 +2271,15 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-0:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-0:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-0:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
+UL_TBF(UL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-0:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=0 USF=0
+UL_TBF(UL:TFI-0-0-0:G){ASSIGN}: Timeout of X2002
+UL_TBF(UL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_READY_CCCH
+UL_TBF(UL:TFI-0-0-0:G){ASSIGN}: state_chg to FLOW
 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=2654167 Rx UL DATA from unexpected TBF(UL:TFI-0-0-0:G){FLOW}
 TBF(UL:TFI-0-0-0:G){FLOW} UL DATA TFI=0 received (V(Q)=0 .. V(R)=0)
@@ -2337,11 +2341,15 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-0:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-0:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-0:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
+UL_TBF(UL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-0:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=0 USF=0
+UL_TBF(UL:TFI-0-0-0:G){ASSIGN}: Timeout of X2002
+UL_TBF(UL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_READY_CCCH
+UL_TBF(UL:TFI-0-0-0:G){ASSIGN}: state_chg to FLOW
 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=2654167 Rx UL DATA from unexpected TBF(UL:TFI-0-0-0:G){FLOW}
 TBF(UL:TFI-0-0-0:G){FLOW} UL DATA TFI=0 received (V(Q)=0 .. V(R)=0)
@@ -3225,11 +3233,15 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-0:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-0:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-0:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654283
+UL_TBF(UL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-0:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654283
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=0 USF=0
+UL_TBF(UL:TFI-0-0-0:G){ASSIGN}: Timeout of X2002
+UL_TBF(UL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_READY_CCCH
+UL_TBF(UL:TFI-0-0-0:G){ASSIGN}: state_chg to FLOW
 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=2654275 Rx UL DATA from unexpected TBF(UL:TFI-0-0-0:G){FLOW}
 TBF(UL:TFI-0-0-0:G){FLOW} UL DATA TFI=0 received (V(Q)=0 .. V(R)=0)
@@ -9317,8 +9329,9 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-0:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-0:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-0:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
+UL_TBF(UL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-0:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 200000 microsec
+TBF(UL:TFI-0-0-0:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=0 USF=0
@@ -9348,8 +9361,9 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-1:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-1:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-1:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-1:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-1:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
+UL_TBF(UL:TFI-0-0-1:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-1:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 200000 microsec
+TBF(UL:TFI-0-0-1:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=1 USF=1
@@ -9379,8 +9393,9 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-2:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-2:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-2:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-2:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-2:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
+UL_TBF(UL:TFI-0-0-2:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-2:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 200000 microsec
+TBF(UL:TFI-0-0-2:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=2 USF=2
@@ -9410,8 +9425,9 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-3:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-3:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-3:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-3:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-3:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
+UL_TBF(UL:TFI-0-0-3:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-3:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 200000 microsec
+TBF(UL:TFI-0-0-3:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=3 USF=3
@@ -9441,8 +9457,9 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-4:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-4:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-4:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-4:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-4:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
+UL_TBF(UL:TFI-0-0-4:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-4:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 200000 microsec
+TBF(UL:TFI-0-0-4:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=4 USF=4
@@ -9472,8 +9489,9 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-5:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-5:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-5:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-5:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-5:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
+UL_TBF(UL:TFI-0-0-5:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-5:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 200000 microsec
+TBF(UL:TFI-0-0-5:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=5 USF=5
@@ -9503,8 +9521,9 @@ MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-0-6:G){NEW}
 MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf)
 UL_TBF(UL:TFI-0-0-6:G){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-6:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-6:G){NEW}: state_chg to FLOW
-TBF(UL:TFI-0-0-6:G){FLOW} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
+UL_TBF(UL:TFI-0-0-6:G){NEW}: state_chg to ASSIGN
+TBF(UL:TFI-0-0-6:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 200000 microsec
+TBF(UL:TFI-0-0-6:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=2654167
 MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf)
 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 7
 Tx Immediate Assignment on AGCH: TRX=0 (ARFCN 0) TS=7 TA=7 TSC=0 TFI=6 USF=6
@@ -9527,25 +9546,25 @@ MS(TA-220:MSCLS-0-0): - bts_rcv_rach: now used by 0 (-)
 MS(TA-220:MSCLS-0-0) Destroying MS object
 Tx Immediate Assignment Reject on AGCH
 MS(TA-7:MSCLS-0-0:UL) Destroying MS object
-MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-6:G){FLOW}
+MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-6:G){ASSIGN}
 MS(TA-7:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(TA-7:MSCLS-0-0:UL) Destroying MS object
-MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-5:G){FLOW}
+MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-5:G){ASSIGN}
 MS(TA-7:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(TA-7:MSCLS-0-0:UL) Destroying MS object
-MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-4:G){FLOW}
+MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-4:G){ASSIGN}
 MS(TA-7:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(TA-7:MSCLS-0-0:UL) Destroying MS object
-MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-3:G){FLOW}
+MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-3:G){ASSIGN}
 MS(TA-7:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(TA-7:MSCLS-0-0:UL) Destroying MS object
-MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-2:G){FLOW}
+MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-2:G){ASSIGN}
 MS(TA-7:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(TA-7:MSCLS-0-0:UL) Destroying MS object
-MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-1:G){FLOW}
+MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-1:G){ASSIGN}
 MS(TA-7:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(TA-7:MSCLS-0-0:UL) Destroying MS object
-MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-0:G){FLOW}
+MS(TA-7:MSCLS-0-0:UL) Detaching TBF: TBF(UL:TFI-0-0-0:G){ASSIGN}
 MS(TA-7:MSCLS-0-0): - tbf: now used by 0 (-)
 === end test_immediate_assign_rej_multi_block ===
 === start test_immediate_assign_rej_single_block ===
diff --git a/tests/types/TypesTest.err b/tests/types/TypesTest.err
index 4c20672c..55453c97 100644
--- a/tests/types/TypesTest.err
+++ b/tests/types/TypesTest.err
@@ -41,7 +41,7 @@ TBF(UL:TFI-0-0-0:E){NEW} Allocated: trx = 0, ul_slots = 10, dl_slots = 00
 TBF(UL:TFI-0-0-0:E){NEW} setting EGPRS UL window size to 64, base(64) slots(1) ws_pdch(0)
 UL_TBF(UL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH
 TBF(UL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0]
-UL_TBF(UL:TFI-0-0-0:E){NEW}: state_chg to FLOW
+UL_TBF(UL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN
 ************** Test with empty window
 ************** Test with 1 lost packet
 ************** Test with compressed window