summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorDave Barach <dave@barachs.net>2020-11-25 10:07:09 -0500
committerDamjan Marion <dmarion@me.com>2020-11-25 19:01:08 +0000
commitbc867c3d2137dab4b1395196c1936233517980ab (patch)
tree2f0439bc2c6ba0bde5bd3cf3d87723454c74f3d7
parent7483a7272d15354486371be7a20c4bf35ab2eb38 (diff)
vlib: add elog events for vlib log entries
Pretty interesting to see how long plugins take to load. Type: improvement Signed-off-by: Dave Barach <dave@barachs.net> Change-Id: If496eb73b2e1fd9dd714142cd5195fa7ccd93ebd
-rw-r--r--src/vlib/log.c34
-rw-r--r--src/vlib/log.h1
-rw-r--r--src/vlib/main.c20
-rw-r--r--src/vlib/main.h1
-rw-r--r--src/vlib/unix/main.c5
-rw-r--r--src/vppinfra/elog.c23
-rw-r--r--src/vppinfra/elog.h1
7 files changed, 69 insertions, 16 deletions
diff --git a/src/vlib/log.c b/src/vlib/log.c
index e1ab036b25c..bd456aeafe9 100644
--- a/src/vlib/log.c
+++ b/src/vlib/log.c
@@ -18,12 +18,14 @@
#include <vlib/log.h>
#include <vlib/unix/unix.h>
#include <syslog.h>
+#include <vppinfra/elog.h>
vlib_log_main_t log_main = {
.default_log_level = VLIB_LOG_LEVEL_NOTICE,
.default_syslog_log_level = VLIB_LOG_LEVEL_WARNING,
.unthrottle_time = 3,
.size = 512,
+ .add_to_elog = 1,
.default_rate_limit = 50,
};
@@ -222,6 +224,36 @@ vlib_log (vlib_log_level_t level, vlib_log_class_t class, char *fmt, ...)
e->timestamp = t;
s = 0;
+ if (lm->add_to_elog)
+ {
+ /* *INDENT-OFF* */
+ ELOG_TYPE_DECLARE(ee) =
+ {
+ .format = "log-%s: %s",
+ .format_args = "t4T4",
+ .n_enum_strings = 9,
+ .enum_strings = {
+ "emerg",
+ "alert",
+ "crit",
+ "err",
+ "warn",
+ "notice",
+ "info",
+ "debug",
+ "disabled",
+ },
+ };
+ struct {
+ u32 log_level;
+ u32 string_index;
+ } *ed;
+ /* *INDENT-ON* */
+ ed = ELOG_DATA (&vm->elog_main, ee);
+ ed->log_level = level;
+ ed->string_index = elog_string (&vm->elog_main, (char *) e->string);
+ }
+
lm->next = (lm->next + 1) % lm->size;
if (lm->size > lm->count)
lm->count++;
@@ -822,6 +854,8 @@ log_config (vlib_main_t * vm, unformat_input_t * input)
unformat_vlib_log_level,
&lm->default_syslog_log_level))
;
+ else if (unformat (input, "add-to-elog"))
+ lm->add_to_elog = 1;
else if (unformat (input, "class %s %U", &class,
unformat_vlib_cli_sub_input, &sub_input))
{
diff --git a/src/vlib/log.h b/src/vlib/log.h
index 75bdceb806e..a94c57a51eb 100644
--- a/src/vlib/log.h
+++ b/src/vlib/log.h
@@ -108,6 +108,7 @@ typedef struct
/* config */
vlib_log_class_config_t *configs;
uword *config_index_by_name;
+ int add_to_elog;
/* registrations */
vlib_log_class_registration_t *registrations;
diff --git a/src/vlib/main.c b/src/vlib/main.c
index f1de9090612..27cbcb0df18 100644
--- a/src/vlib/main.c
+++ b/src/vlib/main.c
@@ -823,8 +823,8 @@ VLIB_CLI_COMMAND (elog_restart_cli, static) = {
/* *INDENT-ON* */
static clib_error_t *
-elog_resize (vlib_main_t * vm,
- unformat_input_t * input, vlib_cli_command_t * cmd)
+elog_resize_command_fn (vlib_main_t * vm,
+ unformat_input_t * input, vlib_cli_command_t * cmd)
{
elog_main_t *em = &vm->elog_main;
u32 tmp;
@@ -848,7 +848,7 @@ elog_resize (vlib_main_t * vm,
VLIB_CLI_COMMAND (elog_resize_cli, static) = {
.path = "event-logger resize",
.short_help = "event-logger resize <nnn>",
- .function = elog_resize,
+ .function = elog_resize_command_fn,
};
/* *INDENT-ON* */
@@ -2051,8 +2051,9 @@ vlib_main_configure (vlib_main_t * vm, unformat_input_t * input)
turn_on_mem_trace = 1;
else if (unformat (input, "elog-events %d",
- &vm->elog_main.event_ring_size))
- ;
+ &vm->configured_elog_ring_size))
+ vm->configured_elog_ring_size =
+ 1 << max_log2 (vm->configured_elog_ring_size);
else if (unformat (input, "elog-post-mortem-dump"))
vm->elog_post_mortem_dump = 1;
else if (unformat (input, "buffer-alloc-success-rate %f",
@@ -2133,11 +2134,10 @@ vlib_main (vlib_main_t * volatile vm, unformat_input_t * input)
vm->queue_signal_callback = placeholder_queue_signal_callback;
- /* Turn on event log. */
- if (!vm->elog_main.event_ring_size)
- vm->elog_main.event_ring_size = 128 << 10;
- elog_init (&vm->elog_main, vm->elog_main.event_ring_size);
- elog_enable_disable (&vm->elog_main, 1);
+ /* Reconfigure event log which is enabled very early */
+ if (vm->configured_elog_ring_size &&
+ vm->configured_elog_ring_size != vm->elog_main.event_ring_size)
+ elog_resize (&vm->elog_main, vm->configured_elog_ring_size);
vl_api_set_elog_main (&vm->elog_main);
(void) vl_api_set_elog_trace_api_messages (1);
diff --git a/src/vlib/main.h b/src/vlib/main.h
index c420d5f9d28..766c9ec3756 100644
--- a/src/vlib/main.h
+++ b/src/vlib/main.h
@@ -223,6 +223,7 @@ typedef struct vlib_main_t
/* Event logger. */
elog_main_t elog_main;
+ u32 configured_elog_ring_size;
/* Event logger trace flags */
int elog_trace_api_messages;
diff --git a/src/vlib/unix/main.c b/src/vlib/unix/main.c
index 2f1b6ecdae0..e86d421056c 100644
--- a/src/vlib/unix/main.c
+++ b/src/vlib/unix/main.c
@@ -706,6 +706,11 @@ vlib_unix_main (int argc, char *argv[])
clib_time_init (&vm->clib_time);
+ /* Turn on the event logger at the first possible moment */
+ vm->configured_elog_ring_size = 128 << 10;
+ elog_init (&vm->elog_main, vm->configured_elog_ring_size);
+ elog_enable_disable (&vm->elog_main, 1);
+
unformat_init_command_line (&input, (char **) vm->argv);
if ((e = vlib_plugin_config (vm, &input)))
{
diff --git a/src/vppinfra/elog.c b/src/vppinfra/elog.c
index 6fa44cb82f9..423d8d5ba15 100644
--- a/src/vppinfra/elog.c
+++ b/src/vppinfra/elog.c
@@ -484,18 +484,29 @@ elog_nsec_per_clock (elog_main_t * em)
&em->init_time));
}
-__clib_export void
-elog_alloc (elog_main_t * em, u32 n_events)
+static void
+elog_alloc_internal (elog_main_t * em, u32 n_events, int free_ring)
{
- if (em->event_ring)
+ if (free_ring && em->event_ring)
vec_free (em->event_ring);
/* Ring size must be a power of 2. */
em->event_ring_size = n_events = max_pow2 (n_events);
- /* Leave an empty ievent at end so we can always speculatively write
- and event there (possibly a long form event). */
- vec_resize_aligned (em->event_ring, n_events, CLIB_CACHE_LINE_BYTES);
+ vec_validate_aligned (em->event_ring, n_events, CLIB_CACHE_LINE_BYTES);
+ _vec_len (em->event_ring) = n_events;
+}
+
+__clib_export void
+elog_alloc (elog_main_t * em, u32 n_events)
+{
+ elog_alloc_internal (em, n_events, 1 /* free ring */ );
+}
+
+__clib_export void
+elog_resize (elog_main_t * em, u32 n_events)
+{
+ elog_alloc_internal (em, n_events, 0 /* do not free ring */ );
}
__clib_export void
diff --git a/src/vppinfra/elog.h b/src/vppinfra/elog.h
index 93ba4f5e8cc..d0825bdd5b2 100644
--- a/src/vppinfra/elog.h
+++ b/src/vppinfra/elog.h
@@ -526,6 +526,7 @@ void unserialize_elog_main (serialize_main_t * m, va_list * va);
void elog_init (elog_main_t * em, u32 n_events);
void elog_alloc (elog_main_t * em, u32 n_events);
+void elog_resize (elog_main_t * em, u32 n_events);
#ifdef CLIB_UNIX
always_inline clib_error_t *