From 69d3c26e43101475202643cf48e87b9c4789348c Mon Sep 17 00:00:00 2001 From: Neels Hofmeyr Date: Mon, 11 Apr 2016 20:22:46 +0200 Subject: cosmetic: debug and error logging, comment tweaks --- openbsc/src/libiu/iu.c | 25 ++++++++++++++++++++++++- openbsc/src/libmsc/gsm_04_11.c | 4 ++++ openbsc/src/libmsc/gsm_subscriber.c | 8 +++++++- openbsc/src/libmsc/iu_cs.c | 1 + openbsc/src/osmo-cscn/cscn_main.c | 4 ++-- 5 files changed, 38 insertions(+), 4 deletions(-) diff --git a/openbsc/src/libiu/iu.c b/openbsc/src/libiu/iu.c index b3e489dc1..0c00e7fb5 100644 --- a/openbsc/src/libiu/iu.c +++ b/openbsc/src/libiu/iu.c @@ -445,6 +445,8 @@ static void cn_ranap_handle_co(void *ctx, ranap_message *message) rc = ranap_handle_co_iu_rel_req(ctx, &message->msg.iu_ReleaseRequestIEs); break; default: + LOGP(DRANAP, LOGL_ERROR, "Received Initiating Message: unknown Procedure Code %d\n", + message->procedureCode); rc = -1; break; } @@ -460,8 +462,14 @@ static void cn_ranap_handle_co(void *ctx, ranap_message *message) /* Iu Release Complete */ LOGP(DRANAP, LOGL_NOTICE, "FIXME: Handle Iu release complete\n"); rc = global_iu_event_cb(ctx, IU_EVENT_IU_RELEASE, NULL); + if (rc) { + LOGP(DRANAP, LOGL_ERROR, "Iu Release event: Iu Event callback returned %d\n", + rc); + } break; default: + LOGP(DRANAP, LOGL_ERROR, "Received Successful Outcome: unknown Procedure Code %d\n", + message->procedureCode); rc = -1; break; } @@ -474,6 +482,8 @@ static void cn_ranap_handle_co(void *ctx, ranap_message *message) } case RANAP_RANAP_PDU_PR_unsuccessfulOutcome: default: + LOGP(DRANAP, LOGL_ERROR, "Received Unsuccessful Outcome: Procedure Code %d\n", + message->procedureCode); rc = -1; break; } @@ -564,6 +574,14 @@ static int iu_page(const char *imsi, const uint32_t *tmsi_or_ptimsi, struct iu_rnc *rnc; int pagings_sent = 0; + LOGP(DRANAP, LOGL_DEBUG, "%s: Looking for RNCs to page for IMSI %s" + " (paging will use %s)\n", + is_ps? "IuPS" : "IuCS", + imsi, + tmsi_or_ptimsi ? (is_ps? "PTMSI" : "TMSI") + : "IMSI" + ); + llist_for_each_entry(rnc, &rnc_list, entry) { if (!rnc->link) { /* Not actually connected, don't count it. */ @@ -576,8 +594,13 @@ static int iu_page(const char *imsi, const uint32_t *tmsi_or_ptimsi, /* Found a match! */ if (iu_tx_paging_cmd(rnc->link, imsi, tmsi_or_ptimsi, is_ps, 0) - == 0) + == 0) { + LOGP(DRANAP, LOGL_DEBUG, + "%s: Paged for IMSI %s on RNC %d, on SUA link %p\n", + is_ps? "IuPS" : "IuCS", + imsi, rnc->rnc_id, rnc->link); pagings_sent ++; + } } /* Some logging... */ diff --git a/openbsc/src/libmsc/gsm_04_11.c b/openbsc/src/libmsc/gsm_04_11.c index 796f1056e..45d614a0f 100644 --- a/openbsc/src/libmsc/gsm_04_11.c +++ b/openbsc/src/libmsc/gsm_04_11.c @@ -985,10 +985,14 @@ int gsm411_send_sms_subscr(struct gsm_subscriber *subscr, * if yes, send the SMS this way */ conn = connection_for_subscr(subscr); if (conn) { + LOGP(DLSMS, LOGL_DEBUG, "Sending SMS via already open connection %p to %s\n", + conn, subscr_name(subscr)); return gsm411_send_sms(conn, sms); } /* if not, we have to start paging */ + LOGP(DLSMS, LOGL_DEBUG, "Sending SMS: no connection open, start paging %s\n", + subscr_name(subscr)); res = subscr_request_channel(subscr, RSL_CHANNEED_SDCCH, paging_cb_send_sms, sms); if (!res) { diff --git a/openbsc/src/libmsc/gsm_subscriber.c b/openbsc/src/libmsc/gsm_subscriber.c index 39b544b90..2fd9932e5 100644 --- a/openbsc/src/libmsc/gsm_subscriber.c +++ b/openbsc/src/libmsc/gsm_subscriber.c @@ -188,7 +188,7 @@ struct subscr_request *subscr_request_channel(struct gsm_subscriber *subscr, /* Start paging.. we know it is async so we can do it before */ if (!subscr->is_paging) { - LOGP(DMM, LOGL_DEBUG, "Subscriber %s not paged yet.\n", + LOGP(DMM, LOGL_DEBUG, "Subscriber %s not paged yet, start paging.\n", subscr_name(subscr)); rc = msc_paging_request(subscr->group->net, subscr, channel_type, subscr_paging_cb, subscr); @@ -200,6 +200,12 @@ struct subscr_request *subscr_request_channel(struct gsm_subscriber *subscr, /* reduced on the first paging callback */ subscr_get(subscr); subscr->is_paging = 1; + LOGP(DMM, LOGL_DEBUG, "Paged subscriber %s.\n", + subscr_name(subscr)); + } + else { + LOGP(DMM, LOGL_DEBUG, "Subscriber %s already paged.\n", + subscr_name(subscr)); } /* TODO: Stop paging in case of memory allocation failure */ diff --git a/openbsc/src/libmsc/iu_cs.c b/openbsc/src/libmsc/iu_cs.c index 863a67893..391e577f1 100644 --- a/openbsc/src/libmsc/iu_cs.c +++ b/openbsc/src/libmsc/iu_cs.c @@ -60,6 +60,7 @@ static inline void log_subscribers(struct gsm_network *network) break; case IFACE_A: DEBUGPC(DIUCS, " A"); + /* TODO log A-interface connection details */ break; case IFACE_UNKNOWN: DEBUGPC(DIUCS, " ?"); diff --git a/openbsc/src/osmo-cscn/cscn_main.c b/openbsc/src/osmo-cscn/cscn_main.c index de651f4ed..2031c12c2 100644 --- a/openbsc/src/osmo-cscn/cscn_main.c +++ b/openbsc/src/osmo-cscn/cscn_main.c @@ -332,7 +332,7 @@ static int rcvmsg_iu_cs(struct msgb *msg, struct gprs_ra_id *ra_id, /* FIXME gpr static int rx_iu_event(struct ue_conn_ctx *ctx, enum iu_event_type type, void *data) { - DEBUGP(DIUCS, "got Iu-CS event %u\n", type); + DEBUGP(DIUCS, "got IuCS event %u\n", type); return iucs_rx_ranap_event(cscn_network, ctx, type, data); } @@ -489,7 +489,7 @@ TODO: we probably want some of the _net_ ctrl commands from bsc_base_ctrl_cmds_i /* Set up A-Interface */ /* TODO: implement A-Interface and remove above legacy stuff. */ - /* Set up Iu-CS */ + /* Set up IuCS */ iu_init(tall_cscn_ctx, "127.0.0.1", 14001, rcvmsg_iu_cs, rx_iu_event); if (cscn_cmdline_config.daemonize) { -- cgit v1.2.3