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
This commit is contained in:
Alexander V. Chernikov 2022-06-25 19:53:31 +00:00
parent c260d5cd8e
commit 6fa8ed43ee
5 changed files with 96 additions and 27 deletions

View File

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

View File

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

View File

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

View File

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

View File

@ -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;
@ -1100,8 +1107,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);
}
@ -1110,8 +1119,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) {
@ -1304,8 +1315,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.
@ -1374,11 +1387,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);
}
@ -1400,7 +1417,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));
@ -1416,7 +1434,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);
@ -1430,7 +1449,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));
@ -1473,8 +1493,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)) {
/*
@ -1488,7 +1511,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
@ -1533,7 +1557,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);
}
@ -1549,7 +1574,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
@ -1585,8 +1611,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) {
/*