From 7a4428c3adb41538872858df2881d9a00eb0ec41 Mon Sep 17 00:00:00 2001 From: Pau Espin Pedrol Date: Mon, 12 Jun 2023 13:44:55 +0200 Subject: 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 --- src/bts.cpp | 1 + src/gprs_pcu.c | 2 +- src/pcu_l1_if.cpp | 2 ++ src/tbf_ul_ass_fsm.c | 32 +++++++++++++++++++++++-- src/tbf_ul_fsm.c | 12 ++++++---- tests/tbf/TbfTest.err | 65 +++++++++++++++++++++++++++++++++------------------ 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) -- cgit v1.2.3