Change in libosmocore[master]: ns2: Unify logging context via log macros

This is merely a historical archive of years 2008-2021, before the migration to mailman3.

A maintained and still updated list archive can be found at https://lists.osmocom.org/hyperkitty/list/gerrit-log@lists.osmocom.org/.

lynxis lazus gerrit-no-reply at lists.osmocom.org
Wed Jan 20 16:42:34 UTC 2021


lynxis lazus has submitted this change. ( https://gerrit.osmocom.org/c/libosmocore/+/22337 )

Change subject: ns2: Unify logging context via log macros
......................................................................

ns2: Unify logging context via log macros

Let's avoid open-coding the printing of log context and rather rely on
log macros to prefix each log line with the relevant context.  This
helps log readability, log post processing whether by grep or more
sophisticated tools.

Change-Id: I946c0e77686d91efc5afb62031e1ac1033a9a586
---
M src/gb/gprs_ns2.c
M src/gb/gprs_ns2_fr.c
M src/gb/gprs_ns2_frgre.c
M src/gb/gprs_ns2_internal.h
M src/gb/gprs_ns2_message.c
M src/gb/gprs_ns2_sns.c
M src/gb/gprs_ns2_udp.c
M src/gb/gprs_ns2_vc_fsm.c
8 files changed, 112 insertions(+), 119 deletions(-)

Approvals:
  lynxis lazus: Looks good to me, approved
  pespin: Looks good to me, but someone else must approve
  Jenkins Builder: Verified



diff --git a/src/gb/gprs_ns2.c b/src/gb/gprs_ns2.c
index dc8ad8e..ec60dbd 100644
--- a/src/gb/gprs_ns2.c
+++ b/src/gb/gprs_ns2.c
@@ -695,7 +695,7 @@
 
 	nse = gprs_ns2_nse_by_nsei(nsi, nsei);
 	if (nse) {
-		LOGP(DLNS, LOGL_ERROR, "NSEI:%u Can not create a NSE with already taken NSEI\n", nsei);
+		LOGNSE(nse, LOGL_ERROR, "Can not create a NSE with already taken NSEI\n");
 		return nse;
 	}
 
@@ -885,8 +885,9 @@
 	} else {
 		/* nsei already known */
 		if (nse->ll != bind->ll) {
-			LOGP(DLNS, LOGL_ERROR, "Received NS-RESET NS-VCI(%05u) with wrong linklayer(%s) for already known NSE(%05u/%s)\n",
-			     nsei, gprs_ns2_lltype_str(bind->ll), nse->nsei, gprs_ns2_lltype_str(nse->ll));
+			LOGNSE(nse, LOGL_ERROR, "Received NS-RESET NS-VCI(%05u) with wrong linklayer(%s)"
+				" for already known NSE(%s)\n", nsvci, gprs_ns2_lltype_str(bind->ll),
+				gprs_ns2_lltype_str(nse->ll));
 			return GPRS_NS2_CS_SKIPPED;
 		}
 	}
