nat: We want the remote to respond to our DLCX request

We want to send a TRAP with the MGCP statistics from the NAT and
the connected BSC. The BSC endpoint can be either released because
of a DLCX from the MGCP CallAgent or the SCCP Connection release on
the A-link.

This is why we need to queue the statistics when the deleting the
endpoint on the BSC. The processing is continued once the response
arrives. This code assumes that the response of the DLCX will be sent
by the remote side. The current amount of outstanding responses can be
seen on the VTY. This assumption is based on the fact that the BSC has
already responded to the CRCX and maybe to the MDCX.

The MGCP RFC is bended to prefix the transaction identifier with "nat-"
to easily detect the response and hand it to the handler. This will
then parse the response and generate the TRAP. The current version is
v1. We assume that the transaction space is big enough and we will
not re-assign the transaction identifier too early.

10 files changed, 256 insertions, 10 deletions

diff --git a/openbsc/include/openbsc/bsc_nat.h b/openbsc/include/openbsc/bsc_nat.h
index 4baaa8280..6860342a0 100644
--- a/openbsc/include/openbsc/bsc_nat.h
+++ b/openbsc/include/openbsc/bsc_nat.h
@@ -32,6 +32,7 @@
 #include <osmocom/core/rate_ctr.h>
 #include <osmocom/core/statistics.h>
 #include <osmocom/gsm/protocol/gsm_04_08.h>
+#include <osmocom/sccp/sccp_types.h>
 
 #include <regex.h>
 
