api: Implement log_dump/log_details

- Replaces the need to screen scrape "show log".
- Adds an api to return the system time.  When running over a socket, the
  api client may have different time than the vpp host.

expected use:
  vpp_time_before_command = self.vapi.show_vpe_system_time_ticks().vpe_system_time_ticks
  <run some commands>
  log_output = self.vapi.log_dump(start_timestamp=vpp_time_before_command)

Depends-on: https://gerrit.fd.io/r/20484
Depends-on: https://gerrit.fd.io/r/#/c/19581/

==============================================================================
TestVpeApi
==============================================================================
log_details(_0=838, context=3, timestamp_ticks=2.4954863503546518e+48, level=<vl_api_log_level_t.VPE_API_LOG_LEVEL_WARNING: 4>, timestamp=u'2019/07/04 20:35:41:281', msg_class=u'buffer', message=u'vlib_physmem_shared_map_create: clib_mem_create_hugetlb_fd: open: No such file or directory\n\n')
log_details(_0=838, context=3, timestamp_ticks=1.6101902879480125e+159, level=<vl_api_log_level_t.VPE_API_LOG_LEVEL_WARNING: 4>, timestamp=u'2019/07/04 20:35:41:281', msg_class=u'buffer', message=u'falling back to non-hugepage backed buffer pool')
test_log_dump_default (test_vpe_api.TestVpeApi)                          OK
log_details(_0=838, context=13, timestamp_ticks=2.4954863503546518e+48, level=<vl_api_log_level_t.VPE_API_LOG_LEVEL_WARNING: 4>, timestamp=u'2019/07/04 20:35:41:281', msg_class=u'buffer', message=u'vlib_physmem_shared_map_create: clib_mem_create_hugetlb_fd: open: No such file or directory\n\n')
log_details(_0=838, context=13, timestamp_ticks=1.6101902879480125e+159, level=<vl_api_log_level_t.VPE_API_LOG_LEVEL_WARNING: 4>, timestamp=u'2019/07/04 20:35:41:281', msg_class=u'buffer', message=u'falling back to non-hugepage backed buffer pool')
test_log_dump_timestamp_0 (test_vpe_api.TestVpeApi)                      OK
test_log_dump_timestamp_future (test_vpe_api.TestVpeApi)                 SKIP
test_show_vpe_system_time_ticks (test_vpe_api.TestVpeApi)                SKIP

==============================================================================
TEST RESULTS:
     Scheduled tests: 4
      Executed tests: 4
        Passed tests: 2
       Skipped tests: 2
==============================================================================

Test run was successful

Type: feature

Change-Id: I893fc0a65f39749d2091093c2c604659aadd8447
Signed-off-by: Paul Vinciguerra <pvinci@vinciconsulting.com>

2 files changed, 55 insertions, 52 deletions

diff --git a/src/vlib/log.c b/src/vlib/log.c
index 9a0d75fe3ac..578fc942604 100644
--- a/src/vlib/log.c
+++ b/src/vlib/log.c
@@ -18,57 +18,6 @@
 #include <vlib/log.h>
 #include <syslog.h>
 
-typedef struct
-{
-  vlib_log_level_t level;
-  vlib_log_class_t class;
-  f64 timestamp;
-  u8 *string;
-} vlib_log_entry_t;
-
-typedef struct
-{
-  u32 index;
-  u8 *name;
-  // level of log messages kept for this subclass
-  vlib_log_level_t level;
-  // level of log messages sent to syslog for this subclass
-  vlib_log_level_t syslog_level;
-  // flag saying whether this subclass is logged to syslog
-  f64 last_event_timestamp;
-  int last_sec_count;
-  int is_throttling;
-  int rate_limit;
-} vlib_log_subclass_data_t;
-
-typedef struct
-{
-  u32 index;
-  u8 *name;
-  vlib_log_subclass_data_t *subclasses;
-} vlib_log_class_data_t;
-
-typedef struct
-{
-  vlib_log_entry_t *entries;
-  vlib_log_class_data_t *classes;
-  int size, next, count;
-
-  /* our own log class */
-  vlib_log_class_t log_class;
-
-  int default_rate_limit;
-  int default_log_level;
-  int default_syslog_log_level;
-  int unthrottle_time;
-  u32 indent;
-
-  /* time zero */
-  struct timeval time_zero_timeval;
-  f64 time_zero;
-
-} vlib_log_main_t;
-
 vlib_log_main_t log_main = {
   .default_log_level = VLIB_LOG_LEVEL_NOTICE,
   .default_syslog_log_level = VLIB_LOG_LEVEL_WARNING,
@@ -77,7 +26,7 @@ vlib_log_main_t log_main = {
   .default_rate_limit = 50,
 };
 
-static int
+int
 last_log_entry ()
 {
   vlib_log_main_t *lm = &log_main;
diff --git a/src/vlib/log.h b/src/vlib/log.h
index 9b285429b9a..663d7fe86ed 100644
--- a/src/vlib/log.h
+++ b/src/vlib/log.h
@@ -36,11 +36,65 @@ typedef enum
 #undef _
 } vlib_log_level_t;
 
+typedef struct
+{
+  vlib_log_level_t level;
+  vlib_log_class_t class;
+  f64 timestamp;
+  u8 *string;
+} vlib_log_entry_t;
+
+typedef struct
+{
+  u32 index;
+  u8 *name;
+  // level of log messages kept for this subclass
+  vlib_log_level_t level;
+  // level of log messages sent to syslog for this subclass
+  vlib_log_level_t syslog_level;
+  // flag saying whether this subclass is logged to syslog
+  f64 last_event_timestamp;
+  int last_sec_count;
+  int is_throttling;
+  int rate_limit;
+} vlib_log_subclass_data_t;
+
+typedef struct
+{
+  u32 index;
+  u8 *name;
+  vlib_log_subclass_data_t *subclasses;
+} vlib_log_class_data_t;
+
+typedef struct
+{
+  vlib_log_entry_t *entries;
+  vlib_log_class_data_t *classes;
+  int size, next, count;
+
+  /* our own log class */
+  vlib_log_class_t log_class;
+
+  int default_rate_limit;
+  int default_log_level;
+  int default_syslog_log_level;
+  int unthrottle_time;
+  u32 indent;
+
+  /* time zero */
+  struct timeval time_zero_timeval;
+  f64 time_zero;
+
+} vlib_log_main_t;
+
+extern vlib_log_main_t log_main;
 
 vlib_log_class_t vlib_log_register_class (char *vlass, char *subclass);
 u32 vlib_log_get_indent ();
 void vlib_log (vlib_log_level_t level, vlib_log_class_t class, char *fmt,
 	       ...);
+int last_log_entry ();
+u8 *format_vlib_log_class (u8 * s, va_list * args);
 
 #define vlib_log_emerg(...) vlib_log(VLIB_LOG_LEVEL_EMERG, __VA_ARGS__)
 #define vlib_log_alert(...) vlib_log(VLIB_LOG_LEVEL_ALERT, __VA_ARGS__)