2 * Copyright (c) 2015 Cisco and/or its affiliates.
3 * Licensed under the Apache License, Version 2.0 (the "License");
4 * you may not use this file except in compliance with the License.
5 * You may obtain a copy of the License at:
7 * http://www.apache.org/licenses/LICENSE-2.0
9 * Unless required by applicable law or agreed to in writing, software
10 * distributed under the License is distributed on an "AS IS" BASIS,
11 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 * See the License for the specific language governing permissions and
13 * limitations under the License.
16 Copyright (c) 2005,2009 Eliot Dresselhaus
18 Permission is hereby granted, free of charge, to any person obtaining
19 a copy of this software and associated documentation files (the
20 "Software"), to deal in the Software without restriction, including
21 without limitation the rights to use, copy, modify, merge, publish,
22 distribute, sublicense, and/or sell copies of the Software, and to
23 permit persons to whom the Software is furnished to do so, subject to
24 the following conditions:
26 The above copyright notice and this permission notice shall be
27 included in all copies or substantial portions of the Software.
29 THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
30 EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
31 MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
32 NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
33 LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
34 OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
35 WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
38 /* High speed event logger */
41 The fine-grained event logger allows lightweight, thread-safe
42 event logging at minimum cost. In typical operation, logging
43 a single event costs around 80ns on x86_64. It's appropriate
44 for at-least per-frame event-logging in vector packet processing.
46 See https://wiki.fd.io/view/VPP/elog for more information.
49 #ifndef included_clib_elog_h
50 #define included_clib_elog_h
52 #include <vppinfra/cache.h>
53 #include <vppinfra/error.h> /* for ASSERT */
54 #include <vppinfra/serialize.h>
55 #include <vppinfra/time.h> /* for clib_cpu_time_now */
56 #include <vppinfra/hash.h>
57 #include <vppinfra/mhash.h>
63 /** Absolute time stamp in CPU clock cycles. */
66 /** Absolute time as floating point number in seconds. */
70 /** Event type index. */
73 /** Track for this event. Tracks allow events to be sorted and
74 displayed by track. Think of 2 dimensional display with time and
75 track being the x and y axes. */
78 /** 20-bytes of data follows, pads to 32 bytes. */
84 /** Type index plus one assigned to this type.
85 This is used to mark type as seen. */
86 u32 type_index_plus_one;
88 /** String table as a vector constructed when type is registered. */
89 char **enum_strings_vector;
91 /** Format string. (example: "my-event (%d,%d)"). */
94 /** Specifies how arguments to format are parsed from event data.
95 String of characters '0' '1' or '2' '3' to specify log2 size of data
96 (e.g. for u8, u16, u32 or u64),
97 's' means a null-terminated C string
98 't' means argument is an index into enum string table for this type.
103 /** Function name generating event. */
106 /** Number of elements in string enum table. */
109 /** String table for enum/number to string formatting. */
110 char *enum_strings[];
115 /** Track name vector. */
118 /** Set to one when track has been added to
120 u32 track_index_plus_one;
125 /** CPU cycle counter. */
128 /** OS timer in nano secs since epoch 3/30/2017, see elog_time_now() */
134 /** Total number of events in buffer. */
137 /** When count reaches limit logging is disabled. This is
138 used for event triggers. */
139 u32 n_total_events_disable_limit;
141 /** Dummy event to use when logger is disabled. */
142 elog_event_t placeholder_event;
144 /** Power of 2 number of elements in ring. */
145 uword event_ring_size;
147 /** Vector of events (circular buffer). Power of 2 size.
148 Used when events are being collected. */
149 elog_event_t *event_ring;
151 /** Vector of event types. */
152 elog_event_type_t *event_types;
154 /** Hash table mapping type format to type index. */
155 uword *event_type_by_format;
157 /** Events may refer to strings in string table. */
159 uword *string_table_hash;
160 u8 *string_table_tmp;
162 /** Vector of tracks. */
163 elog_track_t *tracks;
165 /** Default track. */
166 elog_track_t default_track;
168 /** Place holder for CPU clock frequency. */
169 clib_time_t cpu_timer;
172 elog_time_stamp_t init_time, serialize_time;
174 /** SMP lock, non-zero means locking required */
177 /** Use serialize_time and init_time to give estimate for
178 cpu clock frequency. */
179 f64 nsec_per_cpu_clock;
181 /** Vector of events converted to generic form after collection. */
182 elog_event_t *events;
185 /** @brief Return number of events in the event-log buffer
186 @param em elog_main_t *
187 @return number of events in the buffer
191 elog_n_events_in_buffer (elog_main_t * em)
193 return clib_min (em->n_total_events, em->event_ring_size);
196 /** @brief Return number of events which can fit in the event buffer
197 @param em elog_main_t *
198 @return number of events which can fit in the buffer
201 elog_buffer_capacity (elog_main_t * em)
203 return em->event_ring_size;
206 /** @brief Reset the event buffer
207 @param em elog_main_t *
210 elog_reset_buffer (elog_main_t * em)
212 em->n_total_events = 0;
213 em->n_total_events_disable_limit = ~0;
216 /** @brief Enable or disable event logging
217 @param em elog_main_t *
220 elog_enable_disable (elog_main_t * em, int is_enabled)
222 em->n_total_events = 0;
223 em->n_total_events_disable_limit = is_enabled ? ~0 : 0;
226 /** @brief disable logging after specified number of ievents have been logged.
228 This is used as a "debug trigger" when a certain event has occurred.
229 Events will be logged both before and after the "event" but the
230 event will not be lost as long as N < RING_SIZE.
232 @param em elog_main_t *
233 @param n uword number of events before disabling event logging
236 elog_disable_after_events (elog_main_t * em, uword n)
238 em->n_total_events_disable_limit = em->n_total_events + n;
241 /* @brief mid-buffer logic-analyzer trigger
243 Currently, only midpoint triggering is supported, but it's pretty obvious
244 how to generalize the scheme.
245 @param em elog_main_t *
248 elog_disable_trigger (elog_main_t * em)
250 em->n_total_events_disable_limit =
251 em->n_total_events + vec_len (em->event_ring) / 2;
254 /** @brief register an event type
255 @param em elog_main_t *
256 @param t elog_event_type_t * event to register
258 @warning Typically not called directly
261 word elog_event_type_register (elog_main_t * em, elog_event_type_t * t);
263 /** @brief register an event track
264 @param em elog_main_t *
265 @param t elog_track_t * track to register
267 @note this function is often called directly
269 word elog_track_register (elog_main_t * em, elog_track_t * t);
271 /** @brief event logging enabled predicate
272 @param em elog_main_t *
273 @return 1 if enabled, 0 if not enabled
276 elog_is_enabled (elog_main_t * em)
278 return em->n_total_events < em->n_total_events_disable_limit;
281 /** @brief Allocate an event to be filled in by the caller
283 Not normally called directly; this function underlies the
284 ELOG_DATA and ELOG_TRACK_DATA macros
286 @param em elog_main_t *
287 @param type elog_event_type_t * type
288 @param track elog_track_t * track
289 @param cpu_time u64 current cpu tick value
290 @returns event to be filled in
293 elog_event_data_inline (elog_main_t * em,
294 elog_event_type_t * type,
295 elog_track_t * track, u64 cpu_time)
299 word type_index, track_index;
301 /* Return the user placeholder memory to scribble data into. */
302 if (PREDICT_FALSE (!elog_is_enabled (em)))
303 return em->placeholder_event.data;
305 type_index = (word) type->type_index_plus_one - 1;
306 track_index = (word) track->track_index_plus_one - 1;
307 if (PREDICT_FALSE ((type_index | track_index) < 0))
310 type_index = elog_event_type_register (em, type);
312 track_index = elog_track_register (em, track);
315 ASSERT (track_index < vec_len (em->tracks));
316 ASSERT (is_pow2 (vec_len (em->event_ring)));
319 ei = clib_atomic_fetch_add (&em->n_total_events, 1);
321 ei = em->n_total_events++;
323 ei &= em->event_ring_size - 1;
324 e = vec_elt_at_index (em->event_ring, ei);
326 e->time_cycles = cpu_time;
327 e->event_type = type_index;
328 e->track = track_index;
330 /* Return user data for caller to fill in. */
334 /* External version of inline. */
335 void *elog_event_data (elog_main_t * em,
336 elog_event_type_t * type,
337 elog_track_t * track, u64 cpu_time);
339 /** @brief Allocate an event to be filled in by the caller, non-inline
341 Not normally called directly; this function underlies the
342 ELOG_DATA and ELOG_TRACK_DATA macros
344 @param em elog_main_t *
345 @param type elog_event_type_t * type
346 @param track elog_track_t * track
347 @param cpu_time u64 current cpu tick value
348 @returns event to be filled in
351 elog_event_data_not_inline (elog_main_t * em,
352 elog_event_type_t * type,
353 elog_track_t * track, u64 cpu_time)
355 /* Return the user placeholder memory to scribble data into. */
356 if (PREDICT_FALSE (!elog_is_enabled (em)))
357 return em->placeholder_event.data;
358 return elog_event_data (em, type, track, cpu_time);
361 /** @brief Log a single-datum event
362 @param em elog_main_t *
363 @param type elog_event_type_t * type
364 @param data u32 single datum to capture
367 elog (elog_main_t * em, elog_event_type_t * type, u32 data)
369 u32 *d = elog_event_data_not_inline (em,
372 clib_cpu_time_now ());
376 /** @brief Log a single-datum event, inline version
377 @param em elog_main_t *
378 @param type elog_event_type_t * type
379 @param data u32 single datum to capture
382 elog_inline (elog_main_t * em, elog_event_type_t * type, u32 data)
384 u32 *d = elog_event_data_inline (em,
387 clib_cpu_time_now ());
391 /** @brief Log a single-datum event to a specific track, non-inline version
392 @param em elog_main_t *
393 @param type elog_event_type_t * type
394 @param type elog_event_track_t * track
395 @param data u32 single datum to capture
398 elog_track (elog_main_t * em, elog_event_type_t * type, elog_track_t * track,
401 u32 *d = elog_event_data_not_inline (em,
404 clib_cpu_time_now ());
408 /** @brief Log a single-datum event to a specific track
409 @param em elog_main_t *
410 @param type elog_event_type_t * type
411 @param type elog_event_track_t * track
412 @param data u32 single datum to capture
415 elog_track_inline (elog_main_t * em, elog_event_type_t * type,
416 elog_track_t * track, u32 data)
418 u32 *d = elog_event_data_inline (em,
421 clib_cpu_time_now ());
426 elog_data (elog_main_t * em, elog_event_type_t * type, elog_track_t * track)
428 return elog_event_data_not_inline (em, type, track, clib_cpu_time_now ());
432 elog_data_inline (elog_main_t * em, elog_event_type_t * type,
433 elog_track_t * track)
435 return elog_event_data_inline (em, type, track, clib_cpu_time_now ());
438 /* Macro shorthands for generating/declaring events. */
439 #define __ELOG_TYPE_VAR(f) f
440 #define __ELOG_TRACK_VAR(f) f
442 #define ELOG_TYPE_DECLARE(f) static elog_event_type_t __ELOG_TYPE_VAR(f)
444 #define ELOG_TYPE_INIT_FORMAT_AND_FUNCTION(fmt,func) \
445 { .format = fmt, .function = func, }
447 #define ELOG_TYPE_INIT(fmt) \
448 ELOG_TYPE_INIT_FORMAT_AND_FUNCTION(fmt,(char *) __FUNCTION__)
450 #define ELOG_TYPE_DECLARE_HELPER(f,fmt,func) \
451 static elog_event_type_t __ELOG_TYPE_VAR(f) = \
452 ELOG_TYPE_INIT_FORMAT_AND_FUNCTION (fmt, func)
454 #define ELOG_TYPE_DECLARE_FORMAT_AND_FUNCTION(f,fmt) \
455 ELOG_TYPE_DECLARE_HELPER (f, fmt, (char *) __FUNCTION__)
457 #define ELOG_TYPE_DECLARE_FORMAT(f,fmt) \
458 ELOG_TYPE_DECLARE_HELPER (f, fmt, 0)
460 /* Shorthands with and without __FUNCTION__.
461 D for decimal; X for hex. F for __FUNCTION__. */
462 #define ELOG_TYPE(f,fmt) ELOG_TYPE_DECLARE_FORMAT_AND_FUNCTION(f,fmt)
463 #define ELOG_TYPE_D(f) ELOG_TYPE_DECLARE_FORMAT (f, #f " %d")
464 #define ELOG_TYPE_X(f) ELOG_TYPE_DECLARE_FORMAT (f, #f " 0x%x")
465 #define ELOG_TYPE_DF(f) ELOG_TYPE_DECLARE_FORMAT_AND_FUNCTION (f, #f " %d")
466 #define ELOG_TYPE_XF(f) ELOG_TYPE_DECLARE_FORMAT_AND_FUNCTION (f, #f " 0x%x")
467 #define ELOG_TYPE_FD(f) ELOG_TYPE_DECLARE_FORMAT_AND_FUNCTION (f, #f " %d")
468 #define ELOG_TYPE_FX(f) ELOG_TYPE_DECLARE_FORMAT_AND_FUNCTION (f, #f " 0x%x")
470 #define ELOG_TRACK_DECLARE(f) static elog_track_t __ELOG_TRACK_VAR(f)
471 #define ELOG_TRACK(f) ELOG_TRACK_DECLARE(f) = { .name = #f, }
473 /* Log 32 bits of data. */
474 #define ELOG(em,f,data) elog ((em), &__ELOG_TYPE_VAR(f), data)
475 #define ELOG_INLINE(em,f,data) elog_inline ((em), &__ELOG_TYPE_VAR(f), data)
477 /* Return data pointer to fill in. */
478 #define ELOG_TRACK_DATA(em,f,track) \
479 elog_data ((em), &__ELOG_TYPE_VAR(f), &__ELOG_TRACK_VAR(track))
480 #define ELOG_TRACK_DATA_INLINE(em,f,track) \
481 elog_data_inline ((em), &__ELOG_TYPE_VAR(f), &__ELOG_TRACK_VAR(track))
483 /* Shorthand with default track. */
484 #define ELOG_DATA(em,f) elog_data ((em), &__ELOG_TYPE_VAR (f), &(em)->default_track)
485 #define ELOG_DATA_INLINE(em,f) elog_data_inline ((em), &__ELOG_TYPE_VAR (f), &(em)->default_track)
487 /** @brief add a string to the event-log string table
489 Often combined with hashing and the T4 elog format specifier to
490 display complex strings in offline tooling
492 @param em elog_main_t *
495 @return u32 index to add to event log
497 u32 elog_string (elog_main_t * em, char *format, ...);
499 void elog_time_now (elog_time_stamp_t * et);
501 /** @brief convert event ring events to events, and return them as a vector.
502 @param em elog_main_t *
503 @return event vector with timestamps in f64 seconds
504 @note sets em->events to resulting vector.
506 elog_event_t *elog_get_events (elog_main_t * em);
508 /** @brief convert event ring events to events, and return them as a vector.
509 @param em elog_main_t *
510 @return event vector with timestamps in f64 seconds
511 @note no side effects
513 elog_event_t *elog_peek_events (elog_main_t * em);
515 /* Merge two logs, add supplied track tags. */
516 void elog_merge (elog_main_t * dst, u8 * dst_tag,
517 elog_main_t * src, u8 * src_tag, f64 align_tweak);
519 /* 2 arguments elog_main_t and elog_event_t to format event or track name. */
520 u8 *format_elog_event (u8 * s, va_list * va);
521 u8 *format_elog_track_name (u8 * s, va_list * va);
522 u8 *format_elog_track (u8 * s, va_list * args);
524 void serialize_elog_main (serialize_main_t * m, va_list * va);
525 void unserialize_elog_main (serialize_main_t * m, va_list * va);
527 void elog_init (elog_main_t * em, u32 n_events);
528 void elog_alloc (elog_main_t * em, u32 n_events);
529 void elog_resize (elog_main_t * em, u32 n_events);
532 always_inline clib_error_t *
533 elog_write_file (elog_main_t * em, char *clib_file, int flush_ring)
538 error = serialize_open_clib_file (&m, clib_file);
541 error = serialize (&m, serialize_elog_main, em, flush_ring);
543 serialize_close (&m);
547 clib_error_t *elog_write_file_not_inline (elog_main_t * em, char *clib_file,
550 always_inline clib_error_t *
551 elog_read_file (elog_main_t * em, char *clib_file)
556 error = unserialize_open_clib_file (&m, clib_file);
559 error = unserialize (&m, unserialize_elog_main, em);
561 unserialize_close (&m);
565 clib_error_t *elog_read_file_not_inline (elog_main_t * em, char *clib_file);
566 char *format_one_elog_event (void *em_arg, void *ep_arg);
568 #endif /* CLIB_UNIX */
570 #endif /* included_clib_elog_h */
573 * fd.io coding-style-patch-verification: ON
576 * eval: (c-set-style "gnu")