@@ -894,8 +895,7 @@
 	nsvc = gprs_ns2_nsvc_by_nsvci(bind->nsi, nsvci);
 	if (nsvc) {
 		if (nsvc->persistent) {
-			LOGP(DLNS, LOGL_ERROR, "Received NS-RESET for a persistent NSE(%05u) NS-VCI(%05u) over wrong connection.\n",
-			     nsei, nsvci);
+			LOGNSVC(nsvc, LOGL_ERROR, "Received NS-RESET for a persistent NSE over wrong connection.\n");
 			return GPRS_NS2_CS_SKIPPED;
 		}
 		/* destroy old dynamic nsvc */
@@ -904,8 +904,8 @@
 
 	/* do nse persistent check late to be more precise on the error message */
 	if (nse->persistent) {
-		LOGP(DLNS, LOGL_ERROR, "Received NS-RESET for a persistent NSE(%05u) but the unknown NS-VCI(%05u)\n",
-		     nsei, nsvci);
+		LOGNSE(nse, LOGL_ERROR, "Received NS-RESET for a persistent NSE but the unknown "
+		       "NS-VCI(%05u)\n", nsvci);
 		return GPRS_NS2_CS_SKIPPED;
 	}
 
diff --git a/src/gb/gprs_ns2_fr.c b/src/gb/gprs_ns2_fr.c
index a7455d7..274ed96 100644
--- a/src/gb/gprs_ns2_fr.c
+++ b/src/gb/gprs_ns2_fr.c
@@ -214,8 +214,7 @@
 
 	rc = recvfrom(bfd->fd, msg->data, NS_ALLOC_SIZE, 0, (struct sockaddr *)&sll, &sll_len);
 	if (rc < 0) {
-		LOGP(DLNS, LOGL_ERROR, "recv error %s during NS-FR-GRE recv\n",
-		     strerror(errno));
+		LOGBIND(bind, LOGL_ERROR, "recv error %s during NS-FR-GRE recv\n", strerror(errno));
 		goto out_err;
 	} else if (rc == 0) {
 		goto out_err;
@@ -273,8 +272,7 @@
 	struct priv_bind *priv = bind->priv;
 
 	if (osmo_wqueue_enqueue(&priv->wqueue, msg)) {
-		LOGP(DLNS, LOGL_ERROR, "frame relay %s: failed to enqueue message\n",
-		     priv->netif);
+		LOGBIND(bind, LOGL_ERROR, "frame relay %s: failed to enqueue message\n", priv->netif);
 		msgb_free(msg);
 		return -EINVAL;
 	}
@@ -303,7 +301,7 @@
 	return ifr.ifr_ifindex;
 }
 
-static int open_socket(int ifindex)
+static int open_socket(int ifindex, const struct gprs_ns2_vc_bind *nsbind)
 {
 	struct sockaddr_ll addr;
 	int fd, rc;
@@ -315,7 +313,7 @@
 
 	fd = socket(AF_PACKET, SOCK_RAW, htons(ETH_P_HDLC));
 	if (fd < 0) {
-		LOGP(DLNS, LOGL_ERROR, "Can not create AF_PACKET socket. Are you root or have CAP_RAW_SOCKET?\n");
+		LOGBIND(nsbind, LOGL_ERROR, "Can not create AF_PACKET socket. Are you root or have CAP_NET_RAW?\n");
 		return fd;
 	}
 
@@ -324,7 +322,7 @@
 
 	rc = bind(fd, (struct sockaddr *)&addr, sizeof(addr));
 	if (rc < 0) {
-		LOGP(DLNS, LOGL_ERROR, "Can not bind AF_PACKET socket to ifindex %d\n", ifindex);
+		LOGBIND(nsbind, LOGL_ERROR, "Can not bind AF_PACKET socket to ifindex %d\n", ifindex);
 		close(fd);
 		return rc;
 	}
@@ -410,8 +408,8 @@
 		struct priv_bind *bpriv = bind->priv;
 		if (bpriv->if_running != if_running) {
 			/* update running state */
-			LOGP(DLNS, LOGL_NOTICE, "FR net-device '%s': Physical link state changed: %s\n",
-			     ifname, if_running ? "UP" : "DOWN");
+			LOGBIND(bind, LOGL_NOTICE, "FR net-device '%s': Physical link state changed: %s\n",
+				ifname, if_running ? "UP" : "DOWN");
 			bpriv->if_running = if_running;
 		}
 	}
@@ -471,7 +469,7 @@
 	return rc;
 }
 
