[PATCH] Expand RLCMAC diagnostics output

msuraev at sysmocom.de msuraev at sysmocom.de
Thu Feb 25 16:39:15 UTC 2016


From: Max <msuraev at sysmocom.de>

When smth bad happens (e. g. we hit timeout in RLCMAC) on TBF - obtain
corresponding MS object and print extended information about it and its
TBFs to aid troubleshooting. Diagnostic function should not change state
hence make it const with no return value.
---
 src/bts.cpp |  2 +-
 src/tbf.cpp | 89 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++-----
 src/tbf.h   |  2 +-
 3 files changed, 84 insertions(+), 9 deletions(-)

diff --git a/src/bts.cpp b/src/bts.cpp
index 715fb51..75766f1 100644
--- a/src/bts.cpp
+++ b/src/bts.cpp
@@ -1254,7 +1254,7 @@ int gprs_rlcmac_pdch::rcv_control_block(
 	bitvec *rlc_block, uint32_t fn)
 {
 	RlcMacUplink_t * ul_control_block = (RlcMacUplink_t *)talloc_zero(tall_pcu_ctx, RlcMacUplink_t);
-	LOGP(DRLCMAC, LOGL_DEBUG, "+++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++\n");
+	LOGP(DRLCMAC, LOGL_DEBUG, "+++++++++++++++++++++++++ RX : Uplink Control Block on FN = %d ++++++++++++++\n", fn);
 	decode_gsm_rlcmac_uplink(rlc_block, ul_control_block);
 	LOGPC(DCSN1, LOGL_NOTICE, "\n");
 	LOGP(DRLCMAC, LOGL_DEBUG, "------------------------- RX : Uplink Control Block -------------------------\n");
diff --git a/src/tbf.cpp b/src/tbf.cpp
index 69b9e3a..5f81e8b 100644
--- a/src/tbf.cpp
+++ b/src/tbf.cpp
@@ -490,7 +490,7 @@ void gprs_rlcmac_tbf::poll_timeout()
 		if (!(state_flags & (1 << GPRS_RLCMAC_FLAG_TO_UL_ACK))) {
 			LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling "
 				"PACKET CONTROL ACK for PACKET UPLINK ACK\n");
-			rlcmac_diag();
+			rlcmac_diag("POLL TIMEOUT for PACKET CONTROL ACK for PACKET UPLINK ACK");
 			state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_UL_ACK);
 		}
 		ul_ack_state = GPRS_RLCMAC_UL_ACK_NONE;
@@ -514,7 +514,7 @@ void gprs_rlcmac_tbf::poll_timeout()
 			LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling "
 				"PACKET CONTROL ACK for PACKET UPLINK "
 				"ASSIGNMENT.\n");
-			rlcmac_diag();
+			rlcmac_diag("POLL TIMEOUT for PACKET CONTROL ACK for PACKET UPLINK ASSIGNMENT");
 			state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_UL_ASS);
 		}
 		ul_ass_state = GPRS_RLCMAC_UL_ASS_NONE;
@@ -534,7 +534,7 @@ void gprs_rlcmac_tbf::poll_timeout()
 			LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling "
 				"PACKET CONTROL ACK for PACKET DOWNLINK "
 				"ASSIGNMENT.\n");
-			rlcmac_diag();
+			rlcmac_diag("POLL TIMEOUT for PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT");
 			state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_DL_ASS);
 		}
 		dl_ass_state = GPRS_RLCMAC_DL_ASS_NONE;
@@ -555,7 +555,7 @@ void gprs_rlcmac_tbf::poll_timeout()
 		if (!(dl_tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_TO_DL_ACK))) {
 			LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling "
 				"PACKET DOWNLINK ACK.\n");
-			dl_tbf->rlcmac_diag();
+			dl_tbf->rlcmac_diag("POLL TIMEOUT for PACKET DOWNLINK ACK");
 			dl_tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_DL_ACK);
 		}
 		dl_tbf->n3105++;
@@ -872,7 +872,7 @@ void gprs_rlcmac_tbf::handle_timeout()
 	case 3195:
 		LOGP(DRLCMAC, LOGL_NOTICE, "%s T%d timeout during "
 			"transsmission\n", tbf_name(this), T);
-		rlcmac_diag();
+		rlcmac_diag("TRANSMISSION TIMEOUT");
 		/* fall through */
 	case 3193:
 		LOGP(DRLCMAC, LOGL_DEBUG,
@@ -887,8 +887,33 @@ void gprs_rlcmac_tbf::handle_timeout()
 	}
 }
 
