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
This commit is contained in:
Harald Welte 2021-01-20 14:54:14 +01:00 committed by lynxis lazus
parent 718e37e5cc
commit f294974e05
8 changed files with 112 additions and 119 deletions

View File

@ -695,7 +695,7 @@ struct gprs_ns2_nse *gprs_ns2_create_nse(struct gprs_ns2_inst *nsi, uint16_t nse
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 @@ enum gprs_ns2_cs ns2_create_vc(struct gprs_ns2_vc_bind *bind,
} 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 @@ enum gprs_ns2_cs ns2_create_vc(struct gprs_ns2_vc_bind *bind,
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 @@ enum gprs_ns2_cs ns2_create_vc(struct gprs_ns2_vc_bind *bind,
/* 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;
}

View File

@ -214,8 +214,7 @@ static int handle_netif_read(struct osmo_fd *bfd)
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 @@ int fr_tx_cb(void *data, struct msgb *msg)
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 @@ static int devname2ifindex(const char *ifname)
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 @@ static int open_socket(int ifindex)
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 @@ static int open_socket(int ifindex)
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 @@ static int linkmon_mnl_cb(const struct nlmsghdr *nlh, void *data)
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 @@ static int set_ifupdown(const char *netif, bool up)
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 @@ static int setup_device(const char *netif)
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 @@ static int setup_device(const char *netif)
/* 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 @@ static int setup_device(const char *netif)
/* 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 @@ int gprs_ns2_fr_bind(struct gprs_ns2_inst *nsi,
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);

View File

@ -180,26 +180,25 @@ static int handle_rx_gre_ipv6(struct osmo_fd *bfd, struct msgb *msg,
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 @@ static int handle_rx_gre_ipv6(struct osmo_fd *bfd, struct msgb *msg,
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 @@ static int handle_rx_gre_ipv4(struct osmo_fd *bfd, struct msgb *msg,
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 @@ static int handle_rx_gre_ipv4(struct osmo_fd *bfd, struct msgb *msg,
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 int handle_rx_gre_ipv4(struct osmo_fd *bfd, struct msgb *msg,
}
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 @@ static struct msgb *read_nsfrgre_msg(struct osmo_fd *bfd, int *error,
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 @@ static struct msgb *read_nsfrgre_msg(struct osmo_fd *bfd, int *error,
/* 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 @@ static struct msgb *read_nsfrgre_msg(struct osmo_fd *bfd, int *error,
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 @@ static struct msgb *read_nsfrgre_msg(struct osmo_fd *bfd, int *error,
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 @@ static struct msgb *read_nsfrgre_msg(struct osmo_fd *bfd, int *error,
/* 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 @@ static int handle_nsfrgre_read(struct osmo_fd *bfd)
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 @@ int gprs_ns2_frgre_bind(struct gprs_ns2_inst *nsi,
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);
}

View File

@ -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;

View File

@ -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 @@ int ns2_tx_block(struct gprs_ns2_vc *nsvc, uint8_t cause)
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 @@ int ns2_tx_block_ack(struct gprs_ns2_vc *nsvc)
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 @@ int ns2_tx_reset(struct gprs_ns2_vc *nsvc, uint8_t cause)
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 @@ int ns2_tx_reset_ack(struct gprs_ns2_vc *nsvc)
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 @@ int ns2_tx_unblock(struct gprs_ns2_vc *nsvc)
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 @@ int ns2_tx_unblock_ack(struct gprs_ns2_vc *nsvc)
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 @@ int ns2_tx_alive(struct gprs_ns2_vc *nsvc)
{
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 @@ int ns2_tx_alive_ack(struct gprs_ns2_vc *nsvc)
{
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 @@ int ns2_tx_unit_data(struct gprs_ns2_vc *nsvc,
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 @@ int ns2_tx_status(struct gprs_ns2_vc *nsvc, uint8_t cause,
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 @@ int ns2_tx_sns_ack(struct gprs_ns2_vc *nsvc, uint8_t trans_id, uint8_t *cause,
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 @@ int ns2_tx_sns_config(struct gprs_ns2_vc *nsvc, bool end_flag,
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 @@ int ns2_tx_sns_config_ack(struct gprs_ns2_vc *nsvc, uint8_t *cause)
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 @@ int ns2_tx_sns_size(struct gprs_ns2_vc *nsvc, bool reset_flag, uint16_t max_nr_n
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 @@ int ns2_tx_sns_size_ack(struct gprs_ns2_vc *nsvc, uint8_t *cause)
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;
}

View File

@ -1447,17 +1447,17 @@ int gprs_ns2_sns_rx(struct gprs_ns2_vc *nsvc, struct msgb *msg, struct tlv_parse
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 @@ int gprs_ns2_sns_rx(struct gprs_ns2_vc *nsvc, struct msgb *msg, struct tlv_parse
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 @@ int gprs_ns2_sns_del_endpoint(struct gprs_ns2_nse *nse,
/* 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");

View File

@ -168,8 +168,8 @@ static int nsip_vc_sendmsg(struct gprs_ns2_vc *nsvc, struct msgb *msg)
}
/* 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 @@ static struct msgb *read_nsip_msg(struct osmo_fd *bfd, int *error,
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 @@ static int handle_nsip_read(struct osmo_fd *bfd)
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 @@ int gprs_ns2_ip_bind(struct gprs_ns2_inst *nsi,
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 @@ struct gprs_ns2_vc *gprs_ns2_ip_bind_connect(struct gprs_ns2_vc_bind *bind,
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 @@ int gprs_ns2_ip_bind_set_dscp(struct gprs_ns2_vc_bind *bind, int dscp)
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;

View File

@ -793,8 +793,8 @@ int gprs_ns2_vc_rx(struct gprs_ns2_vc *nsvc, struct msgb *msg, struct tlv_parsed
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;
}