summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorDamjan Marion <damarion@cisco.com>2018-01-21 06:44:18 -0800
committerDamjan Marion <dmarion.lists@gmail.com>2018-04-17 23:38:05 +0000
commit07a38572caa2c2d2d8658420a7c3df8e7f9d0e74 (patch)
tree1410e662936aac8972f7f1f25e56429f443791d5
parente821ab100aea2fb3f740a98650eb750ff5911c49 (diff)
Add logging support
Change-Id: Ieac9cf50156dbbb4962411e900d59256441915ef Signed-off-by: Damjan Marion <damarion@cisco.com> Signed-off-by: Klement Sekera <ksekera@cisco.com>
-rw-r--r--src/vlib.am2
-rw-r--r--src/vlib/log.c673
-rw-r--r--src/vlib/log.h63
-rw-r--r--src/vlib/vlib.h1
-rw-r--r--src/vnet/bfd/bfd_main.c118
-rw-r--r--src/vnet/bfd/bfd_main.h7
-rw-r--r--src/vnet/bfd/bfd_udp.c51
-rw-r--r--src/vnet/devices/tap/tap.c9
-rw-r--r--src/vnet/devices/tap/tap.h3
-rw-r--r--test/framework.py1
-rw-r--r--test/test_bfd.py8
11 files changed, 882 insertions, 54 deletions
diff --git a/src/vlib.am b/src/vlib.am
index 405bed95fba..55d6e65c2b9 100644
--- a/src/vlib.am
+++ b/src/vlib.am
@@ -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
index 00000000000..dd2ecf2c110
--- /dev/null
+++ b/src/vlib/log.c
@@ -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
index 00000000000..90862dcc9ec
--- /dev/null
+++ b/src/vlib/log.h
@@ -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:
+ */
diff --git a/src/vlib/vlib.h b/src/vlib/vlib.h
index eed5c5bc243..21c5b2aa814 100644
--- a/src/vlib/vlib.h
+++ b/src/vlib/vlib.h
@@ -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>
diff --git a/src/vnet/bfd/bfd_main.c b/src/vnet/bfd/bfd_main.c
index 668a44e89e5..28ece316438 100644
--- a/src/vnet/bfd/bfd_main.c
+++ b/src/vnet/bfd/bfd_main.c
@@ -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
}
diff --git a/src/vnet/bfd/bfd_main.h b/src/vnet/bfd/bfd_main.h
index 93adac3dc8d..9e2a12e1f9b 100644
--- a/src/vnet/bfd/bfd_main.h
+++ b/src/vnet/bfd/bfd_main.h
@@ -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;
- /** A 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);
diff --git a/src/vnet/bfd/bfd_udp.c b/src/vnet/bfd/bfd_udp.c
index 533d98d6865..5464ce91f57 100644
--- a/src/vnet/bfd/bfd_udp.c
+++ b/src/vnet/bfd/bfd_udp.c
@@ -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;
}
diff --git a/src/vnet/devices/tap/tap.c b/src/vnet/devices/tap/tap.c
index 8005b347391..7cffaafb1e2 100644
--- a/src/vnet/devices/tap/tap.c
+++ b/src/vnet/devices/tap/tap.c
@@ -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;
}
diff --git a/src/vnet/devices/tap/tap.h b/src/vnet/devices/tap/tap.h
index 98af0d8f3ab..6e46302770d 100644
--- a/src/vnet/devices/tap/tap.h
+++ b/src/vnet/devices/tap/tap.h
@@ -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);
diff --git a/test/framework.py b/test/framework.py
index 9c9351e4dac..973214503a8 100644
--- a/test/framework.py
+++ b/test/framework.py
@@ -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
diff --git a/test/test_bfd.py b/test/test_bfd.py
index 8fb00cf348a..3b36f558a7e 100644
--- a/test/test_bfd.py
+++ b/test/test_bfd.py
@@ -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()
) { s = ooo_segment_alloc (f, offset_pos, length); f->ooos_list_head = s - f->ooo_segments; f->ooos_newest = f->ooos_list_head; return; } /* Find first segment that starts after new segment */ s = pool_elt_at_index (f->ooo_segments, f->ooos_list_head); while (s->next != OOO_SEGMENT_INVALID_INDEX && f_pos_lt (s->start, offset_pos)) s = pool_elt_at_index (f->ooo_segments, s->next); /* If we have a previous and we overlap it, use it as starting point */ prev = ooo_segment_prev (f, s); if (prev && f_pos_leq (offset_pos, ooo_segment_end_pos (prev))) { s = prev; s_end_pos = ooo_segment_end_pos (s); /* Since we have previous, offset start position cannot be smaller * than prev->start. Check tail */ ASSERT (f_pos_lt (s->start, offset_pos)); goto check_tail; } s_index = s - f->ooo_segments; s_end_pos = ooo_segment_end_pos (s); /* No overlap, add before current segment */ if (f_pos_lt (offset_end_pos, s->start)) { new_s = ooo_segment_alloc (f, offset_pos, length); new_index = new_s - f->ooo_segments; /* Pool might've moved, get segment again */ s = pool_elt_at_index (f->ooo_segments, s_index); if (s->prev != OOO_SEGMENT_INVALID_INDEX) { new_s->prev = s->prev; prev = pool_elt_at_index (f->ooo_segments, new_s->prev); prev->next = new_index; } else { /* New head */ f->ooos_list_head = new_index; } new_s->next = s_index; s->prev = new_index; f->ooos_newest = new_index; return; } /* No overlap, add after current segment */ else if (f_pos_gt (offset_pos, s_end_pos)) { new_s = ooo_segment_alloc (f, offset_pos, length); new_index = new_s - f->ooo_segments; /* Pool might've moved, get segment again */ s = pool_elt_at_index (f->ooo_segments, s_index); /* Needs to be last */ ASSERT (s->next == OOO_SEGMENT_INVALID_INDEX); new_s->prev = s_index; s->next = new_index; f->ooos_newest = new_index; return; } /* * Merge needed */ /* Merge at head */ if (f_pos_lt (offset_pos, s->start)) { s->start = offset_pos; s->length = s_end_pos - s->start; f->ooos_newest = s - f->ooo_segments; } check_tail: /* Overlapping tail */ if (f_pos_gt (offset_end_pos, s_end_pos)) { s->length = offset_end_pos - s->start; /* Remove the completely overlapped segments in the tail */ it = ooo_segment_next (f, s); while (it && f_pos_leq (ooo_segment_end_pos (it), offset_end_pos)) { next = ooo_segment_next (f, it); ooo_segment_free (f, it - f->ooo_segments); it = next; } /* If partial overlap with last, merge */ if (it && f_pos_leq (it->start, offset_end_pos)) { s->length = ooo_segment_end_pos (it) - s->start; ooo_segment_free (f, it - f->ooo_segments); } f->ooos_newest = s - f->ooo_segments; } } /** * Removes segments that can now be enqueued because the fifo's tail has * advanced. Returns the number of bytes added to tail. */ static int ooo_segment_try_collect (svm_fifo_t * f, u32 n_bytes_enqueued, u32 * tail) { u32 s_index, bytes = 0; ooo_segment_t *s; i32 diff; s = pool_elt_at_index (f->ooo_segments, f->ooos_list_head); diff = *tail - s->start; ASSERT (diff != n_bytes_enqueued); if (diff > n_bytes_enqueued) return 0; /* If last tail update overlaps one/multiple ooo segments, remove them */ while (0 <= diff && diff < n_bytes_enqueued) { s_index = s - f->ooo_segments; /* Segment end is beyond the tail. Advance tail and remove segment */ if (s->length > diff) { bytes = s->length - diff; *tail = *tail + bytes; ooo_segment_free (f, s_index); break; } /* If we have next go on */ if (s->next != OOO_SEGMENT_INVALID_INDEX) { s = pool_elt_at_index (f->ooo_segments, s->next); diff = *tail - s->start; ooo_segment_free (f, s_index); } /* End of search */ else { ooo_segment_free (f, s_index); break; } } ASSERT (bytes <= f->size); return bytes; } __clib_unused static ooo_segment_t * ooo_segment_last (svm_fifo_t * f) { ooo_segment_t *s; if (f->ooos_list_head == OOO_SEGMENT_INVALID_INDEX) return 0; s = svm_fifo_first_ooo_segment (f); while (s->next != OOO_SEGMENT_INVALID_INDEX) s = pool_elt_at_index (f->ooo_segments, s->next); return s; } void svm_fifo_init (svm_fifo_t * f, u32 size) { svm_fifo_chunk_t *c, *prev; u32 min_alloc; f->size = size; f->ooos_list_head = OOO_SEGMENT_INVALID_INDEX; f->segment_index = SVM_FIFO_INVALID_INDEX; f->refcnt = 1; f->head = f->tail = f->flags = 0; f->head_chunk = f->tail_chunk = f->start_chunk; f->ooo_deq = f->ooo_enq = 0; min_alloc = size > 32 << 10 ? size >> 3 : 4096; min_alloc = clib_min (min_alloc, 64 << 10); f->min_alloc = min_alloc; /* * Initialize chunks */ f->start_chunk->start_byte = 0; prev = f->start_chunk; c = prev->next; while (c) { c->start_byte = prev->start_byte + prev->length; prev = c; c = c->next; } } void svm_fifo_init_ooo_lookup (svm_fifo_t * f, u8 ooo_type) { if (ooo_type == 0) { ASSERT (!rb_tree_is_init (&f->ooo_enq_lookup)); rb_tree_init (&f->ooo_enq_lookup); } else { ASSERT (!rb_tree_is_init (&f->ooo_deq_lookup)); rb_tree_init (&f->ooo_deq_lookup); } } /** * Creates a fifo in the current heap. Fails vs blow up the process */ svm_fifo_t * svm_fifo_alloc (u32 data_size_in_bytes) { u32 rounded_data_size; svm_fifo_chunk_t *c; svm_fifo_t *f; f = clib_mem_alloc_aligned_or_null (sizeof (*f), CLIB_CACHE_LINE_BYTES); if (f == 0) return 0; clib_memset (f, 0, sizeof (*f)); /* always round fifo data size to the next highest power-of-two */ rounded_data_size = (1 << (max_log2 (data_size_in_bytes))); c = clib_mem_alloc_aligned_or_null (sizeof (*c) + rounded_data_size, CLIB_CACHE_LINE_BYTES); if (!c) { clib_mem_free (f); return 0; } clib_memset (c, 0, sizeof (*c)); c->start_byte = 0; c->length = data_size_in_bytes; c->enq_rb_index = RBTREE_TNIL_INDEX; c->deq_rb_index = RBTREE_TNIL_INDEX; f->start_chunk = f->end_chunk = c; return f; } /** * Creates a fifo chunk in the current heap */ svm_fifo_chunk_t * svm_fifo_chunk_alloc (u32 size) { svm_fifo_chunk_t *c; u32 rounded_size; /* round chunk size to the next highest power-of-two */ rounded_size = (1 << (max_log2 (size))); c = clib_mem_alloc_aligned_or_null (sizeof (*c) + rounded_size, CLIB_CACHE_LINE_BYTES); if (c == 0) return 0; clib_memset (c, 0, sizeof (*c)); c->length = rounded_size; return c; } /** * Find chunk for given byte position * * @param f fifo * @param pos normalized position in fifo * * @return chunk that includes given position or 0 */ static svm_fifo_chunk_t * svm_fifo_find_chunk (svm_fifo_t * f, u32 pos) { svm_fifo_chunk_t *c; c = f->start_chunk; while (c && !f_chunk_includes_pos (c, pos)) c = c->next; return c; } static svm_fifo_chunk_t * svm_fifo_find_next_chunk (svm_fifo_t * f, svm_fifo_chunk_t * start, u32 pos) { svm_fifo_chunk_t *c; ASSERT (start != 0); c = start; while (c && !f_chunk_includes_pos (c, pos)) c = c->next; return c; } u32 svm_fifo_max_read_chunk (svm_fifo_t * f) { u32 head, tail, end_chunk; f_load_head_tail_cons (f, &head, &tail); ASSERT (!f->head_chunk || f_chunk_includes_pos (f->head_chunk, head)); if (!f->head_chunk) { f->head_chunk = svm_fifo_find_chunk (f, head); if (PREDICT_FALSE (!f->head_chunk)) return 0; } end_chunk = f_chunk_end (f->head_chunk); return f_pos_lt (end_chunk, tail) ? end_chunk - head : tail - head; } u32 svm_fifo_max_write_chunk (svm_fifo_t * f) { u32 head, tail; f_load_head_tail_prod (f, &head, &tail); ASSERT (!f->tail_chunk || f_chunk_includes_pos (f->tail_chunk, tail)); return f->tail_chunk ? f_chunk_end (f->tail_chunk) - tail : 0; } static rb_node_t * f_find_node_rbtree (rb_tree_t * rt, u32 pos) { rb_node_t *cur, *prev; cur = rb_node (rt, rt->root); if (PREDICT_FALSE (rb_node_is_tnil (rt, cur))) return 0; while (pos != cur->key) { prev = cur; if (f_pos_lt (pos, cur->key)) { cur = rb_node_left (rt, cur); if (rb_node_is_tnil (rt, cur)) { cur = rb_tree_predecessor (rt, prev); break; } } else { cur = rb_node_right (rt, cur); if (rb_node_is_tnil (rt, cur)) { cur = prev; break; } } } if (rb_node_is_tnil (rt, cur)) return 0; return cur; } static svm_fifo_chunk_t * f_find_chunk_rbtree (rb_tree_t * rt, u32 pos) { svm_fifo_chunk_t *c; rb_node_t *n; if (!rb_tree_is_init (rt)) return 0; n = f_find_node_rbtree (rt, pos); if (!n) return 0; c = uword_to_pointer (n->opaque, svm_fifo_chunk_t *); if (f_chunk_includes_pos (c, pos)) return c; return 0; } static void f_update_ooo_enq (svm_fifo_t * f, u32 start_pos, u32 end_pos) { rb_tree_t *rt = &f->ooo_enq_lookup; svm_fifo_chunk_t *c; rb_node_t *cur; /* Use linear search if rbtree is not initialized */ if (PREDICT_FALSE (!rb_tree_is_init (rt))) { f->ooo_enq = svm_fifo_find_next_chunk (f, f->tail_chunk, start_pos); return; } if (rt->root == RBTREE_TNIL_INDEX) { c = f->tail_chunk; ASSERT (c->enq_rb_index == RBTREE_TNIL_INDEX); c->enq_rb_index = rb_tree_add_custom (rt, c->start_byte, pointer_to_uword (c), f_pos_lt); } else { cur = f_find_node_rbtree (rt, start_pos); c = uword_to_pointer (cur->opaque, svm_fifo_chunk_t *); ASSERT (f_pos_leq (c->start_byte, start_pos)); } if (f_chunk_includes_pos (c, start_pos)) f->ooo_enq = c; if (f_chunk_includes_pos (c, end_pos)) return; do { c = c->next; if (!c || c->enq_rb_index != RBTREE_TNIL_INDEX) break; c->enq_rb_index = rb_tree_add_custom (rt, c->start_byte, pointer_to_uword (c), f_pos_lt); if (f_chunk_includes_pos (c, start_pos)) f->ooo_enq = c; } while (!f_chunk_includes_pos (c, end_pos)); } static void f_update_ooo_deq (svm_fifo_t * f, u32 start_pos, u32 end_pos) { rb_tree_t *rt = &f->ooo_deq_lookup; rb_node_t *cur; svm_fifo_chunk_t *c; /* Use linear search if rbtree is not initialized */ if (PREDICT_FALSE (!rb_tree_is_init (rt))) { f->ooo_deq = svm_fifo_find_chunk (f, start_pos); return; } if (rt->root == RBTREE_TNIL_INDEX) { c = f->start_chunk; ASSERT (c->deq_rb_index == RBTREE_TNIL_INDEX); c->deq_rb_index = rb_tree_add_custom (rt, c->start_byte, pointer_to_uword (c), f_pos_lt); } else { cur = f_find_node_rbtree (rt, start_pos); c = uword_to_pointer (cur->opaque, svm_fifo_chunk_t *); ASSERT (f_pos_leq (c->start_byte, start_pos)); } if (f_chunk_includes_pos (c, start_pos)) f->ooo_deq = c; if (f_chunk_includes_pos (c, end_pos)) return; do { c = c->next; if (!c || c->deq_rb_index != RBTREE_TNIL_INDEX) break; c->deq_rb_index = rb_tree_add_custom (rt, c->start_byte, pointer_to_uword (c), f_pos_lt); if (f_chunk_includes_pos (c, start_pos)) f->ooo_deq = c; } while (!f_chunk_includes_pos (c, end_pos)); } static svm_fifo_chunk_t * f_lookup_clear_enq_chunks (svm_fifo_t * f, svm_fifo_chunk_t * start, u32 end_pos) { rb_tree_t *rt = &f->ooo_enq_lookup; svm_fifo_chunk_t *c; rb_node_t *n; c = start; while (c && !f_chunk_includes_pos (c, end_pos)) { if (c->enq_rb_index != RBTREE_TNIL_INDEX) { n = rb_node (rt, c->enq_rb_index); rb_tree_del_node (rt, n); c->enq_rb_index = RBTREE_TNIL_INDEX; } c = c->next; } /* No ooo segments left, so make sure the current chunk * is not tracked in the enq rbtree */ if (f->ooos_list_head == OOO_SEGMENT_INVALID_INDEX && c && c->enq_rb_index != RBTREE_TNIL_INDEX) { n = rb_node (rt, c->enq_rb_index); rb_tree_del_node (rt, n); c->enq_rb_index = RBTREE_TNIL_INDEX; } return c; } static svm_fifo_chunk_t * f_lookup_clear_deq_chunks (svm_fifo_t * f, svm_fifo_chunk_t * start, u32 end_pos) { rb_tree_t *rt = &f->ooo_deq_lookup; svm_fifo_chunk_t *c; rb_node_t *n; c = start; while (c && !f_chunk_includes_pos (c, end_pos)) { if (c->deq_rb_index != RBTREE_TNIL_INDEX) { n = rb_node (rt, c->deq_rb_index); rb_tree_del_node (rt, n); c->deq_rb_index = RBTREE_TNIL_INDEX; } c = c->next; } return c; } void svm_fifo_free_chunk_lookup (svm_fifo_t * f) { rb_tree_free_nodes (&f->ooo_enq_lookup); rb_tree_free_nodes (&f->ooo_deq_lookup); } void svm_fifo_free (svm_fifo_t * f) { ASSERT (f->refcnt > 0); if (--f->refcnt == 0) { /* ooo data is not allocated on segment heap */ svm_fifo_free_chunk_lookup (f); clib_mem_free (f); } } void svm_fifo_overwrite_head (svm_fifo_t * f, u8 * src, u32 len) { u32 n_chunk; u32 head, tail, head_idx; svm_fifo_chunk_t *c; ASSERT (len <= f->size); f_load_head_tail_cons (f, &head, &tail); if (!f->head_chunk) f->head_chunk = svm_fifo_find_chunk (f, head); c = f->head_chunk; head_idx = head - c->start_byte; n_chunk = c->length - head_idx; if (len <= n_chunk) clib_memcpy_fast (&c->data[head_idx], src, len); else { ASSERT (len - n_chunk <= c->next->length); clib_memcpy_fast (&c->data[head_idx], src, n_chunk); clib_memcpy_fast (&c->next->data[0], src + n_chunk, len - n_chunk); } } static int f_try_chunk_alloc (svm_fifo_t * f, u32 head, u32 tail, u32 len) { svm_fifo_chunk_t *c, *cur, *prev; u32 alloc_size, free_alloced; free_alloced = f_chunk_end (f->end_chunk) - tail; alloc_size = clib_min (f->min_alloc, f->size - (tail - head)); alloc_size = clib_max (alloc_size, len - free_alloced); c = fsh_alloc_chunk (f->fs_hdr, f->slice_index, alloc_size); if (PREDICT_FALSE (!c)) return -1; cur = c; prev = f->end_chunk; while (cur) { cur->start_byte = prev->start_byte + prev->length; cur->enq_rb_index = RBTREE_TNIL_INDEX; cur->deq_rb_index = RBTREE_TNIL_INDEX; prev = cur; cur = cur->next; } prev->next = 0; f->end_chunk->next = c; f->end_chunk = prev; if (!f->tail_chunk) f->tail_chunk = c; return 0; } int svm_fifo_enqueue (svm_fifo_t * f, u32 len, const u8 * src) { u32 tail, head, free_count; svm_fifo_chunk_t *old_tail_c; f->ooos_newest = OOO_SEGMENT_INVALID_INDEX; f_load_head_tail_prod (f, &head, &tail); /* free space in fifo can only increase during enqueue: SPSC */ free_count = f_free_count (f, head, tail); if (PREDICT_FALSE (free_count == 0)) return SVM_FIFO_EFULL; /* number of bytes we're going to copy */ len = clib_min (free_count, len); if (f_pos_gt (tail + len, f_chunk_end (f->end_chunk))) { if (PREDICT_FALSE (f_try_chunk_alloc (f, head, tail, len))) { len = f_chunk_end (f->end_chunk) - tail; if (!len) return SVM_FIFO_EGROW; } } old_tail_c = f->tail_chunk; svm_fifo_copy_to_chunk (f, f->tail_chunk, tail, src, len, &f->tail_chunk); tail = tail + len; svm_fifo_trace_add (f, head, len, 2); /* collect out-of-order segments */ if (PREDICT_FALSE (f->ooos_list_head != OOO_SEGMENT_INVALID_INDEX)) { len += ooo_segment_try_collect (f, len, &tail); /* Tail chunk might've changed even if nothing was collected */ f->tail_chunk = f_lookup_clear_enq_chunks (f, old_tail_c, tail); f->ooo_enq = 0; } /* store-rel: producer owned index (paired with load-acq in consumer) */ clib_atomic_store_rel_n (&f->tail, tail); return len; } /** * Enqueue a future segment. * * Two choices: either copies the entire segment, or copies nothing * Returns 0 of the entire segment was copied * Returns -1 if none of the segment was copied due to lack of space */ int svm_fifo_enqueue_with_offset (svm_fifo_t * f, u32 offset, u32 len, u8 * src) { u32 tail, head, free_count, enq_pos; f_load_head_tail_prod (f, &head, &tail); /* free space in fifo can only increase during enqueue: SPSC */ free_count = f_free_count (f, head, tail); f->ooos_newest = OOO_SEGMENT_INVALID_INDEX; /* will this request fit? */ if ((len + offset) > free_count) return SVM_FIFO_EFULL; enq_pos = tail + offset; if (f_pos_gt (enq_pos + len, f_chunk_end (f->end_chunk))) { if (PREDICT_FALSE (f_try_chunk_alloc (f, head, tail, offset + len))) return SVM_FIFO_EGROW; } svm_fifo_trace_add (f, offset, len, 1); ooo_segment_add (f, offset, head, tail, len); if (!f->ooo_enq || !f_chunk_includes_pos (f->ooo_enq, enq_pos)) f_update_ooo_enq (f, enq_pos, enq_pos + len); svm_fifo_copy_to_chunk (f, f->ooo_enq, enq_pos, src, len, &f->ooo_enq); return 0; } /** * Advance tail */ void svm_fifo_enqueue_nocopy (svm_fifo_t * f, u32 len) { u32 tail; ASSERT (len <= svm_fifo_max_enqueue_prod (f)); /* load-relaxed: producer owned index */ tail = f->tail; tail = tail + len; if (rb_tree_is_init (&f->ooo_enq_lookup)) { f->tail_chunk = f_lookup_clear_enq_chunks (f, f->tail_chunk, tail); f->ooo_enq = 0; } else { f->tail_chunk = svm_fifo_find_next_chunk (f, f->tail_chunk, tail); } /* store-rel: producer owned index (paired with load-acq in consumer) */ clib_atomic_store_rel_n (&f->tail, tail); } always_inline svm_fifo_chunk_t * f_unlink_chunks (svm_fifo_t * f, u32 end_pos, u8 maybe_ooo) { svm_fifo_chunk_t *start, *prev = 0, *c; rb_tree_t *rt; rb_node_t *n; ASSERT (!f_chunk_includes_pos (f->start_chunk, end_pos)); if (maybe_ooo) rt = &f->ooo_deq_lookup; c = f->start_chunk; do { if (maybe_ooo && c->deq_rb_index != RBTREE_TNIL_INDEX) { n = rb_node (rt, c->deq_rb_index); ASSERT (n == f_find_node_rbtree (rt, c->start_byte)); rb_tree_del_node (rt, n); c->deq_rb_index = RBTREE_TNIL_INDEX; } if (!c->next) break; prev = c; c = c->next; } while (!f_chunk_includes_pos (c, end_pos)); if (maybe_ooo) { if (f->ooo_deq && f_pos_lt (f->ooo_deq->start_byte, f_chunk_end (c))) f->ooo_deq = 0; } else { if (PREDICT_FALSE (f->ooo_deq != 0)) f->ooo_deq = 0; } /* Avoid unlinking the last chunk */ if (!prev) return 0; prev->next = 0; start = f->start_chunk; f->start_chunk = c; return start; } int svm_fifo_dequeue (svm_fifo_t * f, u32 len, u8 * dst) { u32 tail, head, cursize; f_load_head_tail_cons (f, &head, &tail); /* current size of fifo can only increase during dequeue: SPSC */ cursize = f_cursize (f, head, tail); if (PREDICT_FALSE (cursize == 0)) return SVM_FIFO_EEMPTY; len = clib_min (cursize, len); if (!f->head_chunk) f->head_chunk = svm_fifo_find_chunk (f, head); svm_fifo_copy_from_chunk (f, f->head_chunk, head, dst, len, &f->head_chunk); head = head + len; if (f_pos_geq (head, f_chunk_end (f->start_chunk))) fsh_collect_chunks (f->fs_hdr, f->slice_index, f_unlink_chunks (f, head, 0)); /* store-rel: consumer owned index (paired with load-acq in producer) */ clib_atomic_store_rel_n (&f->head, head); return len; } int svm_fifo_peek (svm_fifo_t * f, u32 offset, u32 len, u8 * dst) { u32 tail, head, cursize, head_idx; f_load_head_tail_cons (f, &head, &tail); /* current size of fifo can only increase during peek: SPSC */ cursize = f_cursize (f, head, tail); if (PREDICT_FALSE (cursize < offset)) return SVM_FIFO_EEMPTY; len = clib_min (cursize - offset, len); head_idx = head + offset; if (!f->ooo_deq || !f_chunk_includes_pos (f->ooo_deq, head_idx)) f_update_ooo_deq (f, head_idx, head_idx + len); svm_fifo_copy_from_chunk (f, f->ooo_deq, head_idx, dst, len, &f->ooo_deq); return len; } int svm_fifo_dequeue_drop (svm_fifo_t * f, u32 len) { u32 total_drop_bytes, tail, head, cursize; f_load_head_tail_cons (f, &head, &tail); /* number of bytes available */ cursize = f_cursize (f, head, tail); if (PREDICT_FALSE (cursize == 0)) return SVM_FIFO_EEMPTY; /* number of bytes we're going to drop */ total_drop_bytes = clib_min (cursize, len); svm_fifo_trace_add (f, tail, total_drop_bytes, 3); /* move head */ head = head + total_drop_bytes; if (f_pos_geq (head, f_chunk_end (f->start_chunk))) { fsh_collect_chunks (f->fs_hdr, f->slice_index, f_unlink_chunks (f, head, 1)); f->head_chunk = f_chunk_includes_pos (f->start_chunk, head) ? f->start_chunk : 0; } /* store-rel: consumer owned index (paired with load-acq in producer) */ clib_atomic_store_rel_n (&f->head, head); return total_drop_bytes; } /** * Drop all data from fifo * */ void svm_fifo_dequeue_drop_all (svm_fifo_t * f) { u32 head, tail; f_load_head_tail_all_acq (f, &head, &tail); if (!f->head_chunk || !f_chunk_includes_pos (f->head_chunk, head)) f->head_chunk = svm_fifo_find_chunk (f, head); f->head_chunk = f_lookup_clear_deq_chunks (f, f->head_chunk, tail); if (f_pos_geq (tail, f_chunk_end (f->start_chunk))) fsh_collect_chunks (f->fs_hdr, f->slice_index, f_unlink_chunks (f, tail, 0)); /* store-rel: consumer owned index (paired with load-acq in producer) */ clib_atomic_store_rel_n (&f->head, tail); } int svm_fifo_fill_chunk_list (svm_fifo_t * f) { u32 head, tail; f_load_head_tail_prod (f, &head, &tail); if (f_chunk_end (f->end_chunk) - head >= f->size) return 0; if (f_try_chunk_alloc (f, head, tail, f->size - (tail - head))) return SVM_FIFO_EGROW; return 0; } int svm_fifo_segments (svm_fifo_t * f, svm_fifo_seg_t * fs) { u32 cursize, head, tail, head_idx; f_load_head_tail_cons (f, &head, &tail); /* consumer function, cursize can only increase while we're working */ cursize = f_cursize (f, head, tail); if (PREDICT_FALSE (cursize == 0)) return SVM_FIFO_EEMPTY; head_idx = head; if (tail < head) { fs[0].len = f->size - head_idx; fs[0].data = f->head_chunk->data + head_idx; fs[1].len = cursize - fs[0].len; fs[1].data = f->head_chunk->data; } else { fs[0].len = cursize; fs[0].data = f->head_chunk->data + head_idx; fs[1].len = 0; fs[1].data = 0; } return cursize; } void svm_fifo_segments_free (svm_fifo_t * f, svm_fifo_seg_t * fs) { u32 head; /* consumer owned index */ head = f->head; ASSERT (fs[0].data == f->head_chunk->data + head); head = (head + fs[0].len + fs[1].len); /* store-rel: consumer owned index (paired with load-acq in producer) */ clib_atomic_store_rel_n (&f->head, head); } /** * Clones fifo * * Assumptions: * - no prod and cons are accessing either dest or src fifo * - fifo is not multi chunk */ void svm_fifo_clone (svm_fifo_t * df, svm_fifo_t * sf) { u32 head, tail; /* Support only single chunk clones for now */ ASSERT (svm_fifo_n_chunks (sf) == 1); clib_memcpy_fast (df->head_chunk->data, sf->head_chunk->data, sf->size); f_load_head_tail_all_acq (sf, &head, &tail); clib_atomic_store_rel_n (&df->head, head); clib_atomic_store_rel_n (&df->tail, tail); } u32 svm_fifo_n_ooo_segments (svm_fifo_t * f) { return pool_elts (f->ooo_segments); } ooo_segment_t * svm_fifo_first_ooo_segment (svm_fifo_t * f) { return pool_elt_at_index (f->ooo_segments, f->ooos_list_head); } /** * Set fifo pointers to requested offset */ void svm_fifo_init_pointers (svm_fifo_t * f, u32 head, u32 tail) { svm_fifo_chunk_t *c; clib_atomic_store_rel_n (&f->head, head); clib_atomic_store_rel_n (&f->tail, tail); c = svm_fifo_find_chunk (f, head); ASSERT (c != 0); f->head_chunk = f->ooo_deq = c; c = svm_fifo_find_chunk (f, tail); ASSERT (c != 0); f->tail_chunk = f->ooo_enq = c; } void svm_fifo_add_subscriber (svm_fifo_t * f, u8 subscriber) { if (f->n_subscribers >= SVM_FIFO_MAX_EVT_SUBSCRIBERS) return; f->subscribers[f->n_subscribers++] = subscriber; } void svm_fifo_del_subscriber (svm_fifo_t * f, u8 subscriber) { int i; for (i = 0; i < f->n_subscribers; i++) { if (f->subscribers[i] != subscriber) continue; f->subscribers[i] = f->subscribers[f->n_subscribers - 1]; f->n_subscribers--; break; } } u8 svm_fifo_is_sane (svm_fifo_t * f) { svm_fifo_chunk_t *tmp; if (f->head_chunk && !f_chunk_includes_pos (f->head_chunk, f->head)) return 0; if (f->tail_chunk && !f_chunk_includes_pos (f->tail_chunk, f->tail)) return 0; if (f->ooo_deq) { if (rb_tree_is_init (&f->ooo_deq_lookup)) { if (f_pos_lt (f->ooo_deq->start_byte, f->start_chunk->start_byte) || f_pos_gt (f->ooo_deq->start_byte, f_chunk_end (f->end_chunk))) return 0; tmp = f_find_chunk_rbtree (&f->ooo_deq_lookup, f->ooo_deq->start_byte); } else tmp = svm_fifo_find_chunk (f, f->ooo_deq->start_byte); if (tmp != f->ooo_deq) return 0; } if (f->ooo_enq) { if (rb_tree_is_init (&f->ooo_enq_lookup)) { if (f_pos_lt (f->ooo_enq->start_byte, f->start_chunk->start_byte) || f_pos_gt (f->ooo_enq->start_byte, f_chunk_end (f->end_chunk))) return 0; tmp = f_find_chunk_rbtree (&f->ooo_enq_lookup, f->ooo_enq->start_byte); } else { tmp = svm_fifo_find_next_chunk (f, f->tail_chunk, f->ooo_enq->start_byte); } if (tmp != f->ooo_enq) return 0; } if (f->start_chunk->next) { svm_fifo_chunk_t *c, *prev = 0, *tmp; u32 chunks_bytes = 0; c = f->start_chunk; do { tmp = svm_fifo_find_chunk (f, c->start_byte); if (tmp != c) return 0; if (prev && (prev->start_byte + prev->length != c->start_byte)) return 0; if (c->enq_rb_index != RBTREE_TNIL_INDEX) { tmp = f_find_chunk_rbtree (&f->ooo_enq_lookup, c->start_byte); if (tmp) { if (tmp != c) return 0; } } if (c->deq_rb_index != RBTREE_TNIL_INDEX) { tmp = f_find_chunk_rbtree (&f->ooo_deq_lookup, c->start_byte); if (tmp) { if (tmp != c) return 0; } } chunks_bytes += c->length; prev = c; c = c->next; } while (c); if (chunks_bytes < f->tail - f->head) return 0; } return 1; } u32 svm_fifo_n_chunks (svm_fifo_t * f) { svm_fifo_chunk_t *c; int n_chunks = 0; c = f->start_chunk; while (c) { n_chunks++; c = c->next; } return n_chunks; } u8 * format_ooo_segment (u8 * s, va_list * args) { svm_fifo_t __clib_unused *f = va_arg (*args, svm_fifo_t *); ooo_segment_t *seg = va_arg (*args, ooo_segment_t *); s = format (s, "[%u, %u], len %u, next %d, prev %d", seg->start, seg->start + seg->length, seg->length, seg->next, seg->prev); return s; } u8 * svm_fifo_dump_trace (u8 * s, svm_fifo_t * f) { #if SVM_FIFO_TRACE svm_fifo_trace_elem_t *seg = 0; int i = 0; if (f->trace) { vec_foreach (seg, f->trace) { s = format (s, "{%u, %u, %u}, ", seg->offset, seg->len, seg->action); i++; if (i % 5 == 0) s = format (s, "\n"); } s = format (s, "\n"); } return s; #else return 0; #endif } u8 * svm_fifo_replay (u8 * s, svm_fifo_t * f, u8 no_read, u8 verbose) { int i, trace_len; u8 *data = 0; svm_fifo_trace_elem_t *trace; u32 offset; svm_fifo_t *dummy_fifo; if (!f) return s; #if SVM_FIFO_TRACE trace = f->trace; trace_len = vec_len (trace); #else trace = 0; trace_len = 0; #endif dummy_fifo = svm_fifo_alloc (f->size); svm_fifo_init (f, f->size); clib_memset (f->head_chunk->data, 0xFF, f->size); vec_validate (data, f->size); for (i = 0; i < vec_len (data); i++) data[i] = i; for (i = 0; i < trace_len; i++) { offset = trace[i].offset; if (trace[i].action == 1) { if (verbose) s = format (s, "adding [%u, %u]:", trace[i].offset, (trace[i].offset + trace[i].len)); svm_fifo_enqueue_with_offset (dummy_fifo, trace[i].offset, trace[i].len, &data[offset]); } else if (trace[i].action == 2) { if (verbose) s = format (s, "adding [%u, %u]:", 0, trace[i].len); svm_fifo_enqueue (dummy_fifo, trace[i].len, &data[offset]); } else if (!no_read) { if (verbose) s = format (s, "read: %u", trace[i].len); svm_fifo_dequeue_drop (dummy_fifo, trace[i].len); } if (verbose) s = format (s, "%U", format_svm_fifo, dummy_fifo, 1); } s = format (s, "result: %U", format_svm_fifo, dummy_fifo, 1); return s; } u8 * format_ooo_list (u8 * s, va_list * args) { svm_fifo_t *f = va_arg (*args, svm_fifo_t *); u32 indent = va_arg (*args, u32); u32 ooo_segment_index = f->ooos_list_head; ooo_segment_t *seg; while (ooo_segment_index != OOO_SEGMENT_INVALID_INDEX) { seg = pool_elt_at_index (f->ooo_segments, ooo_segment_index); s = format (s, "%U%U\n", format_white_space, indent, format_ooo_segment, f, seg); ooo_segment_index = seg->next; } return s; } u8 * format_svm_fifo (u8 * s, va_list * args) { svm_fifo_t *f = va_arg (*args, svm_fifo_t *); int verbose = va_arg (*args, int); u32 indent; if (!s) return s; indent = format_get_indent (s); s = format (s, "cursize %u nitems %u has_event %d min_alloc %u\n", svm_fifo_max_dequeue (f), f->size, f->has_event, f->min_alloc); s = format (s, "%Uhead %u tail %u segment manager %u\n", format_white_space, indent, f->head, f->tail, f->segment_manager); if (verbose > 1) s = format (s, "%Uvpp session %d thread %d app session %d thread %d\n", format_white_space, indent, f->master_session_index, f->master_thread_index, f->client_session_index, f->client_thread_index); if (verbose) { s = format (s, "%Uooo pool %d active elts newest %u\n", format_white_space, indent, pool_elts (f->ooo_segments), f->ooos_newest); if (svm_fifo_has_ooo_data (f)) s = format (s, " %U", format_ooo_list, f, indent, verbose); } return s; } #endif /* * fd.io coding-style-patch-verification: ON * * Local Variables: * eval: (c-set-style "gnu") * End: */