routing: improve multiline debug

Add IF_DEBUG_LEVEL() macro to ensure all debug output preparation
 is run only if the current debug level is sufficient. Consistently
 use it within routing subsystem.

MFC after:	2 weeks
This commit is contained in:
Alexander V. Chernikov 2022-08-29 15:14:49 +00:00
parent fe05d1dd0f
commit 578a99c939
6 changed files with 59 additions and 57 deletions

View File

@ -179,13 +179,11 @@ link_nhgrp(struct nh_control *ctl, struct nhgrp_priv *grp_priv)
NHOPS_WUNLOCK(ctl); NHOPS_WUNLOCK(ctl);
#if DEBUG_MAX_LEVEL >= LOG_DEBUG2 IF_DEBUG_LEVEL(LOG_DEBUG2) {
{ char nhgrp_buf[NHOP_PRINT_BUFSIZE] __unused;
char nhgrp_buf[NHOP_PRINT_BUFSIZE]; FIB_RH_LOG(LOG_DEBUG2, ctl->ctl_rh, "linked %s",
nhgrp_print_buf(grp_priv->nhg, nhgrp_buf, sizeof(nhgrp_buf)); nhgrp_print_buf(grp_priv->nhg, nhgrp_buf, sizeof(nhgrp_buf)));
FIB_RH_LOG(LOG_DEBUG2, ctl->ctl_rh, "linked %s", nhgrp_buf);
} }
#endif
consider_resize(ctl, new_num_buckets, new_num_items); consider_resize(ctl, new_num_buckets, new_num_items);
return (1); return (1);
@ -214,14 +212,13 @@ unlink_nhgrp(struct nh_control *ctl, struct nhgrp_priv *key)
NHOPS_WUNLOCK(ctl); NHOPS_WUNLOCK(ctl);
#if DEBUG_MAX_LEVEL >= LOG_DEBUG2 IF_DEBUG_LEVEL(LOG_DEBUG2) {
{
char nhgrp_buf[NHOP_PRINT_BUFSIZE]; char nhgrp_buf[NHOP_PRINT_BUFSIZE];
nhgrp_print_buf(nhg_priv_ret->nhg, nhgrp_buf, sizeof(nhgrp_buf)); nhgrp_print_buf(nhg_priv_ret->nhg, nhgrp_buf, sizeof(nhgrp_buf));
FIB_RH_LOG(LOG_DEBUG2, ctl->ctl_rh, "unlinked idx#%d %s", idx, FIB_RH_LOG(LOG_DEBUG2, ctl->ctl_rh, "unlinked idx#%d %s", idx,
nhgrp_buf); nhgrp_buf);
} }
#endif
return (nhg_priv_ret); return (nhg_priv_ret);
} }
@ -340,11 +337,11 @@ nhgrp_ctl_unlink_all(struct nh_control *ctl)
NHOPS_WLOCK_ASSERT(ctl); NHOPS_WLOCK_ASSERT(ctl);
CHT_SLIST_FOREACH(&ctl->gr_head, mpath, nhg_priv) { CHT_SLIST_FOREACH(&ctl->gr_head, mpath, nhg_priv) {
#if DEBUG_MAX_LEVEL >= LOG_DEBUG IF_DEBUG_LEVEL(LOG_DEBUG2) {
char nhgbuf[NHOP_PRINT_BUFSIZE]; char nhgbuf[NHOP_PRINT_BUFSIZE] __unused;
FIB_RH_LOG(LOG_DEBUG, ctl->ctl_rh, "marking %s unlinked", FIB_RH_LOG(LOG_DEBUG2, ctl->ctl_rh, "marking %s unlinked",
nhgrp_print_buf(nhg_priv->nhg, nhgbuf, sizeof(nhgbuf))); nhgrp_print_buf(nhg_priv->nhg, nhgbuf, sizeof(nhgbuf)));
#endif }
refcount_release(&nhg_priv->nhg_linked); refcount_release(&nhg_priv->nhg_linked);
} CHT_SLIST_FOREACH_END; } CHT_SLIST_FOREACH_END;
} }

View File

