tcp: add option for always on event logging

Type: feature

Add option to always compile in debugging infra. Debug verbosity can be
controlled via configuration updatable via cli. Compile time inclusion
and configuration of event logging verbosity is still available in order
to minimize event logging impact.

Change-Id: I9d946efe9fa4204fdace1adb1d6588c97b5ae758
Signed-off-by: Florin Coras <fcoras@cisco.com>

diff --git a/src/plugins/unittest/tcp_test.c b/src/plugins/unittest/tcp_test.c
index 6f765e7..940ffcf 100644 (file)
--- a/src/plugins/unittest/tcp_test.c
+++ b/src/plugins/unittest/tcp_test.c
@@ -762,7 +762,7 @@ tcp_test_session (vlib_main_t * vm, unformat_input_t * input)
       tc0->rcv_opts.mss = 1450;
       tcp_connection_init_vars (tc0);
 
-      TCP_EVT_DBG (TCP_EVT_OPEN, tc0);
+      TCP_EVT (TCP_EVT_OPEN, tc0);
 
       if (session_stream_accept (&tc0->connection, 0 /* listener index */ ,
                                 0 /* thread index */ , 0 /* notify */ ))

diff --git a/src/vnet/CMakeLists.txt b/src/vnet/CMakeLists.txt
index beef1c9..3ad53f9 100644 (file)
--- a/src/vnet/CMakeLists.txt
+++ b/src/vnet/CMakeLists.txt
@@ -633,6 +633,7 @@ list(APPEND VNET_SOURCES
   tcp/tcp_newreno.c
   tcp/tcp_cubic.c
   tcp/tcp_bt.c
+  tcp/tcp_debug.c
   tcp/tcp.c
 )
 

diff --git a/src/vnet/tcp/tcp.c b/src/vnet/tcp/tcp.c
index f9cb2a2..bfab1d6 100644 (file)
--- a/src/vnet/tcp/tcp.c
+++ b/src/vnet/tcp/tcp.c
@@ -139,7 +139,7 @@ tcp_connection_bind (u32 session_index, transport_endpoint_t * lcl)
 
   tcp_connection_timers_init (listener);
 
-  TCP_EVT_DBG (TCP_EVT_BIND, listener);
+  TCP_EVT (TCP_EVT_BIND, listener);
 
   return listener->c_c_index;
 }
@@ -158,7 +158,7 @@ tcp_connection_unbind (u32 listener_index)
 
   tc = pool_elt_at_index (tm->listener_pool, listener_index);
 
-  TCP_EVT_DBG (TCP_EVT_UNBIND, tc);
+  TCP_EVT (TCP_EVT_UNBIND, tc);
 
   /* Poison the entry */
   if (CLIB_DEBUG > 0)