-static int setup_device(const char *netif)
+static int setup_device(const char *netif, const struct gprs_ns2_vc_bind *bind)
 {
 	int sock, rc;
 	char buffer[128];
@@ -480,8 +478,8 @@
 
 	sock = socket(PF_INET, SOCK_DGRAM, IPPROTO_IP);
 	if (sock < 0) {
-		LOGP(DLNS, LOGL_ERROR, "%s: Unable to create socket: %s\n",
-		     netif, strerror(errno));
+		LOGBIND(bind, LOGL_ERROR, "%s: Unable to create socket: %s\n",
+			netif, strerror(errno));
 		return sock;
 	}
 
@@ -495,22 +493,22 @@
 	/* EINVAL is returned when no protocol has been set */
 	rc = ioctl(sock, SIOCWANDEV, &req);
 	if (rc < 0 && errno != EINVAL) {
-		LOGP(DLNS, LOGL_ERROR, "%s: Unable to get FR protocol information: %s\n",
-		     netif, strerror(errno));
+		LOGBIND(bind, LOGL_ERROR, "%s: Unable to get FR protocol information: %s\n",
+			netif, strerror(errno));
 		goto err;
 	}
 
 	/* check if the device is good */
 	if (rc == 0 && req.ifr_settings.type == IF_PROTO_FR && fr->lmi == LMI_NONE) {
-		LOGP(DLNS, LOGL_NOTICE, "%s: has correct frame relay mode and lmi\n", netif);
+		LOGBIND(bind, LOGL_NOTICE, "%s: has correct frame relay mode and lmi\n", netif);
 		goto ifup;
 	}
 
 	/* modify the device to match */
 	rc = set_ifupdown(netif, false);
 	if (rc) {
-		LOGP(DLNS, LOGL_ERROR, "Unable to bring down the device %s: %s\n",
-		      netif, strerror(errno));
+		LOGBIND(bind, LOGL_ERROR, "Unable to bring down the device %s: %s\n",
+			netif, strerror(errno));
 		goto err;
 	}
 
@@ -533,19 +531,19 @@
 	/* monitored events count */
 	fr->n393 = 4;
 
-	LOGP(DLNS, LOGL_INFO, "%s: Setting frame relay related parameters\n", netif);
+	LOGBIND(bind, LOGL_INFO, "%s: Setting frame relay related parameters\n", netif);
 	rc = ioctl(sock, SIOCWANDEV, &req);
 	if (rc) {
-		LOGP(DLNS, LOGL_ERROR, "%s: Unable to set FR protocol on information: %s\n",
-		      netif, strerror(errno));
+		LOGBIND(bind, LOGL_ERROR, "%s: Unable to set FR protocol on information: %s\n",
+			netif, strerror(errno));
 		goto err;
 	}
 
 ifup:
 	rc = set_ifupdown(netif, true);
 	if (rc)
-		LOGP(DLNS, LOGL_ERROR, "Unable to bring up the device %s: %s\n",
-		      netif, strerror(errno));
+		LOGBIND(bind, LOGL_ERROR, "Unable to bring up the device %s: %s\n",
+			netif, strerror(errno));
 err:
 	close(sock);
 	return rc;
@@ -622,18 +620,18 @@
 
 	priv->ifindex = rc = devname2ifindex(netif);
 	if (rc < 0) {
-		LOGP(DLNS, LOGL_ERROR, "Can not get interface index for interface %s\n", netif);
+		LOGBIND(bind, LOGL_ERROR, "Can not get interface index for interface %s\n", netif);
 		goto err_fr;
 	}
 
 	/* set protocol frame relay and lmi */
-	rc = setup_device(priv->netif);
+	rc = setup_device(priv->netif, bind);
 	if(rc < 0) {
-		LOGP(DLNS, LOGL_ERROR, "Failed to setup the interface %s for frame relay and lmi\n", netif);
+		LOGBIND(bind, LOGL_ERROR, "Failed to setup the interface %s for frame relay and lmi\n", netif);
 		goto err_fr;
 	}
 
-	rc = open_socket(priv->ifindex);
+	rc = open_socket(priv->ifindex, bind);
 	if (rc < 0)
 		goto err_fr;
 	osmo_wqueue_init(&priv->wqueue, 10);
diff --git a/src/gb/gprs_ns2_frgre.c b/src/gb/gprs_ns2_frgre.c
index 86f0921..2812e12 100644
--- a/src/gb/gprs_ns2_frgre.c
+++ b/src/gb/gprs_ns2_frgre.c
@@ -180,26 +180,25 @@
 	inner_ip6h = (struct ip6_hdr *) ((uint8_t *)greh + sizeof(*greh));
 
 	if (gre_payload_len < sizeof(*ip6hdr) + sizeof(*inner_greh)) {
-		LOGP(DLNS, LOGL_ERROR, "GRE keepalive too short\n");
+		LOGBIND(bind, LOGL_ERROR, "GRE keepalive too short\n");
 		return -EIO;
 	}
 
 	if (!memcmp(&inner_ip6h->ip6_src, &ip6hdr->ip6_src, sizeof(struct in6_addr)) ||
 	    !memcmp(&inner_ip6h->ip6_dst, &ip6hdr->ip6_dst, sizeof(struct in6_addr))) {
-		LOGP(DLNS, LOGL_ERROR,
-			"GRE keepalive with wrong tunnel addresses\n");
+		LOGBIND(bind, LOGL_ERROR, "GRE keepalive with wrong tunnel addresses\n");
 		return -EIO;
 	}
 
 	/* Are IPv6 extensions header are allowed in the *inner*? In the outer they are */
 	if (inner_ip6h->ip6_ctlun.ip6_un1.ip6_un1_nxt != IPPROTO_GRE) {
-		LOGP(DLNS, LOGL_ERROR, "GRE keepalive with wrong protocol\n");
+		LOGBIND(bind, LOGL_ERROR, "GRE keepalive with wrong protocol\n");
 		return -EIO;
 	}
 
 	inner_greh = (struct gre_hdr *) ((uint8_t *)inner_ip6h + sizeof(struct ip6_hdr));
 	if (inner_greh->ptype != osmo_htons(GRE_PTYPE_KAR)) {
-		LOGP(DLNS, LOGL_ERROR, "GRE keepalive inner GRE type != 0\n");
+		LOGBIND(bind, LOGL_ERROR, "GRE keepalive inner GRE type != 0\n");
 		return -EIO;
 	}
 
@@ -212,7 +211,7 @@
 	ia6 = ip6hdr->ip6_src;
 	char ip6str[INET6_ADDRSTRLEN] = {};
 	inet_ntop(AF_INET6, &ia6, ip6str, INET6_ADDRSTRLEN);
-	LOGP(DLNS, LOGL_DEBUG, "GRE keepalive from %s, responding\n", ip6str);
+	LOGBIND(bind, LOGL_DEBUG, "GRE keepalive from %s, responding\n", ip6str);
 
 	/* why does it reduce the gre_payload_len by the ipv6 header?
 	 * make it similiar to ipv4 even this seems to be wrong */
@@ -238,25 +237,24 @@
 	inner_iph = (struct iphdr *) ((uint8_t *)greh + sizeof(*greh));
 
 	if (gre_payload_len < inner_iph->ihl*4 + sizeof(*inner_greh)) {
-		LOGP(DLNS, LOGL_ERROR, "GRE keepalive too short\n");
+		LOGBIND(bind, LOGL_ERROR, "GRE keepalive too short\n");
 		return -EIO;
 	}
 
 	if (inner_iph->saddr != iph->daddr ||
 	    inner_iph->daddr != iph->saddr) {
-		LOGP(DLNS, LOGL_ERROR,
-			"GRE keepalive with wrong tunnel addresses\n");
+		LOGBIND(bind, LOGL_ERROR, "GRE keepalive with wrong tunnel addresses\n");
 		return -EIO;
 	}
 
 	if (inner_iph->protocol != IPPROTO_GRE) {
-		LOGP(DLNS, LOGL_ERROR, "GRE keepalive with wrong protocol\n");
+		LOGBIND(bind, LOGL_ERROR, "GRE keepalive with wrong protocol\n");
 		return -EIO;
 	}
 
 	inner_greh = (struct gre_hdr *) ((uint8_t *)inner_iph + iph->ihl*4);
 	if (inner_greh->ptype != osmo_htons(GRE_PTYPE_KAR)) {
-		LOGP(DLNS, LOGL_ERROR, "GRE keepalive inner GRE type != 0\n");
+		LOGBIND(bind, LOGL_ERROR, "GRE keepalive inner GRE type != 0\n");
 		return -EIO;
 	}
 
@@ -267,8 +265,7 @@
 	daddr.sin_port = IPPROTO_GRE;
 
 	ia.s_addr = iph->saddr;
-	LOGP(DLNS, LOGL_DEBUG, "GRE keepalive from %s, responding\n",
-		inet_ntoa(ia));
+	LOGBIND(bind, LOGL_DEBUG, "GRE keepalive from %s, responding\n", inet_ntoa(ia));
 
 	/* why does it reduce the gre_payload_len by the ipv4 header? */
 	return sendto(priv->fd.fd, inner_greh,
@@ -277,7 +274,8 @@
 }
 
 static struct msgb *read_nsfrgre_msg(struct osmo_fd *bfd, int *error,
-				     struct osmo_sockaddr *saddr, uint16_t *dlci)
+				     struct osmo_sockaddr *saddr, uint16_t *dlci,
+				     const struct gprs_ns2_vc_bind *bind)
 {
 	struct msgb *msg = msgb_alloc(NS_ALLOC_SIZE, "Gb/NS/FR/GRE Rx");
 	int ret = 0;
@@ -296,8 +294,7 @@
 	ret = recvfrom(bfd->fd, msg->data, NS_ALLOC_SIZE, 0,
 			&saddr->u.sa, &saddr_len);
 	if (ret < 0) {
-		LOGP(DLNS, LOGL_ERROR, "recv error %s during NS-FR-GRE recv\n",
-			strerror(errno));
+		LOGBIND(bind, LOGL_ERROR, "recv error %s during NS-FR-GRE recv\n", strerror(errno));
 		*error = ret;
 		goto out_err;
 	} else if (ret == 0) {
@@ -323,7 +320,7 @@
 
 	/* TODO: add support for the extension headers */
 	if (msg->len < ip46hdr + sizeof(*greh) + 2) {
-		LOGP(DLNS, LOGL_ERROR, "Short IP packet: %u bytes\n", msg->len);
+		LOGBIND(bind, LOGL_ERROR, "Short IP packet: %u bytes\n", msg->len);
 		*error = -EIO;
 		goto out_err;
 	}
@@ -332,7 +329,7 @@
 	case AF_INET:
 		iph = (struct iphdr *) msg->data;
 		if (msg->len < (iph->ihl*4 + sizeof(*greh) + 2)) {
-			LOGP(DLNS, LOGL_ERROR, "Short IP packet: %u bytes\n", msg->len);
+			LOGBIND(bind, LOGL_ERROR, "Short IP packet: %u bytes\n", msg->len);
 			*error = -EIO;
 			goto out_err;
 		}
@@ -344,8 +341,7 @@
 
 	greh = (struct gre_hdr *) (msg->data + iph->ihl*4);
 	if (greh->flags) {
-		LOGP(DLNS, LOGL_NOTICE, "Unknown GRE flags 0x%04x\n",
-			osmo_ntohs(greh->flags));
+		LOGBIND(bind, LOGL_NOTICE, "Unknown GRE flags 0x%04x\n", osmo_ntohs(greh->flags));
 	}
 
 	switch (osmo_ntohs(greh->ptype)) {
@@ -362,29 +358,27 @@
 		/* continue as usual */
 		break;
 	default:
-		LOGP(DLNS, LOGL_NOTICE, "Unknown GRE protocol 0x%04x != FR\n",
-			osmo_ntohs(greh->ptype));
+		LOGBIND(bind, LOGL_NOTICE, "Unknown GRE protocol 0x%04x != FR\n", osmo_ntohs(greh->ptype));
 		*error = -EIO;
 		goto out_err;
 		break;
 	}
 
 	if (msg->len < sizeof(*greh) + 2) {
-		LOGP(DLNS, LOGL_ERROR, "Short FR header: %u bytes\n", msg->len);
+		LOGBIND(bind, LOGL_ERROR, "Short FR header: %u bytes\n", msg->len);
 		*error = -EIO;
 		goto out_err;
 	}
 
 	frh = (uint8_t *)greh + sizeof(*greh);
 	if (frh[0] & 0x01) {
-		LOGP(DLNS, LOGL_NOTICE, "Unsupported single-byte FR address\n");
+		LOGBIND(bind, LOGL_NOTICE, "Unsupported single-byte FR address\n");
 		*error = -EIO;
 		goto out_err;
 	}
 	*dlci = ((frh[0] & 0xfc) << 2);
 	if ((frh[1] & 0x0f) != 0x01) {
-		LOGP(DLNS, LOGL_NOTICE, "Unknown second FR octet 0x%02x\n",
-			frh[1]);
+		LOGBIND(bind, LOGL_NOTICE, "Unknown second FR octet 0x%02x\n", frh[1]);
 		*error = -EIO;
 		goto out_err;
 	}
@@ -430,13 +424,12 @@
 	struct msgb *reject;
 	uint16_t dlci;
 
-	msg = read_nsfrgre_msg(bfd, &rc, &saddr, &dlci);
+	msg = read_nsfrgre_msg(bfd, &rc, &saddr, &dlci, bind);
 	if (!msg)
 		return rc;
 
 	if (dlci == 0 || dlci == 1023) {
-		LOGP(DLNS, LOGL_INFO, "Received FR on LMI DLCI %u - ignoring\n",
-			dlci);
+		LOGBIND(bind, LOGL_INFO, "Received FR on LMI DLCI %u - ignoring\n", dlci);
 		rc = 0;
 		goto out;
 	}
@@ -603,8 +596,7 @@
 		rc = setsockopt(priv->fd.fd, IPPROTO_IP, IP_TOS,
 				&dscp, sizeof(dscp));
 		if (rc < 0)
-			LOGP(DLNS, LOGL_ERROR,
-				"Failed to set the DSCP to %d with ret(%d) errno(%d)\n",
+			LOGBIND(bind, LOGL_ERROR, "Failed to set the DSCP to %d with ret(%d) errno(%d)\n",
 				dscp, rc, errno);
 	}
 
diff --git a/src/gb/gprs_ns2_internal.h b/src/gb/gprs_ns2_internal.h
index ebb2e3b..7183bd8 100644
--- a/src/gb/gprs_ns2_internal.h
+++ b/src/gb/gprs_ns2_internal.h
@@ -8,6 +8,24 @@
 #include <osmocom/gprs/protocol/gsm_08_16.h>
 #include <osmocom/gprs/gprs_ns2.h>
 
+#define LOGNSE(nse, lvl, fmt, args ...) \
+	LOGP(DLNS, lvl, "NSE(%05u) " fmt, (nse)->nsei, ## args)
+
+#define LOGBIND(bind, lvl, fmt, args ...) \
+	LOGP(DLNS, lvl, "BIND(%s) " fmt, (bind)->name, ## args)
+
+
+#define LOGNSVC(nsvc, lvl, fmt, args ...)					\
+	do {									\
+		if ((nsvc)->nsvci_is_valid) {					\
+			LOGP(DLNS, lvl, "NSE(%05u)-NSVC(%05u) " fmt,		\
+			     (nsvc)->nse->nsei, (nsvc)->nsvci, ## args);	\
+		} else { 							\
+			LOGP(DLNS, lvl, "NSE(%05u)-NSVC(none) " fmt, 		\
+			     (nsvc)->nse->nsei, ## args);			\
+		}								\
+	} while (0)
+
 struct osmo_fsm_inst;
 struct tlv_parsed;
 struct vty;
diff --git a/src/gb/gprs_ns2_message.c b/src/gb/gprs_ns2_message.c
index 41605f4..9559229 100644
--- a/src/gb/gprs_ns2_message.c
+++ b/src/gb/gprs_ns2_message.c
@@ -43,8 +43,7 @@
 	do {										\
 		if (!nsvc->nse->bss_sns_fi)						\
 			break;								\
-		LOGP(DLNS, LOGL_DEBUG, "NSEI=%u Rx invalid packet %s with SNS\n",	\
-				       nsvc->nse->nsei, reason);			\
+		LOGNSVC(nsvc, LOGL_DEBUG, "invalid packet %s with SNS\n", reason);	\
 	} while (0)
 
 enum ns_ctr {
@@ -223,8 +222,7 @@
 	if (!msg)
 		return -ENOMEM;
 
-	LOGP(DLNS, LOGL_INFO, "NSEI=%u Tx NS BLOCK (NSVCI=%u, cause=%s)\n",
-		nsvc->nse->nsei, nsvc->nsvci, gprs_ns2_cause_str(cause));
+	LOGNSVC(nsvc, LOGL_INFO, "Tx NS BLOCK (cause=%s)\n", gprs_ns2_cause_str(cause));
 
 	rate_ctr_inc(&nsvc->ctrg->ctr[NS_CTR_BLOCKED]);
 
@@ -256,7 +254,7 @@
 	if (!msg)
 		return -ENOMEM;
 
-	LOGP(DLNS, LOGL_INFO, "NSEI=%u Tx NS BLOCK ACK (NSVCI=%u)\n", nsvc->nse->nsei, nsvc->nsvci);
+	LOGNSVC(nsvc, LOGL_INFO, "Tx NS BLOCK ACK\n");
 
 	msg->l2h = msgb_put(msg, sizeof(*nsh));
 	nsh = (struct gprs_ns_hdr *) msg->l2h;
@@ -287,8 +285,7 @@
 	if (!msg)
 		return -ENOMEM;
 
-	LOGP(DLNS, LOGL_INFO, "NSEI=%u Tx NS RESET (NSVCI=%u, cause=%s)\n",
-		nsvc->nse->nsei, nsvc->nsvci, gprs_ns2_cause_str(cause));
+	LOGNSVC(nsvc, LOGL_INFO, "Tx NS RESET (cause=%s)\n", gprs_ns2_cause_str(cause));
 
 	msg->l2h = msgb_put(msg, sizeof(*nsh));
 	nsh = (struct gprs_ns_hdr *) msg->l2h;
@@ -328,8 +325,7 @@
 
 	nsh->pdu_type = NS_PDUT_RESET_ACK;
 
-	LOGP(DLNS, LOGL_INFO, "NSEI=%u Tx NS RESET ACK (NSVCI=%u)\n",
-		nsvc->nse->nsei, nsvc->nsvci);
+	LOGNSVC(nsvc, LOGL_INFO, "Tx NS RESET ACK\n");
 
 	msgb_tvlv_put(msg, NS_IE_VCI, 2, (uint8_t *)&nsvci);
 	msgb_tvlv_put(msg, NS_IE_NSEI, 2, (uint8_t *)&nsei);
@@ -347,8 +343,7 @@
 
 	ERR_IF_NSVC_USES_SNS(nsvc, "transmit NS UNBLOCK");
 
-	LOGP(DLNS, LOGL_INFO, "NSEI=%u Tx NS UNBLOCK (NSVCI=%u)\n",
-		nsvc->nse->nsei, nsvc->nsvci);
+	LOGNSVC(nsvc, LOGL_INFO, "Tx NS UNBLOCK\n");
 
 	return ns2_tx_simple(nsvc, NS_PDUT_UNBLOCK);
 }
@@ -364,8 +359,7 @@
 
 	ERR_IF_NSVC_USES_SNS(nsvc, "transmit NS UNBLOCK ACK");
 
-	LOGP(DLNS, LOGL_INFO, "NSEI=%u Tx NS UNBLOCK (NSVCI=%u)\n",
-		nsvc->nse->nsei, nsvc->nsvci);
+	LOGNSVC(nsvc, LOGL_INFO, "Tx NS UNBLOCK_ACK\n");
 
 	return ns2_tx_simple(nsvc, NS_PDUT_UNBLOCK_ACK);
 }
@@ -377,8 +371,7 @@
 {
 	log_set_context(LOG_CTX_GB_NSE, nsvc->nse);
 	log_set_context(LOG_CTX_GB_NSVC, nsvc);
-	LOGP(DLNS, LOGL_DEBUG, "NSEI=%u Tx NS ALIVE (NSVCI=%u)\n",
-		nsvc->nse->nsei, nsvc->nsvci);
+	LOGNSVC(nsvc, LOGL_DEBUG, "Tx NS ALIVE\n");
 
 	return ns2_tx_simple(nsvc, NS_PDUT_ALIVE);
 }
@@ -390,8 +383,7 @@
 {
 	log_set_context(LOG_CTX_GB_NSE, nsvc->nse);
 	log_set_context(LOG_CTX_GB_NSVC, nsvc);
-	LOGP(DLNS, LOGL_DEBUG, "NSEI=%u Tx NS ALIVE_ACK (NSVCI=%u)\n",
-		nsvc->nse->nsei, nsvc->nsvci);
+	LOGNSVC(nsvc, LOGL_DEBUG, "Tx NS ALIVE_ACK\n");
 
 	return ns2_tx_simple(nsvc, NS_PDUT_ALIVE_ACK);
 }
@@ -414,7 +406,7 @@
 	msg->l2h = msgb_push(msg, sizeof(*nsh) + 3);
 	nsh = (struct gprs_ns_hdr *) msg->l2h;
 	if (!nsh) {
-		LOGP(DLNS, LOGL_ERROR, "Not enough headroom for NS header\n");
+		LOGNSVC(nsvc, LOGL_ERROR, "Not enough headroom for NS header\n");
 		msgb_free(msg);
 		return -EIO;
 	}
@@ -448,8 +440,7 @@
 	if (!msg)
 		return -ENOMEM;
 
-	LOGP(DLNS, LOGL_NOTICE, "NSEI=%u Tx NS STATUS (NSVCI=%u, cause=%s)\n",
-		nsvc->nse->nsei, nsvc->nsvci, gprs_ns2_cause_str(cause));
+	LOGNSVC(nsvc, LOGL_NOTICE, "Tx NS STATUS (cause=%s)\n", gprs_ns2_cause_str(cause));
 
 	msg->l2h = msgb_put(msg, sizeof(*nsh));
 	nsh = (struct gprs_ns_hdr *) msg->l2h;
@@ -512,8 +503,7 @@
 		return -ENOMEM;
 
 	if (!nsvc->nse->bss_sns_fi) {
-		LOGP(DLNS, LOGL_ERROR, "NSEI=%u Cannot transmit SNS on NSVC without SNS active\n",
-		     nsvc->nse->nsei);
+		LOGNSVC(nsvc, LOGL_ERROR, "Cannot transmit SNS on NSVC without SNS active\n");
 		msgb_free(msg);
 		return -EIO;
 	}
@@ -571,8 +561,7 @@
 		return -ENOMEM;
 
 	if (!nsvc->nse->bss_sns_fi) {
-		LOGP(DLNS, LOGL_ERROR, "NSEI=%u Cannot transmit SNS on NSVC without SNS active\n",
-		     nsvc->nse->nsei);
+		LOGNSVC(nsvc, LOGL_ERROR, "Cannot transmit SNS on NSVC without SNS active\n");
 		msgb_free(msg);
 		return -EIO;
 	}
@@ -620,8 +609,7 @@
 		return -ENOMEM;
 
 	if (!nsvc->nse->bss_sns_fi) {
-		LOGP(DLNS, LOGL_ERROR, "NSEI=%u Cannot transmit SNS on NSVC without SNS active\n",
-		     nsvc->nse->nsei);
+		LOGNSVC(nsvc, LOGL_ERROR, "Cannot transmit SNS on NSVC without SNS active\n");
 		msgb_free(msg);
 		return -EIO;
 	}
@@ -666,8 +654,7 @@
 		return -ENOMEM;
 
 	if (!nsvc->nse->bss_sns_fi) {
-		LOGP(DLNS, LOGL_ERROR, "NSEI=%u Cannot transmit SNS on NSVC without SNS active\n",
-		     nsvc->nse->nsei);
+		LOGNSVC(nsvc, LOGL_ERROR, "Cannot transmit SNS on NSVC without SNS active\n");
 		msgb_free(msg);
 		return -EIO;
 	}
@@ -706,8 +693,7 @@
 		return -ENOMEM;
 
 	if (!nsvc->nse->bss_sns_fi) {
-		LOGP(DLNS, LOGL_ERROR, "NSEI=%u Cannot transmit SNS on NSVC without SNS active\n",
-		     nsvc->nse->nsei);
+		LOGNSVC(nsvc, LOGL_ERROR, "Cannot transmit SNS on NSVC without SNS active\n");
 		msgb_free(msg);
 		return -EIO;
 	}
diff --git a/src/gb/gprs_ns2_sns.c b/src/gb/gprs_ns2_sns.c
index 72e4ea7..90d97b6 100644
--- a/src/gb/gprs_ns2_sns.c
+++ b/src/gb/gprs_ns2_sns.c
@@ -1447,17 +1447,17 @@
 	struct osmo_fsm_inst *fi;
 
 	if (!nse->bss_sns_fi) {
-		LOGP(DLNS, LOGL_NOTICE, "NSEI=%u Rx %s for NS Instance that has no SNS!\n",
-		     nsvc->nse->nsei, get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
+		LOGNSVC(nsvc, LOGL_NOTICE, "Rx %s for NS Instance that has no SNS!\n",
+			get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
 		return -EINVAL;
 	}
 
-	LOGP(DLNS, LOGL_DEBUG, "NSEI=%u Rx SNS PDU type %s\n", nsei,
-		get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
-
 	/* FIXME: how to resolve SNS FSM Instance by NSEI (SGSN)? */
 	fi = nse->bss_sns_fi;
 
+	LOGPFSML(fi, LOGL_DEBUG, "NSEI=%u Rx SNS PDU type %s\n", nsei,
+		 get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
+
 	switch (nsh->pdu_type) {
 	case SNS_PDUT_SIZE:
 		osmo_fsm_inst_dispatch(fi, GPRS_SNS_EV_SIZE, tp);
@@ -1484,12 +1484,12 @@
 		osmo_fsm_inst_dispatch(fi, GPRS_SNS_EV_CHANGE_WEIGHT, tp);
 		break;
 	case SNS_PDUT_ACK:
-		LOGP(DLNS, LOGL_NOTICE, "NSEI=%u Rx unsupported SNS PDU type %s\n", nsei,
-			get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
+		LOGPFSML(fi, LOGL_NOTICE, "NSEI=%u Rx unsupported SNS PDU type %s\n", nsei,
+			 get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
 		break;
 	default:
-		LOGP(DLNS, LOGL_ERROR, "NSEI=%u Rx unknown SNS PDU type %s\n", nsei,
-			get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
+		LOGPFSML(fi, LOGL_ERROR, "NSEI=%u Rx unknown SNS PDU type %s\n", nsei,
+			 get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
 		return -EINVAL;
 	}
 
@@ -1663,7 +1663,7 @@
 
 	/* gprs_ns2_free_nsvcs() will trigger GPRS_SNS_EV_NO_NSVC on the last NS-VC
 	 * and restart SNS SIZE procedure which selects a new initial */
-	LOGP(DLNS, LOGL_INFO, "Current in-use SNS endpoint is being removed."
+	LOGNSE(nse, LOGL_INFO, "Current in-use SNS endpoint is being removed."
 			      "Closing all NS-VC and restart SNS-SIZE procedure"
 			      "with a remaining SNS endpoint.\n");
 
diff --git a/src/gb/gprs_ns2_udp.c b/src/gb/gprs_ns2_udp.c
index 2a335c1..8bfa184 100644
--- a/src/gb/gprs_ns2_udp.c
+++ b/src/gb/gprs_ns2_udp.c
@@ -168,8 +168,8 @@
 }
 
 /* Read a single NS-over-IP message */
-static struct msgb *read_nsip_msg(struct osmo_fd *bfd, int *error,
-				  struct osmo_sockaddr *saddr)
+static struct msgb *read_nsip_msg(struct osmo_fd *bfd, int *error, struct osmo_sockaddr *saddr,
+				  const struct gprs_ns2_vc_bind *bind)
 {
 	struct msgb *msg = gprs_ns2_msgb_alloc();
 	int ret = 0;
@@ -183,8 +183,8 @@
 	ret = recvfrom(bfd->fd, msg->data, NS_ALLOC_SIZE - NS_ALLOC_HEADROOM, 0,
 			&saddr->u.sa, &saddr_len);
 	if (ret < 0) {
-		LOGP(DLNS, LOGL_ERROR, "recv error %s during NSIP recvfrom %s\n",
-		     strerror(errno), osmo_sock_get_name2(bfd->fd));
+		LOGBIND(bind, LOGL_ERROR, "recv error %s during NSIP recvfrom %s\n",
+			strerror(errno), osmo_sock_get_name2(bfd->fd));
 		msgb_free(msg);
 		*error = ret;
 		return NULL;
@@ -219,7 +219,7 @@
 	struct gprs_ns2_vc_bind *bind = bfd->data;
 	struct osmo_sockaddr saddr;
 	struct gprs_ns2_vc *nsvc;
-	struct msgb *msg = read_nsip_msg(bfd, &error, &saddr);
+	struct msgb *msg = read_nsip_msg(bfd, &error, &saddr, bind);
 	struct msgb *reject;
 
 	if (!msg)
@@ -378,8 +378,7 @@
 		rc = setsockopt(priv->fd.fd, IPPROTO_IP, IP_TOS,
 				&dscp, sizeof(dscp));
 		if (rc < 0)
-			LOGP(DLNS, LOGL_ERROR,
-				"Failed to set the DSCP to %d with ret(%d) errno(%d)\n",
+			LOGBIND(bind, LOGL_ERROR, "Failed to set the DSCP to %d with ret(%d) errno(%d)\n",
 				dscp, rc, errno);
 	}
 
@@ -409,8 +408,8 @@
 
 	vc_mode = gprs_ns2_dialect_to_vc_mode(nse->dialect);
 	if ((int) vc_mode == -1) {
-		LOGP(DLNS, LOGL_ERROR, "Can not derive vc mode from dialect %d. Maybe libosmocore is too old.\n",
-		     nse->dialect);
+		LOGNSE(nse, LOGL_ERROR, "Can not derive vc mode from dialect %d. Maybe libosmocore is too old.\n",
+			nse->dialect);
 		return NULL;
 	}
 
@@ -528,10 +527,10 @@
 
 		rc = setsockopt(priv->fd.fd, IPPROTO_IP, IP_TOS,
 				&dscp, sizeof(dscp));
-		if (rc < 0)
-			LOGP(DLNS, LOGL_ERROR,
-			     "Failed to set the DSCP to %d with ret(%d) errno(%d)\n",
-			     dscp, rc, errno);
+		if (rc < 0) {
+			LOGBIND(bind, LOGL_ERROR, "Failed to set the DSCP to %d with ret(%d) errno(%d)\n",
+				dscp, rc, errno);
+		}
 	}
 
 	return rc;
diff --git a/src/gb/gprs_ns2_vc_fsm.c b/src/gb/gprs_ns2_vc_fsm.c
index 5de86f5..fc2a86a 100644
--- a/src/gb/gprs_ns2_vc_fsm.c
+++ b/src/gb/gprs_ns2_vc_fsm.c
@@ -793,8 +793,8 @@
 		osmo_fsm_inst_dispatch(fi, GPRS_NS2_EV_RX_UNITDATA, msg);
 		return 0;
 	default:
-		LOGP(DLNS, LOGL_ERROR, "NSEI=%u Rx unknown NS PDU type %s\n", nsvc->nse->nsei,
-			get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
+		LOGPFSML(fi, LOGL_ERROR, "NSEI=%u Rx unknown NS PDU type %s\n", nsvc->nse->nsei,
+			 get_value_string(gprs_ns_pdu_strings, nsh->pdu_type));
 		return -EINVAL;
 	}
 

-- 
To view, visit https://gerrit.osmocom.org/c/libosmocore/+/22337
To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings

Gerrit-Project: libosmocore
Gerrit-Branch: master
Gerrit-Change-Id: I946c0e77686d91efc5afb62031e1ac1033a9a586
Gerrit-Change-Number: 22337
Gerrit-PatchSet: 3
Gerrit-Owner: laforge <laforge at osmocom.org>
Gerrit-Reviewer: Jenkins Builder
Gerrit-Reviewer: daniel <dwillmann at sysmocom.de>
Gerrit-Reviewer: lynxis lazus <lynxis at fe80.eu>
Gerrit-Reviewer: pespin <pespin at sysmocom.de>
Gerrit-MessageType: merged
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.osmocom.org/pipermail/gerrit-log/attachments/20210120/84c83cb6/attachment.htm>


More information about the gerrit-log mailing list