From: Neale Ranns Date: Mon, 24 Sep 2018 12:36:26 +0000 (+0000) Subject: FIB: use vlib-log for debugging X-Git-Tag: v19.04-rc0~612 X-Git-Url: https://gerrit.fd.io/r/gitweb?p=vpp.git;a=commitdiff_plain;h=710071bf0ed7a0926581d1f738a142b72e795d2b FIB: use vlib-log for debugging Change-Id: I9052202b8cbcf656e61d635253d515f0f3a8d145 Signed-off-by: Neale Ranns --- diff --git a/src/vnet/dpo/load_balance.c b/src/vnet/dpo/load_balance.c index 48f77986f57..6b77f477fae 100644 --- a/src/vnet/dpo/load_balance.c +++ b/src/vnet/dpo/load_balance.c @@ -30,21 +30,19 @@ const f64 multipath_next_hop_error_tolerance = 0.1; static const char *load_balance_attr_names[] = LOAD_BALANCE_ATTR_NAMES; -#undef LB_DEBUG -#ifdef LB_DEBUG +/** + * the logger + */ +vlib_log_class_t load_balance_logger; + #define LB_DBG(_lb, _fmt, _args...) \ { \ - u8* _tmp =NULL; \ - clib_warning("lb:[%s]:" _fmt, \ - load_balance_format(load_balance_get_index((_lb)), \ - 0, _tmp), \ - ##_args); \ - vec_free(_tmp); \ + vlib_log_debug(load_balance_logger, \ + "lb:[%U]:" _fmt, \ + format_load_balance, load_balance_get_index(_lb), \ + LOAD_BALANCE_FORMAT_NONE, \ + ##_args); \ } -#else -#define LB_DBG(_p, _fmt, _args...) -#endif - /** * Pool of all DPOs. It's not static so the DP can have fast access @@ -180,6 +178,7 @@ format_load_balance (u8 * s, va_list * args) return (load_balance_format(lbi, flags, 0, s)); } + static u8* format_load_balance_dpo (u8 * s, va_list * args) { @@ -189,7 +188,6 @@ format_load_balance_dpo (u8 * s, va_list * args) return (load_balance_format(lbi, LOAD_BALANCE_FORMAT_DETAIL, indent, s)); } - static load_balance_t * load_balance_create_i (u32 num_buckets, dpo_proto_t lb_proto, @@ -947,6 +945,9 @@ load_balance_module_init (void) lbi = load_balance_create(1, DPO_PROTO_IP4, 0); load_balance_set_bucket(lbi, 0, drop_dpo_get(DPO_PROTO_IP4)); + load_balance_logger = + vlib_log_register_class("dpo", "load-balance"); + load_balance_map_module_init(); } diff --git a/src/vnet/dpo/load_balance_map.c b/src/vnet/dpo/load_balance_map.c index 588c1a75a4f..8f9bd366c4a 100644 --- a/src/vnet/dpo/load_balance_map.c +++ b/src/vnet/dpo/load_balance_map.c @@ -68,18 +68,20 @@ typedef struct load_balance_map_path_t_ { */ load_balance_map_t *load_balance_map_pool; +/** + * the logger + */ +vlib_log_class_t load_balance_map_logger; + /* * Debug macro */ -#ifdef FIB_DEBUG -#define LOAD_BALANCE_MAP_DBG(_pl, _fmt, _args...) \ - { \ - clib_warning("lbm: FIXME" _fmt, \ - ##_args); \ - } -#else -#define LOAD_BALANCE_MAP_DBG(_pl, _fmt, _args...) -#endif +#define LOAD_BALANCE_MAP_DBG(_pl, _fmt, _args...) \ +{ \ + vlib_log_debug(load_balance_map_logger, \ + "lbm:" _fmt, \ + ##_args); \ +} static index_t load_balance_map_get_index (load_balance_map_t *lbm) @@ -412,6 +414,9 @@ load_balance_map_init (load_balance_map_t *lbm, load_balance_map_fill(lbm); + load_balance_map_logger = + vlib_log_register_class ("dpo", "load-balance-map"); + return (lbm); } diff --git a/src/vnet/dpo/replicate_dpo.c b/src/vnet/dpo/replicate_dpo.c index 6742bff41aa..443df66e238 100644 --- a/src/vnet/dpo/replicate_dpo.c +++ b/src/vnet/dpo/replicate_dpo.c @@ -19,21 +19,20 @@ #include #include -#undef REP_DEBUG +/** + * the logger + */ +vlib_log_class_t replicate_logger; -#ifdef REP_DEBUG #define REP_DBG(_rep, _fmt, _args...) \ { \ - u8* _tmp =NULL; \ - clib_warning("rep:[%s]:" _fmt, \ - replicate_format(replicate_get_index((_rep)), \ - 0, _tmp), \ - ##_args); \ - vec_free(_tmp); \ + vlib_log_debug(replicate_logger, \ + "rep:[%U]:" _fmt, \ + format_replicate, \ + replicate_get_index(_rep), \ + REPLICATE_FORMAT_NONE, \ + ##_args); \ } -#else -#define REP_DBG(_p, _fmt, _args...) -#endif #define foreach_replicate_dpo_error \ _(BUFFER_ALLOCATION_FAILURE, "Buffer Allocation Failure") @@ -580,6 +579,7 @@ void replicate_module_init (void) { dpo_register(DPO_REPLICATE, &rep_vft, replicate_nodes); + replicate_logger = vlib_log_register_class("dpo", "replicate"); } static clib_error_t * diff --git a/src/vnet/fib/fib_entry.c b/src/vnet/fib/fib_entry.c index 8d7ce00b9c0..7de521336b8 100644 --- a/src/vnet/fib/fib_entry.c +++ b/src/vnet/fib/fib_entry.c @@ -41,6 +41,11 @@ static const char *fib_src_attribute_names[] = FIB_ENTRY_SRC_ATTRIBUTES; */ static fib_entry_t *fib_entry_pool; +/** + * the logger + */ +vlib_log_class_t fib_entry_logger; + fib_entry_t * fib_entry_get (fib_node_index_t index) { @@ -101,11 +106,39 @@ format_fib_source (u8 * s, va_list * args) } u8 * -format_fib_entry (u8 * s, va_list * args) +format_fib_entry_flags (u8 *s, va_list *args) +{ + fib_entry_attribute_t attr; + fib_entry_flag_t flag = va_arg(*args, int); + + FOR_EACH_FIB_ATTRIBUTE(attr) { + if ((1<fes_ref_count); if (FIB_ENTRY_FLAG_NONE != src->fes_entry_flags) { - s = format(s, " entry-flags:"); - FOR_EACH_FIB_ATTRIBUTE(attr) { - if ((1<fes_entry_flags) { - s = format (s, "%s,", fib_attribute_names[attr]); - } - } + s = format(s, " entry-flags:%U", + format_fib_entry_flags, src->fes_entry_flags); } if (FIB_ENTRY_SRC_FLAG_NONE != src->fes_flags) { - s = format(s, " src-flags:"); - FOR_EACH_FIB_SRC_ATTRIBUTE(sattr) { - if ((1<fes_flags) { - s = format (s, "%s,", fib_src_attribute_names[sattr]); - } - } + s = format(s, " src-flags:%U", + format_fib_entry_src_flags, src->fes_flags); } s = fib_entry_src_format(fib_entry, source, s); s = format (s, "\n"); @@ -316,6 +341,9 @@ fib_entry_back_walk_notify (fib_node_t *node, */ ctx->fnbw_flags &= ~FIB_NODE_BW_FLAG_FORCE_SYNC; + FIB_ENTRY_DBG(fib_entry, "bw:%U", + format_fib_node_bw_reason, ctx->fnbw_reason); + /* * propagate the backwalk further if we haven't already reached the * maximum depth. @@ -601,8 +629,6 @@ fib_entry_alloc (u32 fib_index, *fib_entry_index = fib_entry_get_index(fib_entry); - FIB_ENTRY_DBG(fib_entry, "alloc"); - return (fib_entry); } @@ -719,6 +745,8 @@ fib_entry_create (u32 fib_index, fib_entry_post_install_actions(fib_entry, source, FIB_ENTRY_FLAG_NONE); + FIB_ENTRY_DBG(fib_entry, "create"); + return (fib_entry_index); } @@ -745,6 +773,8 @@ fib_entry_create_special (u32 fib_index, fib_entry_post_install_actions(fib_entry, source, FIB_ENTRY_FLAG_NONE); + FIB_ENTRY_DBG(fib_entry, "create-special"); + return (fib_entry_index); } @@ -850,6 +880,7 @@ fib_entry_special_add (fib_node_index_t fib_entry_index, fib_entry = fib_entry_src_action_add(fib_entry, source, flags, dpo); fib_entry_source_change(fib_entry, best_source, source); + FIB_ENTRY_DBG(fib_entry, "special-add:%U", format_fib_source, source); } void @@ -866,6 +897,8 @@ fib_entry_special_update (fib_node_index_t fib_entry_index, fib_entry = fib_entry_src_action_update(fib_entry, source, flags, dpo); fib_entry_source_change(fib_entry, best_source, source); + + FIB_ENTRY_DBG(fib_entry, "special-updated:%U", format_fib_source, source); } @@ -890,6 +923,8 @@ fib_entry_path_add (fib_node_index_t fib_entry_index, fib_entry = fib_entry_src_action_path_add(fib_entry, source, flags, rpath); fib_entry_source_change(fib_entry, best_source, source); + + FIB_ENTRY_DBG(fib_entry, "path add:%U", format_fib_source, source); } static fib_entry_src_flag_t @@ -987,6 +1022,8 @@ fib_entry_path_remove (fib_node_index_t fib_entry_index, sflag = fib_entry_src_action_path_remove(fib_entry, source, rpath); + FIB_ENTRY_DBG(fib_entry, "path remove:%U", format_fib_source, source); + /* * if the path list for the source passed is invalid, * then we need to create a new one. else we are updating @@ -1076,6 +1113,8 @@ fib_entry_special_remove (fib_node_index_t fib_entry_index, sflag = fib_entry_src_action_remove_or_update_inherit(fib_entry, source); + FIB_ENTRY_DBG(fib_entry, "special remove:%U", format_fib_source, source); + /* * if the path list for the source passed is invalid, * then we need to create a new one. else we are updating @@ -1206,6 +1245,7 @@ fib_entry_update (fib_node_index_t fib_entry_index, paths); fib_entry_source_change_w_flags(fib_entry, best_source, bflags, source); + FIB_ENTRY_DBG(fib_entry, "update"); } @@ -1279,6 +1319,7 @@ fib_entry_cover_changed (fib_node_index_t fib_entry_index) fib_walk_sync(FIB_NODE_TYPE_ENTRY, fib_entry_index, &bw_ctx); } + FIB_ENTRY_DBG(fib_entry, "cover-changed"); } /* @@ -1352,6 +1393,7 @@ fib_entry_cover_updated (fib_node_index_t fib_entry_index) fib_walk_sync(FIB_NODE_TYPE_ENTRY, fib_entry_index, &bw_ctx); } + FIB_ENTRY_DBG(fib_entry, "cover-updated"); } int @@ -1602,7 +1644,8 @@ fib_entry_unlock (fib_node_index_t fib_entry_index) void fib_entry_module_init (void) { - fib_node_register_type (FIB_NODE_TYPE_ENTRY, &fib_entry_vft); + fib_node_register_type(FIB_NODE_TYPE_ENTRY, &fib_entry_vft); + fib_entry_logger = vlib_log_register_class("fib", "entry"); } void diff --git a/src/vnet/fib/fib_entry.h b/src/vnet/fib/fib_entry.h index 9175a571032..8ede39c1e9d 100644 --- a/src/vnet/fib/fib_entry.h +++ b/src/vnet/fib/fib_entry.h @@ -286,6 +286,8 @@ typedef enum fib_entry_flag_t_ { FIB_ENTRY_FLAG_INTERPOSE = (1 << FIB_ENTRY_ATTRIBUTE_INTERPOSE), } __attribute__((packed)) fib_entry_flag_t; +extern u8 * format_fib_entry_flags(u8 *s, va_list *args); + /** * Flags for the source data */ @@ -337,6 +339,8 @@ typedef enum fib_entry_src_flag_t_ { FIB_ENTRY_SRC_FLAG_INHERITED = (1 << FIB_ENTRY_SRC_ATTRIBUTE_INHERITED), } __attribute__ ((packed)) fib_entry_src_flag_t; +extern u8 * format_fib_entry_src_flags(u8 *s, va_list *args); + /* * Keep the size of the flags field to 2 bytes, so it * can be placed next to the 2 bytes reference count diff --git a/src/vnet/fib/fib_entry_src.c b/src/vnet/fib/fib_entry_src.c index 1b2d7161060..6868da613e0 100644 --- a/src/vnet/fib/fib_entry_src.c +++ b/src/vnet/fib/fib_entry_src.c @@ -692,8 +692,7 @@ fib_entry_src_action_uninstall (fib_entry_t *fib_entry) /* * uninstall the forwarding chain from the forwarding tables */ - FIB_ENTRY_DBG(fib_entry, "uninstall: %d", - fib_entry->fe_adj_index); + FIB_ENTRY_DBG(fib_entry, "uninstall"); if (dpo_id_is_valid(&fib_entry->fe_lb)) { diff --git a/src/vnet/fib/fib_entry_src.h b/src/vnet/fib/fib_entry_src.h index 61740201eb7..1d5f252eb87 100644 --- a/src/vnet/fib/fib_entry_src.h +++ b/src/vnet/fib/fib_entry_src.h @@ -23,24 +23,21 @@ /** * Debug macro */ -#ifdef FIB_DEBUG +extern vlib_log_class_t fib_entry_logger; + #define FIB_ENTRY_DBG(_e, _fmt, _args...) \ { \ - u8*__tmp = NULL; \ - __tmp = format(__tmp, "e:[%d:%U", \ - fib_entry_get_index(_e), \ - format_ip46_address, \ - &_e->fe_prefix.fp_addr, \ - IP46_TYPE_ANY); \ - __tmp = format(__tmp, "/%d]:", \ - _e->fe_prefix.fp_len); \ - __tmp = format(__tmp, _fmt, ##_args); \ - clib_warning("%s", __tmp); \ - vec_free(__tmp); \ + vlib_log_debug(fib_entry_logger, \ + "[@%d:[%U]:%U:%U]: " _fmt, \ + fib_entry_get_index(_e), \ + format_fib_prefix, \ + &_e->fe_prefix, \ + format_fib_entry_flags, \ + _e->fe_srcs[0].fes_entry_flags, \ + format_fib_source, \ + _e->fe_srcs[0].fes_src, \ + ##_args); \ } -#else -#define FIB_ENTRY_DBG(_e, _fmt, _args...) -#endif /** * Source initialisation Function diff --git a/src/vnet/fib/fib_entry_src_adj.c b/src/vnet/fib/fib_entry_src_adj.c index e43e36ee4e5..8c343051e8f 100644 --- a/src/vnet/fib/fib_entry_src_adj.c +++ b/src/vnet/fib/fib_entry_src_adj.c @@ -348,6 +348,7 @@ fib_entry_src_adj_cover_change (fib_entry_src_t *src, res.bw_reason = FIB_NODE_BW_REASON_FLAG_EVALUATE; } + FIB_ENTRY_DBG(fib_entry, "adj-src-cover-changed"); return (res); } @@ -375,6 +376,8 @@ fib_entry_src_adj_cover_update (fib_entry_src_t *src, res.install = (FIB_ENTRY_FLAG_ATTACHED & fib_entry_get_flags_i(cover)); + FIB_ENTRY_DBG(fib_entry, "adj-src-cover-updated"); + return (res); } diff --git a/src/vnet/fib/fib_internal.h b/src/vnet/fib/fib_internal.h index 8abc0e07313..a60ad26dc64 100644 --- a/src/vnet/fib/fib_internal.h +++ b/src/vnet/fib/fib_internal.h @@ -19,11 +19,6 @@ #include #include -/** - * Big train switch; FIB debugs on or off - */ -#undef FIB_DEBUG - extern void fib_prefix_from_mpls_label(mpls_label_t label, mpls_eos_bit_t eos, fib_prefix_t *prf); diff --git a/src/vnet/fib/fib_node.h b/src/vnet/fib/fib_node.h index 3a4ba8470bc..1179dfc0a50 100644 --- a/src/vnet/fib/fib_node.h +++ b/src/vnet/fib/fib_node.h @@ -156,6 +156,8 @@ typedef enum fib_node_bw_reason_flag_t_ { STATIC_ASSERT(sizeof(fib_node_bw_reason_flag_t) < 2, "BW Reason enum < 2 byte. Consequences for cover_upd_res_t"); +extern u8 *format_fib_node_bw_reason(u8 *s, va_list *args); + /** * Flags on the walk */ diff --git a/src/vnet/fib/fib_path.c b/src/vnet/fib/fib_path.c index 4ec04f5b950..e37d47482db 100644 --- a/src/vnet/fib/fib_path.c +++ b/src/vnet/fib/fib_path.c @@ -409,22 +409,22 @@ static const char *fib_path_cfg_attribute_names[] = FIB_PATH_CFG_ATTRIBUTES; */ static fib_path_t *fib_path_pool; +/** + * the logger + */ +vlib_log_class_t fib_path_logger; + /* * Debug macro */ -#ifdef FIB_DEBUG -#define FIB_PATH_DBG(_p, _fmt, _args...) \ -{ \ - u8 *_tmp = NULL; \ - _tmp = fib_path_format(fib_path_get_index(_p), _tmp); \ - clib_warning("path:[%d:%U]:" _fmt, \ - fib_path_get_index(_p), format_fib_path, _p, 0,\ - ##_args); \ - vec_free(_tmp); \ +#define FIB_PATH_DBG(_p, _fmt, _args...) \ +{ \ + vlib_log_debug (fib_path_logger, \ + "[%U]: " _fmt, \ + format_fib_path, fib_path_get_index(_p), 0, \ + FIB_PATH_FORMAT_FLAGS_ONE_LINE, \ + ##_args); \ } -#else -#define FIB_PATH_DBG(_p, _fmt, _args...) -#endif static fib_path_t * fib_path_get (fib_node_index_t index) @@ -456,10 +456,21 @@ format_fib_path (u8 * s, va_list * args) { fib_node_index_t path_index = va_arg (*args, fib_node_index_t); u32 indent = va_arg (*args, u32); + fib_format_path_flags_t flags = va_arg (*args, fib_format_path_flags_t); vnet_main_t * vnm = vnet_get_main(); fib_path_oper_attribute_t oattr; fib_path_cfg_attribute_t cattr; fib_path_t *path; + const char *eol; + + if (flags & FIB_PATH_FORMAT_FLAGS_ONE_LINE) + { + eol = ""; + } + else + { + eol = "\n"; + } path = fib_path_get(path_index); @@ -486,7 +497,8 @@ format_fib_path (u8 * s, va_list * args) } } } - s = format(s, "\n%U", format_white_space, indent+2); + if (!(flags & FIB_PATH_FORMAT_FLAGS_ONE_LINE)) + s = format(s, "\n%U", format_white_space, indent+2); switch (path->fp_type) { @@ -514,11 +526,11 @@ format_fib_path (u8 * s, va_list * args) } if (!dpo_id_is_valid(&path->fp_dpo)) { - s = format(s, "\n%Uunresolved", format_white_space, indent+2); + s = format(s, "%s%Uunresolved", eol, format_white_space, indent+2); } else { - s = format(s, "\n%U%U", + s = format(s, "%s%U%U", eol, format_white_space, indent, format_dpo_id, &path->fp_dpo, 13); @@ -608,17 +620,6 @@ format_fib_path (u8 * s, va_list * args) return (s); } -u8 * -fib_path_format (fib_node_index_t pi, u8 *s) -{ - fib_path_t *path; - - path = fib_path_get(pi); - ASSERT(NULL != path); - - return (format (s, "%U", format_fib_path, path)); -} - /* * fib_path_last_lock_gone * @@ -966,6 +967,9 @@ fib_path_back_walk_notify (fib_node_t *node, path = fib_path_from_fib_node(node); + FIB_PATH_DBG(path, "bw:%U", + format_fib_node_bw_reason, ctx->fnbw_reason); + switch (path->fp_type) { case FIB_PATH_TYPE_RECURSIVE: @@ -2311,8 +2315,6 @@ fib_path_contribute_forwarding (fib_node_index_t path_index, ASSERT(path); ASSERT(FIB_FORW_CHAIN_TYPE_MPLS_EOS != fct); - FIB_PATH_DBG(path, "contribute"); - /* * The DPO stored in the path was created when the path was resolved. * This then represents the path's 'native' protocol; IP. @@ -2667,6 +2669,7 @@ void fib_path_module_init (void) { fib_node_register_type (FIB_NODE_TYPE_PATH, &fib_path_vft); + fib_path_logger = vlib_log_register_class ("fib", "path"); } static clib_error_t * @@ -2685,7 +2688,8 @@ show_fib_path_command (vlib_main_t * vm, if (!pool_is_free_index(fib_path_pool, pi)) { path = fib_path_get(pi); - u8 *s = format(NULL, "%U", format_fib_path, pi, 1); + u8 *s = format(NULL, "%U", format_fib_path, pi, 1, + FIB_PATH_FORMAT_FLAGS_NONE); s = format(s, "children:"); s = fib_node_children_format(path->fp_node.fn_children, s); vlib_cli_output (vm, "%s", s); @@ -2701,7 +2705,8 @@ show_fib_path_command (vlib_main_t * vm, vlib_cli_output (vm, "FIB Paths"); pool_foreach_index (pi, fib_path_pool, ({ - vlib_cli_output (vm, "%U", format_fib_path, pi, 0); + vlib_cli_output (vm, "%U", format_fib_path, pi, 0, + FIB_PATH_FORMAT_FLAGS_NONE); })); } diff --git a/src/vnet/fib/fib_path.h b/src/vnet/fib/fib_path.h index 28ec10a98d5..e162f4dad3a 100644 --- a/src/vnet/fib/fib_path.h +++ b/src/vnet/fib/fib_path.h @@ -127,6 +127,11 @@ typedef enum fib_path_cfg_flags_t_ { FIB_PATH_CFG_FLAG_DEAG_SRC = (1 << FIB_PATH_CFG_ATTRIBUTE_DEAG_SRC), } __attribute__ ((packed)) fib_path_cfg_flags_t; +typedef enum fib_path_format_flags_t_ +{ + FIB_PATH_FORMAT_FLAGS_NONE = 0, + FIB_PATH_FORMAT_FLAGS_ONE_LINE = (1 << 0), +} fib_format_path_flags_t; extern u8 *format_fib_path(u8 *s, va_list *args); diff --git a/src/vnet/fib/fib_path_list.c b/src/vnet/fib/fib_path_list.c index d830eaa3667..4655c687427 100644 --- a/src/vnet/fib/fib_path_list.c +++ b/src/vnet/fib/fib_path_list.c @@ -82,24 +82,22 @@ static fib_path_list_t * fib_path_list_pool; */ static uword *fib_path_list_db; +/** + * the logger + */ +vlib_log_class_t fib_path_list_logger; + /* * Debug macro */ -#ifdef FIB_DEBUG -#define FIB_PATH_LIST_DBG(_pl, _fmt, _args...) \ -{ \ - u8 *_tmp = 0; \ - _tmp = fib_path_list_format( \ - fib_path_list_get_index(_pl), _tmp); \ - clib_warning("pl:[%d:%p:%p:%s]:" _fmt, \ - fib_path_list_get_index(_pl), \ - _pl, _pl->fpl_paths, _tmp, \ - ##_args); \ - vec_free(_tmp); \ +#define FIB_PATH_LIST_DBG(_pl, _fmt, _args...) \ +{ \ + vlib_log_debug(fib_path_list_logger, \ + "[%U]:" _fmt, \ + format_fib_path_list, \ + fib_path_list_get_index(_pl), 0, \ + ##_args); \ } -#else -#define FIB_PATH_LIST_DBG(_pl, _fmt, _args...) -#endif static fib_path_list_t * fib_path_list_get (fib_node_index_t index) @@ -158,7 +156,8 @@ format_fib_path_list (u8 * s, va_list * args) vec_foreach (path_index, path_list->fpl_paths) { - s = format(s, "%U", format_fib_path, *path_index, indent+2); + s = format(s, "%U", format_fib_path, *path_index, indent+2, + FIB_PATH_FORMAT_FLAGS_NONE); s = format(s, "\n"); } @@ -470,6 +469,9 @@ fib_path_list_back_walk (fib_node_index_t path_list_index, fib_path_list_mk_urpf(path_list); + FIB_PATH_LIST_DBG(path_list, "bw:%U", + format_fib_node_bw_reason, ctx->fnbw_reason); + /* * propagate the backwalk further */ @@ -839,7 +841,7 @@ fib_path_list_path_add (fib_node_index_t path_list_index, ASSERT(1 == vec_len(rpaths)); ASSERT(!(path_list->fpl_flags & FIB_PATH_LIST_FLAG_SHARED)); - FIB_PATH_LIST_DBG(orig_path_list, "path-add"); + FIB_PATH_LIST_DBG(path_list, "path-add"); new_path_index = fib_path_create(path_list_index, rpaths); @@ -986,7 +988,7 @@ fib_path_list_path_remove (fib_node_index_t path_list_index, ASSERT(1 == vec_len(rpaths)); ASSERT(!(path_list->fpl_flags & FIB_PATH_LIST_FLAG_SHARED)); - FIB_PATH_LIST_DBG(orig_path_list, "path-remove"); + FIB_PATH_LIST_DBG(path_list, "path-remove"); /* * create a representation of the path to be removed, so it @@ -1222,7 +1224,7 @@ fib_path_list_recursive_loop_detect (fib_node_index_t path_list_index, vec_free(copy); } - FIB_PATH_LIST_DBG(path_list, "loop-detect: eval:%d", eval); + FIB_PATH_LIST_DBG(path_list, "loop-detect: eval:%d", list_looped); if (list_looped) { @@ -1294,7 +1296,6 @@ fib_path_list_lock(fib_node_index_t path_list_index) path_list = fib_path_list_get(path_list_index); fib_node_lock(&path_list->fpl_node); - FIB_PATH_LIST_DBG(path_list, "lock"); } } @@ -1306,7 +1307,6 @@ fib_path_list_unlock (fib_node_index_t path_list_index) if (FIB_NODE_INDEX_INVALID != path_list_index) { path_list = fib_path_list_get(path_list_index); - FIB_PATH_LIST_DBG(path_list, "unlock"); fib_node_unlock(&path_list->fpl_node); } @@ -1356,6 +1356,7 @@ fib_path_list_module_init (void) fib_path_list_db_hash_key_equal, /* format pair/arg */ 0, 0); + fib_path_list_logger = vlib_log_register_class("fib", "path-list"); } static clib_error_t * diff --git a/src/vnet/fib/fib_walk.c b/src/vnet/fib/fib_walk.c index d0942401153..6a64d554f98 100644 --- a/src/vnet/fib/fib_walk.c +++ b/src/vnet/fib/fib_walk.c @@ -16,6 +16,8 @@ #include #include +vlib_log_class_t fib_walk_logger; + /** * The flags on a walk */ @@ -184,6 +186,17 @@ typedef struct fib_walk_history_t_ { } fib_walk_history_t; static fib_walk_history_t fib_walk_history[HISTORY_N_WALKS]; +static u8* format_fib_walk (u8* s, va_list *ap); + +#define FIB_WALK_DBG(_walk, _fmt, _args...) \ +{ \ + vlib_log_debug(fib_walk_logger, \ + "[%U]:" _fmt, \ + format_fib_walk, \ + fib_walk_get_index(_walk), \ + ##_args); \ +} + u8* format_fib_walk_priority (u8 *s, va_list *ap) { @@ -714,6 +727,9 @@ fib_walk_async (fib_node_type_t parent_type, fib_walk_get_index(fwalk)); fwalk->fw_prio_sibling = fib_walk_prio_queue_enquue(prio, fwalk); + + FIB_WALK_DBG(fwalk, "async-start: %U", + format_fib_node_bw_reason, ctx->fnbw_reason); } /** @@ -759,6 +775,8 @@ fib_walk_sync (fib_node_type_t parent_type, FIB_NODE_TYPE_WALK, fib_walk_get_index(fwalk)); fwi = fib_walk_get_index(fwalk); + FIB_WALK_DBG(fwalk, "sync-start: %U", + format_fib_node_bw_reason, ctx->fnbw_reason); while (1) { @@ -812,6 +830,10 @@ fib_walk_sync (fib_node_type_t parent_type, * continue with it now, but let the stack unwind and along the * appropriate frame to read the depth count and bail. */ + FIB_WALK_DBG(fwalk, "sync-stop: %U", + format_fib_node_bw_reason, + ctx->fnbw_reason); + fwalk = NULL; break; } @@ -827,6 +849,9 @@ fib_walk_sync (fib_node_type_t parent_type, if (NULL != fwalk) { + FIB_WALK_DBG(fwalk, "sync-stop: %U", + format_fib_node_bw_reason, + ctx->fnbw_reason); fib_walk_destroy(fwi); } } @@ -924,6 +949,7 @@ fib_walk_module_init (void) } fib_node_register_type(FIB_NODE_TYPE_WALK, &fib_walk_vft); + fib_walk_logger = vlib_log_register_class("fib", "walk"); } static u8* @@ -934,13 +960,27 @@ format_fib_walk (u8* s, va_list *ap) fwalk = fib_walk_get(fwi); - return (format(s, " parent:{%s:%d} visits:%d flags:%d", + return (format(s, "[@%d] parent:{%s:%d} visits:%d flags:%d", fwi, fib_node_type_get_name(fwalk->fw_parent.fnp_type), fwalk->fw_parent.fnp_index, fwalk->fw_n_visits, fwalk->fw_flags)); } +u8 * +format_fib_node_bw_reason (u8 *s, va_list *args) +{ + fib_node_bw_reason_flag_t flag = va_arg (*args, int); + fib_node_back_walk_reason_t reason; + + FOR_EACH_FIB_NODE_BW_REASON(reason) { + if ((1< #include +/** + * the logger + */ +vlib_log_class_t mfib_entry_logger; + /** * Debug macro */ -#ifdef MFIB_DEBUG -#DEFIne MFIB_ENTRY_DBG(_e, _fmt, _args...) \ +#define MFIB_ENTRY_DBG(_e, _fmt, _args...) \ { \ - u8*__tmp = NULL; \ - __tmp = format(__tmp, "e:[%d:%U", \ - mfib_entry_get_index(_e), \ - format_ip46_address, \ - &_e->mfe_prefix.fp_grp_addr, \ - IP46_TYPE_ANY); \ - __tmp = format(__tmp, "/%d,", \ - _e->mfe_prefix.fp_len); \ - __tmp = format(__tmp, "%U]", \ + vlib_log_debug(mfib_entry_logger, \ + "e:[%d:%U]: " _fmt, \ mfib_entry_get_index(_e), \ - format_ip46_address, \ - &_e->mfe_prefix.fp_src_addr, \ - IP46_TYPE_ANY); \ - __tmp = format(__tmp, _fmt, ##_args); \ - clib_warning("%s", __tmp); \ - vec_free(__tmp); \ + format_mfib_prefix, \ + &_e->mfe_prefix, \ + ##_args); \ } -#else -#define MFIB_ENTRY_DBG(_e, _fmt, _args...) -#endif /** * MFIB extensions to each path @@ -1207,6 +1198,7 @@ mfib_entry_module_init (void) { fib_node_register_type (FIB_NODE_TYPE_MFIB_ENTRY, &mfib_entry_vft); dpo_register(DPO_MFIB_ENTRY, &mfib_entry_dpo_vft, mfib_entry_nodes); + mfib_entry_logger = vlib_log_register_class("mfib", "entry"); } void