@@ -240,7 +240,7 @@ tcp_connection_cleanup (tcp_connection_t * tc)
 {
   tcp_main_t *tm = &tcp_main;
 
-  TCP_EVT_DBG (TCP_EVT_DELETE, tc);
+  TCP_EVT (TCP_EVT_DELETE, tc);
 
   /* Cleanup local endpoint if this was an active connect */
   transport_endpoint_cleanup (TRANSPORT_PROTO_TCP, &tc->c_lcl_ip,
@@ -340,7 +340,7 @@ tcp_connection_free (tcp_connection_t * tc)
 void
 tcp_connection_reset (tcp_connection_t * tc)
 {
-  TCP_EVT_DBG (TCP_EVT_RST_RCVD, tc);
+  TCP_EVT (TCP_EVT_RST_RCVD, tc);
   switch (tc->state)
     {
     case TCP_STATE_SYN_RCVD:
@@ -397,7 +397,7 @@ tcp_connection_reset (tcp_connection_t * tc)
 void
 tcp_connection_close (tcp_connection_t * tc)
 {
-  TCP_EVT_DBG (TCP_EVT_CLOSE, tc);
+  TCP_EVT (TCP_EVT_CLOSE, tc);
 
   /* Send/Program FIN if needed and switch state */
   switch (tc->state)
@@ -767,7 +767,7 @@ tcp_session_open (transport_endpoint_cfg_t * rmt)
   /* The other connection vars will be initialized after SYN ACK */
   tcp_connection_timers_init (tc);
 
-  TCP_EVT_DBG (TCP_EVT_OPEN, tc);
+  TCP_EVT (TCP_EVT_OPEN, tc);
   tc->state = TCP_STATE_SYN_SENT;
   tcp_init_snd_vars (tc);
   tcp_send_syn (tc);
@@ -776,12 +776,6 @@ tcp_session_open (transport_endpoint_cfg_t * rmt)
   return tc->c_c_index;
 }
 
-const char *tcp_dbg_evt_str[] = {
-#define _(sym, str) str,
-  foreach_tcp_dbg_evt
-#undef _
-};
-
 const char *tcp_fsm_states[] = {
 #define _(sym, str) str,
   foreach_tcp_fsm_state
@@ -1401,7 +1395,7 @@ tcp_expired_timers_dispatch (u32 * expired_timers)
       connection_index = expired_timers[i] & 0x0FFFFFFF;
       timer_id = expired_timers[i] >> 28;
 
-      TCP_EVT_DBG (TCP_EVT_TIMER_POP, connection_index, timer_id);
+      TCP_EVT (TCP_EVT_TIMER_POP, connection_index, timer_id);
 
       /* Handle expiration */
       (*timer_expiration_handlers[timer_id]) (connection_index);

diff --git a/src/vnet/tcp/tcp.h b/src/vnet/tcp/tcp.h
index c71b577..cad105b 100644 (file)
--- a/src/vnet/tcp/tcp.h
+++ b/src/vnet/tcp/tcp.h
@@ -697,7 +697,7 @@ always_inline void
 tcp_connection_set_state (tcp_connection_t * tc, tcp_state_t state)
 {
   tc->state = state;
-  TCP_EVT_DBG (TCP_EVT_STATE_CHANGE, tc);
+  TCP_EVT (TCP_EVT_STATE_CHANGE, tc);
 }
 
 void tcp_connection_close (tcp_connection_t * tc);

diff --git a/src/vnet/tcp/tcp_debug.c b/src/vnet/tcp/tcp_debug.c
new file mode 100644 (file)
index 0000000..cf61d22
--- /dev/null
+++ b/src/vnet/tcp/tcp_debug.c
@@ -0,0 +1,127 @@
+/*
+ * Copyright (c) 2019 Cisco and/or its affiliates.
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at:
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+#include <vnet/tcp/tcp_debug.h>
+
+tcp_dbg_main_t tcp_dbg_main;
+
+void
+tcp_evt_track_register (elog_track_t * et)
+{
+  tcp_dbg_main_t *tdm = &tcp_dbg_main;
+  u32 fl_len, track_index;
+
+  fl_len = vec_len (tdm->free_track_indices);
+  if (fl_len)
+    {
+      track_index = tdm->free_track_indices[fl_len - 1];
+      _vec_len (tdm->free_track_indices) -= 1;
+      et->track_index_plus_one = track_index + 1;
+    }
+  else
+    elog_track_register (&vlib_global_main.elog_main, et);
+}
+
+static const char *tcp_evt_grp_str[] = {
+#define _(sym, str) str,
+  foreach_tcp_evt_grp
+#undef _
+};
+
+static void
+tcp_debug_show_groups (void)
+{
+  tcp_dbg_main_t *tdm = &tcp_dbg_main;
+  vlib_main_t *vm = vlib_get_main ();
+  int i = 0;
+
+  vlib_cli_output (vm, "%-10s%-30s%-10s", "Index", "Group", "Level");
+
+  for (i = 0; i < TCP_EVT_N_GRP; i++)
+    vlib_cli_output (vm, "%-10d%-30s%-10d", i, tcp_evt_grp_str[i],
+                    tdm->grp_dbg_lvl[i]);
+}
+
+static clib_error_t *
+tcp_debug_fn (vlib_main_t * vm, unformat_input_t * input,
+             vlib_cli_command_t * cmd)
+{
+  unformat_input_t _line_input, *line_input = &_line_input;
+  tcp_dbg_main_t *tdm = &tcp_dbg_main;
+  u32 group = ~0, level = ~0;
+  clib_error_t *error = 0;
+  u8 is_show = 0;
+
+  if (!TCP_DEBUG_ALWAYS)
+    return clib_error_return (0, "must compile with TCP_DEBUG_ALWAYS set");
+
+  if (!unformat_user (input, unformat_line_input, line_input))
+    return clib_error_return (0, "expected enable | disable");
+
+  while (unformat_check_input (line_input) != UNFORMAT_END_OF_INPUT)
+    {
+      if (unformat (line_input, "show"))
+       is_show = 1;
+      else if (unformat (line_input, "group %d", &group))
+       ;
+      else if (unformat (line_input, "level %d", &level))
+       ;
+      else
+       {
+         error = clib_error_return (0, "unknown input `%U'",
+                                    format_unformat_error, line_input);
+         goto done;
+       }
+    }
+
+  if (is_show)
+    {
+      tcp_debug_show_groups ();
+      goto done;
+    }
+  if (group >= TCP_EVT_N_GRP)
+    {
+      error = clib_error_return (0, "group out of bounds");
+      goto done;
+    }
+  if (group == ~0 || level == ~0)
+    {
+      error = clib_error_return (0, "group and level must be set");
+      goto done;
+    }
+
+  tdm->grp_dbg_lvl[group] = level;
+
+done:
+
+  unformat_free (line_input);
+  return error;
+}
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (tcp_debug_command, static) =
+{
+  .path = "tcp debug",
+  .short_help = "tcp [show] [debug group <N> level <N>]",
+  .function = tcp_debug_fn,
+};
+/* *INDENT-ON* */
+
+/*
+ * fd.io coding-style-patch-verification: ON
+ *
+ * Local Variables:
+ * eval: (c-set-style "gnu")
+ * End:
+ */

diff --git a/src/vnet/tcp/tcp_debug.h b/src/vnet/tcp/tcp_debug.h
index a8ddfb6..f4e7c39 100755 (executable)
--- a/src/vnet/tcp/tcp_debug.h
+++ b/src/vnet/tcp/tcp_debug.h
@@ -18,83 +18,154 @@
 
 #include <vlib/vlib.h>
 
-#define TCP_DEBUG (0)
+/**
+ * Build debugging infra unconditionally. Debug components controlled via
+ * debug configuration. Comes with some overhead so it's not recommended for
+ * production/performance scenarios. Takes priority over TCP_DEBUG_ENABLE.
+ */
+#define TCP_DEBUG_ALWAYS (0)
+/**
+ * Build debugging infra only if enabled. Debug components controlled via
+ * macros that follow.
+ */
+#define TCP_DEBUG_ENABLE (0)
+
 #define TCP_DEBUG_SM (0)
 #define TCP_DEBUG_CC (0)
-#define TCP_DEBUG_CC_STAT (0)
-#define TCP_DEBUG_BUFFER_ALLOCATION (0)
-
-#define foreach_tcp_dbg_evt            \
-  _(INIT, "")                          \
-  _(DEALLOC, "")                       \
-  _(OPEN, "open")                      \
-  _(CLOSE, "close")                    \
-  _(BIND, "bind")                      \
-  _(UNBIND, "unbind")                  \
-  _(DELETE, "delete")                  \
-  _(SYN_SENT, "SYN sent")              \
-  _(SYNACK_SENT, "SYNACK sent")                \
-  _(SYNACK_RCVD, "SYNACK rcvd")                \
-  _(SYN_RXT, "SYN retransmit")         \
-  _(FIN_SENT, "FIN sent")              \
-  _(ACK_SENT, "ACK sent")              \
-  _(DUPACK_SENT, "DUPACK sent")                \
-  _(RST_SENT, "RST sent")              \
-  _(SYN_RCVD, "SYN rcvd")              \
-  _(ACK_RCVD, "ACK rcvd")              \
-  _(DUPACK_RCVD, "DUPACK rcvd")                \
-  _(FIN_RCVD, "FIN rcvd")              \
-  _(RST_RCVD, "RST rcvd")              \
-  _(STATE_CHANGE, "state change")      \
-  _(PKTIZE, "packetize")               \
-  _(INPUT, "in")                       \
-  _(SND_WND, "snd_wnd update")         \
-  _(OUTPUT, "output")                  \
-  _(TIMER_POP, "timer pop")            \
-  _(CC_RTX, "retransmit")              \
-  _(CC_EVT, "cc event")                        \
-  _(CC_PACK, "cc partial ack")         \
-  _(CC_STAT, "cc stats")               \
-  _(CC_RTO_STAT, "cc rto stats")       \
-  _(CC_SCOREBOARD, "scoreboard stats") \
-  _(CC_SACKS, "snd sacks stats")       \
-  _(CC_INPUT, "ooo data delivered")    \
-  _(SEG_INVALID, "invalid segment")    \
-  _(PAWS_FAIL, "failed paws check")    \
-  _(ACK_RCV_ERR, "invalid ack")                \
-  _(RCV_WND_SHRUNK, "shrunk rcv_wnd")  \
-
-typedef enum _tcp_dbg
+#define TCP_DEBUG_CS (0)
+#define TCP_DEBUG_LC (0 || TCP_DEBUG_SM || TCP_DEBUG_CC || TCP_DEBUG_CS)
+
+#define TCP_DEBUG (TCP_DEBUG_ALWAYS || TCP_DEBUG_ENABLE)
+#define TCP_DEBUG_BUF_ALLOC (0)
+
+#if TCP_DEBUG > 0
+#define TRANSPORT_DEBUG (1)
+#endif
+
+#define TCP_CONCAT_HELPER(_a, _b) _a##_b
+#define TCP_CC(_a, _b) TCP_CONCAT_HELPER(_a, _b)
+
+#define tcp_evt_lvl(_evt) TCP_CC(_evt, _LVL)
+#define tcp_evt_grp(_evt) TCP_CC(_evt, _GRP)
+#define tcp_evt_handler(_evt, _args...) TCP_CC(_evt, _HANDLER) (_args)
+#define tcp_evt_grp_dbg_lvl(_evt) tcp_dbg_main.grp_dbg_lvl[tcp_evt_grp (_evt)]
+
+#define foreach_tcp_evt_grp                                    \
+  _(LC, "life cycle")                                          \
+  _(SM, "state machine")                                       \
+  _(CC, "congestion control")                                  \
+  _(CS, "cc stats")                                            \
+
+typedef enum tcp_evt_grp_
+{
+#define _(sym, str) TCP_EVT_GRP_ ## sym,
+  foreach_tcp_evt_grp
+#undef _
+  TCP_EVT_N_GRP
+} tcp_evt_grp_e;
+
+typedef struct tcp_dbg_main_
 {
-#define _(sym, str) TCP_DBG_##sym,
+  u8 grp_dbg_lvl[TCP_EVT_N_GRP];
+  u32 *free_track_indices;
+} tcp_dbg_main_t;
+
+extern tcp_dbg_main_t tcp_dbg_main;
+
+#define foreach_tcp_dbg_evt                                    \
+  _(INIT,              LC, 1, "init")                          \
+  _(DEALLOC,           LC, 1, "dealloc")                       \
+  _(OPEN,              LC, 1, "open")                          \
+  _(CLOSE,             LC, 1, "close")                         \
+  _(BIND,              LC, 1, "bind")                          \
+  _(UNBIND,            LC, 1, "unbind")                        \
+  _(DELETE,            LC, 1, "delete")                        \
+  _(SYN_RCVD,          LC, 1, "SYN rcvd")                      \
+  _(STATE_CHANGE,      LC, 1, "state change")                  \
+  _(SYN_SENT,          SM, 1, "SYN sent")                      \
+  _(SYN_RXT,           SM, 1, "SYN retransmit")                \
+  _(SYNACK_SENT,       SM, 1, "SYNACK sent")                   \
+  _(SYNACK_RCVD,       SM, 1, "SYNACK rcvd")                   \
+  _(FIN_SENT,          SM, 1, "FIN sent")                      \
+  _(FIN_RCVD,          SM, 1, "FIN rcvd")                      \
+  _(RST_SENT,          SM, 1, "RST sent")                      \
+  _(RST_RCVD,          SM, 1, "RST rcvd")                      \
+  _(TIMER_POP,                 SM, 1, "timer pop")                     \
+  _(SEG_INVALID,       SM, 2, "invalid segment")               \
+  _(PAWS_FAIL,                 SM, 2, "failed paws check")             \
+  _(ACK_RCV_ERR,       SM, 2, "invalid ack")                   \
+  _(RCV_WND_SHRUNK,    SM, 2, "shrunk rcv_wnd")                \
+  _(ACK_SENT,          SM, 3, "ACK sent")                      \
+  _(ACK_RCVD,          SM, 3, "ACK rcvd")                      \
+  _(PKTIZE,            SM, 3, "packetize")                     \
+  _(INPUT,             SM, 3, "in")                            \
+  _(OUTPUT,            SM, 4, "output")                        \
+  _(SND_WND,           SM, 4, "snd_wnd update")                \
+  _(CC_EVT,            CC, 1, "cc event")                      \
+  _(CC_RTX,            CC, 2, "retransmit")                    \
+  _(CC_PACK,           CC, 2, "cc partial ack")                \
+  _(DUPACK_SENT,       CC, 2, "DUPACK sent")                   \
+  _(DUPACK_RCVD,       CC, 2, "DUPACK rcvd")                   \
+  _(CC_SCOREBOARD,     CC, 2, "scoreboard stats")              \
+  _(CC_SACKS,          CC, 2, "snd sacks stats")               \
+  _(CC_INPUT,          CC, 2, "ooo data delivered")            \
+  _(CC_STAT,           CS, 1, "cc stats")                      \
+  _(CC_RTO_STAT,       CS, 1, "cc rto stats")                  \
+
+typedef enum tcp_evt_types_
+{
+#define _(sym, grp, lvl, str) TCP_EVT_##sym,
   foreach_tcp_dbg_evt
 #undef _
-} tcp_dbg_e;
+} tcp_evt_types_e;
 
-typedef enum _tcp_dbg_evt
+typedef enum tcp_evt_lvl_
 {
-#define _(sym, str) TCP_EVT_##sym,
+#define _(sym, grp, lvl, str) TCP_EVT_## sym ## _LVL = lvl,
   foreach_tcp_dbg_evt
 #undef _
-} tcp_dbg_evt_e;
+} tcp_evt_lvl_e;
 
-#if TCP_DEBUG
+typedef enum tcp_evt_to_grp_
+{
+#define _(sym, grp, lvl, str) TCP_EVT_ ## sym ## _GRP = TCP_EVT_GRP_ ## grp,
+  foreach_tcp_dbg_evt
+#undef _
+} tcp_evt_to_grp_e;
 
-#define TRANSPORT_DEBUG (1)
+#if TCP_DEBUG_ALWAYS > 0
+#define TCP_EVT(_evt, _args...)                                        \
+  if (PREDICT_FALSE (tcp_evt_grp_dbg_lvl (_evt) >= tcp_evt_lvl (_evt)))        \
+    tcp_evt_handler (_evt, _args)
+#define TCP_DBG(_fmt, _args...) clib_warning (_fmt, ##_args)
+#elif TCP_DEBUG_ENABLE > 0
+#define TCP_EVT(_evt, _args...) tcp_evt_handler(_evt, _args)
+#define TCP_DBG(_fmt, _args...) clib_warning (_fmt, ##_args)
+#else
+#define TCP_EVT(_evt, _args...)
+#define TCP_DBG(_fmt, _args...)
+#endif
+
+void tcp_evt_track_register (elog_track_t * et);
+void tcp_debug_init (void);
+
+#define TCP_DECLARE_ETD(_tc, _e, _size)                                        \
+struct                                                                 \
+{                                                                      \
+  u32 data[_size];                                                     \
+} * ed;                                                                        \
+ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main, _e,                         \
+                      _tc->c_elog_track)                               \
 
 /*
- * Infra and evt track setup
+ * Event handlers definitions
  */
 
-#define TCP_DBG(_fmt, _args...) clib_warning (_fmt, ##_args)
+#if TCP_DEBUG_LC || TCP_DEBUG_ALWAYS
 
-#define DECLARE_ETD(_tc, _e, _size)                                    \
-  struct                                                               \
-  {                                                                    \
-    u32 data[_size];                                                   \
-  } * ed;                                                              \
-  ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main,                   \
-                       _e, _tc->c_elog_track)
+/*
+ * Infra and evt track setup
+ */
 
 #define TCP_DBG_IP_TAG_LCL(_tc)                                                \
 {                                                                      \
@@ -105,7 +176,7 @@ typedef enum _tcp_dbg_evt
         .format = "lcl: %d.%d.%d.%d:%d",                               \
         .format_args = "i4i4i4i4i4",                                   \
       };                                                               \
-      DECLARE_ETD(_tc, _e, 5);                                         \
+      TCP_DECLARE_ETD(_tc, _e, 5);                                     \
       ed->data[0] = _tc->c_lcl_ip.ip4.as_u8[0];                                \
       ed->data[1] = _tc->c_lcl_ip.ip4.as_u8[1];                                \
       ed->data[2] = _tc->c_lcl_ip.ip4.as_u8[2];                                \
@@ -123,7 +194,7 @@ typedef enum _tcp_dbg_evt
         .format = "rmt: %d.%d.%d.%d:%d",                               \
         .format_args = "i4i4i4i4i4",                                   \
       };                                                               \
