Add logging support 28/10328/13
authorDamjan Marion <damarion@cisco.com>
Sun, 21 Jan 2018 14:44:18 +0000 (06:44 -0800)
committerDamjan Marion <dmarion.lists@gmail.com>
Tue, 17 Apr 2018 23:38:05 +0000 (23:38 +0000)
Change-Id: Ieac9cf50156dbbb4962411e900d59256441915ef
Signed-off-by: Damjan Marion <damarion@cisco.com>
Signed-off-by: Klement Sekera <ksekera@cisco.com>
src/vlib.am
src/vlib/log.c [new file with mode: 0644]
src/vlib/log.h [new file with mode: 0644]
src/vlib/vlib.h
src/vnet/bfd/bfd_main.c
src/vnet/bfd/bfd_main.h
src/vnet/bfd/bfd_udp.c
src/vnet/devices/tap/tap.c
src/vnet/devices/tap/tap.h
test/framework.py
test/test_bfd.py

index 405bed9..55d6e65 100644 (file)
@@ -35,6 +35,7 @@ libvlib_la_SOURCES =                          \
   vlib/linux/pci.c                             \
   vlib/linux/physmem.c                         \
   vlib/linux/vfio.c                            \
+  vlib/log.c                                   \
   vlib/main.c                                  \
   vlib/mc.c                                    \
   vlib/node.c                                  \
@@ -61,6 +62,7 @@ nobase_include_HEADERS +=                     \
   vlib/i2c.h                                   \
   vlib/init.h                                  \
   vlib/linux/vfio.h                            \
+  vlib/log.h                                   \
   vlib/main.h                                  \
   vlib/mc.h                                    \
   vlib/node_funcs.h                            \
