Abort UL TBF PACCH Ass based on T3168

It makes no sense to continue trying to assign the UL TBF over PACCH
after T3168 * 4 retrans time out.

This helps in releasing the TBF after we got rid of incorrect use of
N3015 in UL TBFs.

While at it, update tbf_ul_fsm to use T3168 instead of X2001, since it
really needs to match T3168. Ideally it would not even have a timer
itself and receive an event from tbf_ul_ass_fsm, but that's left as a
TODO (it was already before) and simply the timer is updated.

Change-Id: I87dff68dedd06b60501e7586d20faf02bb1f0c93

6 files changed, 83 insertions, 31 deletions

diff --git a/src/bts.cpp b/src/bts.cpp
index 44acbeda..44e98c06 100644
--- a/src/bts.cpp
+++ b/src/bts.cpp
@@ -77,6 +77,7 @@ void bts_trx_free_all_tbf(struct gprs_rlcmac_trx *trx)
 
 static struct osmo_tdef T_defs_bts[] = {
 	{ .T=3142, .default_val=20,  .unit=OSMO_TDEF_S,  .desc="Wait Indication used in Imm Ass Reject during TBF Establishment (CCCH)", .val=0, .min_val = 0, .max_val = 255 }, /* TS 44.018 10.5.2.43, TS 44.060 7.1.3.2.1 (T3172) */
+	{ .T=3168, .default_val=4000, .unit=OSMO_TDEF_MS,  .desc="Time MS waits for PACKET UPLINK ACK when establishing a UL TBF", .val=0 },
 	{ .T=3169, .default_val=5,   .unit=OSMO_TDEF_S,  .desc="Reuse of USF and TFI(s) after the MS uplink TBF assignment is invalid", .val=0 },
 	{ .T=3191, .default_val=5,   .unit=OSMO_TDEF_S,  .desc="Reuse of TFI(s) after sending (1) last RLC Data Block on TBF(s), or (2) PACKET TBF RELEASE for an MBMS radio bearer", .val=0 },
 	{ .T=3193, .default_val=100, .unit=OSMO_TDEF_MS, .desc="Reuse of TFI(s) after reception of final PACKET DOWNLINK ACK/NACK from MS for TBF", .val=0 },
diff --git a/src/gprs_pcu.c b/src/gprs_pcu.c
index 2ad5c71d..069f1704 100644
--- a/src/gprs_pcu.c
+++ b/src/gprs_pcu.c
@@ -41,7 +41,7 @@ static struct osmo_tdef T_defs_pcu[] = {
 	{ .T=-101,  .default_val=30,  .unit=OSMO_TDEF_S,  .desc="BSSGP (un)blocking procedures timer (s)",  .val=0 },
 	{ .T=-102,  .default_val=30,  .unit=OSMO_TDEF_S,  .desc="BSSGP reset procedure timer (s)",          .val=0 },
 	{ .T=-2000, .default_val=0,   .unit=OSMO_TDEF_MS, .desc="Delay release of UL TBF after tx Packet Access Reject (PACCH) (ms)", .val=0 },
-	{ .T=-2001, .default_val=2,   .unit=OSMO_TDEF_S,  .desc="PACCH assignment timeout (s)",               .val=0 },
+	{ .T=-2001, .default_val=2,   .unit=OSMO_TDEF_S,  .desc="DL TBF PACCH assignment timeout (s)", .val=0 },
 	{ .T=-2002, .default_val=200, .unit=OSMO_TDEF_MS, .desc="Waiting after IMM.ASS confirm timer (ms)", .val=0 },
 	{ .T=-2030, .default_val=60,  .unit=OSMO_TDEF_S,  .desc="Time to keep an idle MS object alive (s)", .val=0 }, /* slightly above T3314 (default 44s, 24.008, 11.2.2) */
 	{ .T=-2031, .default_val=2000, .unit=OSMO_TDEF_MS, .desc="Time to keep an idle DL TBF alive (ms)",  .val=0 },
diff --git a/src/pcu_l1_if.cpp b/src/pcu_l1_if.cpp
index 0370aeba..7437e16a 100644
--- a/src/pcu_l1_if.cpp
+++ b/src/pcu_l1_if.cpp
@@ -436,6 +436,8 @@ static int pcu_rx_data_ind_bcch(struct gprs_rlcmac_bts *bts, uint8_t *data, uint
 			si_ro = ((struct gsm48_system_information_type_13*)data)->rest_octets;
 			if (osmo_gsm48_rest_octets_si13_decode(&bts->si13_ro_decoded, si_ro) < 0)
 				LOGP(DPCU, LOGL_ERROR, "Error decoding SI13\n");
+			/* Update our cached T3168 from it: */
+			osmo_tdef_set(bts->T_defs_bts, 3168, bts->si13_ro_decoded.cell_opts.t3168, OSMO_TDEF_MS);
 			break;
 		default:
 			LOGP(DL1IF, LOGL_ERROR,
diff --git a/src/tbf_ul_ass_fsm.c b/src/tbf_ul_ass_fsm.c
index 0fea9025..74121078 100644
--- a/src/tbf_ul_ass_fsm.c
+++ b/src/tbf_ul_ass_fsm.c
@@ -33,9 +33,9 @@
 
 static const struct osmo_tdef_state_timeout tbf_ul_ass_fsm_timeouts[32] = {
 	[TBF_UL_ASS_NONE] = {},
-	[TBF_UL_ASS_SEND_ASS] = {},
+	[TBF_UL_ASS_SEND_ASS] = { .keep_timer = true },
 	[TBF_UL_ASS_SEND_ASS_REJ] = {},
-	[TBF_UL_ASS_WAIT_ACK] = {},
+	[TBF_UL_ASS_WAIT_ACK] = { .keep_timer = true },
 };
 
 static const struct value_string tbf_ul_ass_fsm_event_names[] = {
@@ -188,6 +188,32 @@ static void st_none(struct osmo_fsm_inst *fi, uint32_t event, void *data)
 	}
 }
 
+static void st_send_ass_on_enter(struct osmo_fsm_inst *fi, uint32_t prev_state)
+{
+	struct tbf_ul_ass_fsm_ctx *ctx = (struct tbf_ul_ass_fsm_ctx *)fi->priv;
+	unsigned long val;
+	unsigned int sec, micro;
+	struct GprsMs *ms = tbf_ms(ctx->tbf);
+
+	/* Here it's time where received PKT RES REQ or DL ACK/NACK to request a new UL TBF,
+	 * so MS will be gone after T3168 (* 4 retrans, 8.1.1.1.2) if we are unable to seize it.
+	 * Hence, attempt re-scheduling PKT UL ASS (states SEND_ASS<->WAIT_ACK ping-pong)
+	 * until T3168 we announced to the MS expires:
+	 */
+	if (prev_state == TBF_UL_ASS_NONE) {
+		/* tbf_free() called upon trigger */
+		fi->T = 3168;
+		val = osmo_tdef_get(ms->bts->T_defs_bts, fi->T, OSMO_TDEF_MS, -1);
+		val *= 4; /* 4 PKT RES REQ retransmit */
+		sec = val / 1000;
+		micro = (val % 1000) * 1000;
+		LOGPTBF(ctx->tbf, LOGL_DEBUG, "starting timer T3168 [PKT UL ASS PACCH] with %u sec. %u microsec\n",
+			sec, micro);
+		osmo_timer_schedule(&fi->timer, sec, micro);
+	}
+
+}
+
 static void st_send_ass(struct osmo_fsm_inst *fi, uint32_t event, void *data)
 {
 	struct tbf_ul_ass_fsm_ctx *ctx = (struct tbf_ul_ass_fsm_ctx *)fi->priv;
@@ -268,6 +294,7 @@ static int tbf_ul_ass_fsm_timer_cb(struct osmo_fsm_inst *fi)
 	struct tbf_ul_ass_fsm_ctx *ctx = (struct tbf_ul_ass_fsm_ctx *)fi->priv;
 	switch (fi->T) {
 	case -2000:
+	case 3168:
 		tbf_free(ctx->tbf);
 		break;
 	default:
@@ -298,6 +325,7 @@ static struct osmo_fsm_state tbf_ul_ass_fsm_states[] = {
 			X(TBF_UL_ASS_NONE),
 		.name = "SEND_ASS",
 		.action = st_send_ass,
+		.onenter = st_send_ass_on_enter,
 	},
 	[TBF_UL_ASS_SEND_ASS_REJ] = {
 		.in_event_mask =
diff --git a/src/tbf_ul_fsm.c b/src/tbf_ul_fsm.c
index 6160584d..e5c84ed4 100644
--- a/src/tbf_ul_fsm.c
+++ b/src/tbf_ul_fsm.c
@@ -106,6 +106,7 @@ static void st_new(struct osmo_fsm_inst *fi, uint32_t event, void *data)
 static void st_assign_on_enter(struct osmo_fsm_inst *fi, uint32_t prev_state)
 {
 	struct tbf_ul_fsm_ctx *ctx = (struct tbf_ul_fsm_ctx *)fi->priv;
+	struct GprsMs *ms = tbf_ms(ctx->tbf);
 	unsigned long val;
 	unsigned int sec, micro;
 
@@ -118,12 +119,13 @@ static void st_assign_on_enter(struct osmo_fsm_inst *fi, uint32_t prev_state)
 	 * other TBF always signal us assignment failure (we already get
 	 * assignment success through TBF_EV_ASSIGN_ACK_PACCH) */
 	if (ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH)) {
-		fi->T = -2001;
-		val = osmo_tdef_get(the_pcu->T_defs, fi->T, OSMO_TDEF_MS, -1);
+		fi->T = 3168;
+		val = osmo_tdef_get(ms->bts->T_defs_bts, fi->T, OSMO_TDEF_MS, -1);
+		val *= 4; /* 4 PKT RES REQ retransmit */
 		sec = val / 1000;
 		micro = (val % 1000) * 1000;
 		LOGPTBFUL(ctx->ul_tbf, LOGL_DEBUG,
-			  "Starting timer X2001 [assignment (PACCH)] with %u sec. %u microsec\n",
+			  "Starting timer T3168 [UL TBF Ass (PACCH)] with %u sec. %u microsec\n",
 			  sec, micro);
 		osmo_timer_schedule(&fi->timer, sec, micro);
 	}
@@ -259,8 +261,8 @@ 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 -2001:
-		LOGPTBFUL(ctx->ul_tbf, LOGL_NOTICE, "releasing due to PACCH assignment timeout.\n");
+	case 3168:
+		LOGPTBFUL(ctx->ul_tbf, LOGL_NOTICE, "Releasing due to UL TBF PACCH assignment timeout\n");
 		/* fall-through */
 	case 3169:
 		tbf_free(ctx->tbf);
diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err
index 9e750016..1797c792 100644
--- a/tests/tbf/TbfTest.err
+++ b/tests/tbf/TbfTest.err
@@ -55,7 +55,7 @@ MS(TLLI-0x00002342:TA-4:MSCLS-0-0:UL:DL): + tbf: now used by 2 (2*tbf)
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 Modifying MS object, TLLI: 0xffffffff -> 0x00002342, already confirmed partly
 The MS object cannot fully confirm an unexpected TLLI: 0x00004232, partly confirmed
 Modifying MS object, TLLI: 0x00002342 -> 0x00004232, already confirmed partly
@@ -2222,10 +2222,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -2332,10 +2333,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -2507,10 +2509,11 @@ MS(TLLI-0xf5667788:TA-7:MSCLS-1-0:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf5667788:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf)
 PDCH(bts=0,trx=0,ts=7) Expiring FN=2654348 but previous FN=2654301 is still reserved!
 PDCH(bts=0,trx=0,ts=7) Timeout for registered USF (FN=2654301): TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){FLOW}
@@ -2648,10 +2651,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -2766,10 +2770,11 @@ MS(IMSI-0011223344:TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): + tbf: now used by 2 (rcv
 UL_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(IMSI-0011223344:TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654327 + 13 = 2654340
@@ -2873,10 +2878,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -3063,10 +3069,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -4298,10 +4305,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -4416,10 +4424,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -7550,10 +7559,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -7771,10 +7781,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -8231,10 +8242,11 @@ MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): + tbf: now used by 2 (rcv_resource_reques
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283
@@ -9599,10 +9611,11 @@ MS(TLLI-0xffeeddcc:TA-7:MSCLS-11-11:UL): + tbf: now used by 2 (rcv_resource_requ
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xffeeddcc:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf)
 UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){SEND_ASS}: Received Event CREATE_RLCMAC_MSG
 PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654218 + 13 = 2654231
@@ -9649,10 +9662,11 @@ MS(TLLI-0xffeeddcd:TA-7:MSCLS-11-11:UL): + tbf: now used by 2 (rcv_resource_requ
 UL_TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xffeeddcd:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf)
 PDCH(bts=0,trx=0,ts=7) Expiring FN=56 but previous FN=2654231 is still reserved!
 PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN}
@@ -9705,10 +9719,11 @@ MS(TLLI-0xffeeddce:TA-7:MSCLS-11-11:UL): + tbf: now used by 2 (rcv_resource_requ
 UL_TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xffeeddce:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf)
 PDCH(bts=0,trx=0,ts=7) Expiring FN=60 but previous FN=2654231 is still reserved!
 PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN}
@@ -9761,10 +9776,11 @@ MS(TLLI-0xffeeddcf:TA-7:MSCLS-11-11:UL): + tbf: now used by 2 (rcv_resource_requ
 UL_TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xffeeddcf:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf)
 PDCH(bts=0,trx=0,ts=7) Expiring FN=65 but previous FN=2654231 is still reserved!
 PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN}
@@ -9817,10 +9833,11 @@ MS(TLLI-0xffeeddd0:TA-7:MSCLS-11-11:UL): + tbf: now used by 2 (rcv_resource_requ
 UL_TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xffeeddd0:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf)
 PDCH(bts=0,trx=0,ts=7) Expiring FN=69 but previous FN=2654231 is still reserved!
 PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN}
@@ -9873,10 +9890,11 @@ MS(TLLI-0xffeeddd1:TA-7:MSCLS-11-11:UL): + tbf: now used by 2 (rcv_resource_requ
 UL_TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xffeeddd1:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf)
 PDCH(bts=0,trx=0,ts=7) Expiring FN=73 but previous FN=2654231 is still reserved!
 PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN}
@@ -9929,10 +9947,11 @@ MS(TLLI-0xffeeddd2:TA-7:MSCLS-11-11:UL): + tbf: now used by 2 (rcv_resource_requ
 UL_TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete.
 UL_ASS_TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NONE}: Received Event SCHED_ASS
 UL_ASS_TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NONE}: state_chg to SEND_ASS
+TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec
 MS(TLLI-0xffeeddd2:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf)
 PDCH(bts=0,trx=0,ts=7) Expiring FN=78 but previous FN=2654231 is still reserved!
 PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN}
@@ -9983,7 +10002,7 @@ MS(TLLI-0xffeeddd3:TA-7:MSCLS-11-11:UL): + tbf: now used by 2 (rcv_resource_requ
 UL_TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 UL_ASS_TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NONE}: Received Event SCHED_ASS_REJ
 UL_ASS_TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NONE}: state_chg to SEND_ASS_REJ
 MS(TLLI-0xffeeddd3:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf)
@@ -10043,7 +10062,7 @@ MS(TLLI-0xffeeddcc:TA-220:MSCLS-0-0:UL): + tbf: now used by 1 (tbf)
 UL_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 UL_ASS_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NONE}: Received Event SCHED_ASS_REJ
 UL_ASS_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NONE}: state_chg to SEND_ASS_REJ
 UL_ASS_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){SEND_ASS_REJ}: Received Event CREATE_RLCMAC_MSG
@@ -10140,7 +10159,7 @@ MS(TLLI-0xecc1f953:TA-220:MSCLS-0-0:UL): + tbf: now used by 1 (tbf)
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){NEW}: Received Event ASSIGN_ADD_PACCH
 TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0]
 UL_TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){NEW}: state_chg to ASSIGN
-TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec
+TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec
 There is a new MS object for the same MS: (0xa3c2f953, '001001000000001') -> (0xecc1f953, '')
 MS(IMSI-001001000000001:TLLI-0xa3c2f953:TA-220:MSCLS-11-0:DL): + ms_merge_and_clear_ms: now used by 2 (tbf,ms_merge_and_clear_ms)
 MS(TLLI-0xecc1f953:TA-220:MSCLS-0-0:UL) Merge MS: MS(IMSI-001001000000001:TLLI-0xa3c2f953:TA-220:MSCLS-11-0:DL)