summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorNeels Hofmeyr <nhofmeyr@sysmocom.de>2017-06-22 21:03:14 +0200
committerNeels Hofmeyr <nhofmeyr@sysmocom.de>2017-06-25 22:35:01 +0200
commit3468d5dce45e34a63b52061b8aaa9c095f473cf4 (patch)
treecb9b5108040ce263d7b41eefc1eef932d399e26c
parent4e015f6664ce730e1b44107a0f2f05971ae628bd (diff)
add/tweak various logging to help figure out complex routing
Add function osmo_ss7_point_code_print2() to be able to print two point codes in the same log message. Change signatures of two static functions to aid logging: add invalid ref arg to sccp_scoc_rx_inval_src_ref(), pass conn instead of inst to sccp_scoc_rx_inval_opc(). Change-Id: Ia3243606d6cad7721f7da7f6caba2caa90ae2bbd
-rw-r--r--include/osmocom/sigtran/osmo_ss7.h1
-rw-r--r--src/m3ua.c28
-rw-r--r--src/osmo_ss7.c33
-rw-r--r--src/osmo_ss7_hmrt.c23
-rw-r--r--src/sccp_scoc.c19
5 files changed, 85 insertions, 19 deletions
diff --git a/include/osmocom/sigtran/osmo_ss7.h b/include/osmocom/sigtran/osmo_ss7.h
index 4e04352..caf12f5 100644
--- a/include/osmocom/sigtran/osmo_ss7.h
+++ b/include/osmocom/sigtran/osmo_ss7.h
@@ -24,6 +24,7 @@ bool osmo_ss7_pc_is_local(struct osmo_ss7_instance *inst, uint32_t pc);
int osmo_ss7_pointcode_parse(struct osmo_ss7_instance *inst, const char *str);
int osmo_ss7_pointcode_parse_mask_or_len(struct osmo_ss7_instance *inst, const char *in);
const char *osmo_ss7_pointcode_print(struct osmo_ss7_instance *inst, uint32_t pc);
+const char *osmo_ss7_pointcode_print2(struct osmo_ss7_instance *inst, uint32_t pc);
/***********************************************************************
* SS7 Routing Tables
diff --git a/src/m3ua.c b/src/m3ua.c
index d96bd18..c43dfa4 100644
--- a/src/m3ua.c
+++ b/src/m3ua.c
@@ -536,18 +536,34 @@ static int m3ua_rx_xfer(struct osmo_ss7_asp *asp, struct xua_msg *xua)
struct m3ua_data_hdr *dh;
struct osmo_ss7_as *as;
- if (xua->hdr.msg_type != M3UA_XFER_DATA)
+ LOGPASP(asp, DLM3UA, LOGL_DEBUG, "m3ua_rx_xfer\n");
+
+ if (xua->hdr.msg_type != M3UA_XFER_DATA) {
+ LOGPASP(asp, DLM3UA, LOGL_ERROR,
+ "%s(): unsupported message type: %s\n",
+ __func__,
+ get_value_string(m3ua_xfer_msgt_names, xua->hdr.msg_type));
return M3UA_ERR_UNSUPP_MSG_TYPE;
+ }
/* Use routing context IE to look up the AS for which the
* message was received. */
as = osmo_ss7_as_find_by_rctx(asp->inst, rctx);
- if (!as)
+ if (!as) {
+ LOGPASP(asp, DLM3UA, LOGL_ERROR,
+ "%s(): invalid routing context: %u\n",
+ __func__, rctx);
return M3UA_ERR_INVAL_ROUT_CTX;
+ }
- /* Verify that this ASP ix part of the AS. */
- if (!osmo_ss7_as_has_asp(as, asp))
+ /* Verify that this ASP is part of the AS. */
+ if (!osmo_ss7_as_has_asp(as, asp)) {
+ LOGPASP(asp, DLM3UA, LOGL_ERROR,
+ "%s(): This Application Server Process is not part of the AS resolved by"
+ " routing context %u\n",
+ __func__, rctx);
return M3UA_ERR_NO_CONFGD_AS_FOR_ASP;
+ }
/* FIXME: check for AS state == ACTIVE */
@@ -556,6 +572,10 @@ static int m3ua_rx_xfer(struct osmo_ss7_asp *asp, struct xua_msg *xua)
dh = data_hdr_from_m3ua(xua);
OSMO_ASSERT(dh);
m3ua_dh_to_xfer_param(&xua->mtp, dh);
+ LOGPASP(asp, DLM3UA, LOGL_DEBUG,
+ "%s(): M3UA data header: opc=%u=%s dpc=%u=%s\n",
+ __func__, xua->mtp.opc, osmo_ss7_pointcode_print(asp->inst, xua->mtp.opc),
+ xua->mtp.dpc, osmo_ss7_pointcode_print2(asp->inst, xua->mtp.dpc));
/* remove ROUTE_CTX as in the routing case we want to add a new
* routing context on the outbound side */
diff --git a/src/osmo_ss7.c b/src/osmo_ss7.c
index 9477543..c13c588 100644
--- a/src/osmo_ss7.c
+++ b/src/osmo_ss7.c
@@ -245,17 +245,14 @@ err:
return -EINVAL;
}
-/* print a pointcode according to the structure configured for this
- * ss7_instance */
-const char *osmo_ss7_pointcode_print(struct osmo_ss7_instance *inst, uint32_t pc)
+const char *_osmo_ss7_pointcode_print(char *buf, size_t len, struct osmo_ss7_instance *inst, uint32_t pc)
{
- static char buf[MAX_PC_STR_LEN];
const struct osmo_ss7_pc_fmt *pc_fmt = inst ? &inst->cfg.pc_fmt : &default_pc_fmt;
unsigned int num_comp_exp = num_pc_comp_exp(pc_fmt);
const char *fmtstr = gen_pc_fmtstr(pc_fmt, &num_comp_exp);
OSMO_ASSERT(fmtstr);
- snprintf(buf, sizeof(buf), fmtstr,
+ snprintf(buf, len, fmtstr,
pc_comp_shift_and_mask(pc_fmt, 0, pc),
pc_comp_shift_and_mask(pc_fmt, 1, pc),
pc_comp_shift_and_mask(pc_fmt, 2, pc));
@@ -263,6 +260,23 @@ const char *osmo_ss7_pointcode_print(struct osmo_ss7_instance *inst, uint32_t pc
return buf;
}
+
+/* print a pointcode according to the structure configured for this
+ * ss7_instance */
+const char *osmo_ss7_pointcode_print(struct osmo_ss7_instance *inst, uint32_t pc)
+{
+ static char buf[MAX_PC_STR_LEN];
+ return _osmo_ss7_pointcode_print(buf, sizeof(buf), inst, pc);
+}
+
+/* same as osmo_ss7_pointcode_print() but using a separate buffer, useful for multiple point codes in the
+ * same LOGP/printf. */
+const char *osmo_ss7_pointcode_print2(struct osmo_ss7_instance *inst, uint32_t pc)
+{
+ static char buf[MAX_PC_STR_LEN];
+ return _osmo_ss7_pointcode_print(buf, sizeof(buf), inst, pc);
+}
+
int osmo_ss7_pointcode_parse_mask_or_len(struct osmo_ss7_instance *inst, const char *in)
{
unsigned int width = get_pc_width(inst ? &inst->cfg.pc_fmt : &default_pc_fmt);
@@ -740,10 +754,15 @@ osmo_ss7_route_create(struct osmo_ss7_route_table *rtbl, uint32_t pc,
rt->cfg.pc = pc;
rt->cfg.mask = mask;
rt->cfg.linkset_name = talloc_strdup(rt, linkset_name);
- if (lset)
+ if (lset) {
rt->dest.linkset = lset;
- else
+ LOGSS7(rtbl->inst, LOGL_INFO, "Creating route: pc=%u=%s mask=0x%x via linkset '%s'\n",
+ pc, osmo_ss7_pointcode_print(rtbl->inst, pc), mask, lset->cfg.name);
+ } else {
rt->dest.as = as;
+ LOGSS7(rtbl->inst, LOGL_INFO, "Creating route: pc=%u=%s mask=0x%x via AS '%s'\n",
+ pc, osmo_ss7_pointcode_print(rtbl->inst, pc), mask, as->cfg.name);
+ }
rt->rtable = rtbl;
route_insert_sorted(rtbl, rt);
diff --git a/src/osmo_ss7_hmrt.c b/src/osmo_ss7_hmrt.c
index e66762d..8165a36 100644
--- a/src/osmo_ss7_hmrt.c
+++ b/src/osmo_ss7_hmrt.c
@@ -138,20 +138,33 @@ static int hmrt_message_for_routing(struct osmo_ss7_instance *inst,
/* FIXME: Transmit over respective Link */
if (rt->dest.as) {
struct osmo_ss7_as *as = rt->dest.as;
+ DEBUGP(DLSS7,
+ "Found route for dpc=%u=%s: pc=%u=%s mask=0x%x"
+ " via AS %s proto=%s\n",
+ dpc, osmo_ss7_pointcode_print(inst, dpc),
+ rt->cfg.pc, osmo_ss7_pointcode_print2(inst, rt->cfg.pc), rt->cfg.mask,
+ as->cfg.name, osmo_ss7_asp_protocol_name(as->cfg.proto));
+
switch (as->cfg.proto) {
case OSMO_SS7_ASP_PROT_M3UA:
+ DEBUGP(DLSS7, "rt->dest.as proto is M3UA for dpc=%u=%s\n",
+ dpc, osmo_ss7_pointcode_print(inst, dpc));
return m3ua_tx_xua_as(as,xua);
case OSMO_SS7_ASP_PROT_IPA:
return ipa_tx_xua_as(as, xua);
default:
LOGP(DLSS7, LOGL_ERROR, "MTP message "
- "for ASP of unknown protocol%u\n",
+ "for ASP of unknown protocol %u\n",
as->cfg.proto);
break;
}
} else if (rt->dest.linkset) {
- LOGP(DLSS7, LOGL_ERROR, "MTP-TRANSFER.req for linkset"
- "%s unsupported\n",rt->dest.linkset->cfg.name);
+ LOGP(DLSS7, LOGL_ERROR,
+ "Found route for dpc=%u=%s: pc=%u=%s mask=0x%x"
+ " via linkset %s, but MTP-TRANSFER.req unsupported for linkset.\n",
+ dpc, osmo_ss7_pointcode_print(inst, dpc),
+ rt->cfg.pc, osmo_ss7_pointcode_print2(inst, rt->cfg.pc), rt->cfg.mask,
+ rt->dest.linkset->cfg.name);
} else
OSMO_ASSERT(0);
} else {
@@ -171,8 +184,12 @@ int m3ua_hmdc_rx_from_l2(struct osmo_ss7_instance *inst, struct xua_msg *xua)
{
uint32_t dpc = xua->mtp.dpc;
if (osmo_ss7_pc_is_local(inst, dpc)) {
+ DEBUGP(DLSS7, "%s(): found dpc=%u=%s as local\n", __func__,
+ dpc, osmo_ss7_pointcode_print(inst, dpc));
return hmdt_message_for_distribution(inst, xua);
} else {
+ DEBUGP(DLSS7, "%s(): dpc=%u=%s not local, message is for routing\n", __func__,
+ dpc, osmo_ss7_pointcode_print(inst, dpc));
return hmrt_message_for_routing(inst, xua);
}
}
diff --git a/src/sccp_scoc.c b/src/sccp_scoc.c
index fbb6ef8..9502953 100644
--- a/src/sccp_scoc.c
+++ b/src/sccp_scoc.c
@@ -1436,8 +1436,13 @@ static void sccp_scoc_rx_unass_local_ref(struct osmo_sccp_instance *inst,
/* process received message for invalid source local reference */
static void sccp_scoc_rx_inval_src_ref(struct sccp_connection *conn,
- struct xua_msg *xua)
+ struct xua_msg *xua,
+ uint32_t inval_src_ref)
{
+ LOGP(DLSCCP, LOGL_NOTICE,
+ "Received message for source ref %u on conn with mismatching remote ref %u\n",
+ inval_src_ref, conn->remote_ref);
+
/* we have received a message with invalid source local
* reference and thus apply the action indicated in Table
* B.2/Q.714 */
@@ -1463,9 +1468,13 @@ static void sccp_scoc_rx_inval_src_ref(struct sccp_connection *conn,
}
/* process received message for invalid origin point code */
-static void sccp_scoc_rx_inval_opc(struct osmo_sccp_instance *inst,
+static void sccp_scoc_rx_inval_opc(struct sccp_connection *conn,
struct xua_msg *xua)
{
+ LOGP(DLSCCP, LOGL_NOTICE,
+ "Received message for opc=%u=%s on conn with mismatching remote pc=%u=%s\n",
+ xua->mtp.opc, osmo_ss7_pointcode_print(conn->inst->ss7, xua->mtp.opc),
+ conn->remote_pc, osmo_ss7_pointcode_print2(conn->inst->ss7, conn->remote_pc));
/* we have received a message with invalid origin PC and thus
* apply the action indiacted in Table B.2/Q.714 */
switch (xua->hdr.msg_type) {
@@ -1473,7 +1482,7 @@ static void sccp_scoc_rx_inval_opc(struct osmo_sccp_instance *inst,
case SUA_CO_RESRE: /* RSR */
case SUA_CO_RESCO: /* RSC */
/* Send ERR */
- tx_coerr_from_xua(inst, xua, SCCP_ERROR_POINT_CODE_MISMATCH);
+ tx_coerr_from_xua(conn->inst, xua, SCCP_ERROR_POINT_CODE_MISMATCH);
break;
case SUA_CO_RELCO: /* RLC */
case SUA_CO_CODT: /* DT1 */
@@ -1544,14 +1553,14 @@ void sccp_scoc_rx_from_scrc(struct osmo_sccp_instance *inst,
* the one we saved in local state */
src_loc_ref = xua_msg_get_u32(xua, SUA_IEI_SRC_REF);
if (src_loc_ref != conn->remote_ref) {
- sccp_scoc_rx_inval_src_ref(conn, xua);
+ sccp_scoc_rx_inval_src_ref(conn, xua, src_loc_ref);
return;
}
}
/* Check if received OPC != the remote_pc we stored locally */
if (xua->mtp.opc != conn->remote_pc) {
- sccp_scoc_rx_inval_opc(inst, xua);
+ sccp_scoc_rx_inval_opc(conn, xua);
return;
}
}