api: enable binary API event logging in vat

Cleaned up a few instances of side-bet elog_string hash table
usage. Elog_string handles that problem itself.

Add cli commands to vat to initialize, enable/disable, and save an
event log.

Event logging at the same time in both vpp and vat yields a pair
of event logs which can be merged by the "test_elog" tool.

Type: refactor

Change-Id: I8d6a72206f2309c967ea1630077fba31aef47f93
Signed-off-by: Dave Barach <dave@barachs.net>

2 files changed, 86 insertions, 28 deletions

diff --git a/src/vlibapi/api_common.h b/src/vlibapi/api_common.h
index 735921b30f7..98fcbdefef9 100644
--- a/src/vlibapi/api_common.h
+++ b/src/vlibapi/api_common.h
@@ -25,6 +25,7 @@
  */
 
 #include <vppinfra/clib_error.h>
+#include <vppinfra/elog.h>
 #include <vlibapi/api_types.h>
 #include <svm/svm_common.h>
 #include <svm/queue.h>
@@ -339,6 +340,10 @@ typedef struct
   /** List of API client reaper functions */
   _vl_msg_api_function_list_elt_t *reaper_function_registrations;
 
+  /** event log */
+  elog_main_t *elog_main;
+  int elog_trace_api_messages;
+
 } api_main_t;
 
 extern api_main_t api_main;
diff --git a/src/vlibapi/api_shared.c b/src/vlibapi/api_shared.c
index 9579fe1c60f..18eb83b68b7 100644
--- a/src/vlibapi/api_shared.c
+++ b/src/vlibapi/api_shared.c
@@ -398,6 +398,26 @@ msg_handler_internal (api_main_t * am,
   u16 id = clib_net_to_host_u16 (*((u16 *) the_msg));
   u8 *(*print_fp) (void *, void *);
 
+  if (PREDICT_FALSE (am->elog_trace_api_messages))
+    {
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+        {
+          .format = "api-msg: %s",
+          .format_args = "T4",
+        };
+      /* *INDENT-ON* */
+      struct
+      {
+	u32 c;
+      } *ed;
+      ed = ELOG_DATA (am->elog_main, e);
+      if (id < vec_len (am->msg_names))
+	ed->c = elog_string (am->elog_main, (char *) am->msg_names[id]);
+      else
+	ed->c = elog_string (am->elog_main, "BOGUS");
+    }
+
   if (id < vec_len (am->msg_handlers) && am->msg_handlers[id])
     {
       if (trace_it)
@@ -436,28 +456,35 @@ msg_handler_internal (api_main_t * am,
 
   if (free_it)
     vl_msg_api_free (the_msg);
-}
 
-static u32
-elog_id_for_msg_name (vlib_main_t * vm, const char *msg_name)
-{
-  uword *p, r;
-  static uword *h;
-  u8 *name_copy;
-
-  if (!h)
-    h = hash_create_string (0, sizeof (uword));
-
-  p = hash_get_mem (h, msg_name);
-  if (p)
-    return p[0];
-  r = elog_string (&vm->elog_main, "%s", msg_name);
-
-  name_copy = format (0, "%s%c", msg_name, 0);
-
-  hash_set_mem (h, name_copy, r);
+  if (PREDICT_FALSE (am->elog_trace_api_messages))
+    {
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+        {
+          .format = "api-msg-done(%s): %s",
+          .format_args = "t4T4",
+          .n_enum_strings = 2,
+          .enum_strings =
+          {
+            "barrier",
+            "mp-safe",
+          }
+        };
+      /* *INDENT-ON* */
 
-  return r;
+      struct
+      {
+	u32 barrier;
+	u32 c;
+      } *ed;
+      ed = ELOG_DATA (am->elog_main, e);
+      if (id < vec_len (am->msg_names))
+	ed->c = elog_string (am->elog_main, (char *) am->msg_names[id]);
+      else
+	ed->c = elog_string (am->elog_main, "BOGUS");
+      ed->barrier = !am->is_mp_safe[id];
+    }
 }
 
 /* This is only to be called from a vlib/vnet app */
@@ -471,7 +498,7 @@ vl_msg_api_handler_with_vm_node (api_main_t * am,
   u8 *(*print_fp) (void *, void *);
   int is_mp_safe = 1;
 
-  if (PREDICT_FALSE (vm->elog_trace_api_messages))
+  if (PREDICT_FALSE (am->elog_trace_api_messages))
     {
       /* *INDENT-OFF* */
       ELOG_TYPE_DECLARE (e) =
@@ -484,11 +511,11 @@ vl_msg_api_handler_with_vm_node (api_main_t * am,
       {
 	u32 c;
       } *ed;
-      ed = ELOG_DATA (&vm->elog_main, e);
+      ed = ELOG_DATA (am->elog_main, e);
       if (id < vec_len (am->msg_names))
-	ed->c = elog_id_for_msg_name (vm, (const char *) am->msg_names[id]);
+	ed->c = elog_string (am->elog_main, (char *) am->msg_names[id]);
       else
-	ed->c = elog_id_for_msg_name (vm, "BOGUS");
+	ed->c = elog_string (am->elog_main, "BOGUS");
     }
 
   if (id < vec_len (am->msg_handlers) && am->msg_handlers[id])
@@ -534,7 +561,7 @@ vl_msg_api_handler_with_vm_node (api_main_t * am,
   if (!(am->message_bounce[id]))
     vl_msg_api_free (the_msg);
 
-  if (PREDICT_FALSE (vm->elog_trace_api_messages))
+  if (PREDICT_FALSE (am->elog_trace_api_messages))
     {
       /* *INDENT-OFF* */
       ELOG_TYPE_DECLARE (e) =
@@ -555,11 +582,11 @@ vl_msg_api_handler_with_vm_node (api_main_t * am,
 	u32 barrier;
 	u32 c;
       } *ed;
-      ed = ELOG_DATA (&vm->elog_main, e);
+      ed = ELOG_DATA (am->elog_main, e);
       if (id < vec_len (am->msg_names))
-	ed->c = elog_id_for_msg_name (vm, (const char *) am->msg_names[id]);
+	ed->c = elog_string (am->elog_main, (char *) am->msg_names[id]);
       else
-	ed->c = elog_id_for_msg_name (vm, "BOGUS");
+	ed->c = elog_string (am->elog_main, "BOGUS");
       ed->barrier = is_mp_safe;
     }
 }
@@ -1033,6 +1060,32 @@ vl_api_from_api_to_vec (vl_api_string_t * astr)
   return v;
 }
 
+void
+vl_api_set_elog_main (elog_main_t * m)
+{
+  api_main_t *am = &api_main;
+  am->elog_main = m;
+}
+
+int
+vl_api_set_elog_trace_api_messages (int enable)
+{
+  int rv;
+  api_main_t *am = &api_main;
+
+  rv = am->elog_trace_api_messages;
+  am->elog_trace_api_messages = enable;
+  return rv;
+}
+
+int
+vl_api_get_elog_trace_api_messages (void)
+{
+  api_main_t *am = &api_main;
+
+  return am->elog_trace_api_messages;
+}
+
 /*
  * fd.io coding-style-patch-verification: ON
  *