neels submitted this change.

View Change

upf gtp-u echo: improve loging

Tweak GTPv1-U Echo logging to more consistently show logging like:

DGTP INFO apn11 [23] 127.0.0.11:2152: <- 127.0.0.12:2152: rx GTPv1-U Echo Request: seq_nr=123 recovery_count=131
DGTP INFO apn11 [23] 127.0.0.11:2152: -> 127.0.0.12:2152: tx GTPv1-U Echo Response: seq_nr=123 recovery_count=570

Change-Id: I3c7fe7c3eb1467ae34085da6bbf26a935a6c927b
---
M src/osmo-upf/upf_gtpu_echo.c
1 file changed, 27 insertions(+), 16 deletions(-)

diff --git a/src/osmo-upf/upf_gtpu_echo.c b/src/osmo-upf/upf_gtpu_echo.c
index cbf804b..d8958e8 100644
--- a/src/osmo-upf/upf_gtpu_echo.c
+++ b/src/osmo-upf/upf_gtpu_echo.c
@@ -50,12 +50,17 @@
 
 static int tx_echo_resp(struct upf_gtp_dev *dev, const struct osmo_sockaddr *remote, uint16_t seq_nr);
 
-static int rx_echo_req(struct upf_gtp_dev *dev, const struct osmo_sockaddr *remote, const struct gtp1u_hdr *rx_h)
+static int rx_echo_req(struct upf_gtp_dev *dev, const struct osmo_sockaddr *remote, const struct gtp1u_hdr *rx_h,
+		       size_t msg_len)
 {
-	if (!rx_h->s) {
-		LOG_GTP_DEV(dev, LOGL_ERROR, "rx GTPv1-U ECHO REQ without sequence nr\n");
-		return -1;
-	}
+	uint16_t seq_nr = 0;
+	uint8_t recovery_count = 0;
+	if (msg_len >= (sizeof(*rx_h) + 2) && rx_h->data2[0] == GTP1U_IEI_RECOVERY)
+		recovery_count = rx_h->data2[1];
+
+	seq_nr = rx_h->s;
+	LOG_GTP_DEV(dev, LOGL_INFO, "<- %s: rx GTPv1-U Echo Request: seq_nr=%u recovery_count=%u\n",
+		    osmo_sockaddr_to_str(remote), seq_nr, recovery_count);
 
 	return tx_echo_resp(dev, remote, rx_h->ext.seq_nr);
 }
@@ -66,7 +71,7 @@
 	struct gtp1u_hdr *tx_h;
 	int rc;
 
-	msg = msgb_alloc_headroom(1024, 128, "GTP-echo-resp");
+	msg = msgb_alloc_headroom(1024, 128, "GTPv1-U-echo-resp");
 	tx_h = (void *)msgb_put(msg, sizeof(*tx_h));
 
 	*tx_h = (struct gtp1u_hdr){
@@ -90,9 +95,13 @@
 
 	rc = sendto(dev->gtpv1.ofd.fd, msgb_data(msg), msgb_length(msg), 0, &remote->u.sa, sizeof(*remote));
 	if (rc < 0) {
-		int err = errno;
-		LOG_GTP_DEV(dev, LOGL_ERROR, "GTP1-U sendto(len=%d, to=%s): %s\n", msgb_length(msg),
-			    osmo_sockaddr_to_str(remote), strerror(err));
+		rc = -errno;
+		LOG_GTP_DEV(dev, LOGL_ERROR, "-> %s: tx GTPv1-U Echo Response: sendto(len=%d): %s\n",
+			    osmo_sockaddr_to_str(remote), msgb_length(msg), strerror(-rc));
+	} else {
+		LOG_GTP_DEV(dev, LOGL_INFO, "-> %s: tx GTPv1-U Echo Response: seq_nr=%u recovery_count=%u\n",
+			    osmo_sockaddr_to_str(remote), seq_nr, g_upf->tunend.recovery_count);
+		rc = 0;
 	}
 	msgb_free(msg);
 	return rc;
@@ -121,27 +130,29 @@
 	/* A GTPv1-U header of size 8 is valid, but this code expects to handle only ECHO REQUEST messages. These are
 	 * required to have a sequence number, hence this check here consciously uses the full sizeof(*h) == 12. */
 	if (sz < sizeof(*h)) {
-		LOG_GTP_DEV(dev, LOGL_ERROR, "rx GTP packet smaller than the GTPv1-U header + sequence nr: %zd < %zu\n",
-			    sz, sizeof(*h));
+		LOG_GTP_DEV(dev, LOGL_ERROR,
+			    "<- %s: rx GTPv1-U packet smaller than the GTPv1-U header + sequence nr: %zd < %zu\n",
+			    osmo_sockaddr_to_str(&remote), sz, sizeof(*h));
 		return -1;
 	}
 
 	h = (const struct gtp1u_hdr *)buf;
 	if (h->version != 1) {
-		LOG_GTP_DEV(dev, LOGL_ERROR, "rx GTP v%u: only GTP version 1 supported\n", h->version);
+		LOG_GTP_DEV(dev, LOGL_ERROR, "<- %s: rx GTPv1-U v%u: only GTP version 1 supported\n",
+			    osmo_sockaddr_to_str(&remote), h->version);
 		return -1;
 	}
 
 	h_length = osmo_load16be(&h->length);
 	if (offsetof(struct gtp1u_hdr, data1) + h_length > sz) {
-		LOG_GTP_DEV(dev, LOGL_ERROR, "rx GTP: header + h.length = %zu > received bytes = %zd\n",
-			    offsetof(struct gtp1u_hdr, data1) + h_length, sz);
+		LOG_GTP_DEV(dev, LOGL_ERROR, "<- %s: rx GTPv1-U: header + h.length = %zu > received bytes = %zd\n",
+			    osmo_sockaddr_to_str(&remote), offsetof(struct gtp1u_hdr, data1) + h_length, sz);
 		return -1;
 	}
 
 	switch (h->msg_type) {
 	case GTP1U_MSGTYPE_ECHO_REQ:
-		return rx_echo_req(dev, &remote, h);
+		return rx_echo_req(dev, &remote, h, sz);
 	default:
 		LOG_GTP_DEV(dev, LOGL_ERROR, "rx: GTPv1-U message type %u not supported\n", h->msg_type);
 		return -1;
@@ -151,7 +162,7 @@
 int upf_gtpu_echo_setup(struct upf_gtp_dev *dev)
 {
 	if (dev->gtpv1.ofd.fd == -1) {
-		LOGP(DGTP, LOGL_ERROR, "Cannot setup GTP-U ECHO: GTP-v1 socket not initialized\n");
+		LOGP(DGTP, LOGL_ERROR, "Cannot setup GTPv1-U ECHO: socket not initialized\n");
 		return -EINVAL;
 	}
 

To view, visit change 37828. To unsubscribe, or for help writing mail filters, visit settings.