Improve TBF logging
use a format in tbf::name() which is sanitized (osmo_sanitize) and hence
can be used both in regular log as well as for its internal FSM ids.
Until now, the FSMs contained a small amount of information with
different formatting than the regular LOGPTFB(), which made it difficult
to grep or follow a TBF through its lifetime looking at logs. The new
unified format makes that a lot easier.
Extra information is now printed if available, such as IMSI.
Furthermore, the TFI is updated to include BTS and TRX, since the TFI is
unique within the scope of a TRX.
Change-Id: I3ce1f53942a2f881d0adadd6e5643f5cdf6e31da
diff --git a/src/gprs_ms.c b/src/gprs_ms.c
index f233967..aa410aa 100644
--- a/src/gprs_ms.c
+++ b/src/gprs_ms.c
@@ -473,6 +473,20 @@
ms_unref(old_ms);
}
+/* Apply changes to the TLLI directly, used interally by functions below: */
+static void ms_apply_tlli_change(struct GprsMs *ms, uint32_t tlli)
+{
+ ms->tlli = tlli;
+ ms->new_dl_tlli = GSM_RESERVED_TMSI;
+ ms->new_ul_tlli = GSM_RESERVED_TMSI;
+
+ /* Update TBF FSM names: */
+ if (ms->ul_tbf)
+ tbf_update_state_fsm_name(ul_tbf_as_tbf(ms->ul_tbf));
+ if (ms->dl_tbf)
+ tbf_update_state_fsm_name(dl_tbf_as_tbf(ms->dl_tbf));
+}
+
/* Set/update the MS object TLLI based on knowledge gained from the MS side (Uplink direction) */
void ms_set_tlli(struct GprsMs *ms, uint32_t tlli)
{
@@ -493,9 +507,7 @@
"already confirmed partly\n",
ms->tlli, tlli);
- ms->tlli = tlli;
- ms->new_dl_tlli = GSM_RESERVED_TMSI;
- ms->new_ul_tlli = GSM_RESERVED_TMSI;
+ ms_apply_tlli_change(ms, tlli);
}
/* Set/update the MS object TLLI based on knowledge gained from the SGSN side (Downlink direction) */
@@ -520,9 +532,7 @@
LOGP(DRLCMAC, LOGL_INFO,
"Modifying MS object, TLLI: 0x%08x confirmed\n", tlli);
- ms->tlli = tlli;
- ms->new_dl_tlli = GSM_RESERVED_TMSI;
- ms->new_ul_tlli = GSM_RESERVED_TMSI;
+ ms_apply_tlli_change(ms, tlli);
return true;
}
@@ -565,8 +575,14 @@
/* old_ms may no longer be available here */
}
-
+ /* Store the new IMSI: */
osmo_strlcpy(ms->imsi, imsi, sizeof(ms->imsi));
+
+ /* Update TBF FSM names: */
+ if (ms->ul_tbf)
+ tbf_update_state_fsm_name(ul_tbf_as_tbf(ms->ul_tbf));
+ if (ms->dl_tbf)
+ tbf_update_state_fsm_name(dl_tbf_as_tbf(ms->dl_tbf));
}
uint16_t ms_paging_group(struct GprsMs *ms)
diff --git a/src/tbf.cpp b/src/tbf.cpp
index 0ba0438..39de56b 100644
--- a/src/tbf.cpp
+++ b/src/tbf.cpp
@@ -670,28 +670,35 @@
return tbf ? tbf->name() : "(no TBF)";
}
-const char *gprs_rlcmac_tbf::name() const
+const char *gprs_rlcmac_tbf::name(bool enclousure) const
{
- int8_t tfi = (m_tfi == TBF_TS_UNSET) ? -1 : m_tfi;
- snprintf(m_name_buf, sizeof(m_name_buf) - 1,
- "TBF(TFI=%d TLLI=0x%08x DIR=%s STATE=%s%s)",
- tfi, tlli(),
- direction == GPRS_RLCMAC_UL_TBF ? "UL" : "DL",
- state_name(),
- is_egprs_enabled() ? " EGPRS" : ""
- );
- m_name_buf[sizeof(m_name_buf) - 1] = '\0';
+ struct osmo_strbuf sb = { .buf = m_name_buf, .len = sizeof(m_name_buf) };
+
+ if (enclousure)
+ OSMO_STRBUF_PRINTF(sb, "TBF(");
+ OSMO_STRBUF_PRINTF(sb, "%s", direction == GPRS_RLCMAC_UL_TBF ? "UL" : "DL");
+ if (this->trx) { /* This may not be available during TBF alloc func time */
+ int8_t tfi = (m_tfi == TBF_TS_UNSET) ? -1 : m_tfi;
+ OSMO_STRBUF_PRINTF(sb, ":TFI-%u-%u-%d",
+ this->trx->bts->nr, this->trx->trx_no, tfi);
+ }
+ OSMO_STRBUF_PRINTF(sb, ":STATE-%s:%sGPRS",
+ state_name(), is_egprs_enabled() ? "E" : "");
+ if (m_ms) {
+ uint32_t tlli = ms_tlli(m_ms);
+ if (ms_imsi_is_valid(m_ms))
+ OSMO_STRBUF_PRINTF(sb, ":IMSI-%s", ms_imsi(m_ms));
+ if (tlli != GSM_RESERVED_TMSI)
+ OSMO_STRBUF_PRINTF(sb, ":TLLI-0x%08x", tlli);
+ }
+ if (enclousure)
+ OSMO_STRBUF_PRINTF(sb, ")");
return m_name_buf;
}
void tbf_update_state_fsm_name(struct gprs_rlcmac_tbf *tbf)
{
- char buf[64];
- int8_t tfi = (tbf_tfi(tbf) == TBF_TS_UNSET) ? -1 : tbf_tfi(tbf);
- snprintf(buf, sizeof(buf), "%s-TFI_%d",
- tbf_direction(tbf) == GPRS_RLCMAC_UL_TBF ? "UL" : "DL",
- tfi);
- osmo_identifier_sanitize_buf(buf, NULL, '_');
+ const char *buf = tbf->name(false);
osmo_fsm_inst_update_id(tbf->state_fsm.fi, buf);
osmo_fsm_inst_update_id(tbf->ul_ass_fsm.fi, buf);
diff --git a/src/tbf.h b/src/tbf.h
index 3146ee0..678607b 100644
--- a/src/tbf.h
+++ b/src/tbf.h
@@ -173,7 +173,7 @@
bool check_n_clear(uint8_t state_flag);
const char *state_name() const;
- const char *name() const;
+ const char *name(bool enclousure = true) const;
struct msgb *create_dl_ass(uint32_t fn, uint8_t ts);
@@ -276,7 +276,7 @@
bool m_egprs_enabled;
struct osmo_timer_list Tarr[T_MAX];
uint8_t Narr[N_MAX];
- mutable char m_name_buf[60];
+ mutable char m_name_buf[128];
};
inline bool gprs_rlcmac_tbf::state_is(enum tbf_fsm_states rhs) const