routing: improve debug logging
Use standard logging (FIB_XX_LOG) across nhg code instead of using old-style DPRINTFs. Add debug object printer for nhgs (`nhgrp_print_buf`). Example: ``` Jun 19 20:17:09 devel2 kernel: [nhgrp] inet.0 nhgrp_ctl_alloc_default: multipath init done Jun 19 20:17:09 devel2 kernel: [nhg_ctl] inet.0 alloc_nhgrp: num_nhops: 2, compiled_nhop: 2 Jun 19 20:17:26 devel2 kernel: [nhg_ctl] inet.0 alloc_nhgrp: num_nhops: 3, compiled_nhop: 3 Jun 19 20:17:26 devel2 kernel: [nhg_ctl] inet.0 destroy_nhgrp: destroying nhg#0/sz=2:[#6:1,#5:1] ``` Differential Revision: https://reviews.freebsd.org/D35525 MFC after: 2 weeks
This commit is contained in:
Alexander V. Chernikov
parent
f6ed05f123
commit
5d6894bd66
@ -60,6 +60,11 @@
|
||||
#include <net/route/nhop_var.h>
|
||||
#include <net/route/nhgrp_var.h>
|
||||
|
||||
#define DEBUG_MOD_NAME nhgrp
|
||||
#define DEBUG_MAX_LEVEL LOG_DEBUG
|
||||
#include <net/route/route_debug.h>
|
||||
_DECLARE_DEBUG(LOG_INFO);
|
||||
|
||||
/*
|
||||
* This file contains data structures management logic for the nexthop
|
||||
* groups ("nhgrp") route subsystem.
|
||||
@ -163,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);
|
||||
DPRINTF("Unable to allocate mpath index");
|
||||
FIB_RH_LOG(LOG_INFO, ctl->ctl_rh, "Unable to allocate nhg index");
|
||||
consider_resize(ctl, new_num_buckets, new_num_items);
|
||||
return (0);
|
||||
}
|
||||
@ -190,7 +195,7 @@ unlink_nhgrp(struct nh_control *ctl, struct nhgrp_priv *key)
|
||||
CHT_SLIST_REMOVE(&ctl->gr_head, mpath, key, nhg_priv_ret);
|
||||
|
||||
if (nhg_priv_ret == NULL) {
|
||||
DPRINTF("Unable to find nhop group!");
|
||||
FIB_RH_LOG(LOG_DEBUG, ctl->ctl_rh, "Unable to find nhg");
|
||||
NHOPS_WUNLOCK(ctl);
|
||||
return (NULL);
|
||||
}
|
||||
@ -233,7 +238,8 @@ consider_resize(struct nh_control *ctl, uint32_t new_gr_bucket, uint32_t new_idx
|
||||
return;
|
||||
}
|
||||
|
||||
DPRINTF("mp: going to resize: gr:[ptr:%p sz:%u] idx:[ptr:%p sz:%u]",
|
||||
FIB_RH_LOG(LOG_DEBUG, ctl->ctl_rh,
|
||||
"going to resize nhg hash: [ptr:%p sz:%u] idx:[ptr:%p sz:%u]",
|
||||
gr_ptr, new_gr_bucket, gr_idx_ptr, new_idx_items);
|
||||
|
||||
old_idx_ptr = NULL;
|
||||
@ -271,7 +277,7 @@ nhgrp_ctl_alloc_default(struct nh_control *ctl, int malloc_flags)
|
||||
cht_ptr = malloc(alloc_size, M_NHOP, malloc_flags);
|
||||
|
||||
if (cht_ptr == NULL) {
|
||||
DPRINTF("mpath init failed");
|
||||
FIB_RH_LOG(LOG_WARNING, ctl->ctl_rh, "multipath init failed");
|
||||
return (false);
|
||||
}
|
||||
|
||||
@ -287,8 +293,7 @@ nhgrp_ctl_alloc_default(struct nh_control *ctl, int malloc_flags)
|
||||
free(cht_ptr, M_NHOP);
|
||||
}
|
||||
|
||||
DPRINTF("mpath init done for fib/af %d/%d", ctl->rh->rib_fibnum,
|
||||
ctl->rh->rib_family);
|
||||
FIB_RH_LOG(LOG_DEBUG, ctl->ctl_rh, "multipath init done");
|
||||
|
||||
return (true);
|
||||
}
|
||||
@ -320,7 +325,11 @@ nhgrp_ctl_unlink_all(struct nh_control *ctl)
|
||||
NHOPS_WLOCK_ASSERT(ctl);
|
||||
|
||||
CHT_SLIST_FOREACH(&ctl->gr_head, mpath, nhg_priv) {
|
||||
DPRINTF("Marking nhgrp %u unlinked", nhg_priv->nhg_idx);
|
||||
#if DEBUG_MAX_LEVEL >= LOG_DEBUG
|
||||
char nhgbuf[NHOP_PRINT_BUFSIZE];
|
||||
FIB_RH_LOG(LOG_DEBUG, ctl->ctl_rh, "marking %s unlinked",
|
||||
nhgrp_print_buf(nhg_priv->nhg, nhgbuf, sizeof(nhgbuf)));
|
||||
#endif
|
||||
refcount_release(&nhg_priv->nhg_linked);
|
||||
} CHT_SLIST_FOREACH_END;
|
||||
}
|
||||
|
||||
@ -58,6 +58,11 @@
|
||||
#include <net/route/nhop_var.h>
|
||||
#include <net/route/nhgrp_var.h>
|
||||
|
||||
#define DEBUG_MOD_NAME nhgrp_ctl
|
||||
#define DEBUG_MAX_LEVEL LOG_DEBUG
|
||||
#include <net/route/route_debug.h>
|
||||
_DECLARE_DEBUG(LOG_INFO);
|
||||
|
||||
/*
|
||||
* This file contains the supporting functions for creating multipath groups
|
||||
* and compiling their dataplane parts.
|
||||
@ -222,7 +227,8 @@ compile_nhgrp(struct nhgrp_priv *dst_priv, const struct weightened_nhop *x,
|
||||
for (i = 0; i < dst_priv->nhg_nh_count; i++)
|
||||
remaining_sum += x[i].weight;
|
||||
remaining_slots = num_slots;
|
||||
DPRINTF("O: %u/%u", (uint32_t)remaining_sum, remaining_slots);
|
||||
FIB_NH_LOG(LOG_DEBUG3, x[0].nh, "sum: %lu, slots: %d",
|
||||
remaining_sum, remaining_slots);
|
||||
for (i = 0; i < dst_priv->nhg_nh_count; i++) {
|
||||
/* Calculate number of slots for the current nexthop */
|
||||
if (remaining_sum > 0) {
|
||||
@ -234,9 +240,9 @@ compile_nhgrp(struct nhgrp_priv *dst_priv, const struct weightened_nhop *x,
|
||||
remaining_sum -= x[i].weight;
|
||||
remaining_slots -= nh_slots;
|
||||
|
||||
DPRINTF(" OO[%d]: %u/%u curr=%d slot_idx=%d", i,
|
||||
(uint32_t)remaining_sum, remaining_slots,
|
||||
(int)nh_slots, slot_idx);
|
||||
FIB_NH_LOG(LOG_DEBUG3, x[0].nh,
|
||||
" rem_sum: %lu, rem_slots: %d nh_slots: %d, slot_idx: %d",
|
||||
remaining_sum, remaining_slots, (int)nh_slots, slot_idx);
|
||||
|
||||
KASSERT((slot_idx + nh_slots <= num_slots),
|
||||
("index overflow during nhg compilation"));
|
||||
@ -267,12 +273,14 @@ alloc_nhgrp(struct weightened_nhop *wn, int num_nhops)
|
||||
size_t sz = get_nhgrp_alloc_size(nhgrp_size, num_nhops);
|
||||
nhg = malloc(sz, M_NHOP, M_NOWAIT | M_ZERO);
|
||||
if (nhg == NULL) {
|
||||
FIB_NH_LOG(LOG_INFO, wn[0].nh,
|
||||
"unable to allocate group with num_nhops %d (compiled %u)",
|
||||
num_nhops, nhgrp_size);
|
||||
return (NULL);
|
||||
}
|
||||
|
||||
/* Has to be the first to make NHGRP_PRIV() work */
|
||||
nhg->nhg_size = nhgrp_size;
|
||||
DPRINTF("new mpath group: num_nhops: %u", (uint32_t)nhgrp_size);
|
||||
nhg->nhg_flags = MPF_MULTIPATH;
|
||||
|
||||
nhg_priv = NHGRP_PRIV(nhg);
|
||||
@ -286,6 +294,9 @@ alloc_nhgrp(struct weightened_nhop *wn, int num_nhops)
|
||||
memcpy(&nhg_priv->nhg_nh_weights[0], wn,
|
||||
num_nhops * sizeof(struct weightened_nhop));
|
||||
|
||||
FIB_NH_LOG(LOG_DEBUG, wn[0].nh, "num_nhops: %d, compiled_nhop: %u",
|
||||
num_nhops, nhgrp_size);
|
||||
|
||||
compile_nhgrp(nhg_priv, wn, nhg->nhg_size);
|
||||
|
||||
return (nhg_priv);
|
||||
@ -345,7 +356,8 @@ nhgrp_free(struct nhgrp_object *nhg)
|
||||
ctl = nhg_priv->nh_control;
|
||||
if (unlink_nhgrp(ctl, nhg_priv) == NULL) {
|
||||
/* Do not try to reclaim */
|
||||
DPRINTF("Failed to unlink nexhop group %p", nhg_priv);
|
||||
RT_LOG(LOG_INFO, "Failed to unlink nexhop group %p",
|
||||
nhg_priv);
|
||||
NET_EPOCH_EXIT(et);
|
||||
return;
|
||||
}
|
||||
@ -371,13 +383,16 @@ destroy_nhgrp(struct nhgrp_priv *nhg_priv)
|
||||
{
|
||||
|
||||
KASSERT((nhg_priv->nhg_refcount == 0), ("nhg_refcount != 0"));
|
||||
|
||||
DPRINTF("DEL MPATH %p", nhg_priv);
|
||||
|
||||
KASSERT((nhg_priv->nhg_idx == 0), ("gr_idx != 0"));
|
||||
|
||||
free_nhgrp_nhops(nhg_priv);
|
||||
#if DEBUG_MAX_LEVEL >= LOG_DEBUG
|
||||
char nhgbuf[NHOP_PRINT_BUFSIZE];
|
||||
FIB_NH_LOG(LOG_DEBUG, nhg_priv->nhg_nh_weights[0].nh,
|
||||
"destroying %s", nhgrp_print_buf(nhg_priv->nhg,
|
||||
nhgbuf, sizeof(nhgbuf)));
|
||||
#endif
|
||||
|
||||
free_nhgrp_nhops(nhg_priv);
|
||||
destroy_nhgrp_int(nhg_priv);
|
||||
}
|
||||
|
||||
@ -695,6 +710,37 @@ nhgrp_get_nhops(struct nhgrp_object *nhg, uint32_t *pnum_nhops)
|
||||
return (nhg_priv->nhg_nh_weights);
|
||||
}
|
||||
|
||||
/*
|
||||
* Prints nexhop group @nhg data in the provided @buf.
|
||||
* Example: nhg#33/sz=3:[#1:100,#2:100,#3:100]
|
||||
* Example: nhg#33/sz=5:[#1:100,#2:100,..]
|
||||
*/
|
||||
char *
|
||||
nhgrp_print_buf(const struct nhgrp_object *nhg, char *buf, size_t bufsize)
|
||||
{
|
||||
const struct nhgrp_priv *nhg_priv = NHGRP_PRIV_CONST(nhg);
|
||||
|
||||
int off = snprintf(buf, bufsize, "nhg#%u/sz=%u:[", nhg_priv->nhg_idx,
|
||||
nhg_priv->nhg_nh_count);
|
||||
|
||||
for (int i = 0; i < nhg_priv->nhg_nh_count; i++) {
|
||||
const struct weightened_nhop *wn = &nhg_priv->nhg_nh_weights[i];
|
||||
int len = snprintf(&buf[off], bufsize - off, "#%u:%u,",
|
||||
wn->nh->nh_priv->nh_idx, wn->weight);
|
||||
if (len + off + 3 >= bufsize) {
|
||||
int len = snprintf(&buf[off], bufsize - off, "...");
|
||||
off += len;
|
||||
break;
|
||||
}
|
||||
off += len;
|
||||
}
|
||||
if (off > 0)
|
||||
off--; // remove last ","
|
||||
if (off + 1 < bufsize)
|
||||
snprintf(&buf[off], bufsize - off, "]");
|
||||
return buf;
|
||||
}
|
||||
|
||||
__noinline static int
|
||||
dump_nhgrp_entry(struct rib_head *rh, const struct nhgrp_priv *nhg_priv,
|
||||
char *buffer, size_t buffer_size, struct sysctl_req *w)
|
||||
|
||||
@ -584,7 +584,7 @@ finalize_nhop(struct nh_control *ctl, struct rt_addrinfo *info,
|
||||
* the epoch end, as nexthop is not used
|
||||
* and return.
|
||||
*/
|
||||
char nhbuf[48];
|
||||
char nhbuf[NHOP_PRINT_BUFSIZE];
|
||||
FIB_NH_LOG(LOG_WARNING, nh, "failed to link %s",
|
||||
nhop_print_buf(nh, nhbuf, sizeof(nhbuf)));
|
||||
destroy_nhop(nh_priv);
|
||||
@ -593,7 +593,7 @@ finalize_nhop(struct nh_control *ctl, struct rt_addrinfo *info,
|
||||
}
|
||||
|
||||
#if DEBUG_MAX_LEVEL >= LOG_DEBUG
|
||||
char nhbuf[48];
|
||||
char nhbuf[NHOP_PRINT_BUFSIZE];
|
||||
FIB_NH_LOG(LOG_DEBUG, nh, "finalized: %s", nhop_print_buf(nh, nhbuf, sizeof(nhbuf)));
|
||||
#endif
|
||||
|
||||
@ -655,7 +655,7 @@ nhop_free(struct nhop_object *nh)
|
||||
return;
|
||||
|
||||
#if DEBUG_MAX_LEVEL >= LOG_DEBUG
|
||||
char nhbuf[48];
|
||||
char nhbuf[NHOP_PRINT_BUFSIZE];
|
||||
FIB_NH_LOG(LOG_DEBUG, nh, "deleting %s", nhop_print_buf(nh, nhbuf, sizeof(nhbuf)));
|
||||
#endif
|
||||
|
||||
@ -683,7 +683,7 @@ nhop_free(struct nhop_object *nh)
|
||||
ctl = nh_priv->nh_control;
|
||||
if (unlink_nhop(ctl, nh_priv) == NULL) {
|
||||
/* Do not try to reclaim */
|
||||
char nhbuf[48];
|
||||
char nhbuf[NHOP_PRINT_BUFSIZE];
|
||||
FIB_NH_LOG(LOG_WARNING, nh, "failed to unlink %s",
|
||||
nhop_print_buf(nh, nhbuf, sizeof(nhbuf)));
|
||||
NET_EPOCH_EXIT(et);
|
||||
@ -864,6 +864,17 @@ nhop_print_buf(const struct nhop_object *nh, char *buf, size_t bufsize)
|
||||
return (buf);
|
||||
}
|
||||
|
||||
char *
|
||||
nhop_print_buf_any(const struct nhop_object *nh, char *buf, size_t bufsize)
|
||||
{
|
||||
#ifdef ROUTE_MPATH
|
||||
if (NH_IS_NHGRP(nh))
|
||||
return (nhgrp_print_buf((const struct nhgrp_object *)nh, buf, bufsize));
|
||||
else
|
||||
#endif
|
||||
return (nhop_print_buf(nh, buf, bufsize));
|
||||
}
|
||||
|
||||
/*
|
||||
* Dumps a single entry to sysctl buffer.
|
||||
*
|
||||
|
||||
@ -76,6 +76,8 @@
|
||||
|
||||
/* Same as FIB_LOG, but uses nhop to get fib and family */
|
||||
#define FIB_NH_LOG(_l, _nh, _fmt, ...) FIB_LOG_##_l(_l, nhop_get_fibnum(_nh), nhop_get_upper_family(_nh), _fmt, ## __VA_ARGS__)
|
||||
/* Same as FIB_LOG, but uses rib_head to get fib and family */
|
||||
#define FIB_RH_LOG(_l, _rh, _fmt, ...) FIB_LOG_##_l(_l, (_rh)->rib_fibnum, (_rh)->rib_family, _fmt, ## __VA_ARGS__)
|
||||
|
||||
/*
|
||||
* Generic logging for routing subsystem
|
||||
@ -90,7 +92,7 @@
|
||||
/*
|
||||
* Wrapper logic to avoid compiling high levels of debugging messages for production systems.
|
||||
*/
|
||||
#if DEBUG_MAX_LEVEL>=LOG_DEBUG2
|
||||
#if DEBUG_MAX_LEVEL>=LOG_DEBUG3
|
||||
#define FIB_LOG_LOG_DEBUG3 _FIB_LOG
|
||||
#define RT_LOG_LOG_DEBUG3 _RT_LOG
|
||||
#else
|
||||
@ -129,10 +131,14 @@
|
||||
|
||||
/* Helpers for fancy-printing various objects */
|
||||
struct nhop_object;
|
||||
struct nhgrp_object;
|
||||
struct llentry;
|
||||
struct nhop_neigh;
|
||||
|
||||
#define NHOP_PRINT_BUFSIZE 48
|
||||
char *nhop_print_buf(const struct nhop_object *nh, char *buf, size_t bufsize);
|
||||
char *nhop_print_buf_any(const struct nhop_object *nh, char *buf, size_t bufsize);
|
||||
char *nhgrp_print_buf(const struct nhgrp_object *nhg, char *buf, size_t bufsize);
|
||||
char *llentry_print_buf(const struct llentry *lle, struct ifnet *ifp, int family, char *buf,
|
||||
size_t bufsize);
|
||||
char *llentry_print_buf_lltable(const struct llentry *lle, char *buf, size_t bufsize);
|
||||
|
||||
Loading…
Reference in New Issue
Block a user