diff --git a/src/gb/gprs_ns2.c b/src/gb/gprs_ns2.c index dc8ad8e53..ec60dbdb4 100644 --- a/src/gb/gprs_ns2.c +++ b/src/gb/gprs_ns2.c @@ -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; } diff --git a/src/gb/gprs_ns2_fr.c b/src/gb/gprs_ns2_fr.c index a7455d7c5..274ed9690 100644 --- a/src/gb/gprs_ns2_fr.c +++ b/src/gb/gprs_ns2_fr.c @@ -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); diff --git a/src/gb/gprs_ns2_frgre.c b/src/gb/gprs_ns2_frgre.c index 86f0921b1..2812e1279 100644 --- a/src/gb/gprs_ns2_frgre.c +++ b/src/gb/gprs_ns2_frgre.c @@ -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); } diff --git a/src/gb/gprs_ns2_internal.h b/src/gb/gprs_ns2_internal.h index ebb2e3bc7..7183bd81f 100644 --- a/src/gb/gprs_ns2_internal.h +++ b/src/gb/gprs_ns2_internal.h @@ -8,6 +8,24 @@ #include #include +#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 41605f4b0..955922991 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 @@ 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; } diff --git a/src/gb/gprs_ns2_sns.c b/src/gb/gprs_ns2_sns.c index 72e4ea7e1..90d97b6a7 100644 --- a/src/gb/gprs_ns2_sns.c +++ b/src/gb/gprs_ns2_sns.c @@ -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"); diff --git a/src/gb/gprs_ns2_udp.c b/src/gb/gprs_ns2_udp.c index 2a335c116..8bfa184d2 100644 --- a/src/gb/gprs_ns2_udp.c +++ b/src/gb/gprs_ns2_udp.c @@ -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; diff --git a/src/gb/gprs_ns2_vc_fsm.c b/src/gb/gprs_ns2_vc_fsm.c index 5de86f520..fc2a86a89 100644 --- a/src/gb/gprs_ns2_vc_fsm.c +++ b/src/gb/gprs_ns2_vc_fsm.c @@ -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; }