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.
diff --git a/openbsc/include/openbsc/bsc_nat.h b/openbsc/include/openbsc/bsc_nat.h
index 4baaa82..6860342 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 @@
 	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 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 7a416dd..811dcfd 100644
--- a/openbsc/include/openbsc/mgcp.h
+++ b/openbsc/include/openbsc/mgcp.h
@@ -172,6 +172,7 @@
 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 6919a59..dc5e0f9 100644
--- a/openbsc/src/libmgcp/mgcp_protocol.c
+++ b/openbsc/src/libmgcp/mgcp_protocol.c
@@ -1167,9 +1167,37 @@
 				&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 480a8f6..a29e9d7 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 @@
 	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 @@
 	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 @@
 	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 @@
 				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 @@
  * 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 @@
 		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 @@
 
 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 0c56a8c..2e6d9a3 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 @@
 	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 32e5106..e5993b4 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 @@
 
 	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 e284851..9b71d09 100644
--- a/openbsc/tests/bsc-nat/Makefile.am
+++ b/openbsc/tests/bsc-nat/Makefile.am
@@ -14,6 +14,7 @@
 			$(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 3b5c24e..c2931f9 100644
--- a/openbsc/tests/bsc-nat/bsc_nat_test.c
+++ b/openbsc/tests/bsc-nat/bsc_nat_test.c
@@ -514,6 +514,7 @@
 					       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 4dfd2ab..5565e73 100644
--- a/openbsc/tests/mgcp/mgcp_test.c
+++ b/openbsc/tests/mgcp/mgcp_test.c
@@ -323,6 +323,30 @@
 	}
 }
 
+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 @@
 	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 224bba8..8711e38 100644
--- a/openbsc/tests/mgcp/mgcp_test.ok
+++ b/openbsc/tests/mgcp/mgcp_test.ok
@@ -25,4 +25,7 @@
 Testing DLCX
 Re-transmitting DLCX
 Testing packet loss calculation.
+Testing stat parsing
+Parsing result: 0
+Parsing result: 0
 Done