aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorDaniel Willmann <dwillmann@sysmocom.de>2014-09-15 16:21:03 +0200
committerDaniel Willmann <daniel@totalueberwachung.de>2014-09-15 19:13:06 +0200
commit4365ae9f4cd2e64bdbe9f1cdd7bddd2e7227ec70 (patch)
tree5aefb843a613f3f7855cc073313ae12938be9037
parentb6f8a4f7cb8ac76eb7431a4cf536e0cb433ea3be (diff)
tbf: Don't multiplex one timer per tbfsysmocom/tbf-final-ack
Multiplexing one timer for all the TBF-specific timers means that only one can run at a time. It's not clear if that is always the case so use one timer per Txxxx timer. Sponsored-by: On-Waves ehf
-rw-r--r--src/bts.cpp10
-rw-r--r--src/tbf.cpp235
-rw-r--r--src/tbf.h24
-rw-r--r--src/tbf_dl.cpp4
-rw-r--r--src/tbf_ul.cpp2
-rw-r--r--tests/tbf/TbfTest.err4
6 files changed, 177 insertions, 102 deletions
diff --git a/src/bts.cpp b/src/bts.cpp
index f58ff3a..979e051 100644
--- a/src/bts.cpp
+++ b/src/bts.cpp
@@ -409,7 +409,7 @@ int BTS::rcv_imm_ass_cnf(const uint8_t *data, uint32_t fn)
LOGP(DRLCMAC, LOGL_DEBUG, "Got IMM.ASS confirm for TLLI=%08x\n", tlli);
if (dl_tbf->m_wait_confirm)
- tbf_timer_start(dl_tbf, 0, Tassign_agch);
+ tbf_timer_start(dl_tbf, GPRS_RLCMAC_TASSIGN, Tassign_agch);
return 0;
}
@@ -469,7 +469,7 @@ int BTS::rcv_rach(uint8_t ra, uint32_t Fn, int16_t qta)
tbf->ta = qta >> 2;
tbf->set_state(GPRS_RLCMAC_FLOW);
tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_CCCH);
- tbf_timer_start(tbf, 3169, m_bts.t3169, 0);
+ tbf_timer_start(tbf, GPRS_RLCMAC_T3169, m_bts.t3169, 0);
LOGP(DRLCMAC, LOGL_DEBUG, "%s [UPLINK] START\n",
tbf_name(tbf));
LOGP(DRLCMAC, LOGL_DEBUG, "%s RX: [PCU <- BTS] RACH "
@@ -504,7 +504,7 @@ void BTS::trigger_dl_ass(
struct gprs_rlcmac_tbf *old_tbf, const char *imsi)
{
/* stop pending timer */
- dl_tbf->stop_timer();
+ dl_tbf->stop_timers();
/* check for downlink tbf: */
if (old_tbf) {
@@ -521,7 +521,7 @@ void BTS::trigger_dl_ass(
dl_tbf->set_state(GPRS_RLCMAC_ASSIGN);
dl_tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_PACCH);
/* start timer */
- tbf_timer_start(dl_tbf, 0, Tassign_pacch);
+ tbf_timer_start(dl_tbf, GPRS_RLCMAC_TASSIGN, Tassign_pacch);
} else {
LOGP(DRLCMAC, LOGL_DEBUG, "Send dowlink assignment for %s on PCH, no TBF exist (IMSI=%s)\n", tbf_name(dl_tbf), imsi);
if (!imsi || strlen(imsi) < 3) {
@@ -782,7 +782,7 @@ void gprs_rlcmac_pdch::rcv_control_ack(Packet_Control_Acknowledgement_t *packet,
new_tbf->set_state(GPRS_RLCMAC_FLOW);
/* stop pending assignment timer */
- new_tbf->stop_timer();
+ new_tbf->stop_timer(GPRS_RLCMAC_TASSIGN);
if ((new_tbf->state_flags &
(1 << GPRS_RLCMAC_FLAG_TO_DL_ASS))) {
new_tbf->state_flags &=
diff --git a/src/tbf.cpp b/src/tbf.cpp
index 2afe257..6f601aa 100644
--- a/src/tbf.cpp
+++ b/src/tbf.cpp
@@ -38,7 +38,57 @@ extern "C" {
extern void *tall_pcu_ctx;
-static void tbf_timer_cb(void *_tbf);
+static void tbf_timer_tassign_cb(void *_tbf)
+{
+ struct gprs_rlcmac_tbf *tbf = (struct gprs_rlcmac_tbf *)_tbf;
+ tbf->handle_assignment_timeout();
+}
+
+static void tbf_timer_t3169_cb(void *_tbf)
+{
+ struct gprs_rlcmac_tbf *tbf = (struct gprs_rlcmac_tbf *)_tbf;
+ tbf->handle_timeout(GPRS_RLCMAC_T3169);
+}
+
+static void tbf_timer_t3191_cb(void *_tbf)
+{
+ struct gprs_rlcmac_tbf *tbf = (struct gprs_rlcmac_tbf *)_tbf;
+ tbf->handle_timeout(GPRS_RLCMAC_T3191);
+}
+
+static void tbf_timer_t3193_cb(void *_tbf)
+{
+ struct gprs_rlcmac_tbf *tbf = (struct gprs_rlcmac_tbf *)_tbf;
+ tbf->handle_timeout(GPRS_RLCMAC_T3193);
+}
+
+static void tbf_timer_t3195_cb(void *_tbf)
+{
+ struct gprs_rlcmac_tbf *tbf = (struct gprs_rlcmac_tbf *)_tbf;
+ tbf->handle_timeout(GPRS_RLCMAC_T3195);
+}
+
+static void tbf_timer_t3197_cb(void *_tbf)
+{
+ struct gprs_rlcmac_tbf *tbf = (struct gprs_rlcmac_tbf *)_tbf;
+ tbf->handle_timeout(GPRS_RLCMAC_T3197);
+}
+
+static void tbf_timer_t3199_cb(void *_tbf)
+{
+ struct gprs_rlcmac_tbf *tbf = (struct gprs_rlcmac_tbf *)_tbf;
+ tbf->handle_timeout(GPRS_RLCMAC_T3199);
+}
+
+static void (*tbf_timer_cb[GPRS_RLCMAC_TMAX])(void *_tbf) = {
+ tbf_timer_tassign_cb,
+ tbf_timer_t3169_cb,
+ tbf_timer_t3191_cb,
+ tbf_timer_t3193_cb,
+ tbf_timer_t3195_cb,
+ tbf_timer_t3197_cb,
+ tbf_timer_t3199_cb,
+};
gprs_rlcmac_bts *gprs_rlcmac_tbf::bts_data() const
{
@@ -85,7 +135,7 @@ gprs_rlcmac_ul_tbf *tbf_alloc_ul(struct gprs_rlcmac_bts *bts,
tbf->ta = ta; /* use current TA */
tbf->set_state(GPRS_RLCMAC_ASSIGN);
tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_PACCH);
- tbf_timer_start(tbf, 3169, bts->t3169, 0);
+ tbf_timer_start(tbf, GPRS_RLCMAC_T3169, bts->t3169, 0);
return tbf;
}
@@ -127,7 +177,7 @@ void tbf_free(struct gprs_rlcmac_tbf *tbf)
"assignment message never gets transmitted. Please "
"be sure not to free in this state. PLEASE FIX!\n",
tbf_name(tbf));
- tbf->stop_timer();
+ tbf->stop_timers();
#warning "TODO: Could/Should generate bssgp_tx_llc_discarded"
tbf->m_llc.clear(tbf->bts);
tbf_unlink_pdch(tbf);
@@ -188,38 +238,58 @@ const char *gprs_rlcmac_tbf::tbf_state_name[] = {
"RELEASING",
};
-void tbf_timer_start(struct gprs_rlcmac_tbf *tbf, unsigned int T,
+static const char *timer_no[GPRS_RLCMAC_TMAX] = {
+ "Tassign",
+ "T3169",
+ "T3191",
+ "T3193",
+ "T3195",
+ "T3197",
+ "T3199"
+};
+
+void tbf_timer_start(struct gprs_rlcmac_tbf *tbf, enum gprs_rlcmac_tbf_timer_type type,
unsigned int seconds, unsigned int microseconds)
{
- if (!osmo_timer_pending(&tbf->timer))
- LOGP(DRLCMAC, LOGL_DEBUG, "%s starting timer %u.\n",
- tbf_name(tbf), T);
+ if (type < 0 || type > GPRS_RLCMAC_TMAX)
+ return;
+ if (!osmo_timer_pending(&tbf->timer[type]))
+ LOGP(DRLCMAC, LOGL_DEBUG, "%s starting timer %s.\n",
+ tbf_name(tbf), timer_no[type]);
else
- LOGP(DRLCMAC, LOGL_DEBUG, "%s restarting timer %u "
- "while old timer %u pending \n",
- tbf_name(tbf), T, tbf->T);
+ LOGP(DRLCMAC, LOGL_DEBUG, "%s restarting timer %s "
+ "while old timer pending \n",
+ tbf_name(tbf), timer_no[type]);
- tbf->T = T;
- tbf->num_T_exp = 0;
+ /* Running timers can be safely re-scheduled. */
+ tbf->timer[type].data = tbf;
+ tbf->timer[type].cb = tbf_timer_cb[type];
- /* Tunning timers can be safely re-scheduled. */
- tbf->timer.data = tbf;
- tbf->timer.cb = &tbf_timer_cb;
-
- osmo_timer_schedule(&tbf->timer, seconds, microseconds);
+ osmo_timer_schedule(&tbf->timer[type], seconds, microseconds);
}
void gprs_rlcmac_tbf::stop_t3191()
{
- return stop_timer();
+ return stop_timer(GPRS_RLCMAC_T3191);
+}
+
+void gprs_rlcmac_tbf::stop_timer(enum gprs_rlcmac_tbf_timer_type type)
+{
+ if (type < 0 || type > GPRS_RLCMAC_TMAX)
+ return;
+ if (osmo_timer_pending(&timer[type])) {
+ LOGP(DRLCMAC, LOGL_DEBUG, "%s stopping timer %s.\n",
+ tbf_name(this), timer_no[type]);
+ osmo_timer_del(&timer[type]);
+ }
}
-void gprs_rlcmac_tbf::stop_timer()
+void gprs_rlcmac_tbf::stop_timers()
{
- if (osmo_timer_pending(&timer)) {
- LOGP(DRLCMAC, LOGL_DEBUG, "%s stopping timer %u.\n",
- tbf_name(this), T);
- osmo_timer_del(&timer);
+ unsigned int i;
+
+ for (i = 0; i < GPRS_RLCMAC_TMAX; i++) {
+ stop_timer((enum gprs_rlcmac_tbf_timer_type)i);
}
}
@@ -245,7 +315,7 @@ void gprs_rlcmac_tbf::poll_timeout()
LOGP(DRLCMAC, LOGL_NOTICE,
"- N3103 exceeded\n");
ul_tbf->set_state(GPRS_RLCMAC_RELEASING);
- tbf_timer_start(ul_tbf, 3169, ul_tbf->bts->bts_data()->t3169, 0);
+ tbf_timer_start(ul_tbf, GPRS_RLCMAC_T3169, ul_tbf->bts->bts_data()->t3169, 0);
return;
}
/* reschedule UL ack */
@@ -264,7 +334,7 @@ void gprs_rlcmac_tbf::poll_timeout()
if (n3105 == bts_data()->n3105) {
LOGP(DRLCMAC, LOGL_NOTICE, "- N3105 exceeded\n");
set_state(GPRS_RLCMAC_RELEASING);
- tbf_timer_start(this, 3195, bts_data()->t3195, 0);
+ tbf_timer_start(this, GPRS_RLCMAC_T3195, bts_data()->t3195, 0);
return;
}
/* reschedule UL assignment */
@@ -282,7 +352,7 @@ void gprs_rlcmac_tbf::poll_timeout()
if (n3105 == bts->bts_data()->n3105) {
LOGP(DRLCMAC, LOGL_NOTICE, "- N3105 exceeded\n");
set_state(GPRS_RLCMAC_RELEASING);
- tbf_timer_start(this, 3195, bts_data()->t3195, 0);
+ tbf_timer_start(this, GPRS_RLCMAC_T3195, bts_data()->t3195, 0);
return;
}
/* reschedule DL assignment */
@@ -300,7 +370,7 @@ void gprs_rlcmac_tbf::poll_timeout()
if (dl_tbf->n3105 == dl_tbf->bts->bts_data()->n3105) {
LOGP(DRLCMAC, LOGL_NOTICE, "- N3105 exceeded\n");
dl_tbf->set_state(GPRS_RLCMAC_RELEASING);
- tbf_timer_start(dl_tbf, 3195, dl_tbf->bts_data()->t3195, 0);
+ tbf_timer_start(dl_tbf, GPRS_RLCMAC_T3195, dl_tbf->bts_data()->t3195, 0);
return;
}
/* resend IMM.ASS on CCCH on timeout */
@@ -430,69 +500,62 @@ struct gprs_rlcmac_dl_tbf *tbf_alloc_dl_tbf(struct gprs_rlcmac_bts *bts,
return tbf;
}
-static void tbf_timer_cb(void *_tbf)
+void gprs_rlcmac_tbf::handle_assignment_timeout()
{
- struct gprs_rlcmac_tbf *tbf = (struct gprs_rlcmac_tbf *)_tbf;
- tbf->handle_timeout();
-}
+ if ((state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH))) {
+ if (state_is(GPRS_RLCMAC_ASSIGN)) {
+ LOGP(DRLCMAC, LOGL_NOTICE, "%s releasing due to "
+ "PACCH assignment timeout.\n", tbf_name(this));
+ tbf_free(this);
+ return;
+ } else
+ LOGP(DRLCMAC, LOGL_ERROR, "Error: %s is not "
+ "in assign state\n", tbf_name(this));
+ }
+ if ((state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH))) {
+ gprs_rlcmac_dl_tbf *dl_tbf = static_cast<gprs_rlcmac_dl_tbf *>(this);
+ dl_tbf->m_wait_confirm = 0;
+ if (dl_tbf->state_is(GPRS_RLCMAC_ASSIGN)) {
+ tbf_assign_control_ts(dl_tbf);
+
+ if (!dl_tbf->upgrade_to_multislot) {
+ /* change state to FLOW, so scheduler
+ * will start transmission */
+ dl_tbf->set_state(GPRS_RLCMAC_FLOW);
+ return;
+ }
-void gprs_rlcmac_tbf::handle_timeout()
-{
- LOGP(DRLCMAC, LOGL_DEBUG, "%s timer %u expired.\n",
- tbf_name(this), T);
+ /* This tbf can be upgraded to use multiple DL
+ * timeslots and now that there is already one
+ * slot assigned send another DL assignment via
+ * PDCH. */
- num_T_exp++;
+ /* keep to flags */
+ dl_tbf->state_flags &= GPRS_RLCMAC_FLAG_TO_MASK;
+ dl_tbf->state_flags &= ~(1 << GPRS_RLCMAC_FLAG_CCCH);
- switch (T) {
- case 0: /* assignment */
- if ((state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH))) {
- if (state_is(GPRS_RLCMAC_ASSIGN)) {
- LOGP(DRLCMAC, LOGL_NOTICE, "%s releasing due to "
- "PACCH assignment timeout.\n", tbf_name(this));
- tbf_free(this);
- return;
- } else
- LOGP(DRLCMAC, LOGL_ERROR, "Error: %s is not "
- "in assign state\n", tbf_name(this));
- }
- if ((state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH))) {
- gprs_rlcmac_dl_tbf *dl_tbf = static_cast<gprs_rlcmac_dl_tbf *>(this);
- dl_tbf->m_wait_confirm = 0;
- if (dl_tbf->state_is(GPRS_RLCMAC_ASSIGN)) {
- tbf_assign_control_ts(dl_tbf);
-
- if (!dl_tbf->upgrade_to_multislot) {
- /* change state to FLOW, so scheduler
- * will start transmission */
- dl_tbf->set_state(GPRS_RLCMAC_FLOW);
- break;
- }
-
- /* This tbf can be upgraded to use multiple DL
- * timeslots and now that there is already one
- * slot assigned send another DL assignment via
- * PDCH. */
-
- /* keep to flags */
- dl_tbf->state_flags &= GPRS_RLCMAC_FLAG_TO_MASK;
- dl_tbf->state_flags &= ~(1 << GPRS_RLCMAC_FLAG_CCCH);
-
- dl_tbf->update();
-
- dl_tbf->bts->trigger_dl_ass(dl_tbf, dl_tbf, NULL);
- } else
- LOGP(DRLCMAC, LOGL_NOTICE, "%s Continue flow after "
- "IMM.ASS confirm\n", tbf_name(dl_tbf));
- }
- break;
- case 3169:
- case 3191:
- case 3195:
- LOGP(DRLCMAC, LOGL_NOTICE, "%s T%d timeout during "
- "transsmission\n", tbf_name(this), T);
+ dl_tbf->update();
+
+ dl_tbf->bts->trigger_dl_ass(dl_tbf, dl_tbf, NULL);
+ } else
+ LOGP(DRLCMAC, LOGL_NOTICE, "%s Continue flow after "
+ "IMM.ASS confirm\n", tbf_name(dl_tbf));
+ }
+}
+void gprs_rlcmac_tbf::handle_timeout(enum gprs_rlcmac_tbf_timer_type type)
+{
+ LOGP(DRLCMAC, LOGL_DEBUG, "%s timer %s expired.\n",
+ tbf_name(this), timer_no[type]);
+
+ switch (type) {
+ case GPRS_RLCMAC_T3169:
+ case GPRS_RLCMAC_T3191:
+ case GPRS_RLCMAC_T3195:
+ LOGP(DRLCMAC, LOGL_NOTICE, "%s %s timeout during "
+ "transsmission\n", tbf_name(this), timer_no[type]);
rlcmac_diag();
/* fall through */
- case 3193:
+ case GPRS_RLCMAC_T3193:
LOGP(DRLCMAC, LOGL_DEBUG,
"%s will be freed due to timeout\n", tbf_name(this));
/* free TBF */
@@ -501,7 +564,7 @@ void gprs_rlcmac_tbf::handle_timeout()
break;
default:
LOGP(DRLCMAC, LOGL_ERROR,
- "%s timer expired in unknown mode: %u\n", tbf_name(this), T);
+ "%s timer expired in unknown mode: %s\n", tbf_name(this), timer_no[type]);
}
}
@@ -606,7 +669,7 @@ struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn)
new_dl_tbf->set_state(GPRS_RLCMAC_FLOW);
tbf_assign_control_ts(new_dl_tbf);
/* stop pending assignment timer */
- new_dl_tbf->stop_timer();
+ new_dl_tbf->stop_timer(GPRS_RLCMAC_TASSIGN);
}
diff --git a/src/tbf.h b/src/tbf.h
index 69f1f05..67d4b7e 100644
--- a/src/tbf.h
+++ b/src/tbf.h
@@ -75,6 +75,17 @@ enum gprs_rlcmac_tbf_direction {
GPRS_RLCMAC_UL_TBF
};
+enum gprs_rlcmac_tbf_timer_type {
+ GPRS_RLCMAC_TASSIGN,
+ GPRS_RLCMAC_T3169,
+ GPRS_RLCMAC_T3191,
+ GPRS_RLCMAC_T3193,
+ GPRS_RLCMAC_T3195,
+ GPRS_RLCMAC_T3197,
+ GPRS_RLCMAC_T3199,
+ GPRS_RLCMAC_TMAX
+};
+
#define GPRS_RLCMAC_FLAG_CCCH 0 /* assignment on CCCH */
#define GPRS_RLCMAC_FLAG_PACCH 1 /* assignment on PACCH */
#define GPRS_RLCMAC_FLAG_UL_DATA 2 /* uplink data received */
@@ -125,8 +136,10 @@ struct gprs_rlcmac_tbf {
int rlcmac_diag();
int update();
- void handle_timeout();
- void stop_timer();
+ void handle_timeout(enum gprs_rlcmac_tbf_timer_type type);
+ void handle_assignment_timeout();
+ void stop_timer(enum gprs_rlcmac_tbf_timer_type type);
+ void stop_timers();
void stop_t3191();
void poll_timeout();
@@ -177,9 +190,8 @@ struct gprs_rlcmac_tbf {
uint8_t n3105; /* N3105 counter */
- struct osmo_timer_list timer;
- unsigned int T; /* Txxxx number */
- unsigned int num_T_exp; /* number of consecutive T expirations */
+ struct osmo_timer_list timer[GPRS_RLCMAC_TMAX];
+ unsigned int num_T_exp[GPRS_RLCMAC_TMAX]; /* number of consecutive T expirations */
struct osmo_gsm_timer_list gsm_timer;
unsigned int fT; /* fTxxxx number */
@@ -246,7 +258,7 @@ void tbf_free(struct gprs_rlcmac_tbf *tbf);
int tbf_assign_control_ts(struct gprs_rlcmac_tbf *tbf);
-void tbf_timer_start(struct gprs_rlcmac_tbf *tbf, unsigned int T,
+void tbf_timer_start(struct gprs_rlcmac_tbf *tbf, enum gprs_rlcmac_tbf_timer_type type,
unsigned int seconds, unsigned int microseconds);
inline bool gprs_rlcmac_tbf::state_is(enum gprs_rlcmac_tbf_state rhs) const
diff --git a/src/tbf_dl.cpp b/src/tbf_dl.cpp
index feed6c7..41bf2e6 100644
--- a/src/tbf_dl.cpp
+++ b/src/tbf_dl.cpp
@@ -525,7 +525,7 @@ struct msgb *gprs_rlcmac_dl_tbf::create_dl_acked_block(
m_tx_counter = 0;
/* start timer whenever we send the final block */
if (rh->fbi == 1)
- tbf_timer_start(this, 3191, bts_data()->t3191, 0);
+ tbf_timer_start(this, GPRS_RLCMAC_T3191, bts_data()->t3191, 0);
/* schedule polling */
poll_state = GPRS_RLCMAC_POLL_SCHED;
@@ -629,7 +629,7 @@ int gprs_rlcmac_dl_tbf::maybe_start_new_window()
/* no message, start T3193, change state to RELEASE */
LOGP(DRLCMACDL, LOGL_DEBUG, "- No new message, so we release.\n");
/* start T3193 */
- tbf_timer_start(this, 3193,
+ tbf_timer_start(this, GPRS_RLCMAC_T3193,
bts_data()->t3193_msec / 1000,
(bts_data()->t3193_msec % 1000) * 1000);
diff --git a/src/tbf_ul.cpp b/src/tbf_ul.cpp
index 3ab71f0..91e0e9f 100644
--- a/src/tbf_ul.cpp
+++ b/src/tbf_ul.cpp
@@ -300,7 +300,7 @@ int gprs_rlcmac_ul_tbf::rcv_data_block_acknowledged(const uint8_t *data, size_t
}
/* restart T3169 */
- tbf_timer_start(this, 3169, bts_data()->t3169, 0);
+ tbf_timer_start(this, GPRS_RLCMAC_T3169, bts_data()->t3169, 0);
/* Increment RX-counter */
this->m_rx_counter++;
diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err
index 3466370..dc012ed 100644
--- a/tests/tbf/TbfTest.err
+++ b/tests/tbf/TbfTest.err
@@ -71,10 +71,10 @@ Slot Allocation (Algorithm A) for class 45
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) Trigger dowlink assignment on PACCH, because another LLC PDU has arrived in between
Send dowlink assignment on PACCH, because TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) exists
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
-TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) starting timer 0.
+TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) starting timer Tassign.
DL packet loss of IMSI= / TLLI=0x00000000: 0%
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) free
********** TBF ends here **********
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) free
-TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) stopping timer 0.
+TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) stopping timer Tassign.
********** TBF ends here **********