FIB: use vlib-log for debugging 99/15299/2
authorNeale Ranns <nranns@cisco.com>
Mon, 24 Sep 2018 12:36:26 +0000 (12:36 +0000)
committerDamjan Marion <dmarion@me.com>
Tue, 16 Oct 2018 12:22:49 +0000 (12:22 +0000)
Change-Id: I9052202b8cbcf656e61d635253d515f0f3a8d145
Signed-off-by: Neale Ranns <nranns@cisco.com>
15 files changed:
src/vnet/dpo/load_balance.c
src/vnet/dpo/load_balance_map.c
src/vnet/dpo/replicate_dpo.c
src/vnet/fib/fib_entry.c
src/vnet/fib/fib_entry.h
src/vnet/fib/fib_entry_src.c
src/vnet/fib/fib_entry_src.h
src/vnet/fib/fib_entry_src_adj.c
src/vnet/fib/fib_internal.h
src/vnet/fib/fib_node.h
src/vnet/fib/fib_path.c
src/vnet/fib/fib_path.h
src/vnet/fib/fib_path_list.c
src/vnet/fib/fib_walk.c
src/vnet/mfib/mfib_entry.c

index 48f7798..6b77f47 100644 (file)
@@ -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();
 }
 
index 588c1a7..8f9bd36 100644 (file)
@@ -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);
 }
 
index 6742bff..443df66 100644 (file)
 #include <vnet/adj/adj.h>
 #include <vnet/mpls/mpls_types.h>
 
-#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 *
index 8d7ce00..7de5213 100644 (file)
@@ -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<<attr) & flag) {
+            s = format (s, "%s,", fib_attribute_names[attr]);
+        }
+    }
+
+    return (s);
+}
+
+u8 *
+format_fib_entry_src_flags (u8 *s, va_list *args)
 {
     fib_entry_src_attribute_t sattr;
+    fib_entry_src_flag_t flag = va_arg(*args, int);
+
+    FOR_EACH_FIB_SRC_ATTRIBUTE(sattr) {
+        if ((1<<sattr) & flag) {
+            s = format (s, "%s,", fib_src_attribute_names[sattr]);
+        }
+    }
+
+    return (s);
+}
+
+u8 *
+format_fib_entry (u8 * s, va_list * args)
+{
     fib_forward_chain_type_t fct;
-    fib_entry_attribute_t attr;
     fib_entry_t *fib_entry;
     fib_entry_src_t *src;
     fib_node_index_t fei;
@@ -129,20 +162,12 @@ format_fib_entry (u8 * s, va_list * args)
            s = format (s, "\n  %U", format_fib_source, source);
            s = format (s, " refs:%d", src->fes_ref_count);
            if (FIB_ENTRY_FLAG_NONE != src->fes_entry_flags) {
-               s = format(s, " entry-flags:");
-               FOR_EACH_FIB_ATTRIBUTE(attr) {
-                   if ((1<<attr) & src->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<<sattr) & src->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
index 9175a57..8ede39c 100644 (file)
@@ -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
index 1b2d716..6868da6 100644 (file)
@@ -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))
     {
index 6174020..1d5f252 100644 (file)
 /**
  * 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 
index e43e36e..8c34305 100644 (file)
@@ -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);
 }
 
index 8abc0e0..a60ad26 100644 (file)
 #include <vnet/ip/ip.h>
 #include <vnet/dpo/dpo.h>
 
-/**
- * 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);
index 3a4ba84..1179dfc 100644 (file)
@@ -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
  */
index 4ec04f5..e37d474 100644 (file)
@@ -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);
        }));
     }
 
index 28ec10a..e162f4d 100644 (file)
@@ -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);
 
index d830eaa..4655c68 100644 (file)
@@ -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 *
index d094240..6a64d55 100644 (file)
@@ -16,6 +16,8 @@
 #include <vnet/fib/fib_walk.h>
 #include <vnet/fib/fib_node_list.h>
 
+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<<reason) & flag)
+            s = format(s, "%s", fib_node_bw_reason_names[reason]);
+    }
+
+    return (s);
+}
+
 static clib_error_t *
 fib_walk_show (vlib_main_t * vm,
               unformat_input_t * input,
@@ -1045,7 +1085,6 @@ fib_walk_show (vlib_main_t * vm,
     {
        if (0 != fib_walk_history[ii].fwh_reason[0])
        {
-            fib_node_back_walk_reason_t reason;
             u8 *s = NULL;
             u32 jj;
 
@@ -1064,11 +1103,8 @@ fib_walk_show (vlib_main_t * vm,
             jj = 0;
             while (0 != fib_walk_history[ii].fwh_reason[jj])
             {
-                FOR_EACH_FIB_NODE_BW_REASON(reason) {
-                    if ((1<<reason) & fib_walk_history[ii].fwh_reason[jj]) {
-                        s = format (s, "%s,", fib_node_bw_reason_names[reason]);
-                    }
-                }
+                s = format (s, "%U,", format_fib_node_bw_reason,
+                            fib_walk_history[ii].fwh_reason[jj]);
                 jj++;
             }
             vlib_cli_output(vm, "%v", s);
index 7427334..a8d2f89 100644 (file)
 #include <vnet/dpo/drop_dpo.h>
 #include <vnet/dpo/replicate_dpo.h>
 
+/**
+ * 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