@ -406,12 +406,12 @@ destroy_nhgrp(struct nhgrp_priv *nhg_priv)
KASSERT((nhg_priv->nhg_refcount == 0), ("nhg_refcount != 0")); KASSERT((nhg_priv->nhg_refcount == 0), ("nhg_refcount != 0"));
KASSERT((nhg_priv->nhg_idx == 0), ("gr_idx != 0")); KASSERT((nhg_priv->nhg_idx == 0), ("gr_idx != 0"));
#if DEBUG_MAX_LEVEL >= LOG_DEBUG IF_DEBUG_LEVEL(LOG_DEBUG2) {
char nhgbuf[NHOP_PRINT_BUFSIZE]; char nhgbuf[NHOP_PRINT_BUFSIZE] __unused;
FIB_NH_LOG(LOG_DEBUG, nhg_priv->nhg_nh_weights[0].nh, FIB_NH_LOG(LOG_DEBUG2, nhg_priv->nhg_nh_weights[0].nh,
"destroying %s", nhgrp_print_buf(nhg_priv->nhg, "destroying %s", nhgrp_print_buf(nhg_priv->nhg,
nhgbuf, sizeof(nhgbuf))); nhgbuf, sizeof(nhgbuf)));
#endif }
free_nhgrp_nhops(nhg_priv); free_nhgrp_nhops(nhg_priv);
destroy_nhgrp_int(nhg_priv); destroy_nhgrp_int(nhg_priv);

View File

