TCP/session improvements

- Added svm fifo flag for tracking fifo dequeue events (replaces event
  length). Updated all code to switch to the new scheme.
- More session debugging
- Fix peek index wrap
- Add a trivial socket test client
- Fast retransmit/cc fixes
- tx and rx SACK fixes and unit testing
- SRTT computation fix
- remove dupack/ack burst filters
- improve ack rx
- improved segment rx
- builtin client test code

Change-Id: Ic4eb2d5ca446eb2260ccd3ccbcdaa73c64e7f4e1
Signed-off-by: Florin Coras <fcoras@cisco.com>
Signed-off-by: Dave Barach <dbarach@cisco.com>

1 files changed, 214 insertions, 38 deletions

diff --git a/src/vnet/tcp/tcp_debug.h b/src/vnet/tcp/tcp_debug.h
index 069c512da26..5a71694ec13 100644
--- a/src/vnet/tcp/tcp_debug.h
+++ b/src/vnet/tcp/tcp_debug.h
@@ -19,6 +19,8 @@
 #include <vlib/vlib.h>
 
 #define TCP_DEBUG (1)
+#define TCP_DEBUG_CC (1)
+#define TCP_DEBUG_VERBOSE (0)
 
 #define foreach_tcp_dbg_evt		\
   _(INIT, "")				\
@@ -30,14 +32,24 @@
   _(DELETE, "delete")			\
   _(SYN_SENT, "SYN sent")		\
   _(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")		\
   _(PKTIZE, "packetize")		\
   _(INPUT, "in")			\
-  _(TIMER_POP, "timer pop")
+  _(SND_WND, "snd_wnd update")		\
+  _(OUTPUT, "output")			\
+  _(TIMER_POP, "timer pop")		\
+  _(CC_RTX, "retransmit")		\
+  _(CC_EVT, "cc event")			\
+  _(CC_PACK, "cc partial ack")		\
+  _(SEG_INVALID, "invalid segment")	\
+  _(ACK_RCV_ERR, "invalid ack")		\
 
 typedef enum _tcp_dbg
 {
@@ -73,10 +85,10 @@ typedef enum _tcp_dbg_evt
   ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main,			\
 			_e, _tc->c_elog_track)
 
-#define TCP_EVT_INIT_HANDLER(_tc, ...)					\
+#define TCP_EVT_INIT_HANDLER(_tc, _fmt, ...)				\
 {									\
   _tc->c_elog_track.name = 						\
-	(char *) format (0, "%d%c", _tc->c_c_index, 0);			\
+	(char *) format (0, _fmt, _tc->c_c_index, 0);			\
   elog_track_register (&vlib_global_main.elog_main, &_tc->c_elog_track);\
 }
 
@@ -87,7 +99,7 @@ typedef enum _tcp_dbg_evt
 
 #define TCP_EVT_OPEN_HANDLER(_tc, ...)					\
 {									\
-  TCP_EVT_INIT_HANDLER(_tc);						\
+  TCP_EVT_INIT_HANDLER(_tc, "s%d%c");					\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
     .format = "open: index %d",						\
@@ -110,7 +122,7 @@ typedef enum _tcp_dbg_evt
 
 #define TCP_EVT_BIND_HANDLER(_tc, ...)					\
 {									\
-  TCP_EVT_INIT_HANDLER(_tc);						\
+  TCP_EVT_INIT_HANDLER(_tc, "l%d%c");					\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
     .format = "bind: listener %d",					\
@@ -138,16 +150,44 @@ typedef enum _tcp_dbg_evt
     .format = "delete: %d",						\
     .format_args = "i4",						\
   };									\
-  DECLARE_ETD(_tc, _e, 0);						\
+  DECLARE_ETD(_tc, _e, 1);						\
   ed->data[0] = _tc->c_c_index;						\
   TCP_EVT_DEALLOC_HANDLER(_tc);						\
 }
 
+#define TCP_EVT_ACK_SENT_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "ack_prep: acked %u rcv_nxt %u rcv_wnd %u snd_nxt %u",	\
+    .format_args = "i4i4i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 4);						\
+  ed->data[0] = _tc->rcv_nxt - _tc->rcv_las;				\
+  ed->data[1] = _tc->rcv_nxt - _tc->irs;				\
+  ed->data[2] = _tc->rcv_wnd;						\
+  ed->data[3] = _tc->snd_nxt - _tc->iss;				\
+}
+
+#define TCP_EVT_DUPACK_SENT_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "dack_tx: rcv_nxt %u rcv_wnd %u snd_nxt %u av-wnd %u",	\
+    .format_args = "i4i4i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 4);						\
+  ed->data[0] = _tc->rcv_nxt - _tc->irs;				\
+  ed->data[1] = _tc->rcv_wnd;						\
+  ed->data[2] = _tc->snd_nxt - _tc->iss;				\
+  ed->data[3] = tcp_available_wnd(_tc);					\
+}
+
 #define TCP_EVT_SYN_SENT_HANDLER(_tc, ...)				\
 {									\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "SYN: iss %d",						\
+    .format = "SYNtx: iss %u",					\
     .format_args = "i4",						\
   };									\
   DECLARE_ETD(_tc, _e, 1);						\
@@ -158,7 +198,7 @@ typedef enum _tcp_dbg_evt
 {									\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "FIN: snd_nxt %d rcv_nxt %d",				\
+    .format = "FINtx: snd_nxt %d rcv_nxt %d",				\
     .format_args = "i4i4",						\
   };									\
   DECLARE_ETD(_tc, _e, 2);						\
@@ -170,7 +210,7 @@ typedef enum _tcp_dbg_evt
 {									\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "RST: snd_nxt %d rcv_nxt %d",				\
+    .format = "RSTtx: snd_nxt %d rcv_nxt %d",				\
     .format_args = "i4i4",						\
   };									\
   DECLARE_ETD(_tc, _e, 2);						\
@@ -180,10 +220,10 @@ typedef enum _tcp_dbg_evt
 
 #define TCP_EVT_SYN_RCVD_HANDLER(_tc, ...)				\
 {									\
-  TCP_EVT_INIT_HANDLER(_tc);						\
+  TCP_EVT_INIT_HANDLER(_tc, "s%d%c");					\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "SYN rcvd: irs %d",					\
+    .format = "SYNrx: irs %u",						\
     .format_args = "i4",						\
   };									\
   DECLARE_ETD(_tc, _e, 1);						\
@@ -194,7 +234,7 @@ typedef enum _tcp_dbg_evt
 {									\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "FIN rcvd: snd_nxt %d rcv_nxt %d",			\
+    .format = "FINrx: snd_nxt %d rcv_nxt %d",				\
     .format_args = "i4i4",						\
   };									\
   DECLARE_ETD(_tc, _e, 2);						\
@@ -206,7 +246,7 @@ typedef enum _tcp_dbg_evt
 {									\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "RST rcvd: snd_nxt %d rcv_nxt %d",			\
+    .format = "RSTrx: snd_nxt %d rcv_nxt %d",				\
     .format_args = "i4i4",						\
   };									\
   DECLARE_ETD(_tc, _e, 2);						\
@@ -214,54 +254,68 @@ typedef enum _tcp_dbg_evt
   ed->data[1] = _tc->rcv_nxt - _tc->irs;				\
 }
 
