session: add cli option to dump session elog 61/16561/4
authorFlorin Coras <fcoras@cisco.com>
Wed, 19 Dec 2018 21:07:49 +0000 (13:07 -0800)
committerFlorin Coras <fcoras@cisco.com>
Thu, 20 Dec 2018 07:42:09 +0000 (23:42 -0800)
Change-Id: I1f42644f143bb65ee764c0f869b402595126adac
Signed-off-by: Florin Coras <fcoras@cisco.com>
src/tools/perftool/c2cpel.c
src/tools/perftool/elog_merge.c
src/vnet/session/session_cli.c
src/vnet/session/transport_interface.h
src/vnet/tcp/tcp_input.c
src/vppinfra/elog.c
src/vppinfra/elog.h
src/vppinfra/test_elog.c

index e68d0dc..35885de 100644 (file)
@@ -105,7 +105,7 @@ void convert_clib_file(char *clib_file)
 
         ep->event_id = find_or_add_event(brief_event_name, "%s");
 
-        track_name = format (0, "%U%c", format_elog_track, em, e, 0);
+        track_name = format (0, "%U%c", format_elog_track_name, em, e, 0);
 
         ep->track_id = find_or_add_track (track_name);
 
index 46b19dd..862b6de 100644 (file)
@@ -121,7 +121,8 @@ elog_merge_main (unformat_input_t * input)
       vec_foreach (e, es)
       {
        clib_warning ("%18.9f: %12U %U\n", e->time,
-                     format_elog_track, em, e, format_elog_event, em, e);
+                     format_elog_track_name, em, e, format_elog_event, em,
+                     e);
       }
     }
 
index 3fe4991..135138c 100755 (executable)
@@ -204,10 +204,11 @@ static clib_error_t *
 show_session_command_fn (vlib_main_t * vm, unformat_input_t * input,
                         vlib_cli_command_t * cmd)
 {
+  u8 *str = 0, one_session = 0, do_listeners = 0, sst, do_elog = 1;
   session_manager_main_t *smm = &session_manager_main;
-  u8 *str = 0, one_session = 0, do_listeners = 0, sst;
+  u32 transport_proto = ~0, track_index;
   stream_session_t *pool, *s;
-  u32 transport_proto = ~0;
+  transport_connection_t *tc;
   app_worker_t *app_wrk;
   int verbose = 0, i;
   const u8 *app_name;
@@ -230,6 +231,8 @@ show_session_command_fn (vlib_main_t * vm, unformat_input_t * input,
        {
          one_session = 1;
        }
+      else if (unformat (input, "elog"))
+       do_elog = 1;
       else
        return clib_error_return (0, "unknown input `%U'",
                                  format_unformat_error, input);
@@ -237,7 +240,21 @@ show_session_command_fn (vlib_main_t * vm, unformat_input_t * input,
 
   if (one_session)
     {
-      vlib_cli_output (vm, "%U", format_stream_session, s, 3);
+      str = format (0, "%U", format_stream_session, s, 3);
+      if (do_elog)
+       {
+         elog_main_t *em = &vm->elog_main;
+         f64 dt;
+
+         tc = session_get_transport (s);
+         track_index = transport_elog_track_index (tc);
+         dt = (em->init_time.cpu - vm->clib_time.init_cpu_time)
+           * vm->clib_time.seconds_per_clock;
+         if (track_index != ~0)
+           str = format (str, " session elog:\n%U", format_elog_track, em,
+                         dt, track_index);
+       }
+      vlib_cli_output (vm, "%v", str);
       return 0;
     }
 
index 10579c4..e8a6dbc 100644 (file)
@@ -103,6 +103,16 @@ transport_tx_fn_type_t transport_protocol_tx_fn_type (transport_proto_t tp);
 void transport_update_time (f64 time_now, u8 thread_index);
 void transport_enable_disable (vlib_main_t * vm, u8 is_en);
 
+always_inline u32
+transport_elog_track_index (transport_connection_t * tc)
+{
+#if TRANSPORT_DEBUG
+  return tc->elog_track.track_index_plus_one - 1;
+#else
+  return ~0;
+#endif
+}
+
 void transport_connection_tx_pacer_reset (transport_connection_t * tc,
                                          u32 rate_bytes_per_sec,
                                          u32 initial_bucket, u64 time_now);
index f1d0f01..dc8fffe 100644 (file)
@@ -2819,6 +2819,7 @@ tcp46_rcv_process_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
                  tcp_send_fin (tc0);
                  tcp_connection_timers_reset (tc0);
                  tc0->state = TCP_STATE_LAST_ACK;
+                 TCP_EVT_DBG (TCP_EVT_STATE_CHANGE, tc0);
                  tcp_timer_update (tc0, TCP_TIMER_WAITCLOSE, TCP_2MSL_TIME);
                }
            }
index 8e3f6c1..6daed96 100644 (file)
@@ -396,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 *);
@@ -404,6 +404,29 @@ format_elog_track (u8 * s, va_list * va)
   return format (s, "%s", t->name);
 }
 
+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;
+}
+
 void
 elog_time_now (elog_time_stamp_t * et)
 {
index 322c2c6..26352f7 100644 (file)
@@ -515,7 +515,8 @@ void elog_merge (elog_main_t * dst, u8 * dst_tag,
 
 /* 2 arguments elog_main_t and elog_event_t to format event or track name. */
 u8 *format_elog_event (u8 * s, va_list * va);
-u8 *format_elog_track (u8 * s, va_list * va);
+u8 *format_elog_track_name (u8 * s, va_list * va);
+u8 *format_elog_track (u8 * s, va_list * args);
 
 void serialize_elog_main (serialize_main_t * m, va_list * va);
 void unserialize_elog_main (serialize_main_t * m, va_list * va);
index 1cf5ba1..6abd334 100644 (file)
@@ -244,7 +244,8 @@ test_elog_main (unformat_input_t * input)
       vec_foreach (e, es)
       {
        clib_warning ("%18.9f: %12U %U\n", e->time,
-                     format_elog_track, em, e, format_elog_event, em, e);
+                     format_elog_track_name, em, e, format_elog_event, em,
+                     e);
       }
     }