@ -534,10 +534,11 @@ finalize_nhop(struct nh_control *ctl, struct nhop_object *nh, bool link)
return (ENOBUFS); return (ENOBUFS);
} }
#if DEBUG_MAX_LEVEL >= LOG_DEBUG IF_DEBUG_LEVEL(LOG_DEBUG) {
char nhbuf[NHOP_PRINT_BUFSIZE]; char nhbuf[NHOP_PRINT_BUFSIZE] __unused;
FIB_NH_LOG(LOG_DEBUG, nh, "finalized: %s", nhop_print_buf(nh, nhbuf, sizeof(nhbuf))); FIB_NH_LOG(LOG_DEBUG, nh, "finalized: %s",
#endif nhop_print_buf(nh, nhbuf, sizeof(nhbuf)));
}
return (0); return (0);
} }
@ -598,10 +599,11 @@ nhop_free(struct nhop_object *nh)
return; return;
} }
#if DEBUG_MAX_LEVEL >= LOG_DEBUG IF_DEBUG_LEVEL(LOG_DEBUG) {
char nhbuf[NHOP_PRINT_BUFSIZE]; char nhbuf[NHOP_PRINT_BUFSIZE] __unused;
FIB_NH_LOG(LOG_DEBUG, nh, "deleting %s", nhop_print_buf(nh, nhbuf, sizeof(nhbuf))); FIB_NH_LOG(LOG_DEBUG, nh, "deleting %s",
#endif nhop_print_buf(nh, nhbuf, sizeof(nhbuf)));
}
/* /*
* There are only 2 places, where nh_linked can be decreased: * There are only 2 places, where nh_linked can be decreased:
@ -1189,10 +1191,7 @@ nhops_dump_sysctl(struct rib_head *rh, struct sysctl_req *w)
ctl = rh->nh_control; ctl = rh->nh_control;
NHOPS_RLOCK(ctl); NHOPS_RLOCK(ctl);
#if DEBUG_MAX_LEVEL >= LOG_DEBUG FIB_RH_LOG(LOG_DEBUG, rh, "dump %u items", ctl->nh_head.items_count);
FIB_LOG(LOG_DEBUG, rh->rib_fibnum, rh->rib_family, "dump %u items",
ctl->nh_head.items_count);
#endif
CHT_SLIST_FOREACH(&ctl->nh_head, nhops, nh_priv) { CHT_SLIST_FOREACH(&ctl->nh_head, nhops, nh_priv) {
error = dump_nhop_entry(rh, nh_priv->nh, w); error = dump_nhop_entry(rh, nh_priv->nh, w);
if (error != 0) { if (error != 0) {

View File

@ -609,13 +609,13 @@ rib_copy_route(struct rtentry *rt, const struct route_nhop_data *rnd_src,
MPASS((nh_src->nh_flags & NHF_MULTIPATH) == 0); MPASS((nh_src->nh_flags & NHF_MULTIPATH) == 0);
#if DEBUG_MAX_LEVEL >= LOG_DEBUG2 IF_DEBUG_LEVEL(LOG_DEBUG2) {
char nhbuf[NHOP_PRINT_BUFSIZE], rtbuf[NHOP_PRINT_BUFSIZE]; char nhbuf[NHOP_PRINT_BUFSIZE], rtbuf[NHOP_PRINT_BUFSIZE];
nhop_print_buf_any(nh_src, nhbuf, sizeof(nhbuf)); nhop_print_buf_any(nh_src, nhbuf, sizeof(nhbuf));
rt_print_buf(rt, rtbuf, sizeof(rtbuf)); rt_print_buf(rt, rtbuf, sizeof(rtbuf));
FIB_RH_LOG(LOG_DEBUG2, rh_dst, "copying %s -> %s from fib %u", FIB_RH_LOG(LOG_DEBUG2, rh_dst, "copying %s -> %s from fib %u",
rtbuf, nhbuf, nhop_get_fibnum(nh_src)); rtbuf, nhbuf, nhop_get_fibnum(nh_src));
#endif }
struct nhop_object *nh = nhop_alloc(rh_dst->rib_fibnum, rh_dst->rib_family); struct nhop_object *nh = nhop_alloc(rh_dst->rib_fibnum, rh_dst->rib_family);
if (nh == NULL) { if (nh == NULL) {
FIB_RH_LOG(LOG_INFO, rh_dst, "unable to allocate new nexthop"); FIB_RH_LOG(LOG_INFO, rh_dst, "unable to allocate new nexthop");
@ -645,11 +645,12 @@ rib_copy_route(struct rtentry *rt, const struct route_nhop_data *rnd_src,
error = add_route_flags(rh_dst, rt_new, &rnd, op_flags, rc); error = add_route_flags(rh_dst, rt_new, &rnd, op_flags, rc);
if (error != 0) { if (error != 0) {
#if DEBUG_MAX_LEVEL >= LOG_DEBUG IF_DEBUG_LEVEL(LOG_DEBUG2) {
char buf[NHOP_PRINT_BUFSIZE]; char buf[NHOP_PRINT_BUFSIZE];
rt_print_buf(rt_new, buf, sizeof(buf)); rt_print_buf(rt_new, buf, sizeof(buf));
FIB_RH_LOG(LOG_DEBUG, rh_dst, "Unable to add route %s: error %d", buf, error); FIB_RH_LOG(LOG_DEBUG, rh_dst,
#endif "Unable to add route %s: error %d", buf, error);
}
nhop_free(nh); nhop_free(nh);
rt_free_immediate(rt_new); rt_free_immediate(rt_new);
} }
@ -1295,15 +1296,13 @@ change_route_conditional(struct rib_head *rnh, struct rtentry *rt,
struct rtentry *rt_new; struct rtentry *rt_new;
int error = 0; int error = 0;
#if DEBUG_MAX_LEVEL >= LOG_DEBUG2 IF_DEBUG_LEVEL(LOG_DEBUG2) {
{
char buf_old[NHOP_PRINT_BUFSIZE], buf_new[NHOP_PRINT_BUFSIZE]; char buf_old[NHOP_PRINT_BUFSIZE], buf_new[NHOP_PRINT_BUFSIZE];
nhop_print_buf_any(rnd_orig->rnd_nhop, buf_old, NHOP_PRINT_BUFSIZE); nhop_print_buf_any(rnd_orig->rnd_nhop, buf_old, NHOP_PRINT_BUFSIZE);
nhop_print_buf_any(rnd_new->rnd_nhop, buf_new, NHOP_PRINT_BUFSIZE); nhop_print_buf_any(rnd_new->rnd_nhop, buf_new, NHOP_PRINT_BUFSIZE);
FIB_LOG(LOG_DEBUG2, rnh->rib_fibnum, rnh->rib_family, FIB_LOG(LOG_DEBUG2, rnh->rib_fibnum, rnh->rib_family,
"trying change %s -> %s", buf_old, buf_new); "trying change %s -> %s", buf_old, buf_new);
} }
#endif
RIB_WLOCK(rnh); RIB_WLOCK(rnh);
struct route_nhop_data rnd; struct route_nhop_data rnd;

View File

@ -83,6 +83,8 @@
#define _output printf #define _output printf
#define _DEBUG_PASS_MSG(_l) (DEBUG_VAR_NAME >= (_l)) #define _DEBUG_PASS_MSG(_l) (DEBUG_VAR_NAME >= (_l))
#define IF_DEBUG_LEVEL(_l) if ((DEBUG_MAX_LEVEL >= (_l)) && (__predict_false(DEBUG_VAR_NAME >= (_l))))
/* /*
* Logging for events specific for particular family and fib * Logging for events specific for particular family and fib
* Example: [nhop_neigh] inet.0 find_lle: nhop nh#4/inet/vtnet0/10.0.0.1: mapped to lle NULL * Example: [nhop_neigh] inet.0 find_lle: nhop nh#4/inet/vtnet0/10.0.0.1: mapped to lle NULL
@ -155,6 +157,7 @@ struct nhgrp_object;
struct llentry; struct llentry;
struct nhop_neigh; struct nhop_neigh;
struct rtentry; struct rtentry;
struct ifnet;
#define NHOP_PRINT_BUFSIZE 48 #define NHOP_PRINT_BUFSIZE 48
char *nhop_print_buf(const struct nhop_object *nh, char *buf, size_t bufsize); char *nhop_print_buf(const struct nhop_object *nh, char *buf, size_t bufsize);

View File

@ -261,27 +261,33 @@ rib_lookup(uint32_t fibnum, const struct sockaddr *dst, uint32_t flags,
#ifdef ROUTE_MPATH #ifdef ROUTE_MPATH
static void static void
notify_add(struct rib_cmd_info *rc, const struct weightened_nhop *wn_src, notify_add(struct rib_cmd_info *rc, const struct weightened_nhop *wn_src,
route_notification_t *cb, void *cbdata) { route_notification_t *cb, void *cbdata)
{
rc->rc_nh_new = wn_src->nh; rc->rc_nh_new = wn_src->nh;
rc->rc_nh_weight = wn_src->weight; rc->rc_nh_weight = wn_src->weight;
#if DEBUG_MAX_LEVEL >= LOG_DEBUG2
char nhbuf[NHOP_PRINT_BUFSIZE]; IF_DEBUG_LEVEL(LOG_DEBUG2) {
FIB_NH_LOG(LOG_DEBUG2, wn_src->nh, "RTM_ADD for %s @ w=%u", char nhbuf[NHOP_PRINT_BUFSIZE] __unused;
nhop_print_buf(wn_src->nh, nhbuf, sizeof(nhbuf)), wn_src->weight); FIB_NH_LOG(LOG_DEBUG2, wn_src->nh, "RTM_ADD for %s @ w=%u",
#endif nhop_print_buf(wn_src->nh, nhbuf, sizeof(nhbuf)),
wn_src->weight);
}
cb(rc, cbdata); cb(rc, cbdata);
} }
static void static void
notify_del(struct rib_cmd_info *rc, const struct weightened_nhop *wn_src, notify_del(struct rib_cmd_info *rc, const struct weightened_nhop *wn_src,
route_notification_t *cb, void *cbdata) { route_notification_t *cb, void *cbdata)
{
rc->rc_nh_old = wn_src->nh; rc->rc_nh_old = wn_src->nh;
rc->rc_nh_weight = wn_src->weight; rc->rc_nh_weight = wn_src->weight;
#if DEBUG_MAX_LEVEL >= LOG_DEBUG2
char nhbuf[NHOP_PRINT_BUFSIZE]; IF_DEBUG_LEVEL(LOG_DEBUG2) {
FIB_NH_LOG(LOG_DEBUG2, wn_src->nh, "RTM_DEL for %s @ w=%u", char nhbuf[NHOP_PRINT_BUFSIZE] __unused;
nhop_print_buf(wn_src->nh, nhbuf, sizeof(nhbuf)), wn_src->weight); FIB_NH_LOG(LOG_DEBUG2, wn_src->nh, "RTM_DEL for %s @ w=%u",
#endif nhop_print_buf(wn_src->nh, nhbuf, sizeof(nhbuf)),
wn_src->weight);
}
cb(rc, cbdata); cb(rc, cbdata);
} }
@ -313,14 +319,12 @@ decompose_change_notification(struct rib_cmd_info *rc, route_notification_t *cb,
wn_new = &tmp; wn_new = &tmp;
num_new = 1; num_new = 1;
} }
#if DEBUG_MAX_LEVEL >= LOG_DEBUG IF_DEBUG_LEVEL(LOG_DEBUG) {
{
char buf_old[NHOP_PRINT_BUFSIZE], buf_new[NHOP_PRINT_BUFSIZE]; char buf_old[NHOP_PRINT_BUFSIZE], buf_new[NHOP_PRINT_BUFSIZE];
nhop_print_buf_any(rc->rc_nh_old, buf_old, NHOP_PRINT_BUFSIZE); nhop_print_buf_any(rc->rc_nh_old, buf_old, NHOP_PRINT_BUFSIZE);
nhop_print_buf_any(rc->rc_nh_new, buf_new, NHOP_PRINT_BUFSIZE); nhop_print_buf_any(rc->rc_nh_new, buf_new, NHOP_PRINT_BUFSIZE);
FIB_NH_LOG(LOG_DEBUG, wn_old[0].nh, "change %s -> %s", buf_old, buf_new); FIB_NH_LOG(LOG_DEBUG, wn_old[0].nh, "change %s -> %s", buf_old, buf_new);
} }
#endif
/* Use the fact that each @wn array is sorted */ /* Use the fact that each @wn array is sorted */
/* /*