-#define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...)				\
+#define TCP_EVT_ACK_RCVD_HANDLER(_tc, _ack, ...)			\
 {									\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "ACK: acked %u cwnd %u inflight %u",			\
-    .format_args = "i4i4i4",						\
+    .format = "acked: %u snd_una %u ack %u cwnd %u inflight %u",	\
+    .format_args = "i4i4i4i4i4",					\
   };									\
-  DECLARE_ETD(_tc, _e, 3);						\
+  DECLARE_ETD(_tc, _e, 5);						\
   ed->data[0] = _tc->bytes_acked;					\
-  ed->data[1] = _tc->cwnd;						\
-  ed->data[2] = tcp_flight_size(_tc);					\
+  ed->data[1] = _tc->snd_una - _tc->iss;				\
+  ed->data[2] = _ack - _tc->iss;					\
+  ed->data[3] = _tc->cwnd;						\
+  ed->data[4] = tcp_flight_size(_tc);					\
 }
 
-#define TCP_EVT_PKTIZE_HANDLER(_tc, ...)				\
+#define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...)				\
 {									\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "pktize: snd_una %u snd_nxt %u una_max %u",		\
-    .format_args = "i4i4i4",						\
+    .format = "dack_rx: snd_una %u cwnd %u snd_wnd %u inflight %u",	\
+    .format_args = "i4i4i4i4",						\
   };									\
-  DECLARE_ETD(_tc, _e, 3);						\
+  DECLARE_ETD(_tc, _e, 4);						\
   ed->data[0] = _tc->snd_una - _tc->iss;				\
-  ed->data[1] = _tc->snd_nxt - _tc->iss;				\
-  ed->data[2] = _tc->snd_una_max - _tc->iss;				\
+  ed->data[1] = _tc->cwnd;						\
+  ed->data[2] = _tc->snd_wnd;						\
+  ed->data[3] = tcp_flight_size(_tc);					\
 }
 
-#define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)			\
+#define TCP_EVT_PKTIZE_HANDLER(_tc, ...)				\
 {									\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "out: flags %x, bytes %u",				\
-    .format_args = "i4i4",						\
+    .format = "pktize: una %u snd_nxt %u space %u flight %u rcv_wnd %u",\
+    .format_args = "i4i4i4i4i4",					\
   };									\
-  DECLARE_ETD(_tc, _e, 2);						\
-  ed->data[0] = flags;							\
-  ed->data[1] = n_bytes;						\
+  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_snd_space (_tc);				\
+  ed->data[3] = tcp_flight_size (_tc);					\
+  ed->data[4] = _tc->rcv_wnd;						\
 }
 
