From bcf125c524482a442fd27938036a18f9bcc6e265 Mon Sep 17 00:00:00 2001 From: Holger Hans Peter Freyther Date: Wed, 14 Nov 2012 06:07:47 +0100 Subject: smr: Introduce an id and prefix all log messages with SMR(ID) When OpenBSC is handling more than one message at a time it is difficult to see which log message belongs to which SMR instance. Introduce a uint64_t id that can be set to the row_id/message_id and prefix all log messages with SMR(ID). This change is ABI and API incompatible with previous versions of libosmogsm. --- src/gsm/gsm0411_smr.c | 99 +++++++++++++++++++++++++++++++++++---------------- 1 file changed, 68 insertions(+), 31 deletions(-) (limited to 'src') diff --git a/src/gsm/gsm0411_smr.c b/src/gsm/gsm0411_smr.c index 7dd8f723..61ffacf3 100644 --- a/src/gsm/gsm0411_smr.c +++ b/src/gsm/gsm0411_smr.c @@ -49,6 +49,7 @@ #include #include +#include #include #include #include @@ -59,16 +60,19 @@ #include #include +#define SMR_LOG_STR "SMR(%" PRIu64 ") " + static void rp_timer_expired(void *data); /* init a new instance */ -void gsm411_smr_init(struct gsm411_smr_inst *inst, int network, +void gsm411_smr_init(struct gsm411_smr_inst *inst, uint64_t id, int network, int (*rl_recv) (struct gsm411_smr_inst *inst, int msg_type, struct msgb *msg), int (*mn_send) (struct gsm411_smr_inst *inst, int msg_type, struct msgb *msg)) { memset(inst, 0, sizeof(*inst)); + inst->id = id; inst->network = network; inst->rp_state = GSM411_RPS_IDLE; inst->rl_recv = rl_recv; @@ -76,13 +80,16 @@ void gsm411_smr_init(struct gsm411_smr_inst *inst, int network, inst->rp_timer.data = inst; inst->rp_timer.cb = rp_timer_expired; - LOGP(DLSMS, LOGL_INFO, "New SMR instance created\n"); + LOGP(DLSMS, LOGL_INFO, + SMR_LOG_STR "instance created for %d\n", + inst->id, inst->network); } /* clear instance */ void gsm411_smr_clear(struct gsm411_smr_inst *inst) { - LOGP(DLSMS, LOGL_INFO, "Clear SMR instance\n"); + LOGP(DLSMS, LOGL_INFO, + SMR_LOG_STR "clearing SMR instance\n", inst->id); osmo_timer_del(&inst->rp_timer); } @@ -127,7 +134,8 @@ const struct value_string gsm411_rp_cause_strs[] = { static void new_rp_state(struct gsm411_smr_inst *inst, enum gsm411_rp_state state) { - LOGP(DLSMS, LOGL_INFO, "New RP state %s -> %s\n", + LOGP(DLSMS, LOGL_INFO, + SMR_LOG_STR "new RP state %s -> %s\n", inst->id, smr_state_names[inst->rp_state], smr_state_names[state]); inst->rp_state = state; @@ -160,8 +168,9 @@ static int gsm411_send_rp_error(struct gsm411_smr_inst *inst, msgb_tv_put(msg, 1, cause); - LOGP(DLSMS, LOGL_NOTICE, "TX: SMS RP ERROR, cause %d (%s)\n", cause, - get_value_string(gsm411_rp_cause_strs, cause)); + LOGP(DLSMS, LOGL_NOTICE, + SMR_LOG_STR "TX: SMS RP ERROR, cause %d (%s)\n", inst->id, + cause, get_value_string(gsm411_rp_cause_strs, cause)); return gsm411_rp_sendmsg(inst, msg, (inst->network) ? GSM411_MT_RP_ERROR_MT : GSM411_MT_RP_ERROR_MO, @@ -172,7 +181,8 @@ static int gsm411_send_release(struct gsm411_smr_inst *inst) { struct msgb *msg = gsm411_msgb_alloc(); - LOGP(DLSMS, LOGL_DEBUG, "TX: MNSMS-REL-REQ\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "TX: MNSMS-REL-REQ\n", inst->id); return inst->mn_send(inst, GSM411_MNSMS_REL_REQ, msg); } @@ -181,8 +191,10 @@ static int gsm411_send_abort(struct gsm411_smr_inst *inst) { struct msgb *msg = gsm411_msgb_alloc(); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "TX: MNSMS-ABORT-REQ\n", inst->id); + msgb_tv_put(msg, 1, 111); //FIXME: better idea ? */ - LOGP(DLSMS, LOGL_DEBUG, "TX: MNSMS-ABORT-REQ\n"); return inst->mn_send(inst, GSM411_MNSMS_ABORT_REQ, msg); } @@ -191,14 +203,16 @@ static int gsm411_send_report(struct gsm411_smr_inst *inst) { struct msgb *msg = gsm411_msgb_alloc(); - LOGP(DLSMS, LOGL_DEBUG, "Sending empty SM_RL_REPORT_IND\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "Sending empty SM_RL_REPORT_IND\n", inst->id); return inst->rl_recv(inst, GSM411_SM_RL_REPORT_IND, msg); } static int gsm411_rl_data_req(struct gsm411_smr_inst *inst, struct msgb *msg) { - LOGP(DLSMS, LOGL_DEBUG, "TX SMS RP-DATA\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "TX SMS RP-DATA\n", inst->id); /* start TR1N and enter 'wait for RP-ACK state' */ osmo_timer_schedule(&inst->rp_timer, GSM411_TMR_TR1M); new_rp_state(inst, GSM411_RPS_WAIT_FOR_RP_ACK); @@ -208,7 +222,8 @@ static int gsm411_rl_data_req(struct gsm411_smr_inst *inst, struct msgb *msg) static int gsm411_rl_report_req(struct gsm411_smr_inst *inst, struct msgb *msg) { - LOGP(DLSMS, LOGL_DEBUG, "TX SMS REPORT\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "TX SMS REPORT\n", inst->id); new_rp_state(inst, GSM411_RPS_IDLE); inst->mn_send(inst, GSM411_MNSMS_DATA_REQ, msg); @@ -225,7 +240,9 @@ static int gsm411_mnsms_est_ind(struct gsm411_smr_inst *inst, struct msgb *msg) /* check direction */ if (inst->network == (msg_type & 1)) { - LOGP(DLSMS, LOGL_NOTICE, "Invalid RP type 0x%02x\n", msg_type); + LOGP(DLSMS, LOGL_NOTICE, + SMR_LOG_STR "Invalid RP type 0x%02x\n", + inst->id, msg_type); gsm411_send_rp_error(inst, rp_data->msg_ref, GSM411_RP_CAUSE_MSG_INCOMP_STATE); new_rp_state(inst, GSM411_RPS_IDLE); @@ -236,21 +253,25 @@ static int gsm411_mnsms_est_ind(struct gsm411_smr_inst *inst, struct msgb *msg) switch (msg_type) { case GSM411_MT_RP_DATA_MT: case GSM411_MT_RP_DATA_MO: - LOGP(DLSMS, LOGL_DEBUG, "RX SMS RP-DATA\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "RX SMS RP-DATA\n", inst->id); /* start TR2N and enter 'wait to send RP-ACK state' */ osmo_timer_schedule(&inst->rp_timer, GSM411_TMR_TR2M); new_rp_state(inst, GSM411_RPS_WAIT_TO_TX_RP_ACK); rc = inst->rl_recv(inst, GSM411_SM_RL_DATA_IND, msg); break; case GSM411_MT_RP_SMMA_MO: - LOGP(DLSMS, LOGL_DEBUG, "RX SMS RP-SMMA\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "RX SMS RP-SMMA\n", inst->id); /* start TR2N and enter 'wait to send RP-ACK state' */ osmo_timer_schedule(&inst->rp_timer, GSM411_TMR_TR2M); new_rp_state(inst, GSM411_RPS_WAIT_TO_TX_RP_ACK); rc = inst->rl_recv(inst, GSM411_SM_RL_DATA_IND, msg); break; default: - LOGP(DLSMS, LOGL_NOTICE, "Invalid RP type 0x%02x\n", msg_type); + LOGP(DLSMS, LOGL_NOTICE, + SMR_LOG_STR "invalid RP type 0x%02x\n", + inst->id, msg_type); gsm411_send_rp_error(inst, rp_data->msg_ref, GSM411_RP_CAUSE_MSGTYPE_NOTEXIST); new_rp_state(inst, GSM411_RPS_IDLE); @@ -271,7 +292,9 @@ static int gsm411_mnsms_data_ind_tx(struct gsm411_smr_inst *inst, /* check direction */ if (inst->network == (msg_type & 1)) { - LOGP(DLSMS, LOGL_NOTICE, "Invalid RP type 0x%02x\n", msg_type); + LOGP(DLSMS, LOGL_NOTICE, + SMR_LOG_STR "invalid RP type 0x%02x\n", + inst->id, msg_type); gsm411_send_rp_error(inst, rp_data->msg_ref, GSM411_RP_CAUSE_MSG_INCOMP_STATE); new_rp_state(inst, GSM411_RPS_IDLE); @@ -282,20 +305,24 @@ static int gsm411_mnsms_data_ind_tx(struct gsm411_smr_inst *inst, switch (msg_type) { case GSM411_MT_RP_ACK_MO: case GSM411_MT_RP_ACK_MT: - LOGP(DLSMS, LOGL_DEBUG, "RX SMS RP-ACK\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "RX SMS RP-ACK\n", inst->id); new_rp_state(inst, GSM411_RPS_IDLE); inst->rl_recv(inst, GSM411_SM_RL_REPORT_IND, msg); gsm411_send_release(inst); return 0; case GSM411_MT_RP_ERROR_MO: case GSM411_MT_RP_ERROR_MT: - LOGP(DLSMS, LOGL_DEBUG, "RX SMS RP-ERROR\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "RX SMS RP-ERROR\n", inst->id); new_rp_state(inst, GSM411_RPS_IDLE); inst->rl_recv(inst, GSM411_SM_RL_REPORT_IND, msg); gsm411_send_release(inst); return 0; default: - LOGP(DLSMS, LOGL_NOTICE, "Invalid RP type 0x%02x\n", msg_type); + LOGP(DLSMS, LOGL_NOTICE, + SMR_LOG_STR "Invalid RP type 0x%02x\n", + inst->id, msg_type); gsm411_send_rp_error(inst, rp_data->msg_ref, GSM411_RP_CAUSE_MSGTYPE_NOTEXIST); new_rp_state(inst, GSM411_RPS_IDLE); @@ -309,7 +336,8 @@ static int gsm411_mnsms_data_ind_tx(struct gsm411_smr_inst *inst, static int gsm411_mnsms_error_ind_tx(struct gsm411_smr_inst *inst, struct msgb *msg) { - LOGP(DLSMS, LOGL_DEBUG, "RX SMS MNSMS-ERROR-IND\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "RX SMS MNSMS-ERROR-IND\n", inst->id); new_rp_state(inst, GSM411_RPS_IDLE); inst->rl_recv(inst, GSM411_SM_RL_REPORT_IND, msg); gsm411_send_release(inst); @@ -319,7 +347,8 @@ static int gsm411_mnsms_error_ind_tx(struct gsm411_smr_inst *inst, static int gsm411_mnsms_error_ind_rx(struct gsm411_smr_inst *inst, struct msgb *msg) { - LOGP(DLSMS, LOGL_DEBUG, "RX SMS MNSMS-ERROR-IND\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "RX SMS MNSMS-ERROR-IND\n", inst->id); new_rp_state(inst, GSM411_RPS_IDLE); return inst->rl_recv(inst, GSM411_SM_RL_REPORT_IND, msg); } @@ -328,11 +357,13 @@ static int gsm411_mnsms_error_ind_rx(struct gsm411_smr_inst *inst, static void rp_timer_expired(void *data) { struct gsm411_smr_inst *inst = data; + const char *str; + + str = inst->rp_state == GSM411_RPS_WAIT_TO_TX_RP_ACK + ? "TR2N" : "TR1N"; - if (inst->rp_state == GSM411_RPS_WAIT_TO_TX_RP_ACK) - LOGP(DLSMS, LOGL_DEBUG, "TR2N\n"); - else - LOGP(DLSMS, LOGL_DEBUG, "TR1N\n"); + LOGP(DLSMS, LOGL_DEBUG, + SMR_LOG_STR "%s expired\n", inst->id, str); gsm411_send_report(inst); gsm411_send_abort(inst); } @@ -372,13 +403,16 @@ int gsm411_smr_send(struct gsm411_smr_inst *inst, int msg_type, break; } if (i == SMRDOWNSLLEN) { - LOGP(DLSMS, LOGL_NOTICE, "Message %u unhandled at this state " - "%s.\n", msg_type, smr_state_names[inst->rp_state]); + LOGP(DLSMS, LOGL_NOTICE, + SMR_LOG_STR "message %u unhandled at this state " + "%s.\n", inst->id, msg_type, + smr_state_names[inst->rp_state]); msgb_free(msg); return 0; } - LOGP(DLSMS, LOGL_INFO, "Message %s received in state %s\n", + LOGP(DLSMS, LOGL_INFO, + SMR_LOG_STR "message %s received in state %s\n", inst->id, smrdownstatelist[i].name, smr_state_names[inst->rp_state]); rc = smrdownstatelist[i].rout(inst, msg); @@ -437,12 +471,15 @@ int gsm411_smr_recv(struct gsm411_smr_inst *inst, int msg_type, break; } if (i == SMRDATASLLEN) { - LOGP(DLSMS, LOGL_NOTICE, "Message %u unhandled at this state " - "%s.\n", msg_type, smr_state_names[inst->rp_state]); + LOGP(DLSMS, LOGL_NOTICE, + SMR_LOG_STR "message %u unhandled at this state " + "%s.\n", inst->id, msg_type, + smr_state_names[inst->rp_state]); return 0; } - LOGP(DLSMS, LOGL_INFO, "Message %s received in state %s\n", + LOGP(DLSMS, LOGL_INFO, + SMR_LOG_STR "message %s received in state %s\n", inst->id, smrdatastatelist[i].name, smr_state_names[inst->rp_state]); rc = smrdatastatelist[i].rout(inst, msg); -- cgit v1.2.3