subscr_conn: introduce usage tokens for ref error tracking
When hunting a conn use count bug, it was very hard to figure out who's (not)
using the conn. To ease tracking down this bug and future bugs, explicitly name
what a conn is being reserved for, and track in a bit mask.
Show in the DREF logs what uses and un-uses a conn. See the test expectation
updates, which nicely show how that clarifies the state of the conn in the
logs.
On errors, log them, but don't fail hard: if one conn use/un-use fails, we
don't want to crash the entire MSC before we have to.
Change-Id: I259aa0eec41efebb4c8221275219433eafaa549b
diff --git a/src/libmsc/gsm_04_08.c b/src/libmsc/gsm_04_08.c
index 5fab409..e783b5e 100644
--- a/src/libmsc/gsm_04_08.c
+++ b/src/libmsc/gsm_04_08.c
@@ -2981,7 +2981,7 @@
}
/* Assign conn */
- trans->conn = msc_subscr_conn_get(conn);
+ trans->conn = msc_subscr_conn_get(conn, MSC_CONN_USE_TRANS_CC);
vlr_subscr_put(vsub);
} else {
/* update the subscriber we deal with */
@@ -3133,7 +3133,7 @@
return -ENOMEM;
}
/* Assign transaction */
- trans->conn = msc_subscr_conn_get(conn);
+ trans->conn = msc_subscr_conn_get(conn, MSC_CONN_USE_TRANS_CC);
cm_service_request_concludes(conn, msg);
}
diff --git a/src/libmsc/gsm_04_11.c b/src/libmsc/gsm_04_11.c
index 103c259..50242a6 100644
--- a/src/libmsc/gsm_04_11.c
+++ b/src/libmsc/gsm_04_11.c
@@ -949,7 +949,7 @@
gsm411_smr_init(&trans->sms.smr_inst, 0, 1,
gsm411_rl_recv, gsm411_mn_send);
- trans->conn = msc_subscr_conn_get(conn);
+ trans->conn = msc_subscr_conn_get(conn, MSC_CONN_USE_TRANS_SMS);
new_trans = 1;
cm_service_request_concludes(conn, msg);
@@ -1031,7 +1031,7 @@
gsm411_rl_recv, gsm411_mn_send);
trans->sms.sms = sms;
- trans->conn = msc_subscr_conn_get(conn);
+ trans->conn = msc_subscr_conn_get(conn, MSC_CONN_USE_TRANS_SMS);
/* Hardcode SMSC Originating Address for now */
data = (uint8_t *)msgb_put(msg, 8);
diff --git a/src/libmsc/osmo_msc.c b/src/libmsc/osmo_msc.c
index f807f2a..d55940d 100644
--- a/src/libmsc/osmo_msc.c
+++ b/src/libmsc/osmo_msc.c
@@ -69,14 +69,14 @@
int msc_compl_l3(struct gsm_subscriber_connection *conn,
struct msgb *msg, uint16_t chosen_channel)
{
- msc_subscr_conn_get(conn);
+ msc_subscr_conn_get(conn, MSC_CONN_USE_COMPL_L3);
gsm0408_dispatch(conn, msg);
/* Bump whether the conn wants to be closed */
subscr_conn_bump(conn);
/* If this should be kept, the conn->conn_fsm has placed a use_count */
- msc_subscr_conn_put(conn);
+ msc_subscr_conn_put(conn, MSC_CONN_USE_COMPL_L3);
/* Always return acceptance, because even if the conn was not accepted,
* we assumed ownership of it and the caller shall not interfere with
@@ -104,12 +104,12 @@
/* Receive a DTAP message from BSC */
void msc_dtap(struct gsm_subscriber_connection *conn, uint8_t link_id, struct msgb *msg)
{
- msc_subscr_conn_get(conn);
+ msc_subscr_conn_get(conn, MSC_CONN_USE_DTAP);
gsm0408_dispatch(conn, msg);
/* Bump whether the conn wants to be closed */
subscr_conn_bump(conn);
- msc_subscr_conn_put(conn);
+ msc_subscr_conn_put(conn, MSC_CONN_USE_DTAP);
}
/* Receive an ASSIGNMENT COMPLETE from BSC */
@@ -343,6 +343,7 @@
/* increment the ref-count. Needs to be called by every user */
struct gsm_subscriber_connection *
_msc_subscr_conn_get(struct gsm_subscriber_connection *conn,
+ enum msc_subscr_conn_use balance_token,
const char *file, int line)
{
OSMO_ASSERT(conn);
@@ -350,36 +351,74 @@
if (conn->in_release)
return NULL;
+ if (balance_token != MSC_CONN_USE_UNTRACKED) {
+ uint32_t flag = 1 << balance_token;
+ OSMO_ASSERT(balance_token < 32);
+ if (conn->use_tokens & flag)
+ LOGPSRC(DREF, LOGL_ERROR, file, line,
+ "%s: MSC conn use error: using an already used token: %s\n",
+ vlr_subscr_name(conn->vsub),
+ msc_subscr_conn_use_name(balance_token));
+ conn->use_tokens |= flag;
+ }
+
conn->use_count++;
LOGPSRC(DREF, LOGL_DEBUG, file, line,
- "%s: MSC conn use + 1 == %u\n",
- vlr_subscr_name(conn->vsub), conn->use_count);
+ "%s: MSC conn use + %s == %u (0x%x)\n",
+ vlr_subscr_name(conn->vsub), msc_subscr_conn_use_name(balance_token),
+ conn->use_count, conn->use_tokens);
return conn;
}
/* decrement the ref-count. Once it reaches zero, we release */
void _msc_subscr_conn_put(struct gsm_subscriber_connection *conn,
+ enum msc_subscr_conn_use balance_token,
const char *file, int line)
{
OSMO_ASSERT(conn);
+ if (balance_token != MSC_CONN_USE_UNTRACKED) {
+ uint32_t flag = 1 << balance_token;
+ OSMO_ASSERT(balance_token < 32);
+ if (!(conn->use_tokens & flag))
+ LOGPSRC(DREF, LOGL_ERROR, file, line,
+ "%s: MSC conn use error: freeing an unused token: %s\n",
+ vlr_subscr_name(conn->vsub),
+ msc_subscr_conn_use_name(balance_token));
+ conn->use_tokens &= ~flag;
+ }
+
if (conn->use_count == 0) {
LOGPSRC(DREF, LOGL_ERROR, file, line,
- "%s: MSC conn use - 1 failed: is already 0\n",
- vlr_subscr_name(conn->vsub));
+ "%s: MSC conn use - %s failed: is already 0\n",
+ vlr_subscr_name(conn->vsub),
+ msc_subscr_conn_use_name(balance_token));
return;
}
conn->use_count--;
LOGPSRC(DREF, LOGL_DEBUG, file, line,
- "%s: MSC conn use - 1 == %u\n",
- vlr_subscr_name(conn->vsub), conn->use_count);
+ "%s: MSC conn use - %s == %u (0x%x)\n",
+ vlr_subscr_name(conn->vsub), msc_subscr_conn_use_name(balance_token),
+ conn->use_count, conn->use_tokens);
if (conn->use_count == 0)
msc_subscr_con_free(conn);
}
+const struct value_string msc_subscr_conn_use_names[] = {
+ {MSC_CONN_USE_UNTRACKED, "UNTRACKED"},
+ {MSC_CONN_USE_COMPL_L3, "compl_l3"},
+ {MSC_CONN_USE_DTAP, "dtap"},
+ {MSC_CONN_USE_FSM, "fsm"},
+ {MSC_CONN_USE_TRANS_CC, "trans_cc"},
+ {MSC_CONN_USE_TRANS_SMS, "trans_sms"},
+ {MSC_CONN_USE_TRANS_USSD, "trans_ussd"},
+ {MSC_CONN_USE_SILENT_CALL, "silent_call"},
+ {0, NULL},
+};
+
void msc_stop_paging(struct vlr_subscr *vsub)
{
DEBUGP(DPAG, "Paging can stop for %s\n", vlr_subscr_name(vsub));
diff --git a/src/libmsc/silent_call.c b/src/libmsc/silent_call.c
index 5b19700..b9a8ed9 100644
--- a/src/libmsc/silent_call.c
+++ b/src/libmsc/silent_call.c
@@ -59,7 +59,7 @@
conn->lchan->ts->nr, conn->lchan->ts->trx->arfcn);
#endif
conn->silent_call = 1;
- msc_subscr_conn_get(conn);
+ msc_subscr_conn_get(conn, MSC_CONN_USE_SILENT_CALL);
/* increment lchan reference count */
osmo_signal_dispatch(SS_SCALL, S_SCALL_SUCCESS, &sigdata);
break;
@@ -159,7 +159,7 @@
#endif
conn->silent_call = 0;
- msc_subscr_conn_put(conn);
+ msc_subscr_conn_put(conn, MSC_CONN_USE_SILENT_CALL);
return 0;
}
diff --git a/src/libmsc/subscr_conn.c b/src/libmsc/subscr_conn.c
index 62b7619..0fb4f54 100644
--- a/src/libmsc/subscr_conn.c
+++ b/src/libmsc/subscr_conn.c
@@ -225,7 +225,7 @@
return;
conn->conn_fsm = NULL;
msc_subscr_conn_close(conn, cause);
- msc_subscr_conn_put(conn);
+ msc_subscr_conn_put(conn, MSC_CONN_USE_FSM);
}
int subscr_conn_fsm_timeout(struct osmo_fsm_inst *fi)
@@ -320,7 +320,7 @@
* connection, then in _osmo_fsm_inst_term() the osmo_fsm_inst_free()
* that follows the cleanup() call would run into a double free. */
fi = osmo_fsm_inst_alloc(&subscr_conn_fsm, conn->network,
- msc_subscr_conn_get(conn),
+ msc_subscr_conn_get(conn, MSC_CONN_USE_FSM),
LOGL_DEBUG, id);
if (!fi) {
diff --git a/src/libmsc/transaction.c b/src/libmsc/transaction.c
index 01d69c2..4dcd24d 100644
--- a/src/libmsc/transaction.c
+++ b/src/libmsc/transaction.c
@@ -117,12 +117,16 @@
*/
void trans_free(struct gsm_trans *trans)
{
+ enum msc_subscr_conn_use conn_usage_token = MSC_CONN_USE_UNTRACKED;
+
switch (trans->protocol) {
case GSM48_PDISC_CC:
_gsm48_cc_trans_free(trans);
+ conn_usage_token = MSC_CONN_USE_TRANS_CC;
break;
case GSM48_PDISC_SMS:
_gsm411_sms_trans_free(trans);
+ conn_usage_token = MSC_CONN_USE_TRANS_SMS;
break;
}
@@ -139,7 +143,7 @@
llist_del(&trans->entry);
if (trans->conn)
- msc_subscr_conn_put(trans->conn);
+ msc_subscr_conn_put(trans->conn, conn_usage_token);
trans->conn = NULL;
talloc_free(trans);