vlib: barrier sync elog tracing improvements

[vpp.git] / src / vlib / threads.h

diff --git a/src/vlib/threads.h b/src/vlib/threads.h
index 1794453..7de0412 100644 (file)
--- a/src/vlib/threads.h
+++ b/src/vlib/threads.h
@@ -18,22 +18,6 @@
 #include <vlib/main.h>
 #include <linux/sched.h>
 
-/*
- * To enable detailed tracing of barrier usage, including call stacks and
- * timings, define BARRIER_TRACING here or in relevant TAGS.  If also used
- * with CLIB_DEBUG, timing will _not_ be representative of normal code
- * execution.
- *
- */
-
-// #define BARRIER_TRACING 1
-
-/*
- * Two options for barrier tracing output: syslog & elog.
- */
-
-// #define BARRIER_TRACING_ELOG 1
-
 extern vlib_main_t **vlib_mains;
 
 void vlib_set_thread_name (char *name);
@@ -118,10 +102,9 @@ typedef struct
   vlib_thread_registration_t *registration;
   u8 *name;
   u64 barrier_sync_count;
-#ifdef BARRIER_TRACING
+  u8 barrier_elog_enabled;
   const char *barrier_caller;
   const char *barrier_context;
-#endif
   volatile u32 *node_reforks_required;
 
   long lwp;
@@ -216,12 +199,7 @@ u32 vlib_frame_queue_main_init (u32 node_index, u32 frame_queue_nelts);
 #define BARRIER_SYNC_TIMEOUT (1.0)
 #endif
 
-#ifdef BARRIER_TRACING
 #define vlib_worker_thread_barrier_sync(X) {vlib_worker_threads[0].barrier_caller=__FUNCTION__;vlib_worker_thread_barrier_sync_int(X);}
-#else
-#define vlib_worker_thread_barrier_sync(X) vlib_worker_thread_barrier_sync_int(X)
-#endif
-
 
 void vlib_worker_thread_barrier_sync_int (vlib_main_t * vm);
 void vlib_worker_thread_barrier_release (vlib_main_t * vm);
@@ -410,7 +388,30 @@ vlib_worker_thread_barrier_check (void)
 {
   if (PREDICT_FALSE (*vlib_worker_threads->wait_at_barrier))
     {
-      vlib_main_t *vm;
+      vlib_main_t *vm = vlib_get_main ();
+      u32 thread_index = vm->thread_index;
+      f64 t = vlib_time_now (vm);
+
+      if (PREDICT_FALSE (vlib_worker_threads->barrier_elog_enabled))
+       {
+         vlib_worker_thread_t *w = vlib_worker_threads + thread_index;
+         /* *INDENT-OFF* */
+         ELOG_TYPE_DECLARE (e) = {
+           .format = "barrier-wait-thread-%d",
+           .format_args = "i4",
+         };
+         /* *INDENT-ON* */
+
+         struct
+         {
+           u32 thread_index;
+         } __clib_packed *ed;
+
+         ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main, e,
+                               w->elog_track);
+         ed->thread_index = thread_index;
+       }
+
       clib_smp_atomic_add (vlib_worker_threads->workers_at_barrier, 1);
       if (CLIB_DEBUG > 0)
        {
@@ -425,12 +426,55 @@ vlib_worker_thread_barrier_check (void)
 
       if (PREDICT_FALSE (*vlib_worker_threads->node_reforks_required))
        {
+         if (PREDICT_FALSE (vlib_worker_threads->barrier_elog_enabled))
+           {
+             t = vlib_time_now (vm) - t;
+             vlib_worker_thread_t *w = vlib_worker_threads + thread_index;
+              /* *INDENT-OFF* */
+              ELOG_TYPE_DECLARE (e) = {
+                .format = "barrier-refork-thread-%d",
+                .format_args = "i4",
+              };
+              /* *INDENT-ON* */
+
+             struct
+             {
+               u32 thread_index;
+             } __clib_packed *ed;
+
+             ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main, e,
+                                   w->elog_track);
+             ed->thread_index = thread_index;
+           }
+
          vlib_worker_thread_node_refork ();
          clib_smp_atomic_add (vlib_worker_threads->node_reforks_required,
                               -1);
          while (*vlib_worker_threads->node_reforks_required)
            ;
        }
+      if (PREDICT_FALSE (vlib_worker_threads->barrier_elog_enabled))
+       {
+         t = vlib_time_now (vm) - t;
+         vlib_worker_thread_t *w = vlib_worker_threads + thread_index;
+         /* *INDENT-OFF* */
+         ELOG_TYPE_DECLARE (e) = {
+           .format = "barrier-released-thread-%d: %dus",
+           .format_args = "i4i4",
+         };
+         /* *INDENT-ON* */
+
+         struct
+         {
+           u32 thread_index;
+           u32 duration;
+         } __clib_packed *ed;
+
+         ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main, e,
+                               w->elog_track);
+         ed->thread_index = thread_index;
+         ed->duration = (int) (1000000.0 * t);
+       }
     }
 }