diff --git a/src/vlib/log.c b/src/vlib/log.c
new file mode 100644 (file)
index 0000000..dd2ecf2
--- /dev/null
@@ -0,0 +1,673 @@
+/*
+ * Copyright (c) 2018 Cisco and/or its affiliates.
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at:
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include <stdbool.h>
+#include <vlib/vlib.h>
+#include <vlib/log.h>
+#include <syslog.h>
+
+#define VLIB_LOG_DEFAULT_SIZE 50
+#define VLIB_LOG_DEFAULT_RATE_LIMIT 10
+#define VLIB_LOG_DEFAULT_UNTHROTTLE_TIME 3
+#define VLIB_LOG_DEFAULT_LOG_LEVEL VLIB_LOG_LEVEL_CRIT
+
+typedef struct
+{
+  vlib_log_level_t level;
+  vlib_log_class_t class;
+  f64 timestamp;
+  u8 *string;
+} vlib_log_entry_t;
+
+typedef struct
+{
+  u32 index;
+  u8 *name;
+  // level of log messages kept for this subclass
+  vlib_log_level_t level;
+  // level of log messages sent to syslog for this subclass
+  vlib_log_level_t syslog_level;
+  // flag saying whether this subclass is logged to syslog
+  bool syslog_enabled;
+  f64 last_event_timestamp;
+  int last_sec_count;
+  int is_throttling;
+  int rate_limit;
+} vlib_log_subclass_data_t;
+
+typedef struct
+{
+  u32 index;
+  u8 *name;
+  vlib_log_subclass_data_t *subclasses;
+} vlib_log_class_data_t;
+
+typedef struct
+{
+  vlib_log_entry_t *entries;
+  vlib_log_class_data_t *classes;
+  int size, next, count;
+
+  /* our own log class */
+  vlib_log_class_t log_class;
+
+  int default_rate_limit;
+  int unthrottle_time;
+  u32 indent;
+} vlib_log_main_t;
+
+vlib_log_main_t log_main;
+
+
+static int
+last_log_entry ()
+{
+  vlib_log_main_t *lm = &log_main;
+  int i;
+
+  i = lm->next - lm->count;
+
+  if (i < 0)
+    i += lm->size;
+  return i;
+}
+
+static vlib_log_class_data_t *
+get_class_data (vlib_log_class_t ci)
+{
+  vlib_log_main_t *lm = &log_main;
+  return vec_elt_at_index (lm->classes, (ci >> 16));
+}
+
+static vlib_log_subclass_data_t *
+get_subclass_data (vlib_log_class_t ci)
+{
+  vlib_log_class_data_t *c = get_class_data (ci);
+  return vec_elt_at_index (c->subclasses, (ci & 0xffff));
+}
+
+static int
+vlib_log_level_to_syslog_priority (vlib_log_level_t level)
+{
+  switch (level)
+    {
+#define _(n,uc,lc) \
+    case VLIB_LOG_LEVEL_##uc:\
+      return LOG_##uc;
+      foreach_vlib_log_level
+#undef _
+    }
+  return LOG_DEBUG;
+}
+
+u8 *
+format_vlib_log_class (u8 * s, va_list * args)
+{
+  vlib_log_class_t ci = va_arg (*args, vlib_log_class_t);
+  vlib_log_class_data_t *c = get_class_data (ci);
+  vlib_log_subclass_data_t *sc = get_subclass_data (ci);
+
+  if (sc->name)
+    return format (s, "%v/%v", c->name, sc->name);
+  else
+    return format (s, "%v", c->name, 0);
+}
+
+
+void
+vlib_log (vlib_log_level_t level, vlib_log_class_t class, char *fmt, ...)
+{
+  vlib_main_t *vm = vlib_get_main ();
+  vlib_log_main_t *lm = &log_main;
+  vlib_log_entry_t *e;
+  vlib_log_subclass_data_t *sc = get_subclass_data (class);
+  va_list va;
+  f64 t = vlib_time_now (vm);
+  f64 delta = t - sc->last_event_timestamp;
+  u8 *s = 0;
+  bool use_formatted_log_entry = true;
+
+  /* make sure we are running on the main thread to avoid use in dataplane
+     code, for dataplane logging consider use of event-logger */
+  ASSERT (vlib_get_thread_index () == 0);
+
+  if (level > sc->level)
+    {
+      use_formatted_log_entry = false;
+      goto syslog;
+    }
+
+  if ((delta > lm->unthrottle_time) ||
+      (sc->is_throttling == 0 && (delta > 1)))
+    {
+      sc->last_event_timestamp = t;
+      sc->last_sec_count = 0;
+      sc->is_throttling = 0;
+    }
+  else
+    {
+      sc->last_sec_count++;
+      if (sc->last_sec_count > sc->rate_limit)
+       return;
+      else if (sc->last_sec_count == sc->rate_limit)
+       {
+         vec_reset_length (s);
+         s = format (0, "--- message(s) throttled ---");
+         sc->is_throttling = 1;
+       }
+    }
+
+  if (s == 0)
+    {
+      va_start (va, fmt);
+      s = va_format (s, fmt, &va);
+      va_end (va);
+    }
+
+  e = vec_elt_at_index (lm->entries, lm->next);
+  vec_free (e->string);
+  e->level = level;
+  e->class = class;
+  e->string = s;
+  e->timestamp = t;
+
+  lm->next = (lm->next + 1) % lm->size;
+  if (lm->size > lm->count)
+    lm->count++;
+
+syslog:
+  if (sc->syslog_enabled && level <= sc->syslog_level)
+    {
+      u8 *tmp = format (NULL, "%U", format_vlib_log_class, class);
+      if (use_formatted_log_entry)
+       {
+         syslog (vlib_log_level_to_syslog_priority (level), "%.*s: %.*s",
+                 vec_len (tmp), tmp,
+                 vec_len (s) - (vec_c_string_is_terminated (s) ? 1 : 0), s);
+       }
+      else
+       {
+         tmp = format (tmp, ": ");
+         va_start (va, fmt);
+         tmp = va_format (tmp, fmt, &va);
+         va_end (va);
+         syslog (vlib_log_level_to_syslog_priority (level), "%.*s",
+                 vec_len (tmp) - (vec_c_string_is_terminated (tmp) ? 1 : 0),
+                 tmp);
+       }
+      vec_free (tmp);
+    }
+
+}
+
+vlib_log_class_t
+vlib_log_register_class (char *class, char *subclass)
+{
+  vlib_log_main_t *lm = &log_main;
+  vlib_log_class_data_t *c = NULL;
+  vlib_log_subclass_data_t *s;
+  vlib_log_class_data_t *tmp;
+  vec_foreach (tmp, lm->classes)
+  {
+    if (!memcmp (class, tmp->name, vec_len (tmp->name)))
+      {
+       c = tmp;
+       break;
+      }
+  }
+  if (!c)
+    {
+      vec_add2 (lm->classes, c, 1);
+      c->index = c - lm->classes;
+      c->name = format (0, "%s", class);
+    }
+
+  vec_add2 (c->subclasses, s, 1);
+  s->index = s - c->subclasses;
+  s->name = subclass ? format (0, "%s", subclass) : 0;
+  s->rate_limit = lm->default_rate_limit;
+  s->level = VLIB_LOG_DEFAULT_LOG_LEVEL;
+  return (c->index << 16) | (s->index);
+}
+
+u8 *
+format_vlib_log_level (u8 * s, va_list * args)
+{
+  vlib_log_level_t i = va_arg (*args, vlib_log_level_t);
+  char *t = 0;
+
+  switch (i)
+    {
+#define _(v,uc,lc) case VLIB_LOG_LEVEL_##uc: t = #lc; break;
+      foreach_vlib_log_level
+#undef _
+    default:
+      return format (s, "unknown");
+    }
+  return format (s, "%s", t);
+}
+
+u32
+vlib_log_get_indent ()
+{
+  return log_main.indent;
+}
+
+static clib_error_t *
+vlib_log_init (vlib_main_t * vm)
+{
+  vlib_log_main_t *lm = &log_main;
+  lm->size = VLIB_LOG_DEFAULT_SIZE;
+  vec_validate (lm->entries, lm->size);
+  lm->log_class = vlib_log_register_class ("log", 0);
+  u8 *tmp = format (NULL, "%U %-10U %-10U ", format_time_float, 0, (f64) 0,
+                   format_white_space, 255, format_white_space, 255);
+  log_main.indent = vec_len (tmp);
+  vec_free (tmp);
+  return 0;
+}
+
+VLIB_INIT_FUNCTION (vlib_log_init);
+
+
+static clib_error_t *
+show_log (vlib_main_t * vm,
+         unformat_input_t * input, vlib_cli_command_t * cmd)
+{
+  clib_error_t *error = 0;
+  vlib_log_main_t *lm = &log_main;
+  vlib_log_entry_t *e;
+  int i = last_log_entry ();
+  int count = lm->count;
+
+  while (count--)
+    {
+      e = vec_elt_at_index (lm->entries, i);
+      vlib_cli_output (vm, "%U %-10U %-10U %v (%d)",
+                      format_time_float, 0, e->timestamp,
+                      format_vlib_log_level, e->level,
+                      format_vlib_log_class, e->class, e->string, i);
+      i = (i + 1) % lm->size;
+    }
+
+  return error;
+}
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (cli_show_log, static) = {
+  .path = "show logging",
+  .short_help = "show logging",
+  .function = show_log,
+};
+/* *INDENT-ON* */
+
+static clib_error_t *
+clear_log (vlib_main_t * vm,
+          unformat_input_t * input, vlib_cli_command_t * cmd)
+{
+  clib_error_t *error = 0;
+  vlib_log_main_t *lm = &log_main;
+  vlib_log_entry_t *e;
+  int i = last_log_entry ();
+  int count = lm->count;
+
+  while (count--)
+    {
+      e = vec_elt_at_index (lm->entries, i);
+      vec_free (e->string);
+      i = (i + 1) % lm->size;
+    }
+
+  lm->count = 0;
+  lm->next = 0;
+  vlib_log_info (lm->log_class, "log cleared");
+  return error;
+}
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (cli_clear_log, static) = {
+  .path = "clear logging",
+  .short_help = "clear logging",
+  .function = clear_log,
+};
+/* *INDENT-ON* */
+
+static uword
+unformat_vlib_log_level (unformat_input_t * input, va_list * args)
+{
+  vlib_log_level_t *level = va_arg (*args, vlib_log_level_t *);
+  u8 *level_str = NULL;
+  uword rv = 1;
+  if (unformat (input, "%v", &level_str))
+    {
+#define _(v, uc, lc)                                   \
+  const char __##uc[] = #lc;                           \
+  if (!memcmp (level_str, __##uc, sizeof (__##uc))) \
+    {                                                  \
+      *level = VLIB_LOG_LEVEL_##uc;                 \
+      rv = 1;                                          \
+      goto done;                                       \
+    }
+      foreach_vlib_log_level;
+      rv = 0;
+#undef _
+    }
+done:
+  vec_free (level_str);
+  return rv;
+}
+
+static uword
+unformat_vlib_log_class (unformat_input_t * input, va_list * args)
+{
+  vlib_log_class_data_t **class = va_arg (*args, vlib_log_class_data_t **);
+  uword rv = 0;
+  u8 *class_str = NULL;
+  vlib_log_main_t *lm = &log_main;
+  if (unformat (input, "%v", &class_str))
+    {
+      vlib_log_class_data_t *cdata;
+      vec_foreach (cdata, lm->classes)
+      {
+       if (vec_is_equal (cdata->name, class_str))
+         {
+           *class = cdata;
+           rv = 1;
+           break;
+         }
+      }
+    }
+  vec_free (class_str);
+  return rv;
+}
+
+static clib_error_t *
+set_log_class (vlib_main_t * vm,
+              unformat_input_t * input, vlib_cli_command_t * cmd)
+{
+  unformat_input_t _line_input, *line_input = &_line_input;
+  clib_error_t *rv = NULL;
+  int rate_limit;
+  bool set_rate_limit = false;
+  bool set_level = false;
+  bool set_syslog_level = false;
+  vlib_log_level_t level;
+  vlib_log_level_t syslog_level;
+
+  /* Get a line of input. */
+  if (!unformat_user (input, unformat_line_input, line_input))
+    return 0;
+
+  vlib_log_class_data_t *class = NULL;
+  if (!unformat (line_input, "%U", unformat_vlib_log_class, &class))
+    {
+      return clib_error_return (0, "unknown log class `%U'",
+                               format_unformat_error, line_input);
+    }
+  while (unformat_check_input (line_input) != UNFORMAT_END_OF_INPUT)
+    {
+      if (unformat (line_input, "rate-limit %d", &rate_limit))
+       {
+         set_rate_limit = true;
+       }
+      else
+       if (unformat
+           (line_input, "level %U", unformat_vlib_log_level, &level))
+       {
+         set_level = true;
+       }
+      else
+       if (unformat
+           (line_input, "syslog-level %U", unformat_vlib_log_level,
+            &syslog_level))
+       {
+         set_syslog_level = true;
+       }
+      else
+       {
+         return clib_error_return (0, "unknown input `%U'",
+                                   format_unformat_error, line_input);
+       }
+    }
+
+  if (set_level)
+    {
+      vlib_log_subclass_data_t *subclass;
+      vec_foreach (subclass, class->subclasses)
+      {
+       subclass->level = level;
+      }
+    }
+  if (set_syslog_level)
+    {
+      vlib_log_subclass_data_t *subclass;
+      vec_foreach (subclass, class->subclasses)
+      {
+       subclass->syslog_level = syslog_level;
+       subclass->syslog_enabled = true;
+      }
+    }
+  else
+    {
+      vlib_log_subclass_data_t *subclass;
+      vec_foreach (subclass, class->subclasses)
+      {
+       subclass->syslog_enabled = false;
+      }
+    }
+  if (set_rate_limit)
+    {
+      vlib_log_subclass_data_t *subclass;
+      vec_foreach (subclass, class->subclasses)
+      {
+       subclass->rate_limit = rate_limit;
+      }
+    }
+
+  return rv;
+}
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (cli_set_log, static) = {
+  .path = "set logging class",
+  .short_help = "set loggging class <class> [rate-limit <int>] "
+    "[level <level>] [syslog-level <level>]",
+  .function = set_log_class,
+};
+/* *INDENT-ON* */
+
+static clib_error_t *
+set_log_unth_time (vlib_main_t * vm,
+                  unformat_input_t * input, vlib_cli_command_t * cmd)
+{
+  unformat_input_t _line_input, *line_input = &_line_input;
+  clib_error_t *rv = NULL;
+  int unthrottle_time;
+  vlib_log_main_t *lm = &log_main;
+
+  /* Get a line of input. */
+  if (!unformat_user (input, unformat_line_input, line_input))
+    return 0;
+
+  while (unformat_check_input (line_input) != UNFORMAT_END_OF_INPUT)
+    {
+      if (unformat (line_input, "%d", &unthrottle_time))
+       lm->unthrottle_time = unthrottle_time;
+      else
+       return clib_error_return (0, "unknown input `%U'",
+                                 format_unformat_error, line_input);
+    }
+
+  return rv;
+}
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (cli_set_log_params, static) = {
+  .path = "set logging unthrottle-time",
+  .short_help = "set logging unthrottle-time <int>",
+  .function = set_log_unth_time,
+};
+/* *INDENT-ON* */
+
+static clib_error_t *
+set_log_size (vlib_main_t * vm,
+             unformat_input_t * input, vlib_cli_command_t * cmd)
+{
+  unformat_input_t _line_input, *line_input = &_line_input;
+  clib_error_t *rv = NULL;
+  int size;
+  vlib_log_main_t *lm = &log_main;
+
+  /* Get a line of input. */
+  if (!unformat_user (input, unformat_line_input, line_input))
+    return 0;
+
+  while (unformat_check_input (line_input) != UNFORMAT_END_OF_INPUT)
+    {
+      if (unformat (line_input, "%d", &size))
+       {
+         lm->size = size;
+         vec_validate (lm->entries, lm->size);
+       }
+      else
+       return clib_error_return (0, "unknown input `%U'",
+                                 format_unformat_error, line_input);
+    }
+
+  return rv;
+}
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (cli_set_log_size, static) = {
+  .path = "set logging size",
+  .short_help = "set logging size <int>",
+  .function = set_log_size,
+};
+/* *INDENT-ON* */
+
+static uword
+unformat_vlib_log_subclass (unformat_input_t * input, va_list * args)
+{
+  vlib_log_class_data_t *class = va_arg (*args, vlib_log_class_data_t *);
+  vlib_log_subclass_data_t **subclass =
+    va_arg (*args, vlib_log_subclass_data_t **);
+  uword rv = 0;
+  u8 *subclass_str = NULL;
+  if (unformat (input, "%v", &subclass_str))
+    {
+      vlib_log_subclass_data_t *scdata;
+      vec_foreach (scdata, class->subclasses)
+      {
+       if (vec_is_equal (scdata->name, subclass_str))
+         {
+           rv = 1;
+           *subclass = scdata;
+           break;
+         }
+      }
+    }
+  vec_free (subclass_str);
+  return rv;
+}
+
+static clib_error_t *
+test_log_class_subclass (vlib_main_t * vm,
+                        unformat_input_t * input, vlib_cli_command_t * cmd)
+{
+  unformat_input_t _line_input, *line_input = &_line_input;
+  /* Get a line of input. */
+  if (!unformat_user (input, unformat_line_input, line_input))
+    return 0;
+
+  vlib_log_class_data_t *class = NULL;
+  vlib_log_subclass_data_t *subclass = NULL;
+  vlib_log_level_t level;
+  if (unformat (line_input, "%U", unformat_vlib_log_level, &level))
+    {
+      if (unformat (line_input, "%U", unformat_vlib_log_class, &class))
+       {
+         if (unformat
+             (line_input, "%U", unformat_vlib_log_subclass, class,
+              &subclass))
+           {
+             vlib_log (level,
+                       (class->index << 16) | (subclass->index), "%U",
+                       format_unformat_input, line_input);
+           }
+         else
+           {
+             return clib_error_return (0,
+                                       "unknown log subclass near beginning of `%U'",
+                                       format_unformat_error, line_input);
+           }
+       }
+      else
+       {
+         return clib_error_return (0,
+                                   "unknown log class near beginning of `%U'",
+                                   format_unformat_error, line_input);
+       }
+    }
+  else
+    {
+      return clib_error_return (0, "unknown log level near beginning of `%U'",
+                               format_unformat_error, line_input);
+    }
+  return 0;
+}
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (cli_test_log, static) = {
+  .path = "test log",
+  .short_help = "test log <class> <subclass> <level> <message",
+  .function = test_log_class_subclass,
+};
+/* *INDENT-ON* */
+
+static clib_error_t *
+log_config (vlib_main_t * vm, unformat_input_t * input)
+{
+  vlib_log_main_t *lm = &log_main;
+  int size;
+
+  while (unformat_check_input (input) != UNFORMAT_END_OF_INPUT)
+    {
+      if (unformat (input, "size %d", &size))
+       {
+         lm->size = size;
+         vec_validate (lm->entries, lm->size);
+       }
+      else if (unformat (input, "unthrottle-time %d", &lm->unthrottle_time))
+       {
+         // nothing to do here
+       }
+      else
+       {
+         return unformat_parse_error (input);
+       }
+    }
+
+  return 0;
+}
+
+VLIB_EARLY_CONFIG_FUNCTION (log_config, "logging");
+
+/*
+ * fd.io coding-style-patch-verification: ON
+ *
+ * Local Variables:
+ * eval: (c-set-style "gnu")
+ * End:
+ */
diff --git a/src/vlib/log.h b/src/vlib/log.h
new file mode 100644 (file)
index 0000000..90862dc
--- /dev/null
@@ -0,0 +1,63 @@
+/*
+ * Copyright (c) 2018 Cisco and/or its affiliates.
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at:
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#ifndef included_vlib_log_h
+#define included_vlib_log_h
+
+#include <vppinfra/types.h>
+
+typedef u32 vlib_log_class_t;
+
+#define foreach_vlib_log_level \
+  _(0, EMERG, emerg) \
+  _(1, ALERT, alert) \
+  _(2, CRIT, crit) \
+  _(3, ERR, err) \
+  _(4, WARNING, warn) \
+  _(5, NOTICE, notice) \
+  _(6, INFO, info) \
+  _(7, DEBUG, debug)
+
+typedef enum
+{
+#define _(n,uc,lc) VLIB_LOG_LEVEL_##uc = n,
+  foreach_vlib_log_level
+#undef _
+} vlib_log_level_t;
+
+
+vlib_log_class_t vlib_log_register_class (char *vlass, char *subclass);
+u32 vlib_log_get_indent ();
+void vlib_log (vlib_log_level_t level, vlib_log_class_t class, char *fmt,
+              ...);
+
+#define vlib_log_emerg(...) vlib_log(VLIB_LOG_LEVEL_EMERG, __VA_ARGS__)
+#define vlib_log_alert(...) vlib_log(VLIB_LOG_LEVEL_ALERT, __VA_ARGS__)
+#define vlib_log_crit(...) vlib_log(VLIB_LOG_LEVEL_CRIT, __VA_ARGS__)
+#define vlib_log_err(...) vlib_log(VLIB_LOG_LEVEL_ERR, __VA_ARGS__)
+#define vlib_log_warn(...) vlib_log(VLIB_LOG_LEVEL_WARN, __VA_ARGS__)
+#define vlib_log_notice(...) vlib_log(VLIB_LOG_LEVEL_NOTICE, __VA_ARGS__)
+#define vlib_log_info(...) vlib_log(VLIB_LOG_LEVEL_INFO, __VA_ARGS__)
+#define vlib_log_debug(...) vlib_log(VLIB_LOG_LEVEL_DEBUG, __VA_ARGS__)
+
+#endif /* included_vlib_log_h */
+
+/*
+ * fd.io coding-style-patch-verification: ON
+ *
+ * Local Variables:
+ * eval: (c-set-style "gnu")
+ * End:
+ */
index eed5c5b..21c5b2a 100644 (file)
@@ -59,6 +59,7 @@ struct vlib_main_t;
 #include <vlib/mc.h>
 #include <vlib/node.h>
 #include <vlib/trace.h>
+#include <vlib/log.h>
 
 /* Main include depends on other vlib/ includes so we put it last. */
 #include <vlib/main.h>
index 668a44e..28ece31 100644 (file)
@@ -34,6 +34,7 @@
 #include <vnet/bfd/bfd_debug.h>
 #include <vnet/bfd/bfd_protocol.h>
 #include <vnet/bfd/bfd_main.h>
+#include <vlib/log.h>
 
 static u64
 bfd_calc_echo_checksum (u32 discriminator, u64 expire_time, u32 secret)
@@ -403,6 +404,8 @@ void
 bfd_session_start (bfd_main_t * bm, bfd_session_t * bs)
 {
   BFD_DBG ("\nStarting session: %U", format_bfd_session, bs);
+  vlib_log_info (bm->log_class, "start BFD session: %U",
+                format_bfd_session_brief, bs);
   bfd_set_effective_required_min_rx (bm, bs,
                                     bs->config_required_min_rx_clocks);
   bfd_recalc_tx_interval (bm, bs);
@@ -419,6 +422,8 @@ bfd_session_set_flags (bfd_session_t * bs, u8 admin_up_down)
   if (admin_up_down)
     {
       BFD_DBG ("Session set admin-up, bs-idx=%u", bs->bs_idx);
+      vlib_log_info (bm->log_class, "set session admin-up: %U",
+                    format_bfd_session_brief, bs);
       bfd_set_state (bm, bs, BFD_STATE_down, 0);
       bfd_set_diag (bs, BFD_DIAG_CODE_no_diag);
       bfd_calc_next_tx (bm, bs, now);
@@ -427,6 +432,8 @@ bfd_session_set_flags (bfd_session_t * bs, u8 admin_up_down)
   else
     {
       BFD_DBG ("Session set admin-down, bs-idx=%u", bs->bs_idx);
+      vlib_log_info (bm->log_class, "set session admin-down: %U",
+                    format_bfd_session_brief, bs);
       bfd_set_diag (bs, BFD_DIAG_CODE_admin_down);
       bfd_set_state (bm, bs, BFD_STATE_admin_down, 0);
       bfd_calc_next_tx (bm, bs, now);
@@ -668,6 +675,7 @@ bfd_add_sha1_auth_section (vlib_buffer_t * b, bfd_session_t * bs)
 static void
 bfd_add_auth_section (vlib_buffer_t * b, bfd_session_t * bs)
 {
+  bfd_main_t *bm = &bfd_main;
   if (bs->auth.curr_key)
     {
       const bfd_auth_type_e auth_type = bs->auth.curr_key->auth_type;
@@ -680,8 +688,9 @@ bfd_add_auth_section (vlib_buffer_t * b, bfd_session_t * bs)
        case BFD_AUTH_TYPE_keyed_md5:
          /* fallthrough */
        case BFD_AUTH_TYPE_meticulous_keyed_md5:
-         clib_warning ("Internal error, unexpected BFD auth type '%d'",
-                       auth_type);
+         vlib_log_crit (bm->log_class,
+                        "internal error, unexpected BFD auth type '%d'",
+                        auth_type);
          break;
 #if WITH_LIBSSL > 0
        case BFD_AUTH_TYPE_keyed_sha1:
@@ -693,8 +702,9 @@ bfd_add_auth_section (vlib_buffer_t * b, bfd_session_t * bs)
        case BFD_AUTH_TYPE_keyed_sha1:
          /* fallthrough */
        case BFD_AUTH_TYPE_meticulous_keyed_sha1:
-         clib_warning ("Internal error, unexpected BFD auth type '%d'",
-                       auth_type);
+         vlib_log_crit (bm->log_class,
+                        "internal error, unexpected BFD auth type '%d'",
+                        auth_type);
          break;
 #endif
        }
@@ -768,7 +778,7 @@ bfd_send_echo (vlib_main_t * vm, vlib_node_runtime_t * rt,
       u32 bi;
       if (vlib_buffer_alloc (vm, &bi, 1) != 1)
        {
-         clib_warning ("buffer allocation failure");
+         vlib_log_crit (bm->log_class, "buffer allocation failure");
          return;
        }
       vlib_buffer_t *b = vlib_get_buffer (vm, bi);
@@ -842,7 +852,7 @@ bfd_send_periodic (vlib_main_t * vm, vlib_node_runtime_t * rt,
       u32 bi;
       if (vlib_buffer_alloc (vm, &bi, 1) != 1)
        {
-         clib_warning ("buffer allocation failure");
+         vlib_log_crit (bm->log_class, "buffer allocation failure");
          return;
        }
       vlib_buffer_t *b = vlib_get_buffer (vm, bi);
@@ -1063,7 +1073,7 @@ bfd_process (vlib_main_t * vm, vlib_node_runtime_t * rt, vlib_frame_t * f)
            }
          break;
        default:
-         clib_warning ("BUG: event type 0x%wx", event_type);
+         vlib_log_err (bm->log_class, "BUG: event type 0x%wx", event_type);
          break;
        }
       BFD_DBG ("advancing wheel, now is %lu", now);
@@ -1166,6 +1176,8 @@ bfd_main_init (vlib_main_t * vm)
   const u64 now = clib_cpu_time_now ();
   timing_wheel_init (&bm->wheel, now, bm->cpu_cps);
   bm->wheel_inaccuracy = 2 << bm->wheel.log2_clocks_per_bin;
+  bm->log_class = vlib_log_register_class ("bfd", 0);
+  vlib_log_debug (bm->log_class, "initialized");
   return 0;
 }
 
@@ -1186,8 +1198,9 @@ bfd_get_session (bfd_main_t * bm, bfd_transport_e t)
       result->local_discr = random_u32 (&bm->random_seed);
       if (counter > limit)
        {
-         clib_warning ("Couldn't allocate unused session discriminator even "
-                       "after %u tries!", limit);
+         vlib_log_crit (bm->log_class,
+                        "couldn't allocate unused session discriminator even "
+                        "after %u tries!", limit);
          pool_put (bm->sessions, result);
          return NULL;
        }
@@ -1202,6 +1215,8 @@ bfd_get_session (bfd_main_t * bm, bfd_transport_e t)
 void
 bfd_put_session (bfd_main_t * bm, bfd_session_t * bs)
 {
+  vlib_log_info (bm->log_class, "delete session: %U",
+                format_bfd_session_brief, bs);
   bfd_notify_listeners (bm, BFD_LISTEN_EVENT_DELETE, bs);
   if (bs->auth.curr_key)
     {
@@ -1468,23 +1483,27 @@ bfd_verify_pkt_auth_key (const bfd_pkt_t * pkt, u32 pkt_size,
                         bfd_session_t * bs, u8 bfd_key_id,
                         bfd_auth_key_t * auth_key)
 {
+  bfd_main_t *bm = &bfd_main;
   switch (auth_key->auth_type)
     {
     case BFD_AUTH_TYPE_reserved:
-      clib_warning ("Internal error, unexpected auth_type=%d:%s",
+      vlib_log_err (bm->log_class,
+                   "internal error, unexpected auth_type=%d:%s",
                    auth_key->auth_type,
                    bfd_auth_type_str (auth_key->auth_type));
       return 0;
     case BFD_AUTH_TYPE_simple_password:
-      clib_warning
-       ("Internal error, not implemented, unexpected auth_type=%d:%s",
-        auth_key->auth_type, bfd_auth_type_str (auth_key->auth_type));
+      vlib_log_err (bm->log_class,
+                   "internal error, not implemented, unexpected auth_type=%d:%s",
+                   auth_key->auth_type,
+                   bfd_auth_type_str (auth_key->auth_type));
       return 0;
     case BFD_AUTH_TYPE_keyed_md5:
       /* fallthrough */
     case BFD_AUTH_TYPE_meticulous_keyed_md5:
-      clib_warning
-       ("Internal error, not implemented, unexpected auth_type=%d:%s",
+      vlib_log_err
+       (bm->log_class,
+        "internal error, not implemented, unexpected auth_type=%d:%s",
         auth_key->auth_type, bfd_auth_type_str (auth_key->auth_type));
       return 0;
     case BFD_AUTH_TYPE_keyed_sha1:
@@ -1504,8 +1523,9 @@ bfd_verify_pkt_auth_key (const bfd_pkt_t * pkt, u32 pkt_size,
        }
       while (0);
 #else
-      clib_warning
-       ("Internal error, attempt to use SHA1 without SSL support");
+      vlib_log_err
+       (bm->log_class,
+        "internal error, attempt to use SHA1 without SSL support");
       return 0;
 #endif
     }
@@ -1625,8 +1645,9 @@ bfd_consume_pkt (bfd_main_t * bm, const bfd_pkt_t * pkt, u32 bs_idx)
        case BFD_AUTH_TYPE_keyed_md5:
          /* fallthrough */
        case BFD_AUTH_TYPE_meticulous_keyed_md5:
-         clib_warning ("Internal error, unexpected auth_type=%d:%s",
-                       auth_type, bfd_auth_type_str (auth_type));
+         vlib_log_crit (bm->log_class,
+                        "internal error, unexpected auth_type=%d:%s",
+                        auth_type, bfd_auth_type_str (auth_type));
          break;
        case BFD_AUTH_TYPE_keyed_sha1:
          /* fallthrough */
@@ -1768,7 +1789,7 @@ u8 *
 format_bfd_session (u8 * s, va_list * args)
 {
   const bfd_session_t *bs = va_arg (*args, bfd_session_t *);
-  u32 indent = format_get_indent (s);
+  u32 indent = format_get_indent (s) + vlib_log_get_indent ();
   s = format (s, "bs_idx=%u local-state=%s remote-state=%s\n"
              "%Ulocal-discriminator=%u remote-discriminator=%u\n"
              "%Ulocal-diag=%s echo-active=%s\n"
@@ -1800,6 +1821,17 @@ format_bfd_session (u8 * s, va_list * args)
   return s;
 }
 
+u8 *
+format_bfd_session_brief (u8 * s, va_list * args)
+{
+  const bfd_session_t *bs = va_arg (*args, bfd_session_t *);
+  s =
+    format (s, "bs_idx=%u local-state=%s remote-state=%s", bs->bs_idx,
+           bfd_state_string (bs->local_state),
+           bfd_state_string (bs->remote_state));
+  return s;
+}
+
 unsigned
 bfd_auth_type_supported (bfd_auth_type_e auth_type)
 {
@@ -1820,7 +1852,8 @@ bfd_auth_activate (bfd_session_t * bs, u32 conf_key_id,
     hash_get (bm->auth_key_by_conf_key_id, conf_key_id);
   if (!key_idx_p)
     {
-      clib_warning ("Authentication key with config ID %u doesn't exist)",
+      vlib_log_err (bm->log_class,
+                   "authentication key with config ID %u doesn't exist)",
                    conf_key_id);
       return VNET_API_ERROR_BFD_ENOENT;
     }
@@ -1854,12 +1887,15 @@ bfd_auth_activate (bfd_session_t * bs, u32 conf_key_id,
     }
   ++key->use_count;
   BFD_DBG ("\nSession auth modified: %U", format_bfd_session, bs);
+  vlib_log_info (bm->log_class, "session auth modified: %U",
+                format_bfd_session_brief, bs);
   return 0;
 }
 
 vnet_api_error_t
 bfd_auth_deactivate (bfd_session_t * bs, u8 is_delayed)
 {
+  bfd_main_t *bm = &bfd_main;
 #if WITH_LIBSSL > 0
   if (!is_delayed)
     {
@@ -1888,9 +1924,12 @@ bfd_auth_deactivate (bfd_session_t * bs, u8 is_delayed)
       bs->auth.next_key = NULL;
     }
   BFD_DBG ("\nSession auth modified: %U", format_bfd_session, bs);
+  vlib_log_info (bm->log_class, "session auth modified: %U",
+                format_bfd_session_brief, bs);
   return 0;
 #else
-  clib_warning ("SSL missing, cannot deactivate BFD authentication");
+  vlib_log_err (bm->log_class,
+               "SSL missing, cannot deactivate BFD authentication");
   return VNET_API_ERROR_BFD_NOTSUPP;
 #endif
 }
@@ -1946,6 +1985,8 @@ bfd_session_set_params (bfd_main_t * bm, bfd_session_t * bs,
        bfd_usec_to_clocks (bm, required_min_rx_usec);
       BFD_DBG ("\nChanged session params: %U", format_bfd_session, bs);
 
+      vlib_log_info (bm->log_class, "changed session params: %U",
+                    format_bfd_session_brief, bs);
       vlib_process_signal_event (bm->vlib_main, bm->bfd_process_node_index,
                                 BFD_EVENT_CONFIG_CHANGED, bs->bs_idx);
     }
@@ -1960,24 +2001,24 @@ vnet_api_error_t
 bfd_auth_set_key (u32 conf_key_id, u8 auth_type, u8 key_len,
                  const u8 * key_data)
 {
+  bfd_main_t *bm = &bfd_main;
 #if WITH_LIBSSL > 0
   bfd_auth_key_t *auth_key = NULL;
   if (!key_len || key_len > bfd_max_key_len_for_auth_type (auth_type))
     {
-      clib_warning ("Invalid authentication key length for auth_type=%d:%s "
-                   "(key_len=%u, must be "
-                   "non-zero, expected max=%u)",
+      vlib_log_err (bm->log_class,
+                   "invalid authentication key length for auth_type=%d:%s "
+                   "(key_len=%u, must be non-zero, expected max=%u)",
                    auth_type, bfd_auth_type_str (auth_type), key_len,
                    (u32) bfd_max_key_len_for_auth_type (auth_type));
       return VNET_API_ERROR_INVALID_VALUE;
     }
   if (!bfd_auth_type_supported (auth_type))
     {
-      clib_warning ("Unsupported auth type=%d:%s", auth_type,
+      vlib_log_err (bm->log_class, "unsupported auth type=%d:%s", auth_type,
                    bfd_auth_type_str (auth_type));
       return VNET_API_ERROR_BFD_NOTSUPP;
     }
-  bfd_main_t *bm = &bfd_main;
   uword *key_idx_p = hash_get (bm->auth_key_by_conf_key_id, conf_key_id);
   if (key_idx_p)
     {
@@ -1986,9 +2027,10 @@ bfd_auth_set_key (u32 conf_key_id, u8 auth_type, u8 key_len,
       auth_key = pool_elt_at_index (bm->auth_keys, key_idx);
       if (auth_key->use_count > 0)
        {
-         clib_warning ("Authentication key with conf ID %u in use by %u BFD "
-                       "session(s) - cannot modify",
-                       conf_key_id, auth_key->use_count);
+         vlib_log_err (bm->log_class,
+                       "authentication key with conf ID %u in use by %u BFD "
+                       "session(s) - cannot modify", conf_key_id,
+                       auth_key->use_count);
          return VNET_API_ERROR_BFD_EINUSE;
        }
     }
@@ -2005,7 +2047,8 @@ bfd_auth_set_key (u32 conf_key_id, u8 auth_type, u8 key_len,
   clib_memcpy (auth_key->key, key_data, key_len);
   return 0;
 #else
-  clib_warning ("SSL missing, cannot manipulate authentication keys");
+  vlib_log_err (bm->log_class,
+               "SSL missing, cannot manipulate authentication keys");
   return VNET_API_ERROR_BFD_NOTSUPP;
 #endif
 }
@@ -2024,9 +2067,10 @@ bfd_auth_del_key (u32 conf_key_id)
       auth_key = pool_elt_at_index (bm->auth_keys, key_idx);
       if (auth_key->use_count > 0)
        {
-         clib_warning ("Authentication key with conf ID %u in use by %u BFD "
-                       "session(s) - cannot delete",
-                       conf_key_id, auth_key->use_count);
+         vlib_log_err (bm->log_class,
+                       "authentication key with conf ID %u in use by %u BFD "
+                       "session(s) - cannot delete", conf_key_id,
+                       auth_key->use_count);
          return VNET_API_ERROR_BFD_EINUSE;
        }
       hash_unset (bm->auth_key_by_conf_key_id, conf_key_id);
@@ -2036,13 +2080,15 @@ bfd_auth_del_key (u32 conf_key_id)
   else
     {
       /* no such key */
-      clib_warning ("Authentication key with conf ID %u does not exist",
+      vlib_log_err (bm->log_class,
+                   "authentication key with conf ID %u does not exist",
                    conf_key_id);
       return VNET_API_ERROR_BFD_ENOENT;
     }
   return 0;
 #else
-  clib_warning ("SSL missing, cannot manipulate authentication keys");
+  vlib_log_err (bm->log_class,
+               "SSL missing, cannot manipulate authentication keys");
   return VNET_API_ERROR_BFD_NOTSUPP;
 #endif
 }
index 93adac3..9e2a12e 100644 (file)
@@ -23,6 +23,7 @@
 #include <vnet/vnet.h>
 #include <vnet/bfd/bfd_protocol.h>
 #include <vnet/bfd/bfd_udp.h>
+#include <vlib/log.h>
 
 #define foreach_bfd_mode(F) \
   F (asynchronous)          \
@@ -296,8 +297,11 @@ typedef struct
   /** hashmap - index in pool auth_keys by conf_key_id */
   u32 *auth_key_by_conf_key_id;
 
-  /** vector of callback notification functions */
+  /** vector of callback notification functions */
   bfd_notify_fn_t *listeners;
+
+  /** log class */
+  vlib_log_class_t log_class;
 } bfd_main_t;
 
 extern bfd_main_t bfd_main;
@@ -358,6 +362,7 @@ void bfd_init_final_control_frame (vlib_main_t * vm, vlib_buffer_t * b,
                                   bfd_main_t * bm, bfd_session_t * bs,
                                   int is_local);
 u8 *format_bfd_session (u8 * s, va_list * args);
+u8 *format_bfd_session_brief (u8 * s, va_list * args);
 u8 *format_bfd_auth_key (u8 * s, va_list * args);
 void bfd_session_set_flags (bfd_session_t * bs, u8 admin_up_down);
 unsigned bfd_auth_type_supported (bfd_auth_type_e auth_type);
index 533d98d..5464ce9 100644 (file)
@@ -59,6 +59,8 @@ typedef struct
   u32 ip4_rewrite_idx;
   /* node index of "ip6-rewrite" node */
   u32 ip6_rewrite_idx;
+  /* log class */
+  vlib_log_class_t log_class;
 } bfd_udp_main_t;
 
 static vlib_node_registration_t bfd_udp4_input_node;
@@ -481,7 +483,8 @@ bfd_udp_add_session_internal (bfd_udp_main_t * bum, u32 sw_if_index,
   const bfd_session_t *tmp = bfd_lookup_session (bum, key);
   if (tmp)
     {
-      clib_warning ("duplicate bfd-udp session, existing bs_idx=%d",
+      vlib_log_err (bum->log_class,
+                   "duplicate bfd-udp session, existing bs_idx=%d",
                    tmp->bs_idx);
       bfd_put_session (bum->bfd_main, bs);
       return VNET_API_ERROR_BFD_EEXIST;
@@ -491,6 +494,8 @@ bfd_udp_add_session_internal (bfd_udp_main_t * bum, u32 sw_if_index,
           bs->bs_idx, key->sw_if_index, format_ip46_address,
           &key->local_addr, IP46_TYPE_ANY, format_ip46_address,
           &key->peer_addr, IP46_TYPE_ANY);
+  vlib_log_info (bum->log_class, "create BFD session: %U",
+                format_bfd_session, bs);
   if (BFD_TRANSPORT_UDP4 == t)
     {
       bus->adj_index = adj_nbr_add_or_lock (FIB_PROTOCOL_IP4, VNET_LINK_IP4,
@@ -519,20 +524,24 @@ bfd_udp_validate_api_input (u32 sw_if_index,
                            const ip46_address_t * local_addr,
                            const ip46_address_t * peer_addr)
 {
+  bfd_udp_main_t *bum = &bfd_udp_main;
   vnet_sw_interface_t *sw_if =
     vnet_get_sw_interface_safe (bfd_udp_main.vnet_main, sw_if_index);
   u8 local_ip_valid = 0;
   ip_interface_address_t *ia = NULL;
   if (!sw_if)
     {
-      clib_warning ("got NULL sw_if");
+      vlib_log_err (bum->log_class,
+                   "got NULL sw_if when getting interface by index %u",
+                   sw_if_index);
       return VNET_API_ERROR_INVALID_SW_IF_INDEX;
     }
   if (ip46_address_is_ip4 (local_addr))
     {
       if (!ip46_address_is_ip4 (peer_addr))
        {
-         clib_warning ("IP family mismatch");
+         vlib_log_err (bum->log_class,
+                       "IP family mismatch (local is ipv4, peer is ipv6)");
          return VNET_API_ERROR_INVALID_ARGUMENT;
        }
       ip4_main_t *im = &ip4_main;
@@ -555,7 +564,8 @@ bfd_udp_validate_api_input (u32 sw_if_index,
     {
       if (ip46_address_is_ip4 (peer_addr))
        {
-         clib_warning ("IP family mismatch");
+         vlib_log_err (bum->log_class,
+                       "IP family mismatch (local is ipv6, peer is ipv4)");
          return VNET_API_ERROR_INVALID_ARGUMENT;
        }
       ip6_main_t *im = &ip6_main;
@@ -577,7 +587,10 @@ bfd_udp_validate_api_input (u32 sw_if_index,
 
   if (!local_ip_valid)
     {
-      clib_warning ("address not found on interface");
+      vlib_log_err (bum->log_class,
+                   "local address %U not found on interface with index %u",
+                   format_ip46_address, IP46_TYPE_ANY, local_addr,
+                   sw_if_index);
       return VNET_API_ERROR_ADDRESS_NOT_FOUND_FOR_INTERFACE;
     }
 
@@ -604,10 +617,11 @@ bfd_udp_find_session_by_api_input (u32 sw_if_index,
        }
       else
        {
-         clib_warning
-           ("BFD session not found (sw_if_index=%u, local=%U, peer=%U",
-            sw_if_index, format_ip46_address, local_addr, IP46_TYPE_ANY,
-            format_ip46_address, peer_addr, IP46_TYPE_ANY);
+         vlib_log_err (bum->log_class,
+                       "BFD session not found, sw_if_index=%u, local=%U, peer=%U",
+                       sw_if_index, format_ip46_address, local_addr,
+                       IP46_TYPE_ANY, format_ip46_address, peer_addr,
+                       IP46_TYPE_ANY);
          return VNET_API_ERROR_BFD_ENOENT;
        }
     }
@@ -620,6 +634,7 @@ bfd_api_verify_common (u32 sw_if_index, u32 desired_min_tx_usec,
                       const ip46_address_t * local_addr,
                       const ip46_address_t * peer_addr)
 {
+  bfd_udp_main_t *bum = &bfd_udp_main;
   vnet_api_error_t rv =
     bfd_udp_validate_api_input (sw_if_index, local_addr, peer_addr);
   if (rv)
@@ -628,12 +643,12 @@ bfd_api_verify_common (u32 sw_if_index, u32 desired_min_tx_usec,
     }
   if (detect_mult < 1)
     {
-      clib_warning ("detect_mult < 1");
+      vlib_log_err (bum->log_class, "detect_mult < 1");
       return VNET_API_ERROR_INVALID_ARGUMENT;
     }
   if (desired_min_tx_usec < 1)
     {
-      clib_warning ("desired_min_tx_usec < 1");
+      vlib_log_err (bum->log_class, "desired_min_tx_usec < 1");
       return VNET_API_ERROR_INVALID_ARGUMENT;
     }
   return 0;
@@ -675,7 +690,8 @@ bfd_udp_add_session (u32 sw_if_index, const ip46_address_t * local_addr,
       rv = bfd_auth_activate (bs, conf_key_id, bfd_key_id,
                              0 /* is not delayed */ );
 #else
-      clib_warning ("SSL missing, cannot add authenticated BFD session");
+      vlib_log_err (bfd_udp_main.log_class,
+                   "SSL missing, cannot add authenticated BFD session");
       rv = VNET_API_ERROR_BFD_NOTSUPP;
 #endif
       if (rv)
@@ -763,7 +779,8 @@ bfd_udp_auth_activate (u32 sw_if_index,
     }
   return bfd_auth_activate (bs, conf_key_id, key_id, is_delayed);
 #else
-  clib_warning ("SSL missing, cannot activate BFD authentication");
+  vlib_log_err (bfd_udp_main->log_class,
+               "SSL missing, cannot activate BFD authentication");
   return VNET_API_ERROR_BFD_NOTSUPP;
 #endif
 }
@@ -1443,6 +1460,7 @@ static clib_error_t *
 bfd_udp_sw_if_add_del (vnet_main_t * vnm, u32 sw_if_index, u32 is_create)
 {
   bfd_session_t **to_be_freed = NULL;
+  bfd_udp_main_t *bum = &bfd_udp_main;
   BFD_DBG ("sw_if_add_del called, sw_if_index=%u, is_create=%u", sw_if_index,
           is_create);
   if (!is_create)
@@ -1463,8 +1481,9 @@ bfd_udp_sw_if_add_del (vnet_main_t * vnm, u32 sw_if_index, u32 is_create)
   bfd_session_t **bs;
   vec_foreach (bs, to_be_freed)
   {
-    clib_warning ("removal of sw_if_index=%u forces removal of bfd session "
-                 "with bs_idx=%u", sw_if_index, (*bs)->bs_idx);
+    vlib_log_notice (bum->log_class,
+                    "removal of sw_if_index=%u forces removal of bfd session "
+                    "with bs_idx=%u", sw_if_index, (*bs)->bs_idx);
     bfd_session_set_flags (*bs, 0);
     bfd_udp_del_session_internal (*bs);
   }
@@ -1502,6 +1521,8 @@ bfd_udp_init (vlib_main_t * vm)
   ASSERT (node);
   bfd_udp_main.ip6_rewrite_idx = node->index;
 
+  bfd_udp_main.log_class = vlib_log_register_class ("bfd", "udp");
+  vlib_log_debug (bfd_udp_main.log_class, "initialized");
   return 0;
 }
 
index 8005b34..7cffaaf 100644 (file)
@@ -31,6 +31,7 @@
 #include <linux/rtnetlink.h>
 
 #include <vlib/vlib.h>
+#include <vlib/log.h>
 #include <vlib/unix/unix.h>
 #include <vnet/ethernet/ethernet.h>
 #include <vnet/ip/ip4_packet.h>
@@ -519,11 +520,19 @@ tap_dump_ifs (tap_interface_details_t ** out_tapids)
   return 0;
 }
 
+#define vlib_log_info(...) vlib_log(VLIB_LOG_LEVEL_INFO, __VA_ARGS__)
+
 static clib_error_t *
 tap_init (vlib_main_t * vm)
 {
   tap_main_t *tm = &tap_main;
+  clib_error_t *error;
+  error = vlib_call_init_function (vm, vlib_log_init);
+  if (error)
+    return error;
   tm->dev_instance_by_interface_id = hash_create (0, sizeof (uword));
+  tm->log_default = vlib_log_register_class ("tap", 0);
+  vlib_log_info (tm->log_default, "initialized");
   return 0;
 }
 
index 98af0d8..6e46302 100644 (file)
@@ -69,6 +69,9 @@ typedef struct
 {
   u32 last_used_interface_id;
   uword *dev_instance_by_interface_id;
+
+  /* logging */
+  vlib_log_class_t log_default;
 } tap_main_t;
 
 void tap_create_if (vlib_main_t * vm, tap_create_if_args_t * args);
index 9c9351e..9732145 100644 (file)
@@ -454,6 +454,7 @@ class VppTestCase(unittest.TestCase):
             self.logger.info(self.vapi.ppcli("show hardware"))
             self.logger.info(self.vapi.ppcli("show error"))
             self.logger.info(self.vapi.ppcli("show run"))
+            self.logger.info(self.vapi.ppcli("show log"))
             self.registry.remove_vpp_config(self.logger)
             # Save/Dump VPP api trace log
             api_trace = "vpp_api_trace.%s.log" % self._testMethodName
index 8fb00cf..3b36f55 100644 (file)
@@ -52,7 +52,7 @@ class BFDAPITestCase(VppTestCase):
     @classmethod
     def setUpClass(cls):
         super(BFDAPITestCase, cls).setUpClass()
-
+        cls.vapi.cli("set log class bfd level debug")
         try:
             cls.create_pg_interfaces(range(2))
             for i in cls.pg_interfaces:
@@ -626,6 +626,7 @@ class BFD4TestCase(VppTestCase):
     @classmethod
     def setUpClass(cls):
         super(BFD4TestCase, cls).setUpClass()
+        cls.vapi.cli("set log class bfd level debug")
         try:
             cls.create_pg_interfaces([0])
             cls.create_loopback_interfaces([0])
@@ -1431,6 +1432,7 @@ class BFD6TestCase(VppTestCase):
     @classmethod
     def setUpClass(cls):
         super(BFD6TestCase, cls).setUpClass()
+        cls.vapi.cli("set log class bfd level debug")
         try:
             cls.create_pg_interfaces([0])
             cls.pg0.config_ip6()
@@ -1742,6 +1744,7 @@ class BFDSHA1TestCase(VppTestCase):
     @classmethod
     def setUpClass(cls):
         super(BFDSHA1TestCase, cls).setUpClass()
+        cls.vapi.cli("set log class bfd level debug")
         try:
             cls.create_pg_interfaces([0])
             cls.pg0.config_ip4()
@@ -1974,6 +1977,7 @@ class BFDAuthOnOffTestCase(VppTestCase):
     @classmethod
     def setUpClass(cls):
         super(BFDAuthOnOffTestCase, cls).setUpClass()
+        cls.vapi.cli("set log class bfd level debug")
         try:
             cls.create_pg_interfaces([0])
             cls.pg0.config_ip4()
@@ -2179,7 +2183,7 @@ class BFDCLITestCase(VppTestCase):
     @classmethod
     def setUpClass(cls):
         super(BFDCLITestCase, cls).setUpClass()
-
+        cls.vapi.cli("set log class bfd level debug")
         try:
             cls.create_pg_interfaces((0,))
             cls.pg0.config_ip4()