-int gprs_rlcmac_tbf::rlcmac_diag()
+static inline void print_tbf_diag(const struct gprs_rlcmac_tbf * t, bool uplink)
 {
+	const char * d = uplink ? "UL" : "DL";
+
+	LOGP(DRLCMAC, LOGL_NOTICE, "- MS %s %s\n", d, t->name());
+	LOGP(DRLCMAC, LOGL_NOTICE, "- MS %s TBF 1st TS = %d, 1st common TS = %d, ctrl TS = %d\n",
+		d, t->first_ts, t->first_common_ts, t->control_ts);
+	LOGP(DRLCMAC, LOGL_NOTICE, "- MS %s TBF TSC = %d, DL: "OSMO_BIT_SPEC", UL: "OSMO_BIT_SPEC", mslot upgradeable: %d\n",
+		d, t->tsc(), OSMO_BIT_PRINT(t->dl_slots()), OSMO_BIT_PRINT(t->ul_slots()), t->upgrade_to_multislot);
+
+	unsigned i;
+	for (i = 0; i < 8; i++)
+		if (t->pdch[i])
+			if (t->pdch[i]->is_enabled())
+				LOGP(DRLCMAC, LOGL_NOTICE, "- MS %s PDCH[%d] USF = %d, last RTS FN = %d, TSC = %d, TS = %d\n",
+					d, i, t->pdch[i]->assigned_usf(), t->pdch[i]->last_rts_fn, t->pdch[i]->tsc, t->pdch[i]->ts_no);
+
+	if (GPRS_RLCMAC_POLL_SCHED == t->poll_state)
+		LOGP(DRLCMAC, LOGL_NOTICE, "- MS %s TBF poll. scheduled: FN = %d, TS = %d\n", d, t->poll_fn, t->poll_ts);
+	else
+		LOGP(DRLCMAC, LOGL_NOTICE, "- MS %s TBF no polling\n", d);
+}
+
+void gprs_rlcmac_tbf::rlcmac_diag(const char * context) const
+{
+	GprsMs * m = ms();
+	LOGP(DRLCMAC, LOGL_NOTICE, "- RLCMAC diag. report for %s:\n", context);
 	if ((state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH)))
 		LOGP(DRLCMAC, LOGL_NOTICE, "- Assignment was on CCCH\n");
 	if ((state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH)))
@@ -902,7 +927,57 @@ int gprs_rlcmac_tbf::rlcmac_diag()
 	else if (direction == GPRS_RLCMAC_DL_TBF)
 		LOGP(DRLCMAC, LOGL_NOTICE, "- No downlink ACK received yet\n");
 
-	return 0;
+	if (is_tfi_assigned())
+		LOGP(DRLCMAC, LOGL_NOTICE, "- TBF's TFI = %d\n", tfi());
+	else
+		LOGP(DRLCMAC, LOGL_NOTICE, "- No TFI is assigned to this TBF yet\n");
+
+	if (is_tlli_valid())
+		LOGP(DRLCMAC, LOGL_NOTICE, "- TBF's TLLI = 0x%x\n", tlli());
+	else
+		LOGP(DRLCMAC, LOGL_NOTICE, "- No TLLI is assigned to this TBF yet\n");
+
+	LOGP(DRLCMAC, LOGL_NOTICE, "- MS IMSI = %s, GPRS class = %d, EGPRS class = %d, TA = %d, TLLI = 0x%x\n",
+		m->imsi(), m->ms_class(), m->egprs_ms_class(), m->ta(), m->tlli());
+	LOGP(DRLCMAC, LOGL_NOTICE, "- MS 1st common TS = %d, current PACCH = %d\n",
+		m->first_common_ts(), m->current_pacch_slots());
+	LOGP(DRLCMAC, LOGL_NOTICE, "- MS DL: "OSMO_BIT_SPEC" (RSRVD: "OSMO_BIT_SPEC"), UL: "OSMO_BIT_SPEC" (RSRVD: "OSMO_BIT_SPEC")\n",
+		OSMO_BIT_PRINT(m->dl_slots()), OSMO_BIT_PRINT(m->reserved_dl_slots()), OSMO_BIT_PRINT(m->ul_slots()), OSMO_BIT_PRINT(m->reserved_ul_slots()));
+
+	if (m->is_idle())
+		LOGP(DRLCMAC, LOGL_NOTICE, "- MS id idle\n");
+	if (m->need_dl_tbf())
+		LOGP(DRLCMAC, LOGL_NOTICE, "- MS needs DL TBF\n");
+
+	if (m->dl_tbf()) {
+		struct gprs_rlcmac_dl_tbf * dl = m->dl_tbf();
+		print_tbf_diag(dl, false);
+
+		if (m->dl_tbf()->need_control_ts())
+			LOGP(DRLCMAC, LOGL_NOTICE, "- MS DL TBF needs ctrl TS\n");
+
+		if (m->dl_tbf()->have_data())
+			LOGP(DRLCMAC, LOGL_NOTICE, "- MS DL TBF have data\n");
+	} else
+		LOGP(DRLCMAC, LOGL_NOTICE, "- MS have no DL TBF\n");
+
+	if (m->ul_tbf()) {
+		struct gprs_rlcmac_ul_tbf * ul = m->ul_tbf();
+		print_tbf_diag(ul, true);
+
+		LOGP(DRLCMAC, LOGL_NOTICE, "- MS UL TBF USF: %d %d %d %d %d %d %d %d\n",
+			m->ul_tbf()->m_usf[0],
+			m->ul_tbf()->m_usf[1],
+			m->ul_tbf()->m_usf[2],
+			m->ul_tbf()->m_usf[3],
+			m->ul_tbf()->m_usf[4],
+			m->ul_tbf()->m_usf[5],
+			m->ul_tbf()->m_usf[6],
+			m->ul_tbf()->m_usf[7]);
+	} else
+		LOGP(DRLCMAC, LOGL_NOTICE, "- MS have no UL TBF\n");
+
+	LOGP(DRLCMAC, LOGL_NOTICE, "- RLCMAC diag. report complete\n\n");
 }
 
 struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn, uint8_t ts)
diff --git a/src/tbf.h b/src/tbf.h
index ad8ad4c..b556e0c 100644
--- a/src/tbf.h
+++ b/src/tbf.h
@@ -112,7 +112,7 @@ struct gprs_rlcmac_tbf {
 
 	uint8_t tsc() const;
 
-	int rlcmac_diag();
+	void rlcmac_diag(const char * context) const;
 
 	int update();
 	void handle_timeout();
-- 
2.7.2




More information about the osmocom-net-gprs mailing list