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>

1 files changed, 184 insertions, 118 deletions

diff --git a/src/vnet/tcp/tcp_debug.h b/src/vnet/tcp/tcp_debug.h
index a8ddfb627d2..f4e7c39712e 100755
--- 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)			\
 {									\