smc: Introduce an id and prefix all log messages with SMC(ID)
When OpenBSC is handling more than one message at a time it is difficult
to see which log message belongs to which SMC. Introduce a uint64_t id
that can be set to the row_id/message_id and prefix all log messages
with SMC(ID).
This change is ABI and API incompatible with previous versions of
libosmogsm.
Example:
SMC(100) instance created
SMC(100) message MNSMS-EST-REQ received in state IDLE
diff --git a/include/osmocom/gsm/gsm0411_smc.h b/include/osmocom/gsm/gsm0411_smc.h
index 2140db4..239ee13 100644
--- a/include/osmocom/gsm/gsm0411_smc.h
+++ b/include/osmocom/gsm/gsm0411_smc.h
@@ -24,6 +24,7 @@
#define GSM411_MNSMS_REL_REQ 0x107
struct gsm411_smc_inst {
+ uint64_t id; /* a unique id for the SMS */
int network; /* is this a MO (0) or MT (1) transfer */
int (*mn_recv) (struct gsm411_smc_inst *inst, int msg_type,
struct msgb *msg);
@@ -43,7 +44,7 @@
extern const struct value_string gsm411_cp_cause_strs[];
/* init a new instance */
-void gsm411_smc_init(struct gsm411_smc_inst *inst, int network,
+void gsm411_smc_init(struct gsm411_smc_inst *inst, uint64_t id, int network,
int (*mn_recv) (struct gsm411_smc_inst *inst, int msg_type,
struct msgb *msg),
int (*mm_send) (struct gsm411_smc_inst *inst, int msg_type,
diff --git a/src/gsm/gsm0411_smc.c b/src/gsm/gsm0411_smc.c
index 4152ef1..57431ef 100644
--- a/src/gsm/gsm0411_smc.c
+++ b/src/gsm/gsm0411_smc.c
@@ -50,6 +50,7 @@
*/
#include <string.h>
+#include <inttypes.h>
#include <errno.h>
#include <osmocom/core/msgb.h>
#include <osmocom/core/logging.h>
@@ -63,14 +64,17 @@
#define MAX_SMS_RETRY 2
+#define SMC_LOG_STR "SMC(%" PRIu64 ") "
+
/* init a new instance */
-void gsm411_smc_init(struct gsm411_smc_inst *inst, int network,
+void gsm411_smc_init(struct gsm411_smc_inst *inst, uint64_t id, int network,
int (*mn_recv) (struct gsm411_smc_inst *inst, int msg_type,
struct msgb *msg),
int (*mm_send) (struct gsm411_smc_inst *inst, int msg_type,
struct msgb *msg, int cp_msg_type))
{
memset(inst, 0, sizeof(*inst));
+ inst->id = id;
inst->network = network;
inst->cp_max_retr = MAX_SMS_RETRY;
inst->cp_tc1 = GSM411_TMR_TC1A_SEC / (inst->cp_max_retr + 1);
@@ -78,19 +82,22 @@
inst->mn_recv = mn_recv;
inst->mm_send = mm_send;
- LOGP(DLSMS, LOGL_INFO, "New SMC instance created\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "instance created\n", inst->id);
}
/* clear instance */
void gsm411_smc_clear(struct gsm411_smc_inst *inst)
{
- LOGP(DLSMS, LOGL_INFO, "Clear SMC instance\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "clearing instance\n", inst->id);
osmo_timer_del(&inst->cp_timer);
/* free stored msg */
if (inst->cp_msg) {
- LOGP(DLSMS, LOGL_INFO, "Dropping pending message\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "dropping pending message\n", inst->id);
msgb_free(inst->cp_msg);
inst->cp_msg = NULL;
}
@@ -120,7 +127,8 @@
static void new_cp_state(struct gsm411_smc_inst *inst,
enum gsm411_cp_state state)
{
- LOGP(DLSMS, LOGL_INFO, "New CP state %s -> %s\n",
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "new CP state %s -> %s\n", inst->id,
smc_state_names[inst->cp_state], smc_state_names[state]);
inst->cp_state = state;
}
@@ -130,7 +138,8 @@
struct msgb *nmsg = gsm411_msgb_alloc();
uint8_t *causep;
- LOGP(DLSMS, LOGL_NOTICE, "TX CP-ERROR, cause %d (%s)\n", cause,
+ LOGP(DLSMS, LOGL_NOTICE,
+ SMC_LOG_STR "TX CP-ERROR, cause %d (%s)\n", inst->id, cause,
get_value_string(gsm411_cp_cause_strs, cause));
causep = msgb_put(nmsg, 1);
@@ -146,8 +155,10 @@
struct msgb *nmsg;
if (inst->cp_msg) {
- LOGP(DLSMS, LOGL_FATAL, "EST REQ, but we already have an "
- "cp_msg. This should never happen, please fix!\n");
+ LOGP(DLSMS, LOGL_FATAL,
+ SMC_LOG_STR "EST REQ, but we already have an "
+ "cp_msg. This should never happen, please fix!\n",
+ inst->id);
msgb_free(inst->cp_msg);
}
@@ -164,7 +175,8 @@
{
struct msgb *nmsg;
- LOGP(DLSMS, LOGL_INFO, "Send CP data\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "send CP data\n", inst->id);
/* reset retry counter */
if (inst->cp_state != GSM411_CPS_WAIT_CP_ACK)
inst->cp_retx = 0;
@@ -187,8 +199,10 @@
static int gsm411_mmsms_est_cnf(struct gsm411_smc_inst *inst, struct msgb *msg)
{
if (!inst->cp_msg) {
- LOGP(DLSMS, LOGL_FATAL, "EST CNF, but we have no cp_msg. This "
- "should never happen, please fix!\n");
+ LOGP(DLSMS, LOGL_FATAL,
+ SMC_LOG_STR "EST CNF, but we have no cp_msg. This "
+ "should never happen, please fix!\n",
+ inst->id);
return -EINVAL;
}
@@ -203,7 +217,9 @@
if (inst->cp_retx == inst->cp_max_retr) {
- LOGP(DLSMS, LOGL_INFO, "TC1* timeout, no more retries.\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "TC1* timeout, no more retries.\n",
+ inst->id);
/* 5.3.2.1: enter idle state */
new_cp_state(inst, GSM411_CPS_IDLE);
/* indicate error */
@@ -221,7 +237,8 @@
return;
}
- LOGP(DLSMS, LOGL_INFO, "TC1* timeout, retrying...\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "TC1* timeout, retrying...\n", inst->id);
inst->cp_retx++;
gsm411_mmsms_est_cnf(inst, NULL);
}
@@ -234,7 +251,8 @@
inst->cp_msg = NULL;
}
- LOGP(DLSMS, LOGL_INFO, "Received CP-ACK\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "received CP-ACK\n", inst->id);
/* 5.3.2.1 enter MM Connection established */
new_cp_state(inst, GSM411_CPS_MM_ESTABLISHED);
/* 5.3.2.1: Reset Timer TC1* */
@@ -244,7 +262,9 @@
if (inst->cp_rel) {
struct msgb *nmsg;
- LOGP(DLSMS, LOGL_INFO, "We have pending release.\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "we have pending release.\n",
+ inst->id);
new_cp_state(inst, GSM411_CPS_IDLE);
/* release MM connection */
nmsg = gsm411_msgb_alloc();
@@ -259,7 +279,8 @@
struct msgb *nmsg;
int mt = GSM411_MNSMS_DATA_IND;
- LOGP(DLSMS, LOGL_INFO, "Received CP-DATA\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "received CP-DATA\n", inst->id);
/* 5.3.1 enter MM Connection established (if idle) */
if (inst->cp_state == GSM411_CPS_IDLE) {
new_cp_state(inst, GSM411_CPS_MM_ESTABLISHED);
@@ -280,8 +301,10 @@
static int gsm411_mnsms_data_req(struct gsm411_smc_inst *inst, struct msgb *msg)
{
if (inst->cp_msg) {
- LOGP(DLSMS, LOGL_FATAL, "DATA REQ, but we already have an "
- "cp_msg. This should never happen, please fix!\n");
+ LOGP(DLSMS, LOGL_FATAL,
+ SMC_LOG_STR "DATA REQ, but we already have an "
+ "cp_msg. This should never happen, please fix!\n",
+ inst->id);
msgb_free(inst->cp_msg);
}
@@ -304,8 +327,8 @@
/* store release, until established or released */
if (inst->cp_state != GSM411_CPS_MM_ESTABLISHED) {
LOGP(DLSMS, LOGL_NOTICE,
- "Cannot release yet current state: %s\n",
- smc_state_names[inst->cp_state]);
+ SMC_LOG_STR "cannot release yet current state: %s\n",
+ inst->id, smc_state_names[inst->cp_state]);
inst->cp_rel = 1;
return 0;
}
@@ -332,7 +355,8 @@
inst->cp_msg = NULL;
}
- LOGP(DLSMS, LOGL_INFO, "Received CP-ERROR\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "received CP-ERROR\n", inst->id);
/* 5.3.4 enter idle */
new_cp_state(inst, GSM411_CPS_IDLE);
/* indicate error */
@@ -352,7 +376,8 @@
inst->cp_msg = NULL;
}
- LOGP(DLSMS, LOGL_INFO, "MM layer is released\n");
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "MM layer is released\n", inst->id);
/* 5.3.4 enter idle */
new_cp_state(inst, GSM411_CPS_IDLE);
/* indicate error */
@@ -429,13 +454,15 @@
break;
}
if (i == SMCDOWNSLLEN) {
- LOGP(DLSMS, LOGL_NOTICE, "Message %u unhandled at this state "
- "%s.\n", msg_type, smc_state_names[inst->cp_state]);
+ LOGP(DLSMS, LOGL_NOTICE,
+ SMC_LOG_STR "message %u unhandled at this state %s.\n",
+ inst->id, msg_type, smc_state_names[inst->cp_state]);
msgb_free(msg);
return 0;
}
- LOGP(DLSMS, LOGL_INFO, "Message %s received in state %s\n",
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "message %s received in state %s\n", inst->id,
smcdownstatelist[i].name, smc_state_names[inst->cp_state]);
rc = smcdownstatelist[i].rout(inst, msg);
@@ -506,15 +533,17 @@
break;
}
if (i == SMCDATASLLEN) {
- LOGP(DLSMS, LOGL_NOTICE, "Message 0x%x/%u unhandled at this "
- "state %s.\n", msg_type, cp_msg_type,
+ LOGP(DLSMS, LOGL_NOTICE,
+ SMC_LOG_STR "message 0x%x/%u unhandled at this "
+ "state %s.\n", inst->id, msg_type, cp_msg_type,
smc_state_names[inst->cp_state]);
if (msg_type == GSM411_MMSMS_EST_IND
|| msg_type == GSM411_MMSMS_DATA_IND) {
struct msgb *nmsg;
- LOGP(DLSMS, LOGL_NOTICE, "RX Unimplemented CP "
- "msg_type: 0x%02x\n", msg_type);
+ LOGP(DLSMS, LOGL_NOTICE,
+ SMC_LOG_STR "RX Unimplemented CP "
+ "msg_type: 0x%02x\n", inst->id, msg_type);
/* 5.3.4 enter idle */
new_cp_state(inst, GSM411_CPS_IDLE);
/* indicate error */
@@ -532,7 +561,8 @@
return 0;
}
- LOGP(DLSMS, LOGL_INFO, "Message %s received in state %s\n",
+ LOGP(DLSMS, LOGL_INFO,
+ SMC_LOG_STR "message %s received in state %s\n", inst->id,
smcdatastatelist[i].name, smc_state_names[inst->cp_state]);
rc = smcdatastatelist[i].rout(inst, msg);