misc: Change the logging for the tbf and what to log
TLLIs got printed as TBF. Fix that but also rename things to
TFI. The TFI is not required to be unique per BTS but it is
the indicator we use right now.
diff --git a/src/bts.cpp b/src/bts.cpp
index f37dcb4..e7bd4a8 100644
--- a/src/bts.cpp
+++ b/src/bts.cpp
@@ -165,14 +165,14 @@
}
/* mark first slot found, if none is marked already */
if (ts == 8 && first_ts >= 0) {
- LOGP(DRLCMAC, LOGL_DEBUG, "- %s TBF=%d uses "
+ LOGP(DRLCMAC, LOGL_DEBUG, "- %s TFI=%d uses "
"TRX=%d TS=%d, so we mark\n",
(tbf->direction == GPRS_RLCMAC_UL_TBF)
? "UL" : "DL",
tbf->tfi, tbf->trx_no, first_ts);
slot_mask[tbf->trx_no] |= (1 << first_ts);
} else
- LOGP(DRLCMAC, LOGL_DEBUG, "- %s TBF=%d uses "
+ LOGP(DRLCMAC, LOGL_DEBUG, "- %s TFI=%d uses "
"already marked TRX=%d TS=%d\n",
(tbf->direction == GPRS_RLCMAC_UL_TBF)
? "UL" : "DL",
@@ -464,7 +464,7 @@
/* check for downlink tbf: */
if (old_tbf) {
LOGP(DRLCMAC, LOGL_DEBUG, "Send dowlink assignment on "
- "PACCH, because %s TBF=%d exists for TLLI=0x%08x\n",
+ "PACCH, because %s TFI=%d exists for TLLI=0x%08x\n",
(old_tbf->direction == GPRS_RLCMAC_UL_TBF)
? "UL" : "DL", old_tbf->tfi, old_tbf->tlli);
old_tbf->dl_ass_state = GPRS_RLCMAC_DL_ASS_SEND_ASS;
@@ -476,7 +476,7 @@
/* start timer */
tbf_timer_start(tbf, 0, Tassign_pacch);
} else {
- LOGP(DRLCMAC, LOGL_DEBUG, "Send dowlink assignment for TBF=%d on PCH, no TBF exist (IMSI=%s)\n", tbf->tfi, imsi);
+ LOGP(DRLCMAC, LOGL_DEBUG, "Send dowlink assignment for TFI=%d on PCH, no TBF exist (IMSI=%s)\n", tbf->tfi, imsi);
if (!imsi || strlen(imsi) < 3) {
LOGP(DRLCMAC, LOGL_ERROR, "No valid IMSI!\n");
return;
@@ -681,13 +681,13 @@
/* find TBF inst from given TFI */
tbf = bts()->tbf_by_tfi(rh->tfi, trx_no(), GPRS_RLCMAC_UL_TBF);
if (!tbf) {
- LOGP(DRLCMACUL, LOGL_NOTICE, "UL DATA unknown TBF=%d\n",
+ LOGP(DRLCMACUL, LOGL_NOTICE, "UL DATA unknown TFI=%d\n",
rh->tfi);
return 0;
}
tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_UL_DATA);
- LOGP(DRLCMACUL, LOGL_DEBUG, "UL DATA TBF=%d received (V(Q)=%d .. "
+ LOGP(DRLCMACUL, LOGL_DEBUG, "UL DATA TFI=%d received (V(Q)=%d .. "
"V(R)=%d)\n", rh->tfi, tbf->dir.ul.v_q, tbf->dir.ul.v_r);
/* process RSSI */
@@ -699,7 +699,7 @@
/* no TLLI yet */
if (!rh->ti) {
- LOGP(DRLCMACUL, LOGL_NOTICE, "UL DATA TBF=%d without "
+ LOGP(DRLCMACUL, LOGL_NOTICE, "UL DATA TFI=%d without "
"TLLI, but no TLLI received yet\n", rh->tfi);
return 0;
}
@@ -707,14 +707,14 @@
if (rc) {
bts()->decode_error();
LOGP(DRLCMACUL, LOGL_NOTICE, "Failed to decode TLLI "
- "of UL DATA TBF=%d.\n", rh->tfi);
+ "of UL DATA TFI=%d.\n", rh->tfi);
return 0;
}
LOGP(DRLCMACUL, LOGL_INFO, "Decoded premier TLLI=0x%08x of "
- "UL DATA TBF=%d.\n", tbf->tlli, rh->tfi);
+ "UL DATA TFI=%d.\n", tbf->tlli, rh->tfi);
if ((dl_tbf = bts()->tbf_by_tlli(tbf->tlli, GPRS_RLCMAC_DL_TBF))) {
LOGP(DRLCMACUL, LOGL_NOTICE, "Got RACH from "
- "TLLI=0x%08x while DL TBF=%d still exists. "
+ "TLLI=0x%08x while DL TFI=%d still exists. "
"Killing pending DL TBF\n", tbf->tlli,
dl_tbf->tfi);
tbf_free(dl_tbf);
@@ -723,7 +723,7 @@
* yet marked valid */
if ((ul_tbf = bts()->tbf_by_tlli(tbf->tlli, GPRS_RLCMAC_UL_TBF))) {
LOGP(DRLCMACUL, LOGL_NOTICE, "Got RACH from "
- "TLLI=0x%08x while UL TBF=%d still exists. "
+ "TLLI=0x%08x while UL TFI=%d still exists. "
"Killing pending UL TBF\n", tbf->tlli,
ul_tbf->tfi);
tbf_free(ul_tbf);
@@ -738,12 +738,12 @@
rc = Decoding::tlli_from_ul_data(data, len, &tlli);
if (rc) {
LOGP(DRLCMACUL, LOGL_NOTICE, "Failed to decode TLLI "
- "of UL DATA TBF=%d.\n", rh->tfi);
+ "of UL DATA TFI=%d.\n", rh->tfi);
return 0;
}
if (tlli != tbf->tlli) {
LOGP(DRLCMACUL, LOGL_NOTICE, "TLLI mismatch on UL "
- "DATA TBF=%d. (Ignoring due to contention "
+ "DATA TFI=%d. (Ignoring due to contention "
"resolution)\n", rh->tfi);
return 0;
}
@@ -876,7 +876,7 @@
tbf = bts()->tbf_by_poll_fn(fn, trx_no(), ts_no);
if (!tbf) {
LOGP(DRLCMAC, LOGL_NOTICE, "PACKET CONTROL ACK with "
- "unknown FN=%u TLL=0x%08x (TRX %d TS %d)\n",
+ "unknown FN=%u TLLI=0x%08x (TRX %d TS %d)\n",
fn, tlli, trx_no(), ts_no);
return;
}
@@ -898,7 +898,7 @@
tbf->state_flags &=
~(1 << GPRS_RLCMAC_FLAG_TO_UL_ACK);
LOGP(DRLCMAC, LOGL_NOTICE, "Recovered uplink "
- "ack for UL TBF=%d\n", tbf->tfi);
+ "ack for UL TFI=%d\n", tbf->tfi);
}
tbf_free(tbf);
return;
@@ -925,7 +925,7 @@
tbf->state_flags &=
~(1 << GPRS_RLCMAC_FLAG_TO_DL_ASS);
LOGP(DRLCMAC, LOGL_NOTICE, "Recovered downlink "
- "assignment for DL TBF=%d\n", tbf->tfi);
+ "assignment for DL TFI=%d\n", tbf->tfi);
}
tbf_assign_control_ts(tbf);
return;
@@ -951,7 +951,7 @@
tbf->state_flags &=
~(1 << GPRS_RLCMAC_FLAG_TO_UL_ASS);
LOGP(DRLCMAC, LOGL_NOTICE, "Recovered uplink "
- "assignment for UL TBF=%d\n", tbf->tfi);
+ "assignment for UL TFI=%d\n", tbf->tfi);
}
tbf_assign_control_ts(tbf);
return;
@@ -983,7 +983,7 @@
if ((tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_TO_DL_ACK))) {
tbf->state_flags &= ~(1 << GPRS_RLCMAC_FLAG_TO_DL_ACK);
LOGP(DRLCMAC, LOGL_NOTICE, "Recovered downlink ack "
- "for DL TBF=%d\n", tbf->tfi);
+ "for DL TFI=%d\n", tbf->tfi);
}
/* reset N3105 */
tbf->n3105 = 0;
@@ -1023,7 +1023,7 @@
tbf = bts()->tbf_by_tlli(tlli, GPRS_RLCMAC_UL_TBF);
if (tbf) {
LOGP(DRLCMACUL, LOGL_NOTICE, "Got RACH from "
- "TLLI=0x%08x while UL TBF=%d still "
+ "TLLI=0x%08x while UL TFI=%d still "
"exists. Killing pending DL TBF\n",
tlli, tbf->tfi);
tbf_free(tbf);
@@ -1036,7 +1036,7 @@
if ((dl_tbf = bts()->tbf_by_tlli(tlli, GPRS_RLCMAC_DL_TBF))) {
LOGP(DRLCMACUL, LOGL_NOTICE, "Got RACH from "
- "TLLI=0x%08x while DL TBF=%d still exists. "
+ "TLLI=0x%08x while DL TFI=%d still exists. "
"Killing pending DL TBF\n", tlli,
dl_tbf->tfi);
tbf_free(dl_tbf);
@@ -1081,14 +1081,14 @@
tfi = request->ID.u.Global_TFI.u.DOWNLINK_TFI;
tbf = bts()->tbf_by_tfi(tfi, trx_no(), GPRS_RLCMAC_DL_TBF);
if (!tbf) {
- LOGP(DRLCMAC, LOGL_NOTICE, "PACKET RESSOURCE REQ unknown downlink TBF=%d\n", tlli);
+ LOGP(DRLCMAC, LOGL_NOTICE, "PACKET RESSOURCE REQ unknown downlink TLLI=0x%08x\n", tlli);
return;
}
} else {
tfi = request->ID.u.Global_TFI.u.UPLINK_TFI;
tbf = bts()->tbf_by_tfi(tfi, trx_no(), GPRS_RLCMAC_UL_TBF);
if (!tbf) {
- LOGP(DRLCMAC, LOGL_NOTICE, "PACKET RESSOURCE REQ unknown uplink TBF=%d\n", tlli);
+ LOGP(DRLCMAC, LOGL_NOTICE, "PACKET RESSOURCE REQ unknown uplink TLLI=%d\n", tlli);
return;
}
}
diff --git a/src/encoding.cpp b/src/encoding.cpp
index e28fff7..2b15a27 100644
--- a/src/encoding.cpp
+++ b/src/encoding.cpp
@@ -366,7 +366,7 @@
uint16_t mod_sns_half = (tbf->sns >> 1) - 1;
char bit;
- LOGP(DRLCMACUL, LOGL_DEBUG, "Sending Ack/Nack for TBF=%d "
+ LOGP(DRLCMACUL, LOGL_DEBUG, "Sending Ack/Nack for TFI=%d "
"(final=%d)\n", tbf->tfi, final);
block->PAYLOAD_TYPE = 0x1; // RLC/MAC control block that does not include the optional octets of the RLC/MAC control header
diff --git a/src/gprs_rlcmac_sched.cpp b/src/gprs_rlcmac_sched.cpp
index 0a290c4..76ddac4 100644
--- a/src/gprs_rlcmac_sched.cpp
+++ b/src/gprs_rlcmac_sched.cpp
@@ -96,7 +96,7 @@
usf = tbf->dir.ul.usf[ts];
LOGP(DRLCMACSCHED, LOGL_DEBUG, "Received RTS for PDCH: TRX=%d "
"TS=%d FN=%d block_nr=%d scheduling USF=%d for "
- "required uplink resource of UL TBF=%d\n", trx, ts, fn,
+ "required uplink resource of UL TFI=%d\n", trx, ts, fn,
block_nr, usf, tfi);
/* next TBF to handle resource is the next one */
pdch->next_ul_tfi = (tfi + 1) & 31;
@@ -134,7 +134,7 @@
/* any message */
if (msg) {
LOGP(DRLCMACSCHED, LOGL_DEBUG, "Scheduling control "
- "message at RTS for %s TBF=%d (TRX=%d, TS=%d)\n",
+ "message at RTS for %s TFI=%d (TRX=%d, TS=%d)\n",
(tbf->direction == GPRS_RLCMAC_UL_TBF)
? "UL" : "DL", tbf->tfi, trx, ts);
return msg;
@@ -178,7 +178,7 @@
continue;
LOGP(DRLCMACSCHED, LOGL_DEBUG, "Scheduling data message at "
- "RTS for DL TBF=%d (TRX=%d, TS=%d)\n", tfi, trx, ts);
+ "RTS for DL TFI=%d (TRX=%d, TS=%d)\n", tfi, trx, ts);
/* next TBF to handle resource is the next one */
pdch->next_dl_tfi = (tfi + 1) & 31;
/* generate DL data block */
diff --git a/src/tbf.cpp b/src/tbf.cpp
index 0a703a1..d66c738 100644
--- a/src/tbf.cpp
+++ b/src/tbf.cpp
@@ -309,7 +309,7 @@
debug_diagram(tbf->bts, tbf->diag, "+---------------+");
debug_diagram(tbf->bts, tbf->diag, "| THE END |");
debug_diagram(tbf->bts, tbf->diag, "+---------------+");
- LOGP(DRLCMAC, LOGL_INFO, "Free %s TBF=%d with TLLI=0x%08x.\n",
+ LOGP(DRLCMAC, LOGL_INFO, "Free %s TFI=%d with TLLI=0x%08x.\n",
(tbf->direction == GPRS_RLCMAC_UL_TBF) ? "UL" : "DL", tbf->tfi,
tbf->tlli);
if (tbf->ul_ass_state != GPRS_RLCMAC_UL_ASS_NONE)
@@ -395,7 +395,7 @@
enum gprs_rlcmac_tbf_state state)
{
debug_diagram(tbf->bts, tbf->diag, "->%s", tbf_state_name[state]);
- LOGP(DRLCMAC, LOGL_DEBUG, "%s TBF=%d changes state from %s to %s\n",
+ LOGP(DRLCMAC, LOGL_DEBUG, "%s TFI=%d changes state from %s to %s\n",
(tbf->direction == GPRS_RLCMAC_UL_TBF) ? "UL" : "DL", tbf->tfi,
tbf_state_name[tbf->state], tbf_state_name[state]);
tbf->set_state(state);
@@ -405,11 +405,11 @@
unsigned int seconds, unsigned int microseconds)
{
if (!osmo_timer_pending(&tbf->timer))
- LOGP(DRLCMAC, LOGL_DEBUG, "Starting %s TBF=%d timer %u.\n",
+ LOGP(DRLCMAC, LOGL_DEBUG, "Starting %s TFI=%d timer %u.\n",
(tbf->direction == GPRS_RLCMAC_UL_TBF) ? "UL" : "DL",
tbf->tfi, T);
else
- LOGP(DRLCMAC, LOGL_DEBUG, "Restarting %s TBF=%d timer %u "
+ LOGP(DRLCMAC, LOGL_DEBUG, "Restarting %s TFI=%d timer %u "
"while old timer %u pending \n",
(tbf->direction == GPRS_RLCMAC_UL_TBF) ? "UL" : "DL",
tbf->tfi, T, tbf->T);
@@ -432,7 +432,7 @@
void gprs_rlcmac_tbf::stop_timer()
{
if (osmo_timer_pending(&timer)) {
- LOGP(DRLCMAC, LOGL_DEBUG, "Stopping %s TBF=%d timer %u.\n",
+ LOGP(DRLCMAC, LOGL_DEBUG, "Stopping %s TFI=%d timer %u.\n",
(direction == GPRS_RLCMAC_UL_TBF) ? "UL" : "DL", tfi, T);
osmo_timer_del(&timer);
}
@@ -440,7 +440,7 @@
void gprs_rlcmac_tbf::poll_timeout()
{
- LOGP(DRLCMAC, LOGL_NOTICE, "Poll timeout for %s TBF=%d\n",
+ LOGP(DRLCMAC, LOGL_NOTICE, "Poll timeout for %s TFI=%d\n",
(direction == GPRS_RLCMAC_UL_TBF) ? "UL" : "DL", tfi);
poll_state = GPRS_RLCMAC_POLL_NONE;
@@ -527,7 +527,7 @@
if ((state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH))
&& !(state_flags & (1 << GPRS_RLCMAC_FLAG_DL_ACK))) {
LOGP(DRLCMAC, LOGL_DEBUG, "Re-send dowlink assignment "
- "for TBF=%d on PCH (IMSI=%s)\n", tfi,
+ "for TFI=%d on PCH (IMSI=%s)\n", tfi,
dir.dl.imsi);
/* send immediate assignment */
bts->snd_dl_ass(this, 0, dir.dl.imsi);
@@ -634,7 +634,7 @@
void gprs_rlcmac_tbf::handle_timeout()
{
- LOGP(DRLCMAC, LOGL_DEBUG, "%s TBF=%d timer %u expired.\n",
+ LOGP(DRLCMAC, LOGL_DEBUG, "%s TFI=%d timer %u expired.\n",
(direction == GPRS_RLCMAC_UL_TBF) ? "UL" : "DL", tfi, T);
num_T_exp++;
@@ -714,7 +714,7 @@
|| (tv_now.tv_sec == tv->tv_sec /* .. or if secs equal .. */
&& tv_now.tv_usec > tv->tv_usec))) { /* .. usecs expired */
LOGP(DRLCMACDL, LOGL_NOTICE, "Discarding LLC PDU of "
- "DL TBF=%d, because lifetime limit reached\n",
+ "DL TFI=%d, because lifetime limit reached\n",
tfi);
bts->timedout_frame();
frames++;
@@ -776,7 +776,7 @@
break;
/* M == 0 and E == 0 is not allowed in this version. */
if (!m && !e) {
- LOGP(DRLCMACUL, LOGL_NOTICE, "UL DATA TBF=%d "
+ LOGP(DRLCMACUL, LOGL_NOTICE, "UL DATA TFI=%d "
"ignored, because M='0' and E='0'.\n",
this->tfi);
return 0;
@@ -856,7 +856,7 @@
/* Check if last offset would exceed frame. */
if (offset > len) {
- LOGP(DRLCMACUL, LOGL_NOTICE, "UL DATA TBF=%d ignored, "
+ LOGP(DRLCMACUL, LOGL_NOTICE, "UL DATA TFI=%d ignored, "
"because LI delimits data that exceeds block size.\n",
this->tfi);
return -EINVAL;
@@ -889,7 +889,7 @@
if (i != frames - 1) {
/* send frame to SGSN */
LOGP(DRLCMACUL, LOGL_INFO, "Complete UL frame for "
- "TBF=%d: len=%d\n", this->tfi, this->llc_index);
+ "TFI=%d: len=%d\n", this->tfi, this->llc_index);
gprs_rlcmac_tx_ul_ud(this);
this->llc_index = 0; /* reset frame space */
/* also check if CV==0, because the frame may fill up the
@@ -899,7 +899,7 @@
} else if (rh->cv == 0) {
/* send frame to SGSN */
LOGP(DRLCMACUL, LOGL_INFO, "Complete UL frame for "
- "TBF=%d that fits precisely in last block: "
+ "TFI=%d that fits precisely in last block: "
"len=%d\n", this->tfi, this->llc_index);
gprs_rlcmac_tx_ul_ud(this);
this->llc_index = 0; /* reset frame space */
@@ -929,7 +929,7 @@
uint16_t space, chunk;
int first_fin_ack = 0;
- LOGP(DRLCMACDL, LOGL_DEBUG, "DL DATA TBF=%d downlink (V(A)==%d .. "
+ LOGP(DRLCMACDL, LOGL_DEBUG, "DL DATA TFI=%d downlink (V(A)==%d .. "
"V(S)==%d)\n", tfi, dir.dl.v_a, dir.dl.v_s);
do_resend:
@@ -1050,7 +1050,7 @@
"this is a final block, we don't add length "
"header, and we are done\n", chunk, space);
LOGP(DRLCMACDL, LOGL_INFO, "Complete DL frame for "
- "TBF=%d that fits precisely in last block: "
+ "TFI=%d that fits precisely in last block: "
"len=%d\n", tfi, llc_length);
gprs_rlcmac_dl_bw(this, llc_length);
/* block is filled, so there is no extension */
@@ -1110,7 +1110,7 @@
memcpy(data, llc_frame + llc_index, chunk);
data += chunk;
space -= chunk;
- LOGP(DRLCMACDL, LOGL_INFO, "Complete DL frame for TBF=%d: "
+ LOGP(DRLCMACDL, LOGL_INFO, "Complete DL frame for TFI=%d: "
"len=%d\n", tfi, llc_length);
gprs_rlcmac_dl_bw(this, llc_length);
/* reset LLC frame */
@@ -1119,7 +1119,7 @@
msg = llc_dequeue(gprs_bssgp_pcu_current_bctx());
if (msg) {
LOGP(DRLCMACDL, LOGL_INFO, "- Dequeue next LLC for "
- "TBF=%d (len=%d)\n", tfi, msg->len);
+ "TFI=%d (len=%d)\n", tfi, msg->len);
update_llc_frame(msg);
msgb_free(msg);
}
@@ -1177,7 +1177,7 @@
/* scheduling not possible, because: */
if (poll_state != GPRS_RLCMAC_POLL_NONE)
LOGP(DRLCMAC, LOGL_DEBUG, "Polling is already "
- "sheduled for TBF=%d, so we must wait for "
+ "sheduled for TFI=%d, so we must wait for "
"requesting downlink ack\n", tfi);
else if (control_ts != ts)
LOGP(DRLCMAC, LOGL_DEBUG, "Polling cannot be "
@@ -1245,7 +1245,7 @@
if (poll_ass_dl) {
if (poll_state != GPRS_RLCMAC_POLL_NONE) {
LOGP(DRLCMAC, LOGL_DEBUG, "Polling is already sheduled "
- "for TBF=%d, so we must wait for downlink "
+ "for TFI=%d, so we must wait for downlink "
"assignment...\n", tfi);
return NULL;
}
@@ -1272,7 +1272,7 @@
new_tbf = this;
if (!new_tbf) {
LOGP(DRLCMACDL, LOGL_ERROR, "We have a schedule for downlink "
- "assignment at uplink TBF=%d, but there is no downlink "
+ "assignment at uplink TFI=%d, but there is no downlink "
"TBF\n", tfi);
dl_ass_state = GPRS_RLCMAC_DL_ASS_NONE;
return NULL;
@@ -1326,7 +1326,7 @@
#if POLLING_ASSIGNMENT_UL == 1
if (poll_state != GPRS_RLCMAC_POLL_NONE) {
LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already "
- "sheduled for TBF=%d, so we must wait for uplink "
+ "sheduled for TFI=%d, so we must wait for uplink "
"assignment...\n", tfi);
return NULL;
}
@@ -1346,7 +1346,7 @@
if (!new_tbf) {
LOGP(DRLCMACUL, LOGL_ERROR, "We have a schedule for uplink "
- "assignment at downlink TBF=%d, but there is no uplink "
+ "assignment at downlink TFI=%d, but there is no uplink "
"TBF\n", tfi);
ul_ass_state = GPRS_RLCMAC_UL_ASS_NONE;
return NULL;
@@ -1398,7 +1398,7 @@
if (final) {
if (poll_state != GPRS_RLCMAC_POLL_NONE) {
LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already "
- "sheduled for TBF=%d, so we must wait for "
+ "sheduled for TFI=%d, so we must wait for "
"final uplink ack...\n", tfi);
return NULL;
}
@@ -1455,7 +1455,7 @@
struct msgb *msg;
uint16_t lost = 0, received = 0;
- LOGP(DRLCMACDL, LOGL_DEBUG, "TBF=%d downlink acknowledge\n", tfi);
+ LOGP(DRLCMACDL, LOGL_DEBUG, "TFI=%d downlink acknowledge\n", tfi);
if (!final) {
/* show received array in debug (bit 64..1) */
@@ -1479,7 +1479,7 @@
* FIXME: we should implement polling for
* control ack!*/
LOGP(DRLCMACDL, LOGL_NOTICE, "- ack range is out of "
- "V(A)..V(S) range (DL TBF=%d) Free TFB!\n", tfi);
+ "V(A)..V(S) range (DL TFI=%d) Free TBF!\n", tfi);
return 1; /* indicate to free TBF */
}
/* SSN - 1 is in range V(A)..V(S)-1 */