pespin has submitted this change. ( https://gerrit.osmocom.org/c/osmo-bsc/+/40705?usp=email )
Change subject: Introduce LOG_MSC log macro ......................................................................
Introduce LOG_MSC log macro
Change-Id: I4f2502eea856b31783eef5b0af8dc41ccfeb9910 --- M include/osmocom/bsc/bsc_msc_data.h M src/osmo-bsc/a_reset.c M src/osmo-bsc/bsc_vty.c M src/osmo-bsc/codec_pref.c M src/osmo-bsc/gsm_08_08.c M src/osmo-bsc/osmo_bsc_bssap.c M src/osmo-bsc/osmo_bsc_msc.c M src/osmo-bsc/osmo_bsc_sigtran.c 8 files changed, 128 insertions(+), 124 deletions(-)
Approvals: Jenkins Builder: Verified pespin: Looks good to me, approved osmith: Looks good to me, but someone else must approve
diff --git a/include/osmocom/bsc/bsc_msc_data.h b/include/osmocom/bsc/bsc_msc_data.h index ae29725..1968aab 100644 --- a/include/osmocom/bsc/bsc_msc_data.h +++ b/include/osmocom/bsc/bsc_msc_data.h @@ -272,4 +272,10 @@ } }
+#define LOG_MSC_CAT(msc, subsys, level, fmt, args...) \ + LOGP(subsys, level, "(msc=%d) " fmt, (msc)->nr, ## args) +#define LOG_MSC(msc, level, fmt, args...) \ + LOG_MSC_CAT(msc, DMSC, level, fmt, ## args) + + #endif diff --git a/src/osmo-bsc/a_reset.c b/src/osmo-bsc/a_reset.c index c2c89e3..64dfa76 100644 --- a/src/osmo-bsc/a_reset.c +++ b/src/osmo-bsc/a_reset.c @@ -42,7 +42,7 @@ static void a_reset_link_up(void *data) { struct bsc_msc_data *msc = data; - LOGP(DMSC, LOGL_NOTICE, "(msc%d) BSSMAP association is up\n", msc->nr); + LOG_MSC(msc, LOGL_NOTICE, "BSSMAP association is up\n"); osmo_stat_item_inc(osmo_stat_item_group_get_item(msc->msc_statg, MSC_STAT_MSC_LINKS_ACTIVE), 1); osmo_stat_item_inc(osmo_stat_item_group_get_item(msc->network->bsc_statg, BSC_STAT_NUM_MSC_CONNECTED), 1); osmo_signal_dispatch(SS_MSC, S_MSC_CONNECTED, msc); @@ -51,7 +51,7 @@ static void a_reset_link_lost(void *data) { struct bsc_msc_data *msc = data; - LOGP(DMSC, LOGL_NOTICE, "(msc%d) BSSMAP association is down\n", msc->nr); + LOG_MSC(msc, LOGL_NOTICE, "BSSMAP association is down\n"); osmo_stat_item_dec(osmo_stat_item_group_get_item(msc->msc_statg, MSC_STAT_MSC_LINKS_ACTIVE), 1); osmo_stat_item_dec(osmo_stat_item_group_get_item(msc->network->bsc_statg, BSC_STAT_NUM_MSC_CONNECTED), 1); osmo_signal_dispatch(SS_MSC, S_MSC_LOST, msc); @@ -74,7 +74,7 @@
/* There must not be any double allocation! */ if (msc->a.bssmap_reset) { - LOGP(DMSC, LOGL_ERROR, "(msc%d) will not allocate a second reset FSM for this MSC\n", msc->nr); + LOG_MSC(msc, LOGL_ERROR, "will not allocate a second reset FSM for this MSC\n"); return; }
diff --git a/src/osmo-bsc/bsc_vty.c b/src/osmo-bsc/bsc_vty.c index 52ad6b3..e9dabf9 100644 --- a/src/osmo-bsc/bsc_vty.c +++ b/src/osmo-bsc/bsc_vty.c @@ -1189,8 +1189,8 @@ #define NRI_ARGS_TO_STR_FMT "%s%s%s" #define NRI_ARGS_TO_STR_ARGS(ARGC, ARGV) ARGV[0], (ARGC>1)? ".." : "", (ARGC>1)? ARGV[1] : "" #define NRI_WARN(MSC, FORMAT, args...) do { \ - vty_out(vty, "%% Warning: msc %d: " FORMAT "%s", MSC->nr, ##args, VTY_NEWLINE); \ - LOGP(DMSC, LOGL_ERROR, "msc %d: " FORMAT "\n", MSC->nr, ##args); \ + vty_out(vty, "%% Warning: msc %d: " FORMAT "%s", (MSC)->nr, ##args, VTY_NEWLINE); \ + LOG_MSC(MSC, LOGL_ERROR, FORMAT "\n", ##args); \ } while (0)
DEFUN_ATTR(cfg_net_nri_bitlen, @@ -3613,7 +3613,7 @@ return CMD_WARNING; }
- LOGP(DMSC, LOGL_NOTICE, "(msc%d) VTY requests BSSMAP RESET\n", msc_nr); + LOG_MSC(msc, LOGL_NOTICE, "VTY requests BSSMAP RESET\n"); bssmap_reset_resend_reset(msc->a.bssmap_reset); return CMD_SUCCESS; } diff --git a/src/osmo-bsc/codec_pref.c b/src/osmo-bsc/codec_pref.c index 454b00b..c0439d7 100644 --- a/src/osmo-bsc/codec_pref.c +++ b/src/osmo-bsc/codec_pref.c @@ -475,9 +475,9 @@ llist_for_each_entry(bts, &msc->network->bts_list, list) { gen_bss_supported_codec_list(&scl, msc, bts); if (scl.len <= 0) { - LOGP(DMSC, LOGL_FATAL, - "codec-support/trx config of BTS %u does not intersect with codec-list of MSC %u\n", - bts->nr, msc->nr); + LOG_MSC(msc, LOGL_FATAL, + "codec-support/trx config of BTS %u does not intersect with codec-list of this MSC\n", + bts->nr); rc = -1; }
@@ -486,9 +486,9 @@ bts_gsm48_ie = (struct gsm48_multi_rate_conf *)&bts->mr_full.gsm48_ie; rc_rate = calc_amr_rate_intersection(NULL, &msc->amr_conf, bts_gsm48_ie); if (rc_rate < 0) { - LOGP(DMSC, LOGL_FATAL, - "network amr tch-f mode config of BTS %u does not intersect with amr-config of MSC %u\n", - bts->nr, msc->nr); + LOG_MSC(msc, LOGL_FATAL, + "network amr tch-f mode config of BTS %u does not intersect with amr-config of this MSC\n", + bts->nr); rc = -1; } } @@ -498,9 +498,9 @@ bts_gsm48_ie = (struct gsm48_multi_rate_conf *)&bts->mr_half.gsm48_ie; rc_rate = calc_amr_rate_intersection(NULL, &msc->amr_conf, bts_gsm48_ie); if (rc_rate < 0) { - LOGP(DMSC, LOGL_FATAL, - "network amr tch-h mode config of BTS %u does not intersect with amr-config of MSC %u\n", - bts->nr, msc->nr); + LOG_MSC(msc, LOGL_FATAL, + "network amr tch-h mode config of BTS %u does not intersect with amr-config of this MSC\n", + bts->nr); rc = -1; } } diff --git a/src/osmo-bsc/gsm_08_08.c b/src/osmo-bsc/gsm_08_08.c index 692e35c..9ad53fe 100644 --- a/src/osmo-bsc/gsm_08_08.c +++ b/src/osmo-bsc/gsm_08_08.c @@ -275,8 +275,8 @@ return NULL; }
- LOGP(DMSC, LOGL_DEBUG, "New subscriber %s: MSC round-robin selects msc %d\n", - osmo_mobile_identity_to_str_c(OTC_SELECT, mi), msc_target->nr); + LOG_MSC(msc_target, LOGL_DEBUG, "round-robin selects this MSC for new subscriber %s\n", + osmo_mobile_identity_to_str_c(OTC_SELECT, mi));
if (is_null_nri) rate_ctr_inc(rate_ctr_group_get_ctr(msc_target->msc_ctrs, MSC_CTR_MSCPOOL_SUBSCR_REATTACH)); diff --git a/src/osmo-bsc/osmo_bsc_bssap.c b/src/osmo-bsc/osmo_bsc_bssap.c index 3c8b194..395fa49 100644 --- a/src/osmo-bsc/osmo_bsc_bssap.c +++ b/src/osmo-bsc/osmo_bsc_bssap.c @@ -69,21 +69,21 @@
rc = osmo_bssap_tlv_parse(&tp, msg->l4h + 1, length - 1); if (rc < 0) - LOGP(DMSC, LOGL_NOTICE, "Failed parsing TLV looking for Osmux support\n"); + LOG_MSC(msc, LOGL_NOTICE, "Failed parsing TLV looking for Osmux support\n");
msc->remote_supports_osmux = !!TLVP_PRESENT(&tp, GSM0808_IE_OSMO_OSMUX_SUPPORT);
if (old_value != msc->remote_supports_osmux) - LOGP(DMSC, LOGL_INFO, "MSC detected AoIP Osmux support changed: %d->%d\n", - old_value, msc->remote_supports_osmux); + LOG_MSC(msc, LOGL_INFO, "MSC detected AoIP Osmux support changed: %d->%d\n", + old_value, msc->remote_supports_osmux); }
static int bssmap_handle_reset_ack(struct bsc_msc_data *msc, struct msgb *msg, unsigned int length) { - LOGP(DMSC, LOGL_NOTICE, "RESET ACK from MSC: %s\n", - osmo_sccp_addr_name(osmo_ss7_instance_find(msc->a.cs7_instance), - &msc->a.msc_addr)); + LOG_MSC(msc, LOGL_NOTICE, "RESET ACK from MSC: %s\n", + osmo_sccp_addr_name(osmo_ss7_instance_find(msc->a.cs7_instance), + &msc->a.msc_addr));
/* Inform the FSM that controls the RESET/RESET-ACK procedure * that we have successfully received the reset-ack message */ @@ -98,14 +98,14 @@ static int bssmap_handle_reset(struct bsc_msc_data *msc, struct msgb *msg, unsigned int length) { - LOGP(DMSC, LOGL_NOTICE, "RESET from MSC: %s\n", - osmo_sccp_addr_name(osmo_ss7_instance_find(msc->a.cs7_instance), - &msc->a.msc_addr)); + LOG_MSC(msc, LOGL_NOTICE, "RESET from MSC: %s\n", + osmo_sccp_addr_name(osmo_ss7_instance_find(msc->a.cs7_instance), + &msc->a.msc_addr));
update_msc_osmux_support(msc, msg, length);
if (!msc->a.bssmap_reset) { - LOGP(DMSC, LOGL_ERROR, "(msc%d) missing RESET FSM\n", msc->nr); + LOG_MSC(msc, LOGL_ERROR, "(msc%d) missing RESET FSM\n", msc->nr); /* Make sure to shut down all open connections, if any */ osmo_bsc_sigtran_reset(msc); return -1; @@ -277,22 +277,22 @@ };
if (osmo_bssap_tlv_parse(&tp, msg->l4h + 1, payload_length - 1) < 0) { - LOGP(DMSC, LOGL_ERROR, "%s(): tlv_parse() failed\n", __func__); + LOG_MSC(msc, LOGL_ERROR, "%s(): tlv_parse() failed\n", __func__); return -1; } remain = payload_length - 1;
if (!TLVP_PRESENT(&tp, GSM0808_IE_IMSI)) { - LOGP(DMSC, LOGL_ERROR, "Mandatory IMSI not present.\n"); + LOG_MSC(msc, LOGL_ERROR, "Mandatory IMSI not present.\n"); return -1; } else if ((TLVP_VAL(&tp, GSM0808_IE_IMSI)[0] & GSM_MI_TYPE_MASK) != GSM_MI_TYPE_IMSI) { - LOGP(DMSC, LOGL_ERROR, "Wrong content in the IMSI\n"); + LOG_MSC(msc, LOGL_ERROR, "Wrong content in the IMSI\n"); return -1; } remain -= TLVP_LEN(&tp, GSM0808_IE_IMSI);
if (!TLVP_PRESENT(&tp, GSM0808_IE_CELL_IDENTIFIER_LIST)) { - LOGP(DMSC, LOGL_ERROR, "Mandatory CELL IDENTIFIER LIST not present.\n"); + LOG_MSC(msc, LOGL_ERROR, "Mandatory CELL IDENTIFIER LIST not present.\n"); return -1; }
@@ -303,7 +303,7 @@ }
if (remain <= 0) { - LOGP(DMSC, LOGL_ERROR, "Payload too short.\n"); + LOG_MSC(msc, LOGL_ERROR, "Payload too short.\n"); return -1; }
@@ -312,7 +312,7 @@ */ if (osmo_mobile_identity_decode(&paging.imsi, TLVP_VAL(&tp, GSM0808_IE_IMSI), TLVP_LEN(&tp, GSM0808_IE_IMSI), false) || paging.imsi.type != GSM_MI_TYPE_IMSI) { - LOGP(DMSC, LOGL_ERROR, "Paging: could not parse IMSI\n"); + LOG_MSC(msc, LOGL_ERROR, "Paging: could not parse IMSI\n"); return -1; }
@@ -749,15 +749,13 @@ struct gsm_subscriber_connection *conn, struct gsm_bts *bts) { int rc, i, nc = 0; - struct bsc_msc_data *msc; + struct bsc_msc_data *msc = conn->sccp.msc;
if (!bts) { - LOGP(DMSC, LOGL_ERROR, "No lchan, cannot select codecs\n"); + LOG_MSC(msc, LOGL_ERROR, "No lchan, cannot select codecs\n"); return -EINVAL; }
- msc = conn->sccp.msc; - switch (ct->ch_rate_type) { case GSM0808_SPEECH_FULL_BM: rc = match_codec_pref(&req->ch_mode_rate_list[nc], ct, &conn->codec_list, msc, bts, @@ -795,21 +793,21 @@ }
if (!nc) { - LOGP(DMSC, LOGL_ERROR, "No supported audio type found for channel_type =" - " { ch_indctr=0x%x, ch_rate_type=0x%x, perm_spch=[%s] }\n", - ct->ch_indctr, ct->ch_rate_type, osmo_hexdump(ct->perm_spch, ct->perm_spch_len)); + LOG_MSC(msc, LOGL_ERROR, "No supported audio type found for channel_type =" + " { ch_indctr=0x%x, ch_rate_type=0x%x, perm_spch=[%s] }\n", + ct->ch_indctr, ct->ch_rate_type, osmo_hexdump(ct->perm_spch, ct->perm_spch_len)); /* TODO: actually output codec names, e.g. implement * gsm0808_permitted_speech_names[] and iterate perm_spch. */ return -EINVAL; }
for (i = 0; i < nc; i++ ) { - DEBUGP(DMSC, "Found matching audio type (pref=%d): %s %s for channel_type =" - " { ch_indctr=0x%x, ch_rate_type=0x%x, perm_spch=[ %s] }\n", - i, - req->ch_mode_rate_list[i].chan_rate == CH_RATE_FULL ? "full rate" : "half rate", - get_value_string(gsm48_chan_mode_names, req->ch_mode_rate_list[i].chan_mode), - ct->ch_indctr, ct->ch_rate_type, osmo_hexdump(ct->perm_spch, ct->perm_spch_len)); + LOG_MSC(msc, LOGL_DEBUG, "Found matching audio type (pref=%d): %s %s for channel_type =" + " { ch_indctr=0x%x, ch_rate_type=0x%x, perm_spch=[ %s] }\n", + i, + req->ch_mode_rate_list[i].chan_rate == CH_RATE_FULL ? "full rate" : "half rate", + get_value_string(gsm48_chan_mode_names, req->ch_mode_rate_list[i].chan_mode), + ct->ch_indctr, ct->ch_rate_type, osmo_hexdump(ct->perm_spch, ct->perm_spch_len)); }
req->n_ch_mode_rate = nc; @@ -933,10 +931,11 @@ bool *use_osmux, uint8_t *osmux_cid, uint8_t *cause) { int rc; + struct bsc_msc_data *msc = conn->sccp.msc;
if (TLVP_PRESENT(tp, GSM0808_IE_OSMO_OSMUX_CID)) { - if (conn->sccp.msc->use_osmux == OSMUX_USAGE_OFF) { - LOGP(DMSC, LOGL_ERROR, "MSC using Osmux but we have it disabled.\n"); + if (msc->use_osmux == OSMUX_USAGE_OFF) { + LOG_MSC(msc, LOGL_ERROR, "MSC using Osmux but we have it disabled.\n"); *cause = GSM0808_CAUSE_INCORRECT_VALUE; return -1; } @@ -945,21 +944,21 @@ TLVP_VAL(tp, GSM0808_IE_OSMO_OSMUX_CID), TLVP_LEN(tp, GSM0808_IE_OSMO_OSMUX_CID)); if (rc < 0) { - LOGP(DMSC, LOGL_ERROR, "Unable to decode Osmux CID.\n"); + LOG_MSC(msc, LOGL_ERROR, "Unable to decode Osmux CID.\n"); *cause = GSM0808_CAUSE_INCORRECT_VALUE; return -1; } return 0; }
- if (conn->sccp.msc->use_osmux == OSMUX_USAGE_ONLY) { - LOGP(DMSC, LOGL_ERROR, "MSC not using Osmux but we are forced to use it.\n"); + if (msc->use_osmux == OSMUX_USAGE_ONLY) { + LOG_MSC(msc, LOGL_ERROR, "MSC not using Osmux but we are forced to use it.\n"); *cause = GSM0808_CAUSE_INCORRECT_VALUE; return -1; }
- if (conn->sccp.msc->use_osmux == OSMUX_USAGE_ON) - LOGP(DMSC, LOGL_NOTICE, "MSC not using Osmux but we have Osmux enabled.\n"); + if (msc->use_osmux == OSMUX_USAGE_ON) + LOG_MSC(msc, LOGL_NOTICE, "MSC not using Osmux but we have Osmux enabled.\n");
return 0; } @@ -1461,11 +1460,11 @@ struct rate_ctr *ctrs = msc->msc_ctrs->ctr;
if (length < 1) { - LOGP(DMSC, LOGL_ERROR, "Not enough room: %d\n", length); + LOG_MSC(msc, LOGL_ERROR, "Not enough room: %d\n", length); return -1; }
- LOGP(DMSC, LOGL_INFO, "Rx MSC UDT BSSMAP %s\n", + LOG_MSC(msc, LOGL_INFO, "Rx MSC UDT BSSMAP %s\n", gsm0808_bssmap_name(msg->l4h[0]));
switch (msg->l4h[0]) { @@ -1483,7 +1482,7 @@ break; default: rate_ctr_inc(&ctrs[MSC_CTR_BSSMAP_RX_UDT_UNKNOWN]); - LOGP(DMSC, LOGL_NOTICE, "Received unimplemented BSSMAP UDT %s\n", + LOG_MSC(msc, LOGL_NOTICE, "Received unimplemented BSSMAP UDT %s\n", gsm0808_bssmap_name(msg->l4h[0])); break; } @@ -1495,14 +1494,15 @@ struct msgb *msg, unsigned int length) { int ret = 0; - struct rate_ctr *ctrs = conn->sccp.msc->msc_ctrs->ctr; + struct bsc_msc_data *msc = conn->sccp.msc; + struct rate_ctr *ctrs = msc->msc_ctrs->ctr;
if (length < 1) { - LOGP(DMSC, LOGL_ERROR, "Not enough room: %d\n", length); + LOG_MSC(msc, LOGL_ERROR, "Not enough room: %d\n", length); return -1; }
- LOGP(DMSC, LOGL_INFO, "Rx MSC DT1 BSSMAP %s\n", + LOG_MSC(msc, LOGL_INFO, "Rx MSC DT1 BSSMAP %s\n", gsm0808_bssmap_name(msg->l4h[0]));
switch (msg->l4h[0]) { @@ -1553,7 +1553,7 @@ ret = osmo_fsm_inst_dispatch(conn->lcs.loc_req->fi, LCS_LOC_REQ_EV_RX_A_PERFORM_LOCATION_ABORT, msg); } else { - LOGP(DMSC, LOGL_ERROR, "Rx BSSMAP Perform Location Abort without ongoing Location Request\n"); + LOG_MSC(msc, LOGL_ERROR, "Rx BSSMAP Perform Location Abort without ongoing Location Request\n"); ret = 0; } break; @@ -1579,7 +1579,7 @@ break; default: rate_ctr_inc(&ctrs[MSC_CTR_BSSMAP_RX_DT1_UNKNOWN]); - LOGP(DMSC, LOGL_NOTICE, "Unimplemented msg type: %s\n", + LOG_MSC(msc, LOGL_NOTICE, "Unimplemented msg type: %s\n", gsm0808_bssmap_name(msg->l4h[0])); break; } @@ -1594,6 +1594,7 @@ struct msgb *gsm48; uint8_t *data; int dtap_rc; + struct bsc_msc_data *msc; struct rate_ctr *ctrs;
LOGP(DMSC, LOGL_DEBUG, "Rx MSC DTAP: %s\n", @@ -1604,29 +1605,30 @@ return -1; }
- ctrs = conn->sccp.msc->msc_ctrs->ctr; + msc = conn->sccp.msc; + ctrs = msc->msc_ctrs->ctr; header = (struct dtap_header *) msg->l3h; if (sizeof(*header) >= length) { rate_ctr_inc(&ctrs[MSC_CTR_BSSMAP_RX_DT1_DTAP_ERROR]); - LOGP(DMSC, LOGL_ERROR, "The DTAP header does not fit. Wanted: %zu got: %u, hex: %s\n", - sizeof(*header), length, osmo_hexdump(msg->l3h, length)); + LOG_MSC(msc, LOGL_ERROR, "The DTAP header does not fit. Wanted: %zu got: %u, hex: %s\n", + sizeof(*header), length, osmo_hexdump(msg->l3h, length)); return -1; }
if (header->length > length - sizeof(*header)) { rate_ctr_inc(&ctrs[MSC_CTR_BSSMAP_RX_DT1_DTAP_ERROR]); - LOGP(DMSC, LOGL_ERROR, "The DTAP l4 information does not fit. Wanted: %u got: %zu, hex: %s\n", - header->length, length - sizeof(*header), osmo_hexdump(msg->l3h, length)); + LOG_MSC(msc, LOGL_ERROR, "The DTAP l4 information does not fit. Wanted: %u got: %zu, hex: %s\n", + header->length, length - sizeof(*header), osmo_hexdump(msg->l3h, length)); return -1; }
rate_ctr_inc(&ctrs[MSC_CTR_BSSMAP_RX_DT1_DTAP]); - LOGP(DMSC, LOGL_INFO, "Rx MSC DTAP, SAPI: %s CHAN: %u\n", gsm0406_dlci_sapi_name(header->dlci_sapi), header->dlci_cc); + LOG_MSC(msc, LOGL_INFO, "Rx MSC DTAP, SAPI: %s CHAN: %u\n", gsm0406_dlci_sapi_name(header->dlci_sapi), header->dlci_cc);
/* forward the data */ gsm48 = gsm48_msgb_alloc_name("GSM 04.08 DTAP RCV"); if (!gsm48) { - LOGP(DMSC, LOGL_ERROR, "Allocation of the message failed.\n"); + LOG_MSC(msc, LOGL_ERROR, "Allocation of the message failed.\n"); return -1; }
@@ -1652,11 +1654,11 @@ { struct bssmap_header *bs;
- LOGP(DMSC, LOGL_DEBUG, "Rx MSC UDT: %s\n", + LOG_MSC(msc, LOGL_DEBUG, "Rx MSC UDT: %s\n", osmo_hexdump(msgb->l3h, length));
if (length < sizeof(*bs)) { - LOGP(DMSC, LOGL_ERROR, "The header is too short.\n"); + LOG_MSC(msc, LOGL_ERROR, "The header is too short.\n"); return -1; }
@@ -1670,7 +1672,7 @@ bssmap_rcvmsg_udt(msc, msgb, length - sizeof(*bs)); break; default: - LOGP(DMSC, LOGL_NOTICE, "Unimplemented msg type: %s\n", + LOG_MSC(msc, LOGL_NOTICE, "Unimplemented msg type: %s\n", gsm0808_bssmap_name(bs->type)); }
diff --git a/src/osmo-bsc/osmo_bsc_msc.c b/src/osmo-bsc/osmo_bsc_msc.c index 6ce2ded..dd0dde2 100644 --- a/src/osmo-bsc/osmo_bsc_msc.c +++ b/src/osmo-bsc/osmo_bsc_msc.c @@ -384,12 +384,11 @@ msc->mgcp_ipa.local_addr, msc->mgcp_ipa.local_port, NULL, 0, OSMO_SOCK_F_BIND); if (rc < 0) { - LOGP(DMSC, LOGL_ERROR, "msc %u: Could not create/connect/bind MGCP proxy socket: %d\n", - msc->nr, rc); + LOG_MSC(msc, LOGL_ERROR, "Could not create/connect/bind MGCP proxy socket: %d\n", rc); return rc; } - LOGP(DMSC, LOGL_INFO, "msc %u: Socket forwarding IPA-encapsulated MGCP messages towards MGW: %s\n", - msc->nr, osmo_sock_get_name2(msc->mgcp_ipa.ofd.fd)); + LOG_MSC(msc, LOGL_INFO, "Socket forwarding IPA-encapsulated MGCP messages towards MGW: %s\n", + osmo_sock_get_name2(msc->mgcp_ipa.ofd.fd));
return 0; } diff --git a/src/osmo-bsc/osmo_bsc_sigtran.c b/src/osmo-bsc/osmo_bsc_sigtran.c index bfe9817..7a591ca 100644 --- a/src/osmo-bsc/osmo_bsc_sigtran.c +++ b/src/osmo-bsc/osmo_bsc_sigtran.c @@ -63,7 +63,7 @@
ss7 = osmo_ss7_instance_find(msc->a.cs7_instance); OSMO_ASSERT(ss7); - LOGP(DRESET, LOGL_INFO, "Sending RESET to MSC: %s\n", osmo_sccp_addr_name(ss7, &msc->a.msc_addr)); + LOG_MSC_CAT(msc, DRESET, LOGL_INFO, "Sending RESET to MSC: %s\n", osmo_sccp_addr_name(ss7, &msc->a.msc_addr)); msg = gsm0808_create_reset();
if (msc_is_aoip(msc) && msc->use_osmux != OSMUX_USAGE_OFF) @@ -83,7 +83,7 @@
ss7 = osmo_ss7_instance_find(msc->a.cs7_instance); OSMO_ASSERT(ss7); - LOGP(DRESET, LOGL_NOTICE, "Sending RESET ACK to MSC: %s\n", osmo_sccp_addr_name(ss7, &msc->a.msc_addr)); + LOG_MSC_CAT(msc, DRESET, LOGL_NOTICE, "Sending RESET ACK to MSC: %s\n", osmo_sccp_addr_name(ss7, &msc->a.msc_addr)); msg = gsm0808_create_reset_ack();
if (msc_is_aoip(msc) && msc->use_osmux != OSMUX_USAGE_OFF) @@ -178,9 +178,9 @@ goto refuse; }
- LOGP(DMSC, LOGL_DEBUG, "(calling_addr=%s conn_id=%u) N-CONNECT.ind from MSC %d\n", - osmo_sccp_addr_dump(&scu_prim->u.connect.calling_addr), - scu_prim->u.connect.conn_id, msc->nr); + LOG_MSC(msc, LOGL_DEBUG, "(calling_addr=%s conn_id=%u) N-CONNECT.ind\n", + osmo_sccp_addr_dump(&scu_prim->u.connect.calling_addr), + scu_prim->u.connect.conn_id);
conn = bsc_subscr_con_allocate(bsc_gsmnet); if (!conn) @@ -188,8 +188,8 @@ conn->sccp.msc = msc; conn->sccp.conn.conn_id = scu_prim->u.connect.conn_id; if (bsc_sccp_inst_register_gscon(bsc_sccp, &conn->sccp.conn) < 0) { - LOGP(DMSC, LOGL_NOTICE, "(calling_addr=%s conn_id=%u) N-CONNECT.ind failed registering conn\n", - osmo_sccp_addr_dump(&scu_prim->u.connect.calling_addr), scu_prim->u.connect.conn_id); + LOG_MSC(msc, LOGL_NOTICE, "(calling_addr=%s conn_id=%u) N-CONNECT.ind failed registering conn\n", + osmo_sccp_addr_dump(&scu_prim->u.connect.calling_addr), scu_prim->u.connect.conn_id); osmo_fsm_inst_term(conn->fi, OSMO_FSM_TERM_REQUEST, NULL); rc = -ENOENT; goto refuse; @@ -274,19 +274,19 @@ }
if (disconnected && a_reset_conn_ready(msc)) { - LOGP(DMSC, LOGL_NOTICE, - "(msc%d) now unreachable: N-PCSTATE ind: pc=%u=%s sp_status=%s remote_sccp_status=%s\n", - msc->nr, pcst->affected_pc, osmo_ss7_pointcode_print(cs7, pcst->affected_pc), - osmo_sccp_sp_status_name(pcst->sp_status), - osmo_sccp_rem_sccp_status_name(pcst->remote_sccp_status)); + LOG_MSC(msc, LOGL_NOTICE, + "now unreachable: N-PCSTATE ind: pc=%u=%s sp_status=%s remote_sccp_status=%s\n", + pcst->affected_pc, osmo_ss7_pointcode_print(cs7, pcst->affected_pc), + osmo_sccp_sp_status_name(pcst->sp_status), + osmo_sccp_rem_sccp_status_name(pcst->remote_sccp_status)); /* A previously usable MSC has disconnected. Kick the BSSMAP back to DISC state. */ bssmap_reset_set_disconnected(msc->a.bssmap_reset); } else if (connected && !a_reset_conn_ready(msc)) { - LOGP(DMSC, LOGL_NOTICE, - "(msc%d) now available: N-PCSTATE ind: pc=%u=%s sp_status=%s remote_sccp_status=%s\n", - msc->nr, pcst->affected_pc, osmo_ss7_pointcode_print(cs7, pcst->affected_pc), - osmo_sccp_sp_status_name(pcst->sp_status), - osmo_sccp_rem_sccp_status_name(pcst->remote_sccp_status)); + LOG_MSC(msc, LOGL_NOTICE, + "now available: N-PCSTATE ind: pc=%u=%s sp_status=%s remote_sccp_status=%s\n", + pcst->affected_pc, osmo_ss7_pointcode_print(cs7, pcst->affected_pc), + osmo_sccp_sp_status_name(pcst->sp_status), + osmo_sccp_rem_sccp_status_name(pcst->remote_sccp_status)); /* A previously unusable MSC has become reachable. Trigger immediate BSSMAP RESET -- we would resend a * RESET either way, but we might as well do it now to speed up connecting. */ bssmap_reset_resend_reset(msc->a.bssmap_reset); @@ -393,16 +393,16 @@
ss7 = osmo_ss7_instance_find(msc->a.cs7_instance); OSMO_ASSERT(ss7); - LOGP(DMSC, LOGL_INFO, "Initializing resources for new SCCP connection to MSC %d: %s...\n", - msc->nr, osmo_sccp_addr_name(ss7, &msc->a.msc_addr)); + LOG_MSC(msc, LOGL_INFO, "Initializing resources for new SCCP connection: %s...\n", + osmo_sccp_addr_name(ss7, &msc->a.msc_addr));
if (a_reset_conn_ready(msc) == false) { - LOGP(DMSC, LOGL_ERROR, "MSC %d is not connected. Dropping.\n", msc->nr); + LOG_MSC(msc, LOGL_ERROR, "MSC is not connected. Dropping.\n"); return BSC_CON_REJECT_NO_LINK; }
if (bts && !bsc_grace_allow_new_connection(bts->network, bts)) { - LOGP(DMSC, LOGL_NOTICE, "BSC in grace period. No new connections.\n"); + LOG_MSC(msc, LOGL_NOTICE, "BSC in grace period. No new connections.\n"); return BSC_CON_REJECT_RF_GRACE; }
@@ -429,25 +429,25 @@ msc = conn->sccp.msc;
if (a_reset_conn_ready(msc) == false) { - LOGP(DMSC, LOGL_ERROR, "MSC is not connected. Dropping.\n"); + LOG_MSC(msc, LOGL_ERROR, "MSC is not connected. Dropping.\n"); return -EINVAL; }
bsc_sccp = osmo_sccp_get_priv(msc->a.sccp); conn->sccp.conn.conn_id = conn_id = bsc_sccp_inst_next_conn_id(bsc_sccp); if (conn->sccp.conn.conn_id == SCCP_CONN_ID_UNSET) { - LOGP(DMSC, LOGL_ERROR, "Unable to allocate SCCP Connection ID\n"); + LOG_MSC(msc, LOGL_ERROR, "Unable to allocate SCCP Connection ID\n"); return -1; } if (bsc_sccp_inst_register_gscon(bsc_sccp, &conn->sccp.conn) < 0) { - LOGP(DMSC, LOGL_ERROR, "Unable to register SCCP connection (id=%u)\n", conn->sccp.conn.conn_id); + LOG_MSC(msc, LOGL_ERROR, "Unable to register SCCP connection (id=%u)\n", conn->sccp.conn.conn_id); return -1; } - LOGP(DMSC, LOGL_DEBUG, "Allocated new connection id: %u\n", conn->sccp.conn.conn_id); + LOG_MSC(msc, LOGL_DEBUG, "Allocated new connection id: %u\n", conn->sccp.conn.conn_id); ss7 = osmo_ss7_instance_find(msc->a.cs7_instance); OSMO_ASSERT(ss7); - LOGP(DMSC, LOGL_INFO, "Opening new SCCP connection (id=%u) to MSC %d: %s\n", conn_id, - msc->nr, osmo_sccp_addr_name(ss7, &msc->a.msc_addr)); + LOG_MSC(msc, LOGL_INFO, "Opening new SCCP connection (id=%u): %s\n", + conn_id, osmo_sccp_addr_name(ss7, &msc->a.msc_addr));
rc = osmo_sccp_tx_conn_req_msg(msc->a.sccp_user, conn_id, &msc->a.bsc_addr, &msc->a.msc_addr, msg); @@ -482,26 +482,26 @@ switch (msg->data[0]) { case BSSAP_MSG_BSS_MANAGEMENT: rate_ctr_inc(rate_ctr_group_get_ctr(msc->msc_ctrs, MSC_CTR_BSSMAP_TX_BSS_MANAGEMENT)); - LOGP(DMSC, LOGL_INFO, "Tx MSC: BSSMAP: %s\n", + LOG_MSC(msc, LOGL_INFO, "Tx MSC: BSSMAP: %s\n", gsm0808_bssmap_name(msg->data[2])); break; case BSSAP_MSG_DTAP: rate_ctr_inc(rate_ctr_group_get_ctr(msc->msc_ctrs, MSC_CTR_BSSMAP_TX_DTAP)); - LOGP(DMSC, LOGL_INFO, "Tx MSC: DTAP\n"); + LOG_MSC(msc, LOGL_INFO, "Tx MSC: DTAP\n"); break; default: rate_ctr_inc(rate_ctr_group_get_ctr(msc->msc_ctrs, MSC_CTR_BSSMAP_TX_UNKNOWN)); - LOGP(DMSC, LOGL_ERROR, "Tx MSC: unknown message type: 0x%x\n", + LOG_MSC(msc, LOGL_ERROR, "Tx MSC: unknown message type: 0x%x\n", msg->data[0]); } } else { rate_ctr_inc(rate_ctr_group_get_ctr(msc->msc_ctrs, MSC_CTR_BSSMAP_TX_SHORT)); - LOGP(DMSC, LOGL_ERROR, "Tx MSC: message too short: %u\n", msg->len); + LOG_MSC(msc, LOGL_ERROR, "Tx MSC: message too short: %u\n", msg->len); }
if (a_reset_conn_ready(msc) == false) { rate_ctr_inc(rate_ctr_group_get_ctr(msc->msc_ctrs, MSC_CTR_BSSMAP_TX_ERR_CONN_NOT_READY)); - LOGP(DMSC, LOGL_ERROR, "MSC is not connected. Dropping.\n"); + LOG_MSC(msc, LOGL_ERROR, "MSC is not connected. Dropping.\n"); msgb_free(msg); return -EINVAL; } @@ -510,8 +510,8 @@
ss7 = osmo_ss7_instance_find(msc->a.cs7_instance); OSMO_ASSERT(ss7); - LOGP(DMSC, LOGL_DEBUG, "Sending connection (id=%i) oriented data to MSC: %s (%s)\n", - conn_id, osmo_sccp_addr_name(ss7, &msc->a.msc_addr), osmo_hexdump(msg->data, msg->len)); + LOG_MSC(msc, LOGL_DEBUG, "Sending connection (id=%d) oriented data to MSC: %s (%s)\n", + conn_id, osmo_sccp_addr_name(ss7, &msc->a.msc_addr), osmo_hexdump(msg->data, msg->len));
rc = osmo_sccp_tx_data_msg(msc->a.sccp_user, conn_id, msg); if (rc >= 0) @@ -577,8 +577,7 @@ if (!msc->a.cs7_instance_valid) { s7i = osmo_ss7_instance_find(0); if (!s7i) { - LOGP(DMSC, LOGL_NOTICE, "To auto-configure msc %d, creating cs7 instance 0 implicitly\n", - msc->nr); + LOG_MSC(msc, LOGL_NOTICE, "To auto-configure msc, creating cs7 instance 0 implicitly\n"); s7i = osmo_ss7_instance_find_or_create(tall_bsc_ctx, 0); OSMO_ASSERT(s7i); } @@ -592,8 +591,8 @@ * default SCCP address for the MSC to the address book */ if (!msc->a.msc_addr_name) { msc->a.msc_addr_name = talloc_strdup(msc, MSC_DEFAULT_ADDR_NAME); - LOGP(DMSC, LOGL_NOTICE, "To auto-configure msc %d, adding address '%s' to cs7 instance 0 address-book implicitly\n", - msc->nr, msc->a.msc_addr_name); + LOG_MSC(msc, LOGL_NOTICE, "To auto-configure msc, adding address '%s' to cs7 instance 0 address-book implicitly\n", + msc->a.msc_addr_name); } if (!msc->a.msc_addr.presence) { struct osmo_ss7_instance *ss7; @@ -722,27 +721,25 @@ OSMO_SCCP_SSN_BSSAP);
if (!osmo_sccp_check_addr(&msc->a.bsc_addr, OSMO_SCCP_ADDR_T_SSN | OSMO_SCCP_ADDR_T_PC)) { - LOGP(DMSC, LOGL_ERROR, - "%s %s: invalid local (BSC) SCCP address: %s\n", - inst_name, msc_name, osmo_sccp_inst_addr_name(sccp, &msc->a.bsc_addr)); + LOG_MSC(msc, LOGL_ERROR, "%s: invalid local (BSC) SCCP address: %s\n", + inst_name, osmo_sccp_inst_addr_name(sccp, &msc->a.bsc_addr)); return -EINVAL; }
if (!osmo_sccp_check_addr(&msc->a.msc_addr, OSMO_SCCP_ADDR_T_SSN | OSMO_SCCP_ADDR_T_PC)) { - LOGP(DMSC, LOGL_ERROR, - "%s %s: invalid remote (MSC) SCCP address: %s\n", - inst_name, msc_name, osmo_sccp_inst_addr_name(sccp, &msc->a.msc_addr)); + LOG_MSC(msc, LOGL_ERROR, "%s: invalid remote (MSC) SCCP address: %s\n", + inst_name, osmo_sccp_inst_addr_name(sccp, &msc->a.msc_addr)); return -EINVAL; }
- LOGP(DMSC, LOGL_NOTICE, "%s %s: local (BSC) SCCP address: %s\n", - inst_name, msc_name, osmo_sccp_inst_addr_name(sccp, &msc->a.bsc_addr)); - LOGP(DMSC, LOGL_NOTICE, "%s %s: remote (MSC) SCCP address: %s\n", - inst_name, msc_name, osmo_sccp_inst_addr_name(sccp, &msc->a.msc_addr)); + LOG_MSC(msc, LOGL_NOTICE, "%s: local (BSC) SCCP address: %s\n", + inst_name, osmo_sccp_inst_addr_name(sccp, &msc->a.bsc_addr)); + LOG_MSC(msc, LOGL_NOTICE, "%s: remote (MSC) SCCP address: %s\n", + inst_name, osmo_sccp_inst_addr_name(sccp, &msc->a.msc_addr));
/* Bind SCCP user. Bind only one user per sccp_instance and bsc_addr. */ msc->a.sccp_user = osmo_sccp_user_find(sccp, msc->a.bsc_addr.ssn, msc->a.bsc_addr.pc); - LOGP(DMSC, LOGL_NOTICE, "%s %s: %s\n", inst_name, msc_name, + LOG_MSC(msc, LOGL_NOTICE, "%s: %s\n", inst_name, msc->a.sccp_user ? "user already bound for this SCCP instance" : "binding SCCP user"); if (!msc->a.sccp_user) msc->a.sccp_user = osmo_sccp_user_bind(sccp, msc_name, sccp_sap_up, msc->a.bsc_addr.ssn);
-
pespin