git: 6d7d5b869a4f - stable/13 - routing: improve debugging.
- Go to: [ bottom of page ] [ top of archives ] [ this month ]
Date: Fri, 13 Jan 2023 21:24:45 UTC
The branch stable/13 has been updated by melifaro:
URL: https://cgit.FreeBSD.org/src/commit/?id=6d7d5b869a4fa9ae4621cabc3fb13e7fb11730fd
commit 6d7d5b869a4fa9ae4621cabc3fb13e7fb11730fd
Author: Alexander V. Chernikov <melifaro@FreeBSD.org>
AuthorDate: 2022-06-25 19:53:31 +0000
Commit: Alexander V. Chernikov <melifaro@FreeBSD.org>
CommitDate: 2023-01-13 21:18:25 +0000
routing: improve debugging.
Use unified guidelines for the severity across the routing subsystem.
Update severity for some of the already-used messages to adhere the
guidelines.
Convert rtsock logging to the new FIB_ reporting format.
MFC after: 2 weeks
(cherry picked from commit 6fa8ed43ee0ca43cf170f52b57fcad562f97baba)
---
sys/net/route/nhgrp.c | 2 +-
sys/net/route/nhop_ctl.c | 11 +++++---
sys/net/route/route_ctl.c | 23 +++++++++++++----
sys/net/route/route_debug.h | 25 ++++++++++++++++++
sys/net/rtsock.c | 62 ++++++++++++++++++++++++++++++++-------------
5 files changed, 96 insertions(+), 27 deletions(-)
diff --git a/sys/net/route/nhgrp.c b/sys/net/route/nhgrp.c
index de53c792aea9..8f6c04b86395 100644
--- a/sys/net/route/nhgrp.c
+++ b/sys/net/route/nhgrp.c
@@ -168,7 +168,7 @@ link_nhgrp(struct nh_control *ctl, struct nhgrp_priv *grp_priv)
if (bitmask_alloc_idx(&ctl->nh_idx_head, &idx) != 0) {
NHOPS_WUNLOCK(ctl);
- FIB_RH_LOG(LOG_INFO, ctl->ctl_rh, "Unable to allocate nhg index");
+ FIB_RH_LOG(LOG_DEBUG, ctl->ctl_rh, "Unable to allocate nhg index");
consider_resize(ctl, new_num_buckets, new_num_items);
return (0);
}
diff --git a/sys/net/route/nhop_ctl.c b/sys/net/route/nhop_ctl.c
index d35ad0213bb3..4bf7bfb1b416 100644
--- a/sys/net/route/nhop_ctl.c
+++ b/sys/net/route/nhop_ctl.c
@@ -229,7 +229,8 @@ set_nhop_gw_from_info(struct nhop_object *nh, struct rt_addrinfo *info)
struct sockaddr_dl *sdl = (struct sockaddr_dl *)gw;
struct ifnet *ifp = ifnet_byindex(sdl->sdl_index);
if (ifp == NULL) {
- FIB_NH_LOG(LOG_WARNING, nh, "invalid ifindex %d", sdl->sdl_index);
+ FIB_NH_LOG(LOG_DEBUG, nh, "error: invalid ifindex %d",
+ sdl->sdl_index);
return (EINVAL);
}
fill_sdl_from_ifp(&nh->gwl_sa, ifp);
@@ -247,9 +248,9 @@ set_nhop_gw_from_info(struct nhop_object *nh, struct rt_addrinfo *info)
* happy.
*/
if (gw->sa_len > sizeof(struct sockaddr_in6)) {
- FIB_NH_LOG(LOG_WARNING, nh, "nhop SA size too big: AF %d len %u",
+ FIB_NH_LOG(LOG_DEBUG, nh, "nhop SA size too big: AF %d len %u",
gw->sa_family, gw->sa_len);
- return (ENOMEM);
+ return (EINVAL);
}
memcpy(&nh->gw_sa, gw, gw->sa_len);
}
@@ -323,8 +324,10 @@ nhop_create_from_info(struct rib_head *rnh, struct rt_addrinfo *info,
NET_EPOCH_ASSERT();
- if (info->rti_info[RTAX_GATEWAY] == NULL)
+ if (info->rti_info[RTAX_GATEWAY] == NULL) {
+ FIB_RH_LOG(LOG_DEBUG, rnh, "error: empty gateway");
return (EINVAL);
+ }
nh_priv = alloc_nhop_structure();
diff --git a/sys/net/route/route_ctl.c b/sys/net/route/route_ctl.c
index 8a61db449462..f8b6a6eb4cd0 100644
--- a/sys/net/route/route_ctl.c
+++ b/sys/net/route/route_ctl.c
@@ -586,8 +586,10 @@ rib_add_route(uint32_t fibnum, struct rt_addrinfo *info,
*/
if (info->rti_flags & RTF_HOST)
info->rti_info[RTAX_NETMASK] = NULL;
- else if (info->rti_info[RTAX_NETMASK] == NULL)
+ else if (info->rti_info[RTAX_NETMASK] == NULL) {
+ FIB_RH_LOG(LOG_DEBUG, rnh, "error: no RTF_HOST and empty netmask");
return (EINVAL);
+ }
bzero(rc, sizeof(struct rib_cmd_info));
rc->rc_cmd = RTM_ADD;
@@ -642,13 +644,22 @@ create_rtentry(struct rib_head *rnh, struct rt_addrinfo *info,
netmask = info->rti_info[RTAX_NETMASK];
flags = info->rti_flags;
- if ((flags & RTF_GATEWAY) && !gateway)
+ if ((flags & RTF_GATEWAY) && !gateway) {
+ FIB_RH_LOG(LOG_DEBUG, rnh, "error: RTF_GATEWAY set with empty gw");
return (EINVAL);
- if (dst && gateway && !check_gateway(rnh, dst, gateway))
+ }
+ if (dst && gateway && !check_gateway(rnh, dst, gateway)) {
+ FIB_RH_LOG(LOG_DEBUG, rnh,
+ "error: invalid dst/gateway family combination (%d, %d)",
+ dst->sa_family, gateway->sa_family);
return (EINVAL);
+ }
- if (dst->sa_len > sizeof(((struct rtentry *)NULL)->rt_dstb))
+ if (dst->sa_len > sizeof(((struct rtentry *)NULL)->rt_dstb)) {
+ FIB_RH_LOG(LOG_DEBUG, rnh, "error: dst->sa_len too large: %d",
+ dst->sa_len);
return (EINVAL);
+ }
if (info->rti_ifa == NULL) {
error = rt_getifa_fib(info, rnh->rib_fibnum);
@@ -798,8 +809,10 @@ rib_del_route(uint32_t fibnum, struct rt_addrinfo *info, struct rib_cmd_info *rc
if (netmask != NULL) {
/* Ensure @dst is always properly masked */
- if (dst_orig->sa_len > sizeof(mdst))
+ if (dst_orig->sa_len > sizeof(mdst)) {
+ FIB_RH_LOG(LOG_DEBUG, rnh, "error: dst->sa_len too large");
return (EINVAL);
+ }
rt_maskedcopy(dst_orig, (struct sockaddr *)&mdst, netmask);
info->rti_info[RTAX_DST] = (struct sockaddr *)&mdst;
}
diff --git a/sys/net/route/route_debug.h b/sys/net/route/route_debug.h
index 7bc98c43c0dc..ef14da4db81c 100644
--- a/sys/net/route/route_debug.h
+++ b/sys/net/route/route_debug.h
@@ -62,6 +62,31 @@
#define LOG_DEBUG3 9
#endif
+/*
+ * Severity usage guidelines:
+ *
+ * LOG_WARNING - subsystem-global errors ("multipath init failed")
+ *
+ * LOG_INFO - subsystem non-transient errors ("Failed to unlink nexhop").
+ * All logging <= LOG_INFO by default will be written to syslog.
+ *
+ * LOG_DEBUG - subsystem debug. Not-too often events (hash resizes, recoverable failures).
+ * These are compiled in by default on production. Turning it it should NOT notable affect
+ * performance
+ * LOG_DEBUG2 - more debug. Per-item level (nhg,nh,route) debug, up to multiple lines per item.
+ * This is NOT compiled in by default. Turning it on should NOT seriously impact performance
+ * LOG_DEBUG3 - last debug level. Per-item large debug outputs.
+ * This is NOT compiled in by default. All performance bets are off.
+ *
+ */
+
+
+#define LOG_WARNING 4 /* warning conditions */
+#define LOG_NOTICE 5 /* normal but significant condition */
+#define LOG_INFO 6 /* informational */
+#define LOG_DEBUG 7 /* debug-level messages */
+
+
#define _output printf
#define _DEBUG_PASS_MSG(_l) (DEBUG_VAR_NAME >= (_l))
diff --git a/sys/net/rtsock.c b/sys/net/rtsock.c
index 7802c7d8da9e..5d9b4b7fa9f7 100644
--- a/sys/net/rtsock.c
+++ b/sys/net/rtsock.c
@@ -80,6 +80,11 @@
#include <sys/mount.h>
#include <compat/freebsd32/freebsd32.h>
+#define DEBUG_MOD_NAME rtsock
+#define DEBUG_MAX_LEVEL LOG_DEBUG
+#include <net/route/route_debug.h>
+_DECLARE_DEBUG(LOG_INFO);
+
struct if_msghdr32 {
uint16_t ifm_msglen;
uint8_t ifm_version;
@@ -133,8 +138,7 @@ struct linear_buffer {
};
#define SCRATCH_BUFFER_SIZE 1024
-#define RTS_PID_PRINTF(_fmt, ...) \
- printf("rtsock:%s(): PID %d: " _fmt "\n", __func__, curproc->p_pid, ## __VA_ARGS__)
+#define RTS_PID_LOG(_l, _fmt, ...) RT_LOG_##_l(_l, "PID %d: " _fmt, curproc ? curproc->p_pid : 0, ## __VA_ARGS__)
MALLOC_DEFINE(M_RTABLE, "routetbl", "routing tables");
@@ -581,7 +585,7 @@ fill_blackholeinfo(struct rt_addrinfo *info, union sockaddr_union *saun)
sa_family_t saf;
if (V_loif == NULL) {
- RTS_PID_PRINTF("Unable to add blackhole/reject nhop without loopback");
+ RTS_PID_LOG(LOG_INFO, "Unable to add blackhole/reject nhop without loopback");
return (ENOTSUP);
}
info->rti_ifp = V_loif;
@@ -594,8 +598,10 @@ fill_blackholeinfo(struct rt_addrinfo *info, union sockaddr_union *saun)
break;
}
}
- if (info->rti_ifa == NULL)
+ if (info->rti_ifa == NULL) {
+ RTS_PID_LOG(LOG_INFO, "Unable to find ifa for blackhole/reject nhop");
return (ENOTSUP);
+ }
bzero(saun, sizeof(union sockaddr_union));
switch (saf) {
@@ -614,6 +620,7 @@ fill_blackholeinfo(struct rt_addrinfo *info, union sockaddr_union *saun)
break;
#endif
default:
+ RTS_PID_LOG(LOG_INFO, "unsupported family: %d", saf);
return (ENOTSUP);
}
info->rti_info[RTAX_GATEWAY] = &saun->sa;
@@ -1101,8 +1108,10 @@ route_output(struct mbuf *m, struct socket *so, ...)
if (blackhole_flags != 0) {
if (blackhole_flags != (RTF_BLACKHOLE | RTF_REJECT))
error = fill_blackholeinfo(&info, &gw_saun);
- else
+ else {
+ RTS_PID_LOG(LOG_DEBUG, "both BLACKHOLE and REJECT flags specifiied");
error = EINVAL;
+ }
if (error != 0)
senderr(error);
}
@@ -1111,8 +1120,10 @@ route_output(struct mbuf *m, struct socket *so, ...)
case RTM_ADD:
case RTM_CHANGE:
if (rtm->rtm_type == RTM_ADD) {
- if (info.rti_info[RTAX_GATEWAY] == NULL)
+ if (info.rti_info[RTAX_GATEWAY] == NULL) {
+ RTS_PID_LOG(LOG_DEBUG, "RTM_ADD w/o gateway");
senderr(EINVAL);
+ }
}
error = rib_action(fibnum, rtm->rtm_type, &info, &rc);
if (error == 0) {
@@ -1303,8 +1314,10 @@ rt_xaddrs(caddr_t cp, caddr_t cplim, struct rt_addrinfo *rtinfo)
/*
* It won't fit.
*/
- if (cp + sa->sa_len > cplim)
+ if (cp + sa->sa_len > cplim) {
+ RTS_PID_LOG(LOG_DEBUG, "sa_len too big for sa type %d", i);
return (EINVAL);
+ }
/*
* there are no more.. quit now
* If there are more bits, they are in error.
@@ -1372,11 +1385,15 @@ cleanup_xaddrs_lladdr(struct rt_addrinfo *info)
if (sdl->sdl_family != AF_LINK)
return (EINVAL);
- if (sdl->sdl_index == 0)
+ if (sdl->sdl_index == 0) {
+ RTS_PID_LOG(LOG_DEBUG, "AF_LINK gateway w/o ifindex");
return (EINVAL);
+ }
- if (offsetof(struct sockaddr_dl, sdl_data) + sdl->sdl_nlen + sdl->sdl_alen > sdl->sdl_len)
+ if (offsetof(struct sockaddr_dl, sdl_data) + sdl->sdl_nlen + sdl->sdl_alen > sdl->sdl_len) {
+ RTS_PID_LOG(LOG_DEBUG, "AF_LINK gw: sdl_nlen/sdl_alen too large");
return (EINVAL);
+ }
return (0);
}
@@ -1398,7 +1415,8 @@ cleanup_xaddrs_gateway(struct rt_addrinfo *info, struct linear_buffer *lb)
/* Ensure reads do not go beyoud SA boundary */
if (SA_SIZE(gw) < offsetof(struct sockaddr_in, sin_zero)) {
- RTS_PID_PRINTF("gateway sin_len too small: %d", gw->sa_len);
+ RTS_PID_LOG(LOG_DEBUG, "gateway sin_len too small: %d",
+ gw->sa_len);
return (EINVAL);
}
sa = alloc_sockaddr_aligned(lb, sizeof(struct sockaddr_in));
@@ -1414,7 +1432,8 @@ cleanup_xaddrs_gateway(struct rt_addrinfo *info, struct linear_buffer *lb)
{
struct sockaddr_in6 *gw_sin6 = (struct sockaddr_in6 *)gw;
if (gw_sin6->sin6_len < sizeof(struct sockaddr_in6)) {
- RTS_PID_PRINTF("gateway sin6_len too small: %d", gw->sa_len);
+ RTS_PID_LOG(LOG_DEBUG, "gateway sin6_len too small: %d",
+ gw->sa_len);
return (EINVAL);
}
fill_sockaddr_inet6(gw_sin6, &gw_sin6->sin6_addr, 0);
@@ -1428,7 +1447,8 @@ cleanup_xaddrs_gateway(struct rt_addrinfo *info, struct linear_buffer *lb)
size_t sdl_min_len = offsetof(struct sockaddr_dl, sdl_data);
gw_sdl = (struct sockaddr_dl *)gw;
if (gw_sdl->sdl_len < sdl_min_len) {
- RTS_PID_PRINTF("gateway sdl_len too small: %d", gw_sdl->sdl_len);
+ RTS_PID_LOG(LOG_DEBUG, "gateway sdl_len too small: %d",
+ gw_sdl->sdl_len);
return (EINVAL);
}
sa = alloc_sockaddr_aligned(lb, sizeof(struct sockaddr_dl_short));
@@ -1470,8 +1490,11 @@ cleanup_xaddrs_inet(struct rt_addrinfo *info, struct linear_buffer *lb)
mask_sa = (struct sockaddr_in *)info->rti_info[RTAX_NETMASK];
/* Ensure reads do not go beyound the buffer size */
- if (SA_SIZE(dst_sa) < offsetof(struct sockaddr_in, sin_zero))
+ if (SA_SIZE(dst_sa) < offsetof(struct sockaddr_in, sin_zero)) {
+ RTS_PID_LOG(LOG_DEBUG, "prefix dst sin_len too small: %d",
+ dst_sa->sin_len);
return (EINVAL);
+ }
if ((mask_sa != NULL) && mask_sa->sin_len < sizeof(struct sockaddr_in)) {
/*
@@ -1485,7 +1508,8 @@ cleanup_xaddrs_inet(struct rt_addrinfo *info, struct linear_buffer *lb)
len = sizeof(struct in_addr);
memcpy(&mask, &mask_sa->sin_addr, len);
} else {
- RTS_PID_PRINTF("prefix mask sin_len too small: %d", mask_sa->sin_len);
+ RTS_PID_LOG(LOG_DEBUG, "prefix mask sin_len too small: %d",
+ mask_sa->sin_len);
return (EINVAL);
}
} else
@@ -1530,7 +1554,8 @@ cleanup_xaddrs_inet6(struct rt_addrinfo *info, struct linear_buffer *lb)
mask_sa = (struct sockaddr_in6 *)info->rti_info[RTAX_NETMASK];
if (dst_sa->sin6_len < sizeof(struct sockaddr_in6)) {
- RTS_PID_PRINTF("prefix dst sin6_len too small: %d", dst_sa->sin6_len);
+ RTS_PID_LOG(LOG_DEBUG, "prefix dst sin6_len too small: %d",
+ dst_sa->sin6_len);
return (EINVAL);
}
@@ -1546,7 +1571,8 @@ cleanup_xaddrs_inet6(struct rt_addrinfo *info, struct linear_buffer *lb)
len = sizeof(struct in6_addr);
memcpy(&mask, &mask_sa->sin6_addr, len);
} else {
- RTS_PID_PRINTF("rtsock: prefix mask sin6_len too small: %d", mask_sa->sin6_len);
+ RTS_PID_LOG(LOG_DEBUG, "rtsock: prefix mask sin6_len too small: %d",
+ mask_sa->sin6_len);
return (EINVAL);
}
} else
@@ -1582,8 +1608,10 @@ cleanup_xaddrs(struct rt_addrinfo *info, struct linear_buffer *lb)
{
int error = EAFNOSUPPORT;
- if (info->rti_info[RTAX_DST] == NULL)
+ if (info->rti_info[RTAX_DST] == NULL) {
+ RTS_PID_LOG(LOG_DEBUG, "prefix dst is not set");
return (EINVAL);
+ }
if (info->rti_flags & RTF_LLDATA) {
/*