X-Git-Url: https://gerrit.fd.io/r/gitweb?a=blobdiff_plain;f=src%2Fvppinfra%2Felog.c;h=423d8d5ba157115b96ad01a5296681768e17b139;hb=bc867c3;hp=12e3f5d4bd81ab58e224f96496b9bc144ba47658;hpb=903fd513e32a37e55aec0cfb4cf30e000680e0c3;p=vpp.git diff --git a/src/vppinfra/elog.c b/src/vppinfra/elog.c index 12e3f5d4bd8..423d8d5ba15 100644 --- a/src/vppinfra/elog.c +++ b/src/vppinfra/elog.c @@ -41,13 +41,14 @@ #include #include #include +#include static inline void elog_lock (elog_main_t * em) { if (PREDICT_FALSE (em->lock != 0)) - while (__sync_lock_test_and_set (em->lock, 1)) - ; + while (clib_atomic_test_and_set (em->lock)) + CLIB_PAUSE (); } static inline void @@ -55,13 +56,12 @@ elog_unlock (elog_main_t * em) { if (PREDICT_FALSE (em->lock != 0)) { - CLIB_MEMORY_BARRIER (); - *em->lock = 0; + clib_atomic_release (em->lock); } } /* Non-inline version. */ -void * +__clib_export void * elog_event_data (elog_main_t * em, elog_event_type_t * type, elog_track_t * track, u64 cpu_time) { @@ -108,6 +108,13 @@ elog_event_type_register (elog_main_t * em, elog_event_type_t * t) elog_lock (em); + /* Multiple simultaneous registration attempts, */ + if (t->type_index_plus_one > 0) + { + elog_unlock (em); + return t->type_index_plus_one - 1; + } + l = vec_len (em->event_types); t->type_index_plus_one = 1 + l; @@ -187,7 +194,7 @@ elog_event_type_register (elog_main_t * em, elog_event_type_t * t) return l; } -word +__clib_export word elog_track_register (elog_main_t * em, elog_track_t * t) { word l; @@ -285,7 +292,7 @@ done: return s; } -u8 * +__clib_export u8 * format_elog_event (u8 * s, va_list * va) { elog_main_t *em = va_arg (*va, elog_main_t *); @@ -295,7 +302,7 @@ format_elog_event (u8 * s, va_list * va) void *d = (u8 *) e->data; char arg_format[64]; - t = vec_elt_at_index (em->event_types, e->type); + t = vec_elt_at_index (em->event_types, e->event_type); f = t->format; a = t->format_args; @@ -389,7 +396,7 @@ format_elog_event (u8 * s, va_list * va) } u8 * -format_elog_track (u8 * s, va_list * va) +format_elog_track_name (u8 * s, va_list * va) { elog_main_t *em = va_arg (*va, elog_main_t *); elog_event_t *e = va_arg (*va, elog_event_t *); @@ -397,6 +404,38 @@ format_elog_track (u8 * s, va_list * va) return format (s, "%s", t->name); } +__clib_export u8 * +format_elog_track (u8 * s, va_list * args) +{ + elog_main_t *em = va_arg (*args, elog_main_t *); + f64 dt = va_arg (*args, f64); + int track_index = va_arg (*args, int); + elog_event_t *e, *es; + u8 indent; + + indent = format_get_indent (s) + 1; + + es = elog_peek_events (em); + vec_foreach (e, es) + { + if (e->track != track_index) + continue; + s = format (s, "%U%18.9f: %U\n", format_white_space, indent, + e->time + dt, format_elog_event, em, e); + } + vec_free (es); + return s; +} + +__clib_export char * +format_one_elog_event (void *em_arg, void *ep_arg) +{ + elog_main_t *em = (elog_main_t *) em_arg; + elog_event_t *ep = (elog_event_t *) ep_arg; + + return (char *) format (0, "%U", format_elog_event, em, ep); +} + void elog_time_now (elog_time_stamp_t * et) { @@ -406,7 +445,11 @@ elog_time_now (elog_time_stamp_t * et) #ifdef CLIB_UNIX { #include +#ifdef __APPLE__ + clock_gettime (CLOCK_REALTIME, &ts); +#else syscall (SYS_clock_gettime, CLOCK_REALTIME, &ts); +#endif cpu_time_now = clib_cpu_time_now (); /* Subtract 3/30/2017's worth of seconds to retain precision */ os_time_now_nsec = 1e9 * (ts.tv_sec - 1490885108) + ts.tv_nsec; @@ -441,24 +484,35 @@ elog_nsec_per_clock (elog_main_t * em) &em->init_time)); } -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; } -void +__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 elog_init (elog_main_t * em, u32 n_events) { - memset (em, 0, sizeof (em[0])); + clib_memset (em, 0, sizeof (em[0])); em->lock = 0; @@ -474,6 +528,7 @@ elog_init (elog_main_t * em, u32 n_events) elog_track_register (em, &em->default_track); elog_time_now (&em->init_time); + em->string_table_hash = hash_create_string (0, sizeof (uword)); } /* Returns number of events in ring and start index. */ @@ -498,7 +553,7 @@ elog_event_range (elog_main_t * em, uword * lo) } } -elog_event_t * +__clib_export elog_event_t * elog_peek_events (elog_main_t * em) { elog_event_t *e, *f, *es = 0; @@ -523,29 +578,55 @@ elog_peek_events (elog_main_t * em) } /* Add a formatted string to the string table. */ -u32 +__clib_export u32 elog_string (elog_main_t * em, char *fmt, ...) { u32 offset; + uword *p; + uword len; va_list va; + elog_lock (em); + vec_reset_length (em->string_table_tmp); va_start (va, fmt); - offset = vec_len (em->string_table); - em->string_table = (char *) va_format ((u8 *) em->string_table, fmt, &va); + em->string_table_tmp = va_format (em->string_table_tmp, fmt, &va); va_end (va); - /* Null terminate string if it is not already. */ - if (vec_end (em->string_table)[-1] != 0) - vec_add1 (em->string_table, 0); + /* String table entries MUST be NULL terminated */ + len = vec_len (em->string_table_tmp); + ASSERT (len > 0); + if (em->string_table_tmp[len - 1] != 0) + vec_add1 (em->string_table_tmp, 0); + + /* See if we already have this string in the string table */ + p = hash_get_mem (em->string_table_hash, em->string_table_tmp); + + /* We already have the string, so give the caller its offset */ + if (p) + { + elog_unlock (em); + return (p[0]); + } + + /* We don't, so add it. */ + + offset = vec_len (em->string_table); + vec_append (em->string_table, em->string_table_tmp); + + hash_set_mem (em->string_table_hash, em->string_table_tmp, offset); + + /* We gave the key to the string table hash, so we can't reuse it! */ + em->string_table_tmp = 0; + elog_unlock (em); return offset; } -elog_event_t * +__clib_export elog_event_t * elog_get_events (elog_main_t * em) { - if (!em->events) - em->events = elog_peek_events (em); + vec_free (em->events); + em->events = elog_peek_events (em); return em->events; } @@ -625,7 +706,7 @@ elog_merge (elog_main_t * dst, u8 * dst_tag, elog_main_t * src, u8 * src_tag, elog_track_t newt; int i; - memset (&newt, 0, sizeof (newt)); + clib_memset (&newt, 0, sizeof (newt)); /* Acquire src and dst events */ elog_get_events (src); @@ -671,10 +752,11 @@ elog_merge (elog_main_t * dst, u8 * dst_tag, elog_main_t * src, u8 * src_tag, /* Across all (copied) src events... */ for (e = dst->events + l; e < vec_end (dst->events); e++) { - elog_event_type_t *t = vec_elt_at_index (src->event_types, e->type); + elog_event_type_t *t = + vec_elt_at_index (src->event_types, e->event_type); /* Remap type from src -> dst. */ - e->type = find_or_create_type (dst, t); + e->event_type = find_or_create_type (dst, t); /* Remap string table offsets for 'T' format args */ maybe_fix_string_table_offset (e, t, @@ -725,7 +807,7 @@ elog_merge (elog_main_t * dst, u8 * dst_tag, elog_main_t * src, u8 * src_tag, /* * Move the earlier set of events later, to avoid creating - * events which preceed the Big Bang (aka have negative timestamps). + * events which precede the Big Bang (aka have negative timestamps). * * Not to any scale, we have something like the following picture: * @@ -786,11 +868,11 @@ serialize_elog_event (serialize_main_t * m, va_list * va) { elog_main_t *em = va_arg (*va, elog_main_t *); elog_event_t *e = va_arg (*va, elog_event_t *); - elog_event_type_t *t = vec_elt_at_index (em->event_types, e->type); + elog_event_type_t *t = vec_elt_at_index (em->event_types, e->event_type); u8 *d = e->data; u8 *p = (u8 *) t->format_args; - serialize_integer (m, e->type, sizeof (e->type)); + serialize_integer (m, e->event_type, sizeof (e->event_type)); serialize_integer (m, e->track, sizeof (e->track)); serialize (m, serialize_f64, e->time); @@ -853,18 +935,18 @@ unserialize_elog_event (serialize_main_t * m, va_list * va) { u16 tmp[2]; - unserialize_integer (m, &tmp[0], sizeof (e->type)); + unserialize_integer (m, &tmp[0], sizeof (e->event_type)); unserialize_integer (m, &tmp[1], sizeof (e->track)); - e->type = tmp[0]; + e->event_type = tmp[0]; e->track = tmp[1]; /* Make sure it fits. */ - ASSERT (e->type == tmp[0]); + ASSERT (e->event_type == tmp[0]); ASSERT (e->track == tmp[1]); } - t = vec_elt_at_index (em->event_types, e->type); + t = vec_elt_at_index (em->event_types, e->event_type); unserialize (m, unserialize_f64, &e->time); @@ -1027,7 +1109,7 @@ unserialize_elog_time_stamp (serialize_main_t * m, va_list * va) static char *elog_serialize_magic = "elog v0"; -void +__clib_export void serialize_elog_main (serialize_main_t * m, va_list * va) { elog_main_t *em = va_arg (*va, elog_main_t *); @@ -1097,6 +1179,39 @@ unserialize_elog_main (serialize_main_t * m, va_list * va) } } +#ifdef CLIB_UNIX +clib_error_t * +elog_write_file_not_inline (elog_main_t * em, char *clib_file, int flush_ring) +{ + serialize_main_t m; + clib_error_t *error; + + error = serialize_open_clib_file (&m, clib_file); + if (error) + return error; + error = serialize (&m, serialize_elog_main, em, flush_ring); + if (!error) + serialize_close (&m); + return error; +} + +__clib_export clib_error_t * +elog_read_file_not_inline (elog_main_t * em, char *clib_file) +{ + serialize_main_t m; + clib_error_t *error; + + error = unserialize_open_clib_file (&m, clib_file); + if (error) + return error; + error = unserialize (&m, unserialize_elog_main, em); + if (!error) + unserialize_close (&m); + return error; +} +#endif /* CLIB_UNIX */ + + /* * fd.io coding-style-patch-verification: ON *