@@ -111,6 +112,9 @@ struct bsc_connection {
 	int number_multiplexes;
 	int max_endpoints;
 	int last_endpoint;
+	int next_transaction;
+	uint32_t pending_dlcx_count;
+	struct llist_head pending_dlcx;
 
 	/* track the pending commands for this BSC */
 	struct llist_head cmd_pending;
@@ -332,6 +336,33 @@ struct bsc_nat_ussd_con {
 	struct osmo_timer_list auth_timeout;
 };
 
+struct bsc_nat_call_stats {
+	struct llist_head entry;
+
+	struct sccp_source_reference remote_ref;
+	struct sccp_source_reference src_ref; /* as seen by the MSC */
+
+	/* mgcp options */
+	uint32_t ci;
+	int bts_rtp_port;
+	int net_rtp_port;
+	struct in_addr bts_addr;
+	struct in_addr net_addr;
+
+
+	/* as witnessed by the NAT */
+	uint32_t net_ps;
+	uint32_t net_os;
+	uint32_t bts_pr;
+	uint32_t bts_or;
+	uint32_t bts_expected;
+	uint32_t bts_jitter;
+	int      bts_loss;
+
+	uint32_t trans_id;
+	int msc_endpoint;
+};
+
 struct bsc_nat_reject_cause {
 	int lu_reject_cause;
 	int cm_reject_cause;
diff --git a/openbsc/include/openbsc/mgcp.h b/openbsc/include/openbsc/mgcp.h
index 7a416ddd1..811dcfda7 100644
--- a/openbsc/include/openbsc/mgcp.h
+++ b/openbsc/include/openbsc/mgcp.h
@@ -172,6 +172,7 @@ int mgcp_endpoints_allocate(struct mgcp_trunk_config *cfg);
 void mgcp_free_endp(struct mgcp_endpoint *endp);
 int mgcp_reset_transcoder(struct mgcp_config *cfg);
 void mgcp_format_stats(struct mgcp_endpoint *endp, char *stats, size_t size);
+int mgcp_parse_stats(struct msgb *msg, uint32_t *ps, uint32_t *os, uint32_t *pr, uint32_t *_or, int *loss, uint32_t *jitter);
 
 /*
  * format helper functions
diff --git a/openbsc/src/libmgcp/mgcp_protocol.c b/openbsc/src/libmgcp/mgcp_protocol.c
index 6919a591d..dc5e0f992 100644
--- a/openbsc/src/libmgcp/mgcp_protocol.c
+++ b/openbsc/src/libmgcp/mgcp_protocol.c
@@ -1167,9 +1167,37 @@ void mgcp_format_stats(struct mgcp_endpoint *endp, char *msg, size_t size)
 				&expected, &ploss);
 	jitter = mgcp_state_calc_jitter(&endp->net_state);
 
-	snprintf(msg, size, "\r\nP: PS=%u, OS=%u, PR=%u, OR=%u, PL=%d, JI=%d",
+	snprintf(msg, size, "\r\nP: PS=%u, OS=%u, PR=%u, OR=%u, PL=%d, JI=%u",
 			endp->bts_end.packets, endp->bts_end.octets,
 			endp->net_end.packets, endp->net_end.octets,
 			ploss, jitter);
 	msg[size - 1] = '\0';
 }
+
+int mgcp_parse_stats(struct msgb *msg, uint32_t *ps, uint32_t *os,
+		uint32_t *pr, uint32_t *_or, int *loss, uint32_t *jitter)
+{
+	char *line, *save;
+	int rc;
+
+	/* initialize with bad values */
+	*ps = *os = *pr = *_or = *jitter = UINT_MAX;
+	*loss = INT_MAX;
+
+
+	line = strtok_r((char *) msg->l2h, "\r\n", &save);
+	if (!line)
+		return -1;
+
+	/* this can only parse the message that is created above... */
+	for_each_line(line, save) {
+		switch (line[0]) {
+		case 'P':
+			rc = sscanf(line, "P: PS=%u, OS=%u, PR=%u, OR=%u, PL=%d, JI=%u",
+					ps, os, pr, _or, loss, jitter);
+			return rc == 6 ? 0 : -1;
+		}
+	}
+
+	return -1;
+}
diff --git a/openbsc/src/osmo-bsc_nat/bsc_mgcp_utils.c b/openbsc/src/osmo-bsc_nat/bsc_mgcp_utils.c
index 480a8f6d1..a29e9d70d 100644
--- a/openbsc/src/osmo-bsc_nat/bsc_mgcp_utils.c
+++ b/openbsc/src/osmo-bsc_nat/bsc_mgcp_utils.c
@@ -49,6 +49,7 @@
 #include <openbsc/ipaccess.h>
 #include <openbsc/mgcp.h>
 #include <openbsc/mgcp_internal.h>
+#include <openbsc/control_cmd.h>
 
 #include <osmocom/sccp/sccp.h>
 
@@ -276,14 +277,20 @@ static void bsc_mgcp_send_mdcx(struct bsc_connection *bsc, int port, struct mgcp
 	bsc_write_mgcp(bsc, (uint8_t *) buf, len);
 }
 
-static void bsc_mgcp_send_dlcx(struct bsc_connection *bsc, int endpoint)
+static void bsc_mgcp_send_dlcx(struct bsc_connection *bsc, int endpoint, int trans)
 {
 	char buf[2096];
 	int len;
 
+	/*
+	 * The following is a bit of a spec violation. According to the
+	 * MGCP grammar the transaction id is are upto 9 digits but we
+	 * prefix it with an alpha numeric value so we can easily recognize
+	 * it as a response.
+	 */
 	len = snprintf(buf, sizeof(buf),
-		       "DLCX 26 %x@mgw MGCP 1.0\r\n"
-		       "Z: noanswer\r\n", endpoint);
+		       "DLCX nat-%u %x@mgw MGCP 1.0\r\n",
+			trans, endpoint);
 	if (len < 0) {
 		LOGP(DMGCP, LOGL_ERROR, "snprintf for DLCX failed.\n");
 		return;
@@ -298,18 +305,153 @@ void bsc_mgcp_init(struct sccp_connections *con)
 	con->bsc_endp = -1;
 }
 
+/**
+ * This code will remember the network side of the audio statistics and
+ * once the internal DLCX response arrives this can be combined with the
+ * the BSC side and forwarded as a trap.
+ */
+static void remember_pending_dlcx(struct sccp_connections *con, uint32_t transaction)
+{
+	struct bsc_nat_call_stats *stats;
+	struct bsc_connection *bsc = con->bsc;
+	struct mgcp_endpoint *endp;
+
+	stats = talloc_zero(bsc, struct bsc_nat_call_stats);
+	if (!stats) {
+		LOGP(DNAT, LOGL_NOTICE,
+			"Failed to allocate statistics for endpoint 0x%x\n",
+			con->msc_endp);
+		return;
+	}
+
+	/* take the endpoint here */
+	endp = &bsc->nat->mgcp_cfg->trunk.endpoints[con->msc_endp];
+
+	stats->remote_ref = con->remote_ref;
+	stats->src_ref = con->patched_ref;
+
+	stats->ci = endp->ci;
+	stats->bts_rtp_port = endp->bts_end.rtp_port;
+	stats->bts_addr = endp->bts_end.addr;
+	stats->net_rtp_port = endp->net_end.rtp_port;
+	stats->net_addr = endp->net_end.addr;
+
+	stats->net_ps = endp->net_end.packets;
+	stats->net_os = endp->net_end.octets;
+	stats->bts_pr = endp->bts_end.packets;
+	stats->bts_or = endp->bts_end.octets;
+	mgcp_state_calc_loss(&endp->bts_state, &endp->bts_end,
+				&stats->bts_expected, &stats->bts_loss);
+	stats->bts_jitter = mgcp_state_calc_jitter(&endp->bts_state);
+
+	stats->trans_id = transaction;
+	stats->msc_endpoint = con->msc_endp;
+
+	bsc->pending_dlcx_count += 1;
+	llist_add_tail(&stats->entry, &bsc->pending_dlcx);
+}
+
 void bsc_mgcp_dlcx(struct sccp_connections *con)
 {
 	/* send a DLCX down the stream */
 	if (con->bsc_endp != -1 && con->bsc->_endpoint_status) {
+		LOGP(DNAT, LOGL_NOTICE,
+			"Endpoint 0x%x was still allocated on bsc: %d. Freeing it.\n",
+			con->bsc_endp, con->bsc->cfg->nr);
 		if (con->bsc->_endpoint_status[con->bsc_endp] != 1)
 			LOGP(DNAT, LOGL_ERROR, "Endpoint 0x%x was not in use\n", con->bsc_endp);
+		remember_pending_dlcx(con, con->bsc->next_transaction);
 		con->bsc->_endpoint_status[con->bsc_endp] = 0;
-		bsc_mgcp_send_dlcx(con->bsc, con->bsc_endp);
+		bsc_mgcp_send_dlcx(con->bsc, con->bsc_endp, con->bsc->next_transaction++);
 		bsc_mgcp_free_endpoint(con->bsc->nat, con->msc_endp);
 	}
 
 	bsc_mgcp_init(con);
+
+}
+
+/*
+ * Search for the pending request
+ */
+static void handle_dlcx_response(struct bsc_connection *bsc, struct msgb *msg,
+			int code, const char *transaction)
+{
+	uint32_t trans_id = UINT32_MAX;
+	uint32_t b_ps, b_os, n_pr, n_or, jitter;
+	int loss;
+	struct bsc_nat_call_stats *tmp, *stat = NULL;
+	struct ctrl_cmd *cmd;
+
+	/* parse the transaction identifier */
+	int rc = sscanf(transaction, "nat-%u", &trans_id);
+	if (rc != 1) {
+		LOGP(DNAT, LOGL_ERROR, "Can not parse transaction id: '%s'\n",
+			transaction);
+		return;
+	}
+
+	/* find the answer for the request we made */
+	llist_for_each_entry(tmp, &bsc->pending_dlcx, entry) {
+		if (trans_id != tmp->trans_id)
+			continue;
+
+		stat = tmp;
+		break;
+	}
+
+	if (!stat) {
+		LOGP(DNAT, LOGL_ERROR,
+			"Can not find transaction for: %u\n", trans_id);
+		return;
+	}
+
+	/* attempt to parse the data now */
+	rc = mgcp_parse_stats(msg, &b_ps, &b_os, &n_pr, &n_or, &loss, &jitter);
+	if (rc != 0)
+		LOGP(DNAT, LOGL_ERROR,
+			"Can not parse connection statistics: %d\n", rc);
+
+	/* send a trap now */
+	cmd = ctrl_cmd_create(bsc, CTRL_TYPE_TRAP);
+	if (!cmd) {
+		LOGP(DNAT, LOGL_ERROR,
+			"Creating a ctrl cmd failed.\n");
+		goto free_stat;
+	}
+
+	cmd->id = "0";
+	cmd->variable = "nat.call_stats.v1";
+	cmd->reply = talloc_asprintf(cmd,
+			"bsc_id=%d,mg_ip_addr=%s,mg_port=%d,",
+			bsc->cfg->nr, inet_ntoa(stat->net_addr),
+			stat->net_rtp_port);
+	cmd->reply = talloc_asprintf_append(cmd->reply,
+			"endpoint_ip_addr=%s,endpoint_port=%d,",
+			inet_ntoa(stat->bts_addr),
+			stat->bts_rtp_port);
+	cmd->reply = talloc_asprintf_append(cmd->reply,
+			"nat_pkt_in=%u,nat_pkt_out=%u,"
+			"nat_bytes_in=%u,nat_bytes_out=%u,"
+			"nat_jitter=%u,nat_pkt_lost=%d,",
+			stat->bts_pr, stat->net_ps,
+			stat->bts_or, stat->net_os,
+			stat->bts_jitter, stat->bts_loss);
+	cmd->reply = talloc_asprintf_append(cmd->reply,
+			"bsc_pkt_in=%u,bsc_pkt_out=%u,"
+			"bsc_bytes_in=%u,bsc_bytes_out=%u,"
+			"bsc_jitter=%u,bsc_pkt_lost=%d",
+			n_pr, b_ps,
+			n_or, b_os,
+			jitter, loss);
+
+	/* send it and be done */
+	ctrl_cmd_send_to_all(bsc->nat->ctrl, cmd);
+	talloc_free(cmd);
+
+free_stat:
+	bsc->pending_dlcx_count -= 1;
+	llist_del(&stat->entry);
+	talloc_free(stat);
 }
 
 
@@ -330,7 +472,8 @@ struct sccp_connections *bsc_mgcp_find_con(struct bsc_nat *nat, int endpoint)
 	if (con)
 		return con;
 
-	LOGP(DMGCP, LOGL_ERROR, "Failed to find the connection.\n");
+	LOGP(DMGCP, LOGL_ERROR,
+		"Failed to find the connection for endpoint: 0x%x\n", endpoint);
 	return NULL;
 }
 
