Introduce LOG_MSC log macro

Change-Id: I4f2502eea856b31783eef5b0af8dc41ccfeb9910
This commit is contained in:
Pau Espin Pedrol
2025-07-16 16:32:15 +02:00
parent 89bf530ed4
commit 4b3ba64f6c
8 changed files with 128 additions and 124 deletions

View File

@@ -272,4 +272,10 @@ static inline bool msc_is_sccplite(const struct bsc_msc_data *msc)
}
}
#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

View File

@@ -42,7 +42,7 @@ static void a_reset_tx_reset_ack(void *data)
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_up(void *data)
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 @@ void a_reset_alloc(struct bsc_msc_data *msc, const char *name)
/* 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;
}

View File

@@ -1189,8 +1189,8 @@ DEFUN_DEPRECATED(cfg_net_dtx,
#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 @@ DEFUN(msc_bssmap_reset, msc_bssmap_reset_cmd,
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;
}

View File

@@ -475,9 +475,9 @@ int check_codec_pref(struct llist_head *mscs)
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 @@ int check_codec_pref(struct llist_head *mscs)
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 @@ int check_codec_pref(struct llist_head *mscs)
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;
}
}

View File

@@ -275,8 +275,8 @@ static struct bsc_msc_data *bsc_find_msc(struct gsm_subscriber_connection *conn,
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));

View File

@@ -69,21 +69,21 @@ static void update_msc_osmux_support(struct bsc_msc_data *msc,
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_ack(struct bsc_msc_data *msc,
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 @@ static int bssmap_handle_paging(struct bsc_msc_data *msc,
};
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 @@ static int bssmap_handle_paging(struct bsc_msc_data *msc,
}
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 @@ static int bssmap_handle_paging(struct bsc_msc_data *msc,
*/
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 @@ static int select_codecs(struct assignment_request *req, const struct gsm0808_ch
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 @@ static int select_codecs(struct assignment_request *req, const struct gsm0808_ch
}
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 @@ static int bssmap_handle_ass_req_tp_osmux(struct gsm_subscriber_connection *conn
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 @@ static int bssmap_handle_ass_req_tp_osmux(struct gsm_subscriber_connection *conn
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 @@ static int bssmap_rcvmsg_udt(struct bsc_msc_data *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 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 @@ static int bssmap_rcvmsg_udt(struct bsc_msc_data *msc,
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 @@ static int bssmap_rcvmsg_dt1(struct gsm_subscriber_connection *conn,
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 @@ static int bssmap_rcvmsg_dt1(struct gsm_subscriber_connection *conn,
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 @@ static int bssmap_rcvmsg_dt1(struct gsm_subscriber_connection *conn,
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 @@ static int dtap_rcvmsg(struct gsm_subscriber_connection *conn,
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 @@ static int dtap_rcvmsg(struct gsm_subscriber_connection *conn,
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 @@ int bsc_handle_udt(struct bsc_msc_data *msc,
{
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 @@ int bsc_handle_udt(struct bsc_msc_data *msc,
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));
}

View File

@@ -384,12 +384,11 @@ int osmo_bsc_msc_init(struct bsc_msc_data *msc)
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;
}

View File

@@ -63,7 +63,7 @@ void osmo_bsc_sigtran_tx_reset(const struct bsc_msc_data *msc)
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 @@ void osmo_bsc_sigtran_tx_reset_ack(const struct bsc_msc_data *msc)
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 @@ static int handle_n_connect_from_msc(struct osmo_sccp_user *scu, struct osmo_scu
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 @@ static int handle_n_connect_from_msc(struct osmo_sccp_user *scu, struct osmo_scu
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 @@ static void handle_pcstate_ind(struct osmo_ss7_instance *cs7, const struct osmo_
}
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 @@ enum bsc_con osmo_bsc_sigtran_new_conn(struct gsm_subscriber_connection *conn, s
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 @@ __attribute__((weak)) int osmo_bsc_sigtran_open_conn(struct gsm_subscriber_conne
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 @@ int osmo_bsc_sigtran_send(struct gsm_subscriber_connection *conn, struct msgb *m
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 @@ int osmo_bsc_sigtran_send(struct gsm_subscriber_connection *conn, struct msgb *m
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 @@ int osmo_bsc_sigtran_init(struct llist_head *mscs)
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 @@ int osmo_bsc_sigtran_init(struct llist_head *mscs)
* 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 @@ int osmo_bsc_sigtran_init(struct llist_head *mscs)
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);