-      DECLARE_ETD(_tc, _e, 5);                                         \
+      TCP_DECLARE_ETD(_tc, _e, 5);                                     \
       ed->data[0] = _tc->c_rmt_ip.ip4.as_u8[0];                                \
       ed->data[1] = _tc->c_rmt_ip.ip4.as_u8[1];                                \
       ed->data[2] = _tc->c_rmt_ip.ip4.as_u8[2];                                \
@@ -151,7 +222,7 @@ typedef enum _tcp_dbg_evt
                         clib_net_to_host_u16(_tc->c_lcl_port),         \
                         _tc->c_rmt_ip.ip6.as_u8[15],                   \
                         clib_net_to_host_u16(_tc->c_rmt_port), 0);     \
-  elog_track_register (&vlib_global_main.elog_main, &_tc->c_elog_track);\
+  tcp_evt_track_register (&_tc->c_elog_track);                         \
   TCP_DBG_IP_TAG_LCL(_tc);                                             \
   TCP_DBG_IP_TAG_RMT(_tc);                                             \
 }
@@ -159,6 +230,8 @@ typedef enum _tcp_dbg_evt
 #define TCP_EVT_DEALLOC_HANDLER(_tc, ...)                              \
 {                                                                      \
   vec_free (_tc->c_elog_track.name);                                   \
+  vec_add1 (tcp_dbg_main.free_track_indices,                           \
+            _tc->c_elog_track.track_index_plus_one - 1);               \
 }
 
 #define TCP_EVT_OPEN_HANDLER(_tc, ...)                                 \
@@ -169,7 +242,7 @@ typedef enum _tcp_dbg_evt
     .format = "open: index %d",                                                \
     .format_args = "i4",                                               \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 1);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 1);                                         \
   ed->data[0] = _tc->c_c_index;                                                \
 }
 
@@ -180,7 +253,7 @@ typedef enum _tcp_dbg_evt
     .format = "close: cidx %d",                                                \
     .format_args = "i4",                                               \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 1);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 1);                                         \
   ed->data[0] = _tc->c_c_index;                                                \
 }
 
@@ -191,7 +264,7 @@ typedef enum _tcp_dbg_evt
   {                                                                    \
     .format = "bind: listener %d",                                     \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 1);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 1);                                         \
   ed->data[0] = _tc->c_c_index;                                                \
 }
 
@@ -204,7 +277,7 @@ typedef enum _tcp_dbg_evt
     .format = "syn-rx: cidx %u sidx %u irs %u",                                \
     .format_args = "i4i4i4",                                           \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 3);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 3);                                         \
   ed->data[0] = _tc->c_c_index;                                                \
   ed->data[1] = _tc->c_s_index;                                                \
   ed->data[2] = _tc->irs;                                              \
@@ -218,7 +291,7 @@ typedef enum _tcp_dbg_evt
   {                                                                    \
     .format = "unbind: listener %d",                                   \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 1);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 1);                                         \
   ed->data[0] = _tc->c_c_index;                                                \
   TCP_EVT_DEALLOC_HANDLER(_tc);                                                \
 }
@@ -230,24 +303,18 @@ typedef enum _tcp_dbg_evt
     .format = "delete: cidx %d sidx %d",                               \
     .format_args = "i4i4",                                             \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 2);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 2);                                         \
   ed->data[0] = _tc->c_c_index;                                                \
   ed->data[1] = _tc->c_s_index;                                                \
   TCP_EVT_DEALLOC_HANDLER(_tc);                                                \
 }
 