@@ -435,7 +578,7 @@ static void free_chan_downstream(struct mgcp_endpoint *endp, struct bsc_endpoint
 				ENDPOINT_NUMBER(endp));
 		} else {
 			if (con->bsc == bsc) {
-				bsc_mgcp_send_dlcx(bsc, con->bsc_endp);
+				bsc_mgcp_send_dlcx(bsc, con->bsc_endp, con->bsc->next_transaction++);
 			} else {
 				LOGP(DMGCP, LOGL_ERROR,
 					"Endpoint belongs to a different BSC\n");
@@ -452,6 +595,9 @@ static void free_chan_downstream(struct mgcp_endpoint *endp, struct bsc_endpoint
  * this transaction and if it belongs to the BSC. Then we will
  * need to patch the content to point to the local network and we
  * need to update the I: that was assigned by the BSS.
+ *
+ * Only responses to CRCX and DLCX should arrive here. The DLCX
+ * needs to be handled specially to combine the two statistics.
  */
 void bsc_mgcp_forward(struct bsc_connection *bsc, struct msgb *msg)
 {
@@ -488,6 +634,11 @@ void bsc_mgcp_forward(struct bsc_connection *bsc, struct msgb *msg)
 		break;
 	}
 
+	if (!bsc_endp && strncmp("nat-", transaction_id, 4) == 0) {
+		handle_dlcx_response(bsc, msg, code, transaction_id);
+		return;
+	}
+
 	if (!bsc_endp) {
 		LOGP(DMGCP, LOGL_ERROR, "Could not find active endpoint: %s for msg: '%s'\n",
 		     transaction_id, (const char *) msg->l2h);
@@ -523,8 +674,11 @@ void bsc_mgcp_forward(struct bsc_connection *bsc, struct msgb *msg)
 
 int bsc_mgcp_parse_response(const char *str, int *code, char transaction[60])
 {
+	int rc;
 	/* we want to parse two strings */
-	return sscanf(str, "%3d %59s\n", code, transaction) != 2;
+	rc = sscanf(str, "%3d %59s\n", code, transaction) != 2;
+	transaction[59] = '\0';
+	return rc;
 }
 
 uint32_t bsc_mgcp_extract_ci(const char *str)
diff --git a/openbsc/src/osmo-bsc_nat/bsc_nat_utils.c b/openbsc/src/osmo-bsc_nat/bsc_nat_utils.c
index 0c56a8cd9..2e6d9a363 100644
--- a/openbsc/src/osmo-bsc_nat/bsc_nat_utils.c
+++ b/openbsc/src/osmo-bsc_nat/bsc_nat_utils.c
@@ -132,6 +132,7 @@ struct bsc_connection *bsc_connection_alloc(struct bsc_nat *nat)
 	con->nat = nat;
 	osmo_wqueue_init(&con->write_queue, 100);
 	INIT_LLIST_HEAD(&con->cmd_pending);
+	INIT_LLIST_HEAD(&con->pending_dlcx);
 	return con;
 }
 
diff --git a/openbsc/src/osmo-bsc_nat/bsc_nat_vty.c b/openbsc/src/osmo-bsc_nat/bsc_nat_vty.c
index 32e5106ae..e5993b4a8 100644
--- a/openbsc/src/osmo-bsc_nat/bsc_nat_vty.c
+++ b/openbsc/src/osmo-bsc_nat/bsc_nat_vty.c
@@ -206,10 +206,11 @@ DEFUN(show_bsc, show_bsc_cmd, "show bsc connections",
 
 	llist_for_each_entry(con, &_nat->bsc_connections, list_entry) {
 		getpeername(con->write_queue.bfd.fd, (struct sockaddr *) &sock, &len);
-		vty_out(vty, "BSC nr: %d auth: %d fd: %d peername: %s%s",
+		vty_out(vty, "BSC nr: %d auth: %d fd: %d peername: %s pending-stats: %u%s",
 			con->cfg ? con->cfg->nr : -1,
 			con->authenticated, con->write_queue.bfd.fd,
-			inet_ntoa(sock.sin_addr), VTY_NEWLINE);
+			inet_ntoa(sock.sin_addr), con->pending_dlcx_count,
+			VTY_NEWLINE);
 	}
 
 	return CMD_SUCCESS;
diff --git a/openbsc/tests/bsc-nat/Makefile.am b/openbsc/tests/bsc-nat/Makefile.am
index e284851a1..9b71d095c 100644
--- a/openbsc/tests/bsc-nat/Makefile.am
+++ b/openbsc/tests/bsc-nat/Makefile.am
@@ -14,6 +14,7 @@ bsc_nat_test_SOURCES = bsc_nat_test.c \
 			$(top_srcdir)/src/osmo-bsc_nat/bsc_nat_rewrite.c \
 			$(top_srcdir)/src/osmo-bsc_nat/bsc_mgcp_utils.c
 bsc_nat_test_LDADD = $(top_builddir)/src/libbsc/libbsc.a \
+			$(top_srcdir)/src/libctrl/libctrl.a \
 			$(top_srcdir)/src/libmgcp/libmgcp.a \
 			$(top_srcdir)/src/libtrau/libtrau.a \
 			$(top_srcdir)/src/libcommon/libcommon.a \
diff --git a/openbsc/tests/bsc-nat/bsc_nat_test.c b/openbsc/tests/bsc-nat/bsc_nat_test.c
index 3b5c24e36..c2931f98b 100644
--- a/openbsc/tests/bsc-nat/bsc_nat_test.c
+++ b/openbsc/tests/bsc-nat/bsc_nat_test.c
@@ -514,6 +514,7 @@ static void test_mgcp_ass_tracking(void)
 					       33);
 	nat->mgcp_cfg = mgcp_config_alloc();
 	nat->mgcp_cfg->trunk.number_endpoints = 64;
+	mgcp_endpoints_allocate(&nat->mgcp_cfg->trunk);
 
 	bsc = bsc_connection_alloc(nat);
 	bsc->cfg = bsc_config_alloc(nat, "foo");
diff --git a/openbsc/tests/mgcp/mgcp_test.c b/openbsc/tests/mgcp/mgcp_test.c
index 4dfd2abe3..5565e7316 100644
--- a/openbsc/tests/mgcp/mgcp_test.c
+++ b/openbsc/tests/mgcp/mgcp_test.c
@@ -323,6 +323,30 @@ static void test_packet_loss_calc(void)
 	}
 }
 
+static void test_mgcp_stats(void)
+{
+	printf("Testing stat parsing\n");
+
+	uint32_t bps, bos, pr, _or, jitter;
+	struct msgb *msg;
+	int loss;
+	int rc;
+
+	msg = create_msg(DLCX_RET);
+	rc = mgcp_parse_stats(msg, &bps, &bos, &pr, &_or, &loss, &jitter);
+	printf("Parsing result: %d\n", rc);
+	if (bps != 0 || bos != 0 || pr != 0 ||  _or != 0 || loss != 0 || jitter != 0)
+		printf("FAIL: Parsing failed1.\n");
+	msgb_free(msg);
+
+	msg = create_msg("250 7 OK\r\nP: PS=10, OS=20, PR=30, OR=40, PL=-3, JI=40\r\n");
+	rc = mgcp_parse_stats(msg, &bps, &bos, &pr, &_or, &loss, &jitter);
+	printf("Parsing result: %d\n", rc);
+	if (bps != 10 || bos != 20 || pr != 30 || _or != 40 || loss != -3 || jitter != 40)
+		printf("FAIL: Parsing failed2.\n");
+	msgb_free(msg);
+}
+
 int main(int argc, char **argv)
 {
 	osmo_init_logging(&log_info);
@@ -331,6 +355,7 @@ int main(int argc, char **argv)
 	test_retransmission();
 	test_packet_loss_calc();
 	test_rqnt_cb();
+	test_mgcp_stats();
 
 	printf("Done\n");
 	return EXIT_SUCCESS;
diff --git a/openbsc/tests/mgcp/mgcp_test.ok b/openbsc/tests/mgcp/mgcp_test.ok
index 224bba8d7..8711e38f2 100644
--- a/openbsc/tests/mgcp/mgcp_test.ok
+++ b/openbsc/tests/mgcp/mgcp_test.ok
@@ -25,4 +25,7 @@ Re-transmitting MDCX3
 Testing DLCX
 Re-transmitting DLCX
 Testing packet loss calculation.
+Testing stat parsing
+Parsing result: 0
+Parsing result: 0
 Done