-#define TCP_EVT_INPUT_HANDLER(_tc, n_bytes, ...)			\
+#define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...)		\
 {									\
   ELOG_TYPE_DECLARE (_e) =						\
   {									\
-    .format = "in: bytes %u rcv_nxt %u",				\
-    .format_args = "i4i4",						\
+    .format = "in: %s len %u written %d rcv_nxt %u free wnd %d",	\
+    .format_args = "t4i4i4i4i4",					\
+    .n_enum_strings = 2,                                        	\
+    .enum_strings = {                                           	\
+      "order",   	                                        	\
+      "ooo",   								\
+    },									\
   };									\
-  DECLARE_ETD(_tc, _e, 2);						\
-  ed->data[0] = n_bytes;						\
-  ed->data[1] = _tc->rcv_nxt - _tc->irs;				\
+  DECLARE_ETD(_tc, _e, 5);						\
+  ed->data[0] = _type;							\
+  ed->data[1] = _len;							\
+  ed->data[2] = _written;						\
+  ed->data[3] = (_tc->rcv_nxt - _tc->irs) + _written;			\
+  ed->data[4] = _tc->rcv_wnd - (_tc->rcv_nxt - _tc->rcv_las);		\
 }
 
 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)            \
@@ -296,9 +350,131 @@ typedef enum _tcp_dbg_evt
   ed->data[1] = _timer_id;                                      	\
 }
 
+#define TCP_EVT_SEG_INVALID_HANDLER(_tc, _seq, _end, ...)		\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "seg-inv: seq %u end %u rcv_las %u rcv_nxt %u wnd %u",	\
+    .format_args = "i4i4i4i4i4",					\
+  };									\
+  DECLARE_ETD(_tc, _e, 5);						\
+  ed->data[0] = _seq - _tc->irs;					\
+  ed->data[1] = _end - _tc->irs;					\
+  ed->data[2] = _tc->rcv_las - _tc->irs;				\
+  ed->data[3] = _tc->rcv_nxt - _tc->irs;				\
+  ed->data[4] = _tc->rcv_wnd;						\
+}
+
+#define TCP_EVT_ACK_RCV_ERR_HANDLER(_tc, _type, _ack, ...)		\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "ack-err: %s ack %u snd_una %u snd_nxt %u una_max %u",	\
+    .format_args = "t4i4i4i4i4",					\
+    .n_enum_strings = 3,						\
+    .enum_strings = {                                           	\
+      "invalid",                                                 	\
+      "old",                                                 		\
+      "future",								\
+    }, 									\
+  };									\
+  DECLARE_ETD(_tc, _e, 5);						\
+  ed->data[0] = _type;							\
+  ed->data[1] = _ack - _tc->iss;					\
+  ed->data[2] = _tc->snd_una - _tc->iss;				\
+  ed->data[3] = _tc->snd_nxt - _tc->iss;				\
+  ed->data[4] = _tc->snd_una_max - _tc->iss;				\
+}
+
+/*
+ * Congestion Control
+ */
+
+#if TCP_DEBUG_CC
+#define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)		\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "rtx: snd_nxt %u offset %u snd %u rtx %u",		\
+    .format_args = "i4i4i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 4);						\
+  ed->data[0] = _tc->snd_nxt - _tc->iss;				\
+  ed->data[1] = offset;							\
+  ed->data[2] = n_bytes;						\
+  ed->data[3] = _tc->rtx_bytes;						\
+}
+
+#define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...)			\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "cc: %s wnd %u snd_cong %u rtx_bytes %u",			\
+    .format_args = "t4i4i4i4",						\
+    .n_enum_strings = 5,						\
+    .enum_strings = {                                           	\
+      "fast-rtx",	                                             	\
+      "rtx-timeout",                                                 	\
+      "first-rtx",                                                 	\
+      "recovered",							\
+      "congestion",							\
+    },  								\
+  };									\
+  DECLARE_ETD(_tc, _e, 4);						\
+  ed->data[0] = _sub_evt;						\
+  ed->data[1] = tcp_available_snd_space (_tc);				\
+  ed->data[2] = _tc->snd_congestion - _tc->iss;				\
+  ed->data[3] = _tc->rtx_bytes;						\
+}
+
+#define TCP_EVT_CC_PACK_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "pack: snd_una %u snd_una_max %u",			\
+    .format_args = "i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 2);						\
+  ed->data[0] = _tc->snd_una - _tc->iss;				\
+  ed->data[1] = _tc->snd_una_max - _tc->iss;				\
+}
+
+#else
+#define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)
+#define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, _snd_space, ...)
+#define TCP_EVT_CC_PACK_HANDLER(_tc, ...)
+#endif
+
+#if TCP_DBG_VERBOSE
+#define TCP_EVT_SND_WND_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "snd_wnd update: %u ",					\
+    .format_args = "i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 1);						\
+  ed->data[0] = _tc->snd_wnd;						\
+}
+
+#define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)			\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "out: flags %x, bytes %u",				\
+    .format_args = "i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 2);						\
+  ed->data[0] = flags;							\
+  ed->data[1] = n_bytes;						\
+}
+#else
+#define TCP_EVT_SND_WND_HANDLER(_tc, ...)
+#define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)
+#endif
+
 #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