-#define CONCAT_HELPER(_a, _b) _a##_b
-#define CC(_a, _b) CONCAT_HELPER(_a, _b)
-#define TCP_EVT_DBG(_evt, _args...) CC(_evt, _HANDLER)(_args)
-#else
-#define TCP_EVT_DBG(_evt, _args...)
-#define TCP_DBG(_fmt, _args...)
 #endif
 
 /*
  * State machine
  */
-#if TCP_DEBUG_SM
+#if TCP_DEBUG_SM > 0 || TCP_DEBUG_ALWAYS
 
 #define TCP_EVT_STATE_CHANGE_HANDLER(_tc, ...)                         \
 {                                                                      \
@@ -270,7 +337,7 @@ typedef enum _tcp_dbg_evt
       "time-wait",                                                     \
     },                                                                 \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 1);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 1);                                         \
   ed->data[0] = _tc->state;                                            \
 }
 
@@ -281,7 +348,7 @@ typedef enum _tcp_dbg_evt
     .format = "syn-tx: iss %u snd_una %u snd_una_max %u snd_nxt %u",   \
     .format_args = "i4i4i4i4",                                         \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 4);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 4);                                         \
   ed->data[0] = _tc->iss;                                              \
   ed->data[1] = _tc->snd_una - _tc->iss;                               \
   ed->data[2] = _tc->snd_una_max - _tc->iss;                           \
@@ -296,7 +363,7 @@ typedef enum _tcp_dbg_evt
     .format = "synack-tx: iss %u irs %u snd_una %u snd_nxt %u rcv_nxt %u",\
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _tc->iss;                                              \
   ed->data[1] = _tc->irs;                                              \
   ed->data[2] = _tc->snd_una - _tc->iss;                               \
@@ -311,7 +378,7 @@ typedef enum _tcp_dbg_evt
     .format = "synack-rx: iss %u irs %u snd_una %u snd_nxt %u rcv_nxt %u",\
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _tc->iss;                                              \
   ed->data[1] = _tc->irs;                                              \
   ed->data[2] = _tc->snd_una - _tc->iss;                               \
@@ -327,7 +394,7 @@ typedef enum _tcp_dbg_evt
     .format = "fin-tx: snd_nxt %d rcv_nxt %d",                         \
     .format_args = "i4i4",                                             \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 2);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 2);                                         \
   ed->data[0] = _tc->snd_nxt - _tc->iss;                               \
   ed->data[1] = _tc->rcv_nxt - _tc->irs;                               \
 }
@@ -341,7 +408,7 @@ if (_tc)                                                            \
       .format = "rst-tx: snd_nxt %d rcv_nxt %d",                       \
       .format_args = "i4i4",                                           \
     };                                                                 \
-    DECLARE_ETD(_tc, _e, 2);                                           \
+    TCP_DECLARE_ETD(_tc, _e, 2);                                       \
     ed->data[0] = _tc->snd_nxt - _tc->iss;                             \
     ed->data[1] = _tc->rcv_nxt - _tc->irs;                             \
     TCP_EVT_STATE_CHANGE_HANDLER(_tc);                                 \
@@ -355,7 +422,7 @@ if (_tc)                                                            \
     .format = "fin-rx: snd_nxt %d rcv_nxt %d",                         \
     .format_args = "i4i4",                                             \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 2);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 2);                                         \
   ed->data[0] = _tc->snd_nxt - _tc->iss;                               \
   ed->data[1] = _tc->rcv_nxt - _tc->irs;                               \
 }
@@ -367,7 +434,7 @@ if (_tc)                                                            \
     .format = "rst-rx: snd_nxt %d rcv_nxt %d",                         \
     .format_args = "i4i4",                                             \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 2);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 2);                                         \
   ed->data[0] = _tc->snd_nxt - _tc->iss;                               \
   ed->data[1] = _tc->rcv_nxt - _tc->irs;                               \
 }
@@ -384,7 +451,7 @@ if (_tc)                                                            \
         "synack",                                                      \
     },                                                                 \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _type;                                                 \
   ed->data[1] = _tc->iss;                                              \
   ed->data[2] = _tc->irs;                                              \
@@ -395,8 +462,7 @@ if (_tc)                                                            \
 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)            \
 {                                                                      \
   tcp_connection_t *_tc;                                               \
-  if (_timer_id == TCP_TIMER_RETRANSMIT_SYN                            \
-      || _timer_id == TCP_TIMER_ESTABLISH_AO)                          \
+  if (_timer_id == TCP_TIMER_RETRANSMIT_SYN)                           \
     {                                                                  \
       _tc = tcp_half_open_connection_get (_tc_index);                  \
     }                                                                  \
@@ -423,7 +489,7 @@ if (_tc)                                                            \
   };                                                                   \
   if (_tc)                                                             \
     {                                                                  \
-      DECLARE_ETD(_tc, _e, 3);                                         \
+      TCP_DECLARE_ETD(_tc, _e, 3);                                      \
       ed->data[0] = _timer_id;                                         \
       ed->data[1] = _tc->c_c_index;                                            \
       ed->data[2] = _tc->c_s_index;                                            \
@@ -448,7 +514,7 @@ if (_tc)                                                            \
 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)
 #endif
 
-#if TCP_DEBUG_SM > 1
+#if TCP_DEBUG_SM > 1 || TCP_DEBUG_ALWAYS
 #define TCP_EVT_SEG_INVALID_HANDLER(_tc, _btcp, ...)                   \
 {                                                                      \
   ELOG_TYPE_DECLARE (_e) =                                             \
@@ -456,7 +522,7 @@ if (_tc)                                                            \
     .format = "seg-inv: seq %u end %u rcv_las %u rcv_nxt %u rcv_wnd %u",\
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _btcp.seq_number - _tc->irs;                           \
   ed->data[1] = _btcp.seq_end - _tc->irs;                              \
   ed->data[2] = _tc->rcv_las - _tc->irs;                               \
@@ -471,7 +537,7 @@ if (_tc)                                                            \
     .format = "paws-err: seq %u end %u tsval %u tsval_recent %u",      \
     .format_args = "i4i4i4i4",                                         \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 4);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 4);                                         \
   ed->data[0] = _seq - _tc->irs;                                       \
   ed->data[1] = _end - _tc->irs;                                       \
   ed->data[2] = _tc->rcv_opts.tsval;                                   \
@@ -491,7 +557,7 @@ if (_tc)                                                            \
       "future",                                                                \
     },                                                                         \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _type;                                                 \
   ed->data[1] = _ack - _tc->iss;                                       \
   ed->data[2] = _tc->snd_una - _tc->iss;                               \
@@ -508,7 +574,7 @@ if (_av > 0)                                                                \
     .format = "huh?: rcv_wnd %u obsd %u av %u rcv_nxt %u rcv_las %u",  \
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _tc->rcv_wnd;                                          \
   ed->data[1] = _obs;                                                  \
   ed->data[2] = _av;                                                   \
@@ -523,7 +589,7 @@ if (_av > 0)                                                                \
 #define TCP_EVT_RCV_WND_SHRUNK_HANDLER(_tc, _obs, _av, ...)
 #endif
 
-#if TCP_DEBUG_SM > 2
+#if TCP_DEBUG_SM > 2 || TCP_DEBUG_ALWAYS
 
 #define TCP_EVT_ACK_SENT_HANDLER(_tc, ...)                             \
 {                                                                      \
@@ -532,7 +598,7 @@ if (_av > 0)                                                                \
     .format = "ack-tx: acked %u rcv_nxt %u rcv_wnd %u snd_nxt %u snd_wnd %u",\
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _tc->rcv_nxt - _tc->rcv_las;                           \
   ed->data[1] = _tc->rcv_nxt - _tc->irs;                               \
   ed->data[2] = _tc->rcv_wnd;                                          \
@@ -547,7 +613,7 @@ if (_av > 0)                                                                \
     .format = "ack-rx: %u snd_una %u snd_wnd %u cwnd %u inflight %u",  \
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _tc->bytes_acked;                                      \
   ed->data[1] = _tc->snd_una - _tc->iss;                               \
   ed->data[2] = _tc->snd_wnd;                                          \
@@ -562,7 +628,7 @@ if (_av > 0)                                                                \
     .format = "tx: una %u snd_nxt %u space %u flight %u rcv_wnd %u",\
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _tc->snd_una - _tc->iss;                               \
   ed->data[1] = _tc->snd_nxt - _tc->iss;                               \
   ed->data[2] = tcp_available_output_snd_space (_tc);                  \
@@ -582,7 +648,7 @@ if (_av > 0)                                                                \
       "ooo",                                                                   \
     },                                                                 \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _type;                                                 \
   ed->data[1] = _len;                                                  \
   ed->data[2] = _written;                                              \
@@ -600,7 +666,7 @@ if (_av > 0)                                                                \
 /*
  * State machine verbose
  */
-#if TCP_DEBUG_SM > 3
+#if TCP_DEBUG_SM > 3 || TCP_DEBUG_ALWAYS
 #define TCP_EVT_SND_WND_HANDLER(_tc, ...)                              \
 {                                                                      \
   ELOG_TYPE_DECLARE (_e) =                                             \
@@ -608,7 +674,7 @@ if (_av > 0)                                                                \
     .format = "snd-wnd update: %u ",                                   \
     .format_args = "i4",                                               \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 1);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 1);                                         \
   ed->data[0] = _tc->snd_wnd;                                          \
 }
 
@@ -619,7 +685,7 @@ if (_av > 0)                                                                \
     .format = "out: flags %x, bytes %u",                               \
     .format_args = "i4i4",                                             \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 2);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 2);                                         \
   ed->data[0] = flags;                                                 \
   ed->data[1] = n_bytes;                                               \
 }
@@ -632,7 +698,7 @@ if (_av > 0)                                                                \
  * Congestion Control
  */
 
-#if TCP_DEBUG_CC
+#if TCP_DEBUG_CC || TCP_DEBUG_ALWAYS
 
 #define TCP_EVT_CC_EVT_PRINT(_tc, _sub_evt)                            \
 {                                                                      \
@@ -651,7 +717,7 @@ if (_av > 0)                                                                \
       "recovery",                                                      \
     },                                                                 \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _sub_evt;                                              \
   ed->data[1] = tcp_available_cc_snd_space (_tc);                      \
   ed->data[2] = _tc->snd_una - _tc->iss;                               \
@@ -672,7 +738,7 @@ if (_av > 0)                                                                \
 
 #endif
 
-#if TCP_DEBUG_CC > 1
+#if TCP_DEBUG_CC > 1 || TCP_DEBUG_ALWAYS
 #define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)              \
 {                                                                      \
   ELOG_TYPE_DECLARE (_e) =                                             \
@@ -680,7 +746,7 @@ if (_av > 0)                                                                \
     .format = "rxt: snd_nxt %u offset %u snd %u rxt %u",               \
     .format_args = "i4i4i4i4",                                         \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 4);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 4);                                         \
   ed->data[0] = _tc->snd_nxt - _tc->iss;                               \
   ed->data[1] = offset;                                                        \
   ed->data[2] = n_bytes;                                               \
@@ -694,7 +760,7 @@ if (_av > 0)                                                                \
     .format = "dack-tx: rcv_nxt %u seq %u rcv_wnd %u snd_nxt %u av_wnd %u",\
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _tc->rcv_nxt - _tc->irs;                               \
   ed->data[1] = _btcp.seq_number - _tc->irs;                           \
   ed->data[2] = _tc->rcv_wnd;                                          \
@@ -709,7 +775,7 @@ if (_av > 0)                                                                \
     .format = "dack-rx: snd_una %u cwnd %u snd_wnd %u flight %u rcv_wnd %u",\
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _tc->snd_una - _tc->iss;                               \
   ed->data[1] = _tc->cwnd;                                             \
   ed->data[2] = _tc->snd_wnd;                                          \
@@ -724,7 +790,7 @@ if (_av > 0)                                                                \
     .format = "pack: snd_una %u snd_una_max %u",                       \
     .format_args = "i4i4",                                             \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 2);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 2);                                         \
   ed->data[0] = _tc->snd_una - _tc->iss;                               \
   ed->data[1] = _tc->snd_una_max - _tc->iss;                           \
 }
@@ -737,7 +803,7 @@ if (TCP_DEBUG_CC > 1 && _tc->sack_sb.last_sacked_bytes)                     \
       .format = "sb1: holes %u lost %u sacked %u high %u highrxt %u",  \
       .format_args = "i4i4i4i4i4",                                     \
     };                                                                 \
-    DECLARE_ETD(_tc, _e, 5);                                           \
+    TCP_DECLARE_ETD(_tc, _e, 5);                                       \
     ed->data[0] = pool_elts(_tc->sack_sb.holes);                       \
     ed->data[1] = _tc->sack_sb.lost_bytes;                             \
     ed->data[2] = _tc->sack_sb.sacked_bytes;                           \
@@ -753,7 +819,7 @@ if (TCP_DEBUG_CC > 1 && _tc->sack_sb.last_sacked_bytes)                     \
       .format = "sb2: first start: %u end %u last start %u end %u",    \
       .format_args = "i4i4i4i4",                                       \
     };                                                                 \
-    DECLARE_ETD(_tc, _e, 4);                                           \
+    TCP_DECLARE_ETD(_tc, _e, 4);                                       \
     ed->data[0] = hole ? hole->start - _tc->iss : 0;                   \
     ed->data[1] = hole ? hole->end - _tc->iss : 0;                     \
     hole = scoreboard_last_hole (&_tc->sack_sb);                       \
@@ -770,7 +836,7 @@ if (TCP_DEBUG_CC > 1)                                                       \
       .format = "sacks: blocks %u bytes %u",                           \
       .format_args = "i4i4",                                           \
     };                                                                 \
-    DECLARE_ETD(_tc, _e, 2);                                           \
+    TCP_DECLARE_ETD(_tc, _e, 2);                                       \
     ed->data[0] = vec_len (_tc->snd_sacks);                            \
     ed->data[1] = tcp_sack_list_bytes (_tc);                           \
   }                                                                    \
@@ -782,7 +848,7 @@ if (TCP_DEBUG_CC > 1)                                                       \
     .format = "cc input: len %u written %d rcv_nxt %u rcv_wnd(o) %d",  \
     .format_args = "i4i4i4i4",                                         \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 4);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 4);                                         \
   ed->data[0] = _len;                                                  \
   ed->data[1] = _written;                                              \
   ed->data[2] = _tc->rcv_nxt - _tc->irs;                               \
@@ -801,7 +867,7 @@ if (TCP_DEBUG_CC > 1)                                                       \
 /*
  * Congestion control stats
  */
-#if TCP_DEBUG_CC_STAT
+#if TCP_DEBUG_CS || TCP_DEBUG_ALWAYS
 
 #define STATS_INTERVAL 1
 
@@ -816,7 +882,7 @@ if (TCP_DEBUG_CC > 1)                                                       \
     .format = "rcv_stat: rto %u srtt %u mrtt-us %u rttvar %u",         \
     .format_args = "i4i4i4i4",                                         \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 4);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 4);                                         \
   ed->data[0] = _tc->rto;                                              \
   ed->data[1] = _tc->srtt;                                             \
   ed->data[2] = (u32) (_tc->mrtt_us * 1e6);                            \
@@ -839,7 +905,7 @@ if (tcp_cc_time_to_print_stats (_tc))                                       \
     .format = "snd_stat: cc_space %u sacked %u lost %u out %u rxt %u", \
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = tcp_available_cc_snd_space (_tc);                      \
   ed->data[1] = _tc->sack_sb.sacked_bytes;                             \
   ed->data[2] = _tc->sack_sb.lost_bytes;                               \
@@ -863,7 +929,7 @@ if (tcp_cc_time_to_print_stats (_tc))                                       \
     .format = "cc_stat: cwnd %u flight %u space %u ssthresh %u snd_wnd %u",\
     .format_args = "i4i4i4i4i4",                                       \
   };                                                                   \
-  DECLARE_ETD(_tc, _e, 5);                                             \
+  TCP_DECLARE_ETD(_tc, _e, 5);                                         \
   ed->data[0] = _tc->cwnd;                                             \
   ed->data[1] = tcp_flight_size (_tc);                                 \
   ed->data[2] = tcp_snd_space (_tc);                                   \
@@ -889,7 +955,7 @@ if (tcp_cc_time_to_print_stats (_tc))                                       \
 /*
  * Buffer allocation
  */
-#if TCP_DEBUG_BUFFER_ALLOCATION
+#if TCP_DEBUG_BUF_ALLOC
 
 #define TCP_DBG_BUFFER_ALLOC_MAYBE_FAIL(thread_index)                  \
 {                                                                      \

diff --git a/src/vnet/tcp/tcp_input.c b/src/vnet/tcp/tcp_input.c
index b9480ca..0b1ac73 100755 (executable)
--- a/src/vnet/tcp/tcp_input.c
+++ b/src/vnet/tcp/tcp_input.c
@@ -300,8 +300,8 @@ tcp_segment_validate (tcp_worker_ctx_t * wrk, tcp_connection_t * tc0,
   if (PREDICT_FALSE (tcp_segment_check_paws (tc0)))
     {
       *error0 = TCP_ERROR_PAWS;
-      TCP_EVT_DBG (TCP_EVT_PAWS_FAIL, tc0, vnet_buffer (b0)->tcp.seq_number,
-                  vnet_buffer (b0)->tcp.seq_end);
+      TCP_EVT (TCP_EVT_PAWS_FAIL, tc0, vnet_buffer (b0)->tcp.seq_number,
+              vnet_buffer (b0)->tcp.seq_end);
 
       /* If it just so happens that a segment updates tsval_recent for a
        * segment over 24 days old, invalidate tsval_recent. */
@@ -318,7 +318,7 @@ tcp_segment_validate (tcp_worker_ctx_t * wrk, tcp_connection_t * tc0,
       else if (!tcp_rst (th0))
        {
          tcp_program_ack (tc0);
-         TCP_EVT_DBG (TCP_EVT_DUPACK_SENT, tc0, vnet_buffer (b0)->tcp);
+         TCP_EVT (TCP_EVT_DUPACK_SENT, tc0, vnet_buffer (b0)->tcp);
          goto error;
        }
     }
@@ -335,13 +335,13 @@ tcp_segment_validate (tcp_worker_ctx_t * wrk, tcp_connection_t * tc0,
          if (tc0->state == TCP_STATE_SYN_RCVD)
            {
              tcp_send_synack (tc0);
-             TCP_EVT_DBG (TCP_EVT_SYN_RCVD, tc0, 0);
+             TCP_EVT (TCP_EVT_SYN_RCVD, tc0, 0);
              *error0 = TCP_ERROR_SYNS_RCVD;
            }
          else
            {
              tcp_program_ack (tc0);
-             TCP_EVT_DBG (TCP_EVT_SYNACK_RCVD, tc0);
+             TCP_EVT (TCP_EVT_SYNACK_RCVD, tc0);
              *error0 = TCP_ERROR_SYN_ACKS_RCVD;
            }
          goto error;
@@ -372,7 +372,7 @@ tcp_segment_validate (tcp_worker_ctx_t * wrk, tcp_connection_t * tc0,
       if (!tcp_rst (th0))
        {
          tcp_program_dupack (tc0);
-         TCP_EVT_DBG (TCP_EVT_DUPACK_SENT, tc0, vnet_buffer (b0)->tcp);
+         TCP_EVT (TCP_EVT_DUPACK_SENT, tc0, vnet_buffer (b0)->tcp);
        }
       goto error;
 
@@ -1118,7 +1118,7 @@ tcp_rcv_sacks (tcp_connection_t * tc, u32 ack)
          || sb->holes[sb->head].start == ack + sb->snd_una_adv);
   ASSERT (sb->last_lost_bytes <= sb->lost_bytes);
 
-  TCP_EVT_DBG (TCP_EVT_CC_SCOREBOARD, tc);
+  TCP_EVT (TCP_EVT_CC_SCOREBOARD, tc);
 }
 #endif /* CLIB_MARCH_VARIANT */
 
@@ -1139,7 +1139,7 @@ tcp_update_snd_wnd (tcp_connection_t * tc, u32 seq, u32 ack, u32 snd_wnd)
       tc->snd_wnd = snd_wnd;
       tc->snd_wl1 = seq;
       tc->snd_wl2 = ack;
-      TCP_EVT_DBG (TCP_EVT_SND_WND, tc);
+      TCP_EVT (TCP_EVT_SND_WND, tc);
 
       if (PREDICT_FALSE (tc->snd_wnd < tc->snd_mss))
        {
@@ -1178,7 +1178,7 @@ tcp_cc_init_congestion (tcp_connection_t * tc)
   tc->prev_cwnd = tc->cwnd;
   tc->cc_algo->congestion (tc);
   tc->fr_occurences += 1;
-  TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 4);
+  TCP_EVT (TCP_EVT_CC_EVT, tc, 4);
 }
 #endif /* CLIB_MARCH_VARIANT */
 
@@ -1190,7 +1190,7 @@ tcp_cc_recovery_exit (tcp_connection_t * tc)
   tc->snd_rxt_ts = 0;
   tc->rtt_ts = 0;
   tcp_recovery_off (tc);
-  TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 3);
+  TCP_EVT (TCP_EVT_CC_EVT, tc, 3);
 }
 
 #ifndef CLIB_MARCH_VARIANT
@@ -1205,7 +1205,7 @@ tcp_cc_fastrecovery_clear (tcp_connection_t * tc)
   tcp_fastrecovery_first_off (tc);
   tc->flags &= ~TCP_CONN_FRXT_PENDING;
 
-  TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 3);
+  TCP_EVT (TCP_EVT_CC_EVT, tc, 3);
 }
 #endif /* CLIB_MARCH_VARIANT */
 
@@ -1226,7 +1226,7 @@ tcp_cc_congestion_undo (tcp_connection_t * tc)
     }
   tcp_cc_undo_recovery (tc);
   ASSERT (tc->rto_boff == 0);
-  TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 5);
+  TCP_EVT (TCP_EVT_CC_EVT, tc, 5);
 }
 
 static inline u8
@@ -1332,7 +1332,7 @@ tcp_cc_handle_event (tcp_connection_t * tc, tcp_rate_sample_t * rs,
    */
   else if (is_dack && !tcp_in_recovery (tc))
     {
-      TCP_EVT_DBG (TCP_EVT_DUPACK_RCVD, tc, 1);
+      TCP_EVT (TCP_EVT_DUPACK_RCVD, tc, 1);
       ASSERT (tc->snd_una != tc->snd_nxt || tc->sack_sb.last_sacked_bytes);
 
       tc->rcv_dupacks++;
@@ -1418,7 +1418,7 @@ tcp_cc_handle_event (tcp_connection_t * tc, tcp_rate_sample_t * rs,
     return;
 
 partial_ack:
-  TCP_EVT_DBG (TCP_EVT_CC_PACK, tc);
+  TCP_EVT (TCP_EVT_CC_PACK, tc);
 
   /*
    * Legitimate ACK. 1) See if we can exit recovery
@@ -1514,7 +1514,7 @@ tcp_rcv_ack (tcp_worker_ctx_t * wrk, tcp_connection_t * tc, vlib_buffer_t * b,
   tcp_rate_sample_t rs = { 0 };
   u8 is_dack;
 
-  TCP_EVT_DBG (TCP_EVT_CC_STAT, tc);
+  TCP_EVT (TCP_EVT_CC_STAT, tc);
 
   /* If the ACK acks something not yet sent (SEG.ACK > SND.NXT) */
   if (PREDICT_FALSE (seq_gt (vnet_buffer (b)->tcp.ack_number, tc->snd_nxt)))
@@ -1530,8 +1530,7 @@ tcp_rcv_ack (tcp_worker_ctx_t * wrk, tcp_connection_t * tc, vlib_buffer_t * b,
 
       tc->errors.above_ack_wnd += 1;
       *error = TCP_ERROR_ACK_FUTURE;
-      TCP_EVT_DBG (TCP_EVT_ACK_RCV_ERR, tc, 0,
-                  vnet_buffer (b)->tcp.ack_number);
+      TCP_EVT (TCP_EVT_ACK_RCV_ERR, tc, 0, vnet_buffer (b)->tcp.ack_number);
       return -1;
     }
 
@@ -1540,8 +1539,7 @@ tcp_rcv_ack (tcp_worker_ctx_t * wrk, tcp_connection_t * tc, vlib_buffer_t * b,
     {
       tc->errors.below_ack_wnd += 1;
       *error = TCP_ERROR_ACK_OLD;
-      TCP_EVT_DBG (TCP_EVT_ACK_RCV_ERR, tc, 1,
-                  vnet_buffer (b)->tcp.ack_number);
+      TCP_EVT (TCP_EVT_ACK_RCV_ERR, tc, 1, vnet_buffer (b)->tcp.ack_number);
       if (tcp_in_fastrecovery (tc) && tc->rcv_dupacks == TCP_DUPACK_THRESHOLD)
        tcp_cc_handle_event (tc, 0, 1);
       /* Don't drop yet */
@@ -1575,7 +1573,7 @@ process_ack:
   if (tc->flags & TCP_CONN_RATE_SAMPLE)
     tcp_bt_sample_delivery_rate (tc, &rs);
 
-  TCP_EVT_DBG (TCP_EVT_ACK_RCVD, tc);
+  TCP_EVT (TCP_EVT_ACK_RCVD, tc);
 
   /*
    * Check if we have congestion event
@@ -1651,7 +1649,7 @@ tcp_rcv_fin (tcp_worker_ctx_t * wrk, tcp_connection_t * tc, vlib_buffer_t * b,
   tcp_connection_set_state (tc, TCP_STATE_CLOSE_WAIT);
   tcp_program_disconnect (wrk, tc);
   tcp_timer_update (tc, TCP_TIMER_WAITCLOSE, tcp_cfg.closewait_time);
-  TCP_EVT_DBG (TCP_EVT_FIN_RCVD, tc);
+  TCP_EVT (TCP_EVT_FIN_RCVD, tc);
   *error = TCP_ERROR_FIN_RCVD;
 }
 
@@ -1751,7 +1749,7 @@ tcp_session_enqueue_data (tcp_connection_t * tc, vlib_buffer_t * b,
                                               1 /* queue event */ , 1);
   tc->bytes_in += written;
 
-  TCP_EVT_DBG (TCP_EVT_INPUT, tc, 0, data_len, written);
+  TCP_EVT (TCP_EVT_INPUT, tc, 0, data_len, written);
 
   /* Update rcv_nxt */
   if (PREDICT_TRUE (written == data_len))
@@ -1762,7 +1760,7 @@ tcp_session_enqueue_data (tcp_connection_t * tc, vlib_buffer_t * b,
   else if (written > data_len)
     {
       tc->rcv_nxt += written;
-      TCP_EVT_DBG (TCP_EVT_CC_INPUT, tc, data_len, written);
+      TCP_EVT (TCP_EVT_CC_INPUT, tc, data_len, written);
     }
   else if (written > 0)
     {
@@ -1805,11 +1803,11 @@ tcp_session_enqueue_ooo (tcp_connection_t * tc, vlib_buffer_t * b,
   /* Nothing written */
   if (rv)
     {
-      TCP_EVT_DBG (TCP_EVT_INPUT, tc, 1, data_len, 0);
+      TCP_EVT (TCP_EVT_INPUT, tc, 1, data_len, 0);
       return TCP_ERROR_FIFO_FULL;
     }
 
-  TCP_EVT_DBG (TCP_EVT_INPUT, tc, 1, data_len, data_len);
+  TCP_EVT (TCP_EVT_INPUT, tc, 1, data_len, data_len);
   tc->bytes_in += data_len;
 
   /* Update SACK list if in use */
@@ -1830,7 +1828,7 @@ tcp_session_enqueue_ooo (tcp_connection_t * tc, vlib_buffer_t * b,
          end = start + ooo_segment_length (s0->rx_fifo, newest);
          tcp_update_sack_list (tc, start, end);
          svm_fifo_newest_ooo_segment_reset (s0->rx_fifo);
-         TCP_EVT_DBG (TCP_EVT_CC_SACKS, tc);
+         TCP_EVT (TCP_EVT_CC_SACKS, tc);
        }
     }
 
@@ -1933,7 +1931,7 @@ tcp_segment_rcv (tcp_worker_ctx_t * wrk, tcp_connection_t * tc,
       /* RFC2581: Enqueue and send DUPACK for fast retransmit */
       error = tcp_session_enqueue_ooo (tc, b, n_data_bytes);
       tcp_program_dupack (tc);
-      TCP_EVT_DBG (TCP_EVT_DUPACK_SENT, tc, vnet_buffer (b)->tcp);
+      TCP_EVT (TCP_EVT_DUPACK_SENT, tc, vnet_buffer (b)->tcp);
       tc->errors.above_data_wnd += seq_gt (vnet_buffer (b)->tcp.seq_end,
                                           tc->rcv_las + tc->rcv_wnd);
       goto done;
@@ -2133,7 +2131,7 @@ tcp46_established_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
       /* 1-4: check SEQ, RST, SYN */
       if (PREDICT_FALSE (tcp_segment_validate (wrk, tc0, b0, th0, &error0)))
        {
-         TCP_EVT_DBG (TCP_EVT_SEG_INVALID, tc0, vnet_buffer (b0)->tcp);
+         TCP_EVT (TCP_EVT_SEG_INVALID, tc0, vnet_buffer (b0)->tcp);
          goto done;
        }
 
@@ -2487,7 +2485,7 @@ tcp46_syn_sent_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
            transport_tx_fifo_size (&new_tc0->connection);
          /* Update rtt with the syn-ack sample */
          tcp_estimate_initial_rtt (new_tc0);
-         TCP_EVT_DBG (TCP_EVT_SYNACK_RCVD, new_tc0);
+         TCP_EVT (TCP_EVT_SYNACK_RCVD, new_tc0);
          error0 = TCP_ERROR_SYN_ACKS_RCVD;
        }
       /* SYN: Simultaneous open. Change state to SYN-RCVD and send SYN-ACK */
@@ -2500,7 +2498,7 @@ tcp46_syn_sent_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
            {
              tcp_connection_cleanup (new_tc0);
              tcp_send_reset_w_pkt (tc0, b0, my_thread_index, is_ip4);
-             TCP_EVT_DBG (TCP_EVT_RST_SENT, tc0);
+             TCP_EVT (TCP_EVT_RST_SENT, tc0);
              error0 = TCP_ERROR_CREATE_SESSION_FAIL;
              goto drop;
            }
@@ -2698,7 +2696,7 @@ tcp46_rcv_process_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
 
          /* Switch state to ESTABLISHED */
          tc0->state = TCP_STATE_ESTABLISHED;
-         TCP_EVT_DBG (TCP_EVT_STATE_CHANGE, tc0);
+         TCP_EVT (TCP_EVT_STATE_CHANGE, tc0);
 
          /* Initialize session variables */
          tc0->snd_una = vnet_buffer (b0)->tcp.ack_number;
@@ -2887,7 +2885,7 @@ tcp46_rcv_process_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
       if (!is_fin0)
        goto drop;
 
-      TCP_EVT_DBG (TCP_EVT_FIN_RCVD, tc0);
+      TCP_EVT (TCP_EVT_FIN_RCVD, tc0);
 
       switch (tc0->state)
        {
@@ -3155,7 +3153,7 @@ tcp46_listen_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
          goto drop;
        }
 
-      TCP_EVT_DBG (TCP_EVT_SYN_RCVD, child0, 1);
+      TCP_EVT (TCP_EVT_SYN_RCVD, child0, 1);
       child0->tx_fifo_size = transport_tx_fifo_size (&child0->connection);
       tcp_send_synack (child0);
 

diff --git a/src/vnet/tcp/tcp_output.c b/src/vnet/tcp/tcp_output.c
index 2200760..862f4a2 100644 (file)
--- a/src/vnet/tcp/tcp_output.c
+++ b/src/vnet/tcp/tcp_output.c
@@ -147,7 +147,7 @@ tcp_update_rcv_wnd (tcp_connection_t * tc)
   if (PREDICT_FALSE ((i32) available_space < observed_wnd))
     {
       wnd = clib_max (observed_wnd, 0);
-      TCP_EVT_DBG (TCP_EVT_RCV_WND_SHRUNK, tc, observed_wnd, available_space);
+      TCP_EVT (TCP_EVT_RCV_WND_SHRUNK, tc, observed_wnd, available_space);
     }
   else
     {
@@ -514,7 +514,7 @@ static inline void
 tcp_make_ack (tcp_connection_t * tc, vlib_buffer_t * b)
 {
   tcp_make_ack_i (tc, b, TCP_STATE_ESTABLISHED, TCP_FLAG_ACK);
-  TCP_EVT_DBG (TCP_EVT_ACK_SENT, tc);
+  TCP_EVT (TCP_EVT_ACK_SENT, tc);
   tc->rcv_las = tc->rcv_nxt;
 }
 
@@ -834,7 +834,7 @@ tcp_send_reset_w_pkt (tcp_connection_t * tc, vlib_buffer_t * pkt,
     }
 
   tcp_enqueue_to_ip_lookup_now (wrk, b, bi, is_ip4, fib_index);
-  TCP_EVT_DBG (TCP_EVT_RST_SENT, tc);
+  TCP_EVT (TCP_EVT_RST_SENT, tc);
   vlib_node_increment_counter (vm, tcp_node_index (output, tc->c_is_ip4),
                               TCP_ERROR_RST_SENT, 1);
 }
@@ -869,7 +869,7 @@ tcp_send_reset (tcp_connection_t * tc)
   ASSERT (opts_write_len == tc->snd_opts_len);
   vnet_buffer (b)->tcp.connection_index = tc->c_c_index;
   tcp_enqueue_to_output (wrk, b, bi, tc->c_is_ip4);
-  TCP_EVT_DBG (TCP_EVT_RST_SENT, tc);
+  TCP_EVT (TCP_EVT_RST_SENT, tc);
   vlib_node_increment_counter (vm, tcp_node_index (output, tc->c_is_ip4),
                               TCP_ERROR_RST_SENT, 1);
 }
@@ -938,7 +938,7 @@ tcp_send_syn (tcp_connection_t * tc)
 
   tcp_push_ip_hdr (wrk, tc, b);
   tcp_enqueue_to_ip_lookup (wrk, b, bi, tc->c_is_ip4, tc->c_fib_index);
-  TCP_EVT_DBG (TCP_EVT_SYN_SENT, tc);
+  TCP_EVT (TCP_EVT_SYN_SENT, tc);
 }
 
 void
@@ -962,7 +962,7 @@ tcp_send_synack (tcp_connection_t * tc)
   tcp_init_buffer (vm, b);
   tcp_make_synack (tc, b);
   tcp_enqueue_to_output (wrk, b, bi, tc->c_is_ip4);
-  TCP_EVT_DBG (TCP_EVT_SYNACK_SENT, tc);
+  TCP_EVT (TCP_EVT_SYNACK_SENT, tc);
 }
 
 /**
@@ -1041,7 +1041,7 @@ tcp_send_fin (tcp_connection_t * tc)
   tcp_init_buffer (vm, b);
   tcp_make_fin (tc, b);
   tcp_enqueue_to_output_now (wrk, b, bi, tc->c_is_ip4);
-  TCP_EVT_DBG (TCP_EVT_FIN_SENT, tc);
+  TCP_EVT (TCP_EVT_FIN_SENT, tc);
   /* Account for the FIN */
   tc->snd_nxt += 1;
   if (!fin_snt)
@@ -1115,7 +1115,7 @@ tcp_push_hdr_i (tcp_connection_t * tc, vlib_buffer_t * b, u32 snd_nxt,
   tc->bytes_out += data_len;
   tc->data_segs_out += 1;
 
-  TCP_EVT_DBG (TCP_EVT_PKTIZE, tc);
+  TCP_EVT (TCP_EVT_PKTIZE, tc);
 }
 
 u32
@@ -1411,7 +1411,7 @@ tcp_prepare_retransmit_segment (tcp_worker_ctx_t * wrk,
 
   tc->bytes_retrans += n_bytes;
   tc->segs_retrans += 1;
-  TCP_EVT_DBG (TCP_EVT_CC_RTX, tc, offset, n_bytes);
+  TCP_EVT (TCP_EVT_CC_RTX, tc, offset, n_bytes);
   return n_bytes;
 }
 
@@ -1421,7 +1421,7 @@ tcp_prepare_retransmit_segment (tcp_worker_ctx_t * wrk,
 static void
 tcp_cc_init_rxt_timeout (tcp_connection_t * tc)
 {
-  TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 6);
+  TCP_EVT (TCP_EVT_CC_EVT, tc, 6);
   tc->prev_ssthresh = tc->ssthresh;
   tc->prev_cwnd = tc->cwnd;
 
@@ -1466,7 +1466,7 @@ tcp_timer_retransmit_handler (u32 tc_index)
 
   if (tc->state >= TCP_STATE_ESTABLISHED)
     {
-      TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 2);
+      TCP_EVT (TCP_EVT_CC_EVT, tc, 2);
 
       /* Lost FIN, retransmit and return */
       if (tc->flags & TCP_CONN_FINSNT)
@@ -1548,7 +1548,7 @@ tcp_timer_retransmit_handler (u32 tc_index)
   /* Retransmit SYN-ACK */
   else if (tc->state == TCP_STATE_SYN_RCVD)
     {
-      TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 2);
+      TCP_EVT (TCP_EVT_CC_EVT, tc, 2);
 
       tc->rtt_ts = 0;
 
@@ -1576,7 +1576,7 @@ tcp_timer_retransmit_handler (u32 tc_index)
       b = vlib_get_buffer (vm, bi);
       tcp_init_buffer (vm, b);
       tcp_make_synack (tc, b);
-      TCP_EVT_DBG (TCP_EVT_SYN_RXT, tc, 1);
+      TCP_EVT (TCP_EVT_SYN_RXT, tc, 1);
 
       /* Retransmit timer already updated, just enqueue to output */
       tcp_enqueue_to_output (wrk, b, bi, tc->c_is_ip4);
@@ -1619,7 +1619,7 @@ tcp_timer_retransmit_syn_handler (u32 tc_index)
       return;
     }
 
-  TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 2);
+  TCP_EVT (TCP_EVT_CC_EVT, tc, 2);
   tc->rtt_ts = 0;
 
   /* Active open establish timeout */
@@ -1646,7 +1646,7 @@ tcp_timer_retransmit_syn_handler (u32 tc_index)
   tcp_init_buffer (vm, b);
   tcp_make_syn (tc, b);
 
-  TCP_EVT_DBG (TCP_EVT_SYN_RXT, tc, 0);
+  TCP_EVT (TCP_EVT_SYN_RXT, tc, 0);
 
   /* This goes straight to ipx_lookup */
   tcp_push_ip_hdr (wrk, tc, b);
@@ -1748,7 +1748,7 @@ tcp_retransmit_first_unacked (tcp_worker_ctx_t * wrk, tcp_connection_t * tc)
   vlib_buffer_t *b;
   u32 bi, n_bytes;
 
-  TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 1);
+  TCP_EVT (TCP_EVT_CC_EVT, tc, 1);
 
   n_bytes = tcp_prepare_retransmit_segment (wrk, tc, 0, tc->snd_mss, &b);
   if (!n_bytes)
@@ -1820,7 +1820,7 @@ tcp_fast_retransmit_sack (tcp_worker_ctx_t * wrk, tcp_connection_t * tc,
       return 0;
     }
 
-  TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 0);
+  TCP_EVT (TCP_EVT_CC_EVT, tc, 0);
   sb = &tc->sack_sb;
   hole = scoreboard_get_hole (sb, sb->cur_rxt_hole);
 
@@ -1911,7 +1911,7 @@ tcp_fast_retransmit_no_sack (tcp_worker_ctx_t * wrk, tcp_connection_t * tc,
   vlib_buffer_t *b;
 
   ASSERT (tcp_in_fastrecovery (tc));
-  TCP_EVT_DBG (TCP_EVT_CC_EVT, tc, 0);
+  TCP_EVT (TCP_EVT_CC_EVT, tc, 0);
 
   snd_space = tcp_available_cc_snd_space (tc);
 
@@ -2142,7 +2142,7 @@ tcp_output_push_ip (vlib_main_t * vm, vlib_buffer_t * b0,
   tcp_header_t *th0 = 0;
 
   th0 = vlib_buffer_get_current (b0);
-  TCP_EVT_DBG (TCP_EVT_OUTPUT, tc0, th0->flags, b0->current_length);
+  TCP_EVT (TCP_EVT_OUTPUT, tc0, th0->flags, b0->current_length);
   if (is_ip4)
     {
       vlib_buffer_push_ip4 (vm, b0, &tc0->c_lcl_ip4, &tc0->c_rmt_ip4,