VPP-659 Improve tcp/session debugging and testing

- event-logging support for tcp and session layer
- improvements to uri test code
- builtin_server on port 1234
- use the CLOSEWAIT timer when we rx FIN in FIN_WAIT_2 state

Change-Id: Ibc445f164b2086b20323bf89c77cffd3059f570f
Signed-off-by: Florin Coras <fcoras@cisco.com>
Signed-off-by: Dave Barach <dbarach@cisco.com>
Signed-off-by: Dave Barach <dave@barachs.net>

15 files changed, 636 insertions, 181 deletions

diff --git a/src/scripts/vnet/uri/dpdk_setup.cli b/src/scripts/vnet/uri/dpdk_setup.cli
new file mode 100644
index 00000000..02bba58f
--- /dev/null
+++ b/src/scripts/vnet/uri/dpdk_setup.cli
@@ -0,0 +1,4 @@
+set int state GigabitEthernet1b/0/0 up
+set int ip address GigabitEthernet1b/0/0 6.0.1.1/24
+trace add dpdk-input 10
+session enable
diff --git a/src/uri/uri_tcp_test.c b/src/uri/uri_tcp_test.c
index 261fd288..406a5f4e 100644
--- a/src/uri/uri_tcp_test.c
+++ b/src/uri/uri_tcp_test.c
@@ -848,13 +848,21 @@ server_test (uri_tcp_test_main_t * utm)
   fformat (stdout, "Test complete...\n");
 }
 
-#define foreach_uri_msg                         \
-_(BIND_URI_REPLY, bind_uri_reply)               \
-_(UNBIND_URI_REPLY, unbind_uri_reply)           \
-_(ACCEPT_SESSION, accept_session)               \
-_(CONNECT_URI_REPLY, connect_uri_reply)         \
-_(DISCONNECT_SESSION, disconnect_session)       \
-_(RESET_SESSION, reset_session)       		\
+static void
+vl_api_disconnect_session_reply_t_handler (vl_api_disconnect_session_reply_t *
+					   mp)
+{
+  clib_warning ("retval %d", ntohl (mp->retval));
+}
+
+#define foreach_uri_msg                                 \
+_(BIND_URI_REPLY, bind_uri_reply)                       \
+_(UNBIND_URI_REPLY, unbind_uri_reply)                   \
+_(ACCEPT_SESSION, accept_session)                       \
+_(CONNECT_URI_REPLY, connect_uri_reply)                 \
+_(DISCONNECT_SESSION, disconnect_session)               \
+_(DISCONNECT_SESSION_REPLY, disconnect_session_reply)   \
+_(RESET_SESSION, reset_session)                         \
 _(MAP_ANOTHER_SEGMENT, map_another_segment)
 
 void
@@ -877,8 +885,9 @@ main (int argc, char **argv)
   uri_tcp_test_main_t *utm = &uri_tcp_test_main;
   unformat_input_t _argv, *a = &_argv;
   u8 *chroot_prefix;
-  u8 *heap;
-  u8 *bind_name = (u8 *) "tcp://0.0.0.0/1234";
+  u8 *heap, *uri = 0;
+  u8 *bind_uri = (u8 *) "tcp://0.0.0.0/1234";
+  u8 *connect_uri = (u8 *) "tcp://6.0.1.2/1234";
   u32 tmp;
   mheap_t *h;
   session_t *session;
@@ -911,7 +920,7 @@ main (int argc, char **argv)
 	{
 	  vl_set_memory_root_path ((char *) chroot_prefix);
 	}
-      else if (unformat (a, "uri %s", &bind_name))
+      else if (unformat (a, "uri %s", &uri))
 	;
       else if (unformat (a, "segment-size %dM", &tmp))
 	utm->configured_segment_size = tmp << 20;
@@ -932,12 +941,21 @@ main (int argc, char **argv)
 	}
     }
 
-  utm->uri = format (0, "%s%c", bind_name, 0);
+  if (uri)
+    {
+      utm->uri = format (0, "%s%c", uri, 0);
+      utm->connect_uri = format (0, "%s%c", uri, 0);
+    }
+  else
+    {
+      utm->uri = format (0, "%s%c", bind_uri, 0);
+      utm->connect_uri = format (0, "%s%c", connect_uri, 0);
+    }
+
   utm->i_am_master = i_am_master;
   utm->segment_main = &svm_fifo_segment_main;
   utm->drop_packets = drop_packets;
   utm->test_return_packets = test_return_packets;
-  utm->connect_uri = format (0, "tcp://6.0.1.2/1234%c", 0);
 
   setup_signal_handlers ();
   uri_api_hookup (utm);
@@ -952,6 +970,7 @@ main (int argc, char **argv)
   if (i_am_master == 0)
     {
       client_test (utm);
+      vl_client_disconnect_from_vlib ();
       exit (0);
     }
 
diff --git a/src/vnet.am b/src/vnet.am
index bc9655cc..223d5d93 100644
--- a/src/vnet.am
+++ b/src/vnet.am
@@ -469,6 +469,7 @@ libvnet_la_SOURCES +=				\
 nobase_include_HEADERS +=			\
  vnet/tcp/tcp_packet.h				\
  vnet/tcp/tcp_timer.h				\
+ vnet/tcp/tcp_debug.h				\
  vnet/tcp/tcp.h
 
 ########################################
@@ -837,6 +838,7 @@ nobase_include_HEADERS +=			\
   vnet/session/application.h			\
   vnet/session/transport.h			\
   vnet/session/application_interface.h		\
+  vnet/session/session_debug.h			\
   vnet/session/session.api.h
 
 API_FILES += vnet/session/session.api
diff --git a/src/vnet/session/node.c b/src/vnet/session/node.c
index 7fd7e0b7..822afebd 100644
--- a/src/vnet/session/node.c
+++ b/src/vnet/session/node.c
@@ -26,8 +26,8 @@
 #include <vlibmemory/unix_shared_memory_queue.h>
 
 #include <vnet/udp/udp_packet.h>
-#include <vnet/lisp-cp/packets.h>
 #include <math.h>
+#include <vnet/session/session_debug.h>
 
 vlib_node_registration_t session_queue_node;
 
@@ -198,22 +198,12 @@ session_tx_fifo_read_and_snd_i (vlib_main_t * vm, vlib_node_runtime_t * node,
 	  len_to_deq0 = (left_to_snd0 < snd_mss0) ? left_to_snd0 : snd_mss0;
 
 	  /* *INDENT-OFF* */
-	  if (1)
-	    {
-	      ELOG_TYPE_DECLARE (e) = {
-		  .format = "evt-deq: id %d len %d rd %d wnd %d",
-		  .format_args = "i4i4i4i4",
-	      };
-	      struct
-	      {
-		u32 data[4];
-	      } *ed;
-	      ed = ELOG_DATA (&vm->elog_main, e);
+	  SESSION_EVT_DBG(s0, SESSION_EVT_DEQ, ({
 	      ed->data[0] = e0->event_id;
 	      ed->data[1] = e0->enqueue_length;
 	      ed->data[2] = len_to_deq0;
 	      ed->data[3] = left_to_snd0;
-	    }
+	  }));
 	  /* *INDENT-ON* */
 
 	  /* Make room for headers */
@@ -392,7 +382,7 @@ skip_dequeue:
 	case FIFO_EVENT_SERVER_TX:
 	  /* Spray packets in per session type frames, since they go to
 	   * different nodes */
-	  rv = (smm->session_rx_fns[s0->session_type]) (vm, node, smm, e0, s0,
+	  rv = (smm->session_tx_fns[s0->session_type]) (vm, node, smm, e0, s0,
 							my_thread_index,
 							&n_tx_packets);
 	  if (rv < 0)
diff --git a/src/vnet/session/session.c b/src/vnet/session/session.c
index 8867e794..06e2a09a 100644
--- a/src/vnet/session/session.c
+++ b/src/vnet/session/session.c
@@ -23,6 +23,7 @@
 #include <vnet/fib/ip4_fib.h>
 #include <vnet/session/application.h>
 #include <vnet/tcp/tcp.h>
+#include <vnet/session/session_debug.h>
 
 /**
  * Per-type vector of transport protocol virtual function tables
@@ -823,19 +824,12 @@ stream_session_enqueue_notify (stream_session_t * s, u8 block)
   else
     return -1;
 
-  if (1)
-    {
-      ELOG_TYPE_DECLARE (e) =
-      {
-      .format = "evt-enqueue: id %d length %d",.format_args = "i4i4",};
-      struct
-      {
-	u32 data[2];
-      } *ed;
-      ed = ELOG_DATA (&vlib_global_main.elog_main, e);
+  /* *INDENT-OFF* */
+  SESSION_EVT_DBG(s, SESSION_EVT_ENQ, ({
       ed->data[0] = evt.event_id;
       ed->data[1] = evt.enqueue_length;
-    }
+  }));
+  /* *INDENT-ON* */
 
   return 0;
 }
@@ -908,8 +902,7 @@ stream_session_start_listen (u32 server_index, ip46_address_t * ip, u16 port)
   s->app_index = srv->index;
 
   /* Transport bind/listen  */
-  tci = tp_vfts[srv->session_type].bind (smm->vlib_main, s->session_index, ip,
-					 port);
+  tci = tp_vfts[srv->session_type].bind (s->session_index, ip, port);
 
   /* Attach transport to session */
   s->connection_index = tci;
@@ -938,8 +931,7 @@ stream_session_stop_listen (u32 server_index)
   tc = tp_vfts[srv->session_type].get_listener (listener->connection_index);
   stream_session_table_del_for_tc (smm, listener->session_type, tc);
 
-  tp_vfts[srv->session_type].unbind (smm->vlib_main,
-				     listener->connection_index);
+  tp_vfts[srv->session_type].unbind (listener->connection_index);
   pool_put (smm->listen_sessions[srv->session_type], listener);
 }
 
@@ -1235,7 +1227,7 @@ session_register_transport (u8 type, const transport_proto_vft_t * vft)
   tp_vfts[type] = *vft;
 
   /* If an offset function is provided, then peek instead of dequeue */
-  smm->session_rx_fns[type] =
+  smm->session_tx_fns[type] =
     (vft->tx_fifo_offset) ? session_tx_fifo_peek_and_snd :
     session_tx_fifo_dequeue_and_snd;
 }
diff --git a/src/vnet/session/session.h b/src/vnet/session/session.h
index 1b712e2e..96c00d87 100644
--- a/src/vnet/session/session.h
+++ b/src/vnet/session/session.h
@@ -211,7 +211,7 @@ struct _session_manager_main
   session_manager_t *session_managers;
 
   /** Per transport rx function that can either dequeue or peek */
-  session_fifo_rx_fn *session_rx_fns[SESSION_N_TYPES];
+  session_fifo_rx_fn *session_tx_fns[SESSION_N_TYPES];
 
   u8 is_enabled;
 
@@ -358,6 +358,7 @@ u32 stream_session_dequeue_drop (transport_connection_t * tc, u32 max_bytes);
 void
 stream_session_connect_notify (transport_connection_t * tc, u8 sst,
 			       u8 is_fail);
+
 void stream_session_accept_notify (transport_connection_t * tc);
 void stream_session_disconnect_notify (transport_connection_t * tc);
 void stream_session_delete_notify (transport_connection_t * tc);
diff --git a/src/vnet/session/session_debug.h b/src/vnet/session/session_debug.h
new file mode 100644
index 00000000..858f12e0
--- /dev/null
+++ b/src/vnet/session/session_debug.h
@@ -0,0 +1,86 @@
+/*
+ * Copyright (c) 2017 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.
+ */
+#ifndef SRC_VNET_SESSION_SESSION_DEBUG_H_
+#define SRC_VNET_SESSION_SESSION_DEBUG_H_
+
+#include <vnet/session/transport.h>
+#include <vnet/session/session.h>
+#include <vlib/vlib.h>
+
+#define foreach_session_dbg_evt		\
+  _(ENQ, "enqueue")			\
+  _(DEQ, "dequeue")
+
+typedef enum _session_evt_dbg
+{
+#define _(sym, str) SESSION_EVT_##sym,
+  foreach_session_dbg_evt
+#undef _
+} session_evt_dbg_e;
+
+#if TRANSPORT_DEBUG
+
+#define DEC_SESSION_ETD(_s, _e, _size)					\
+  struct								\
+  {									\
+    u32 data[_size];							\
+  } * ed;								\
+  transport_proto_vft_t *vft = 						\
+      session_get_transport_vft (_s->session_type);			\
+  transport_connection_t *_tc = 					\
+      vft->get_connection (_s->connection_index, _s->thread_index);	\
+  ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main,			\
+			_e, _tc->elog_track)
+
+
+#define SESSION_EVT_DEQ_HANDLER(_s, _body)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "deq: id %d len %d rd %d wnd %d",				\
+    .format_args = "i4i4i4i4",						\
+  };									\
+  DEC_SESSION_ETD(_s, _e, 4);						\
+  do { _body; } while (0);						\
+}
+
+#define SESSION_EVT_ENQ_HANDLER(_s, _body)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "enq: id %d length %d",					\
+    .format_args = "i4i4",						\
+  };									\
+  DEC_SESSION_ETD(_s, _e, 2);						\
+  do { _body; } while (0);						\
+}
+
+#define CONCAT_HELPER(_a, _b) _a##_b
+#define CC(_a, _b) CONCAT_HELPER(_a, _b)
+
+#define SESSION_EVT_DBG(_s, _evt, _body) CC(_evt, _HANDLER)(_s, _body)
+
+#else
+#define SESSION_EVT_DBG(_s, _evt, _body)
+#endif
+
+#endif /* SRC_VNET_SESSION_SESSION_DEBUG_H_ */
+/*
+ * fd.io coding-style-patch-verification: ON
+ *
+ * Local Variables:
+ * eval: (c-set-style "gnu")
+ * End:
+ */
diff --git a/src/vnet/session/transport.h b/src/vnet/session/transport.h
index 0da30261..421121d2 100644
--- a/src/vnet/session/transport.h
+++ b/src/vnet/session/transport.h
@@ -20,7 +20,7 @@
 #include <vnet/ip/ip.h>
 #include <vppinfra/bihash_16_8.h>
 #include <vppinfra/bihash_48_8.h>
-
+#include <vnet/tcp/tcp_debug.h>
 /*
  * Protocol independent transport properties associated to a session
  */
@@ -37,6 +37,10 @@ typedef struct _transport_connection
   u8 is_ip4;			/**< Flag if IP4 connection */
   u32 thread_index;		/**< Worker-thread index */
 
+#if TRANSPORT_DEBUG
+  elog_track_t elog_track;	/**< Debug purposes */
+#endif
+
   /** Macros for 'derived classes' where base is named "connection" */
 #define c_lcl_ip connection.lcl_ip
 #define c_rmt_ip connection.rmt_ip
@@ -52,6 +56,7 @@ typedef struct _transport_connection
 #define c_c_index connection.c_index
 #define c_is_ip4 connection.is_ip4
 #define c_thread_index connection.thread_index
+#define c_elog_track connection.elog_track
 } transport_connection_t;
 
 /*
@@ -62,8 +67,8 @@ typedef struct _transport_proto_vft
   /*
    * Setup
    */
-  u32 (*bind) (vlib_main_t *, u32, ip46_address_t *, u16);
-  u32 (*unbind) (vlib_main_t *, u32);
+  u32 (*bind) (u32, ip46_address_t *, u16);
+  u32 (*unbind) (u32);
   int (*open) (ip46_address_t * addr, u16 port_host_byte_order);
   void (*close) (u32 conn_index, u32 thread_index);
   void (*cleanup) (u32 conn_index, u32 thread_index);
@@ -89,7 +94,6 @@ typedef struct _transport_proto_vft
   u8 *(*format_connection) (u8 * s, va_list * args);
   u8 *(*format_listener) (u8 * s, va_list * args);
   u8 *(*format_half_open) (u8 * s, va_list * args);
-
 } transport_proto_vft_t;
 
 /* *INDENT-OFF* */
diff --git a/src/vnet/tcp/builtin_server.c b/src/vnet/tcp/builtin_server.c
index 9b697a01..dd6759c5 100644
--- a/src/vnet/tcp/builtin_server.c
+++ b/src/vnet/tcp/builtin_server.c
@@ -160,7 +160,7 @@ server_create (vlib_main_t * vm)
   memset (a, 0, sizeof (*a));
   memset (options, 0, sizeof (options));
 
-  a->uri = "tcp://0.0.0.0/80";
+  a->uri = "tcp://0.0.0.0/1234";
   a->api_client_index = ~0;
   a->session_cb_vft = &builtin_session_cb_vft;
   a->options = options;
diff --git a/src/vnet/tcp/tcp.c b/src/vnet/tcp/tcp.c
index d2df5c3e..0d2e6d0e 100644
--- a/src/vnet/tcp/tcp.c
+++ b/src/vnet/tcp/tcp.c
@@ -21,7 +21,7 @@
 tcp_main_t tcp_main;
 
 static u32
-tcp_connection_bind (vlib_main_t * vm, u32 session_index, ip46_address_t * ip,
+tcp_connection_bind (u32 session_index, ip46_address_t * ip,
 		     u16 port_host_byte_order, u8 is_ip4)
 {
   tcp_main_t *tm = &tcp_main;
@@ -43,42 +43,41 @@ tcp_connection_bind (vlib_main_t * vm, u32 session_index, ip46_address_t * ip,
   listener->state = TCP_STATE_LISTEN;
   listener->c_is_ip4 = 1;
 
+  tcp_connection_timers_init (listener);
+
+  TCP_EVT_DBG (TCP_EVT_BIND, listener);
+
   return listener->c_c_index;
 }
 
 u32
-tcp_session_bind_ip4 (vlib_main_t * vm, u32 session_index,
-		      ip46_address_t * ip, u16 port_host_byte_order)
+tcp_session_bind_ip4 (u32 session_index, ip46_address_t * ip,
+		      u16 port_host_byte_order)
 {
-  return tcp_connection_bind (vm, session_index, ip, port_host_byte_order, 1);
+  return tcp_connection_bind (session_index, ip, port_host_byte_order, 1);
 }
 
 u32
-tcp_session_bind_ip6 (vlib_main_t * vm, u32 session_index,
-		      ip46_address_t * ip, u16 port_host_byte_order)
+tcp_session_bind_ip6 (u32 session_index, ip46_address_t * ip,
+		      u16 port_host_byte_order)
 {
-  return tcp_connection_bind (vm, session_index, ip, port_host_byte_order, 0);
+  return tcp_connection_bind (session_index, ip, port_host_byte_order, 0);
 
 }
 
 static void
-tcp_session_unbind (u32 listener_index)
+tcp_connection_unbind (u32 listener_index)
 {
   tcp_main_t *tm = vnet_get_tcp_main ();
+  TCP_EVT_DBG (TCP_EVT_UNBIND,
+	       pool_elt_at_index (tm->listener_pool, listener_index));
   pool_put_index (tm->listener_pool, listener_index);
 }
 
 u32
-tcp_session_unbind_ip4 (vlib_main_t * vm, u32 listener_index)
-{
-  tcp_session_unbind (listener_index);
-  return 0;
-}
-
-u32
-tcp_session_unbind_ip6 (vlib_main_t * vm, u32 listener_index)
+tcp_session_unbind (u32 listener_index)
 {
-  tcp_session_unbind (listener_index);
+  tcp_connection_unbind (listener_index);
   return 0;
 }
 
@@ -135,6 +134,7 @@ tcp_connection_cleanup (tcp_connection_t * tc)
 void
 tcp_connection_del (tcp_connection_t * tc)
 {
+  TCP_EVT_DBG (TCP_EVT_DELETE, tc);
   stream_session_delete_notify (&tc->connection);
   tcp_connection_cleanup (tc);
 }
@@ -169,6 +169,8 @@ tcp_connection_reset (tcp_connection_t * tc)
 void
 tcp_connection_close (tcp_connection_t * tc)
 {
+  TCP_EVT_DBG (TCP_EVT_CLOSE, tc);
+
   /* Send FIN if needed */
   if (tc->state == TCP_STATE_ESTABLISHED || tc->state == TCP_STATE_SYN_RCVD
       || tc->state == TCP_STATE_CLOSE_WAIT)
@@ -403,6 +405,8 @@ tcp_connection_open (ip46_address_t * rmt_addr, u16 rmt_port, u8 is_ip4)
 
   tc->state = TCP_STATE_SYN_SENT;
 
+  TCP_EVT_DBG (TCP_EVT_OPEN, tc);
+
   return tc->c_c_index;
 }
 
@@ -418,82 +422,119 @@ tcp_session_open_ip6 (ip46_address_t * addr, u16 port)
   return tcp_connection_open (addr, port, 0);
 }
 
+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
+#undef _
+};
+
 u8 *
-format_tcp_session_ip4 (u8 * s, va_list * args)
+format_tcp_state (u8 * s, va_list * args)
 {
-  u32 tci = va_arg (*args, u32);
-  u32 thread_index = va_arg (*args, u32);
-  tcp_connection_t *tc;
+  tcp_state_t *state = va_arg (*args, tcp_state_t *);
 
-  tc = tcp_connection_get (tci, thread_index);
+  if (*state < TCP_N_STATES)
+    s = format (s, "%s", tcp_fsm_states[*state]);
+  else
+    s = format (s, "UNKNOWN");
+
+  return s;
+}
+
+const char *tcp_conn_timers[] = {
+#define _(sym, str) str,
+  foreach_tcp_timer
+#undef _
+};
+
+u8 *
+format_tcp_timers (u8 * s, va_list * args)
+{
+  tcp_connection_t *tc = va_arg (*args, tcp_connection_t *);
+  int i, last = 0;
 
-  s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip4_address,
-	      &tc->c_lcl_ip4, clib_net_to_host_u16 (tc->c_lcl_port),
-	      format_ip4_address, &tc->c_rmt_ip4,
-	      clib_net_to_host_u16 (tc->c_rmt_port));
+  for (i = 0; i < TCP_N_TIMERS; i++)
+    if (tc->timers[i] != TCP_TIMER_HANDLE_INVALID)
+      last = i;
+
+  s = format (s, "[");
+  for (i = 0; i < last; i++)
+    {
+      if (tc->timers[i] != TCP_TIMER_HANDLE_INVALID)
+	s = format (s, "%s,", tcp_conn_timers[i]);
+    }
+
+  if (last > 0)
+    s = format (s, "%s]", tcp_conn_timers[i]);
+  else
+    s = format (s, "]");
 
   return s;
 }
 
 u8 *
-format_tcp_session_ip6 (u8 * s, va_list * args)
+format_tcp_connection (u8 * s, va_list * args)
 {
-  u32 tci = va_arg (*args, u32);
-  u32 thread_index = va_arg (*args, u32);
-  tcp_connection_t *tc = tcp_connection_get (tci, thread_index);
-  s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip6_address,
-	      &tc->c_lcl_ip6, clib_net_to_host_u16 (tc->c_lcl_port),
-	      format_ip6_address, &tc->c_rmt_ip6,
-	      clib_net_to_host_u16 (tc->c_rmt_port));
+  tcp_connection_t *tc = va_arg (*args, tcp_connection_t *);
+
+  if (tc->c_is_ip4)
+    {
+      s = format (s, "[#%d][%s] %U:%d->%U:%d", tc->c_thread_index, "T",
+		  format_ip4_address, &tc->c_lcl_ip4,
+		  clib_net_to_host_u16 (tc->c_lcl_port), format_ip4_address,
+		  &tc->c_rmt_ip4, clib_net_to_host_u16 (tc->c_rmt_port));
+    }
+  else
+    {
+      s = format (s, "[#%d][%s] %U:%d->%U:%d", tc->c_thread_index, "T",
+		  format_ip6_address, &tc->c_lcl_ip6,
+		  clib_net_to_host_u16 (tc->c_lcl_port), format_ip6_address,
+		  &tc->c_rmt_ip6, clib_net_to_host_u16 (tc->c_rmt_port));
+    }
+
   return s;
 }
 
 u8 *
-format_tcp_listener_session_ip4 (u8 * s, va_list * args)
+format_tcp_connection_verbose (u8 * s, va_list * args)
 {
-  u32 tci = va_arg (*args, u32);
-  tcp_connection_t *tc = tcp_listener_get (tci);
-  s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip4_address,
-	      &tc->c_lcl_ip4, clib_net_to_host_u16 (tc->c_lcl_port),
-	      format_ip4_address, &tc->c_rmt_ip4,
-	      clib_net_to_host_u16 (tc->c_rmt_port));
+  tcp_connection_t *tc = va_arg (*args, tcp_connection_t *);
+  s = format (s, "%U %U %U", format_tcp_connection, tc, format_tcp_state,
+	      &tc->state, format_tcp_timers, tc);
   return s;
 }
 
 u8 *
-format_tcp_listener_session_ip6 (u8 * s, va_list * args)
+format_tcp_session (u8 * s, va_list * args)
 {
   u32 tci = va_arg (*args, u32);
-  tcp_connection_t *tc = tcp_listener_get (tci);
-  s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip6_address,
-	      &tc->c_lcl_ip6, clib_net_to_host_u16 (tc->c_lcl_port),
-	      format_ip6_address, &tc->c_rmt_ip6,
-	      clib_net_to_host_u16 (tc->c_rmt_port));
-  return s;
+  u32 thread_index = va_arg (*args, u32);
+  tcp_connection_t *tc;
+
+  tc = tcp_connection_get (tci, thread_index);
+  return format (s, "%U", format_tcp_connection, tc);
 }
 
 u8 *
-format_tcp_half_open_session_ip4 (u8 * s, va_list * args)
+format_tcp_listener_session (u8 * s, va_list * args)
 {
   u32 tci = va_arg (*args, u32);
-  tcp_connection_t *tc = tcp_half_open_connection_get (tci);
-  s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip4_address,
-	      &tc->c_lcl_ip4, clib_net_to_host_u16 (tc->c_lcl_port),
-	      format_ip4_address, &tc->c_rmt_ip4,
-	      clib_net_to_host_u16 (tc->c_rmt_port));
-  return s;
+  tcp_connection_t *tc = tcp_listener_get (tci);
+  return format (s, "%U", format_tcp_connection, tc);
 }
 
 u8 *
-format_tcp_half_open_session_ip6 (u8 * s, va_list * args)
+format_tcp_half_open_session (u8 * s, va_list * args)
 {
   u32 tci = va_arg (*args, u32);
   tcp_connection_t *tc = tcp_half_open_connection_get (tci);
-  s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip6_address,
-	      &tc->c_lcl_ip6, clib_net_to_host_u16 (tc->c_lcl_port),
-	      format_ip6_address, &tc->c_rmt_ip6,
-	      clib_net_to_host_u16 (tc->c_rmt_port));
-  return s;
+  return format (s, "%U", format_tcp_connection, tc);
 }
 
 transport_connection_t *
@@ -534,7 +575,7 @@ tcp_session_tx_fifo_offset (transport_connection_t * trans_conn)
 /* *INDENT-OFF* */
 const static transport_proto_vft_t tcp4_proto = {
   .bind = tcp_session_bind_ip4,
-  .unbind = tcp_session_unbind_ip4,
+  .unbind = tcp_session_unbind,
   .push_header = tcp_push_header,
   .get_connection = tcp_session_get_transport,
   .get_listener = tcp_session_get_listener,
@@ -545,14 +586,14 @@ const static transport_proto_vft_t tcp4_proto = {
   .send_mss = tcp_session_send_mss,
   .send_space = tcp_session_send_space,
   .tx_fifo_offset = tcp_session_tx_fifo_offset,
-  .format_connection = format_tcp_session_ip4,
-  .format_listener = format_tcp_listener_session_ip4,
-  .format_half_open = format_tcp_half_open_session_ip4
+  .format_connection = format_tcp_session,
+  .format_listener = format_tcp_listener_session,
+  .format_half_open = format_tcp_half_open_session,
 };
 
 const static transport_proto_vft_t tcp6_proto = {
   .bind = tcp_session_bind_ip6,
-  .unbind = tcp_session_unbind_ip6,
+  .unbind = tcp_session_unbind,
   .push_header = tcp_push_header,
   .get_connection = tcp_session_get_transport,
   .get_listener = tcp_session_get_listener,
@@ -563,9 +604,9 @@ const static transport_proto_vft_t tcp6_proto = {
   .send_mss = tcp_session_send_mss,
   .send_space = tcp_session_send_space,
   .tx_fifo_offset = tcp_session_tx_fifo_offset,
-  .format_connection = format_tcp_session_ip6,
-  .format_listener = format_tcp_listener_session_ip6,
-  .format_half_open = format_tcp_half_open_session_ip6
+  .format_connection = format_tcp_session,
+  .format_listener = format_tcp_listener_session,
+  .format_half_open = format_tcp_half_open_session,
 };
 /* *INDENT-ON* */
 
@@ -654,6 +695,8 @@ 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);
+
       /* Handle expiration */
       (*timer_expiration_handlers[timer_id]) (connection_index);
     }
diff --git a/src/vnet/tcp/tcp.h b/src/vnet/tcp/tcp.h
index 3b3d8fc7..082ab1d8 100644
--- a/src/vnet/tcp/tcp.h
+++ b/src/vnet/tcp/tcp.h
@@ -22,6 +22,7 @@
 #include <vnet/tcp/tcp_timer.h>
 #include <vnet/session/transport.h>
 #include <vnet/session/session.h>
+#include <vnet/tcp/tcp_debug.h>
 
 #define TCP_TICK 10e-3			/**< TCP tick period (s) */
 #define THZ 1/TCP_TICK			/**< TCP tick frequency */
@@ -222,7 +223,7 @@ typedef struct _tcp_connection
   u32 prev_ssthresh;	/**< ssthresh before congestion */
   u32 bytes_acked;	/**< Bytes acknowledged by current segment */
   u32 rtx_bytes;	/**< Retransmitted bytes */
-  u32 tsecr_last_ack;	/**< Timestamp echoed to us in last health ACK */
+  u32 tsecr_last_ack;	/**< Timestamp echoed to us in last healthy ACK */
   tcp_cc_algorithm_t *cc_algo;	/**< Congestion control algorithm */
 
   /* RTT and RTO */
@@ -354,6 +355,9 @@ void tcp_connection_cleanup (tcp_connection_t * tc);
 void tcp_connection_del (tcp_connection_t * tc);
 void tcp_connection_reset (tcp_connection_t * tc);
 
+u8 *format_tcp_connection (u8 * s, va_list * args);
+u8 *format_tcp_connection_verbose (u8 * s, va_list * args);
+
 always_inline tcp_connection_t *
 tcp_listener_get (u32 tli)
 {
diff --git a/src/vnet/tcp/tcp_debug.h b/src/vnet/tcp/tcp_debug.h
new file mode 100644
index 00000000..069c512d
--- /dev/null
+++ b/src/vnet/tcp/tcp_debug.h
@@ -0,0 +1,316 @@
+/*
+ * Copyright (c) 2017 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.
+ */
+
+#ifndef SRC_VNET_TCP_TCP_DEBUG_H_
+#define SRC_VNET_TCP_TCP_DEBUG_H_
+
+#include <vlib/vlib.h>
+
+#define TCP_DEBUG (1)
+
+#define foreach_tcp_dbg_evt		\
+  _(INIT, "")				\
+  _(DEALLOC, "")			\
+  _(OPEN, "open")			\
+  _(CLOSE, "close")			\
+  _(BIND, "bind")			\
+  _(UNBIND, "unbind")			\
+  _(DELETE, "delete")			\
+  _(SYN_SENT, "SYN sent")		\
+  _(FIN_SENT, "FIN sent")		\
+  _(RST_SENT, "RST sent")		\
+  _(SYN_RCVD, "SYN rcvd")		\
+  _(ACK_RCVD, "ACK rcvd")		\
+  _(FIN_RCVD, "FIN rcvd")		\
+  _(RST_RCVD, "RST rcvd")		\
+  _(PKTIZE, "packetize")		\
+  _(INPUT, "in")			\
+  _(TIMER_POP, "timer pop")
+
+typedef enum _tcp_dbg
+{
+#define _(sym, str) TCP_DBG_##sym,
+  foreach_tcp_dbg_evt
+#undef _
+} tcp_dbg_e;
+
+typedef enum _tcp_dbg_evt
+{
+#define _(sym, str) TCP_EVT_##sym,
+  foreach_tcp_dbg_evt
+#undef _
+} tcp_dbg_evt_e;
+
+#if TCP_DEBUG
+
+#define TRANSPORT_DEBUG (1)
+
+#define TCP_DBG(_tc, _evt, _args...)					\
+{   		            						\
+    u8 *_tmp = 0;							\
+    _tmp = format(_tmp, "%U", format_tcp_connection_verbose, _tc);	\
+    clib_warning("%s", _tmp);						\
+    vec_free(_tmp);							\
+}
+
+#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)
+
+#define TCP_EVT_INIT_HANDLER(_tc, ...)					\
+{									\
+  _tc->c_elog_track.name = 						\
+	(char *) format (0, "%d%c", _tc->c_c_index, 0);			\
+  elog_track_register (&vlib_global_main.elog_main, &_tc->c_elog_track);\
+}
+
+#define TCP_EVT_DEALLOC_HANDLER(_tc, ...)				\
+{									\
+  vec_free (_tc->c_elog_track.name);					\
+}
+
+#define TCP_EVT_OPEN_HANDLER(_tc, ...)					\
+{									\
+  TCP_EVT_INIT_HANDLER(_tc);						\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "open: index %d",						\
+    .format_args = "i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 1);						\
+  ed->data[0] = _tc->c_c_index;						\
+}
+
+#define TCP_EVT_CLOSE_HANDLER(_tc, ...)					\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "close: %d",						\
+    .format_args = "i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 1);						\
+  ed->data[0] = _tc->c_c_index;						\
+}
+
+#define TCP_EVT_BIND_HANDLER(_tc, ...)					\
+{									\
+  TCP_EVT_INIT_HANDLER(_tc);						\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "bind: listener %d",					\
+  };									\
+  DECLARE_ETD(_tc, _e, 1);						\
+  ed->data[0] = _tc->c_c_index;						\
+}
+
+#define TCP_EVT_UNBIND_HANDLER(_tc, ...)				\
+{									\
+  TCP_EVT_DEALLOC_HANDLER(_tc);						\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "unbind: listener %d",					\
+  };									\
+  DECLARE_ETD(_tc, _e, 1);						\
+  ed->data[0] = _tc->c_c_index;						\
+  TCP_EVT_DEALLOC_HANDLER(_tc);						\
+}
+
+#define TCP_EVT_DELETE_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "delete: %d",						\
+    .format_args = "i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 0);						\
+  ed->data[0] = _tc->c_c_index;						\
+  TCP_EVT_DEALLOC_HANDLER(_tc);						\
+}
+
+#define TCP_EVT_SYN_SENT_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "SYN: iss %d",						\
+    .format_args = "i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 1);						\
+  ed->data[0] = _tc->iss;						\
+}
+
+#define TCP_EVT_FIN_SENT_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "FIN: snd_nxt %d rcv_nxt %d",				\
+    .format_args = "i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 2);						\
+  ed->data[0] = _tc->snd_nxt - _tc->iss;				\
+  ed->data[1] = _tc->rcv_nxt - _tc->irs;				\
+}
+
+#define TCP_EVT_RST_SENT_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "RST: snd_nxt %d rcv_nxt %d",				\
+    .format_args = "i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 2);						\
+  ed->data[0] = _tc->snd_nxt - _tc->iss;				\
+  ed->data[1] = _tc->rcv_nxt - _tc->irs;				\
+}
+
+#define TCP_EVT_SYN_RCVD_HANDLER(_tc, ...)				\
+{									\
+  TCP_EVT_INIT_HANDLER(_tc);						\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "SYN rcvd: irs %d",					\
+    .format_args = "i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 1);						\
+  ed->data[0] = _tc->irs;						\
+}
+
+#define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "FIN rcvd: snd_nxt %d rcv_nxt %d",			\
+    .format_args = "i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 2);						\
+  ed->data[0] = _tc->snd_nxt - _tc->iss;				\
+  ed->data[1] = _tc->rcv_nxt - _tc->irs;				\
+}
+
+#define TCP_EVT_RST_RCVD_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "RST rcvd: snd_nxt %d rcv_nxt %d",			\
+    .format_args = "i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 2);						\
+  ed->data[0] = _tc->snd_nxt - _tc->iss;				\
+  ed->data[1] = _tc->rcv_nxt - _tc->irs;				\
+}
+
+#define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "ACK: acked %u cwnd %u inflight %u",			\
+    .format_args = "i4i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 3);						\
+  ed->data[0] = _tc->bytes_acked;					\
+  ed->data[1] = _tc->cwnd;						\
+  ed->data[2] = tcp_flight_size(_tc);					\
+}
+
+#define TCP_EVT_PKTIZE_HANDLER(_tc, ...)				\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "pktize: snd_una %u snd_nxt %u una_max %u",		\
+    .format_args = "i4i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 3);						\
+  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;				\
+}
+
+#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;						\
+}
+
+#define TCP_EVT_INPUT_HANDLER(_tc, n_bytes, ...)			\
+{									\
+  ELOG_TYPE_DECLARE (_e) =						\
+  {									\
+    .format = "in: bytes %u rcv_nxt %u",				\
+    .format_args = "i4i4",						\
+  };									\
+  DECLARE_ETD(_tc, _e, 2);						\
+  ed->data[0] = n_bytes;						\
+  ed->data[1] = _tc->rcv_nxt - _tc->irs;				\
+}
+
+#define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)            \
+{                                                               	\
+  tcp_connection_t *_tc;                                        	\
+  if (_timer_id == TCP_TIMER_RETRANSMIT_SYN)                           	\
+    {                                                           	\
+      _tc = tcp_half_open_connection_get (_tc_index);           	\
+    }                                                           	\
+  else                                                          	\
+    {                                                           	\
+      u32 _thread_index = os_get_cpu_number ();                 	\
+      _tc = tcp_connection_get (_tc_index, _thread_index);      	\
+    }                                                           	\
+  ELOG_TYPE_DECLARE (_e) =                                      	\
+  {                                                             	\
+    .format = "TimerPop: %s (%d)",                              	\
+    .format_args = "t4i4",                                      	\
+    .n_enum_strings = 7,                                        	\
+    .enum_strings = {                                           	\
+      "retransmit",                                             	\
+      "delack",                                                 	\
+      "BUG",                                                    	\
+      "keep",                                                   	\
+      "waitclose",                                              	\
+      "retransmit syn",                                         	\
+      "establish",                                              	\
+    },                                                          	\
+  };                                                            	\
+  DECLARE_ETD(_tc, _e, 2);                                      	\
+  ed->data[0] = _timer_id;                                      	\
+  ed->data[1] = _timer_id;                                      	\
+}
+
+#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...)
+#endif
+
+
+#endif /* SRC_VNET_TCP_TCP_DEBUG_H_ */
+/*
+ * fd.io coding-style-patch-verification: ON
+ *
+ * Local Variables:
+ * eval: (c-set-style "gnu")
+ * End:
+ */
diff --git a/src/vnet/tcp/tcp_input.c b/src/vnet/tcp/tcp_input.c
index f19fbf87..67af4321 100644
--- a/src/vnet/tcp/tcp_input.c
+++ b/src/vnet/tcp/tcp_input.c
@@ -730,6 +730,8 @@ tcp_rcv_ack (tcp_connection_t * tc, vlib_buffer_t * b,
   /* Updates congestion control (slow start/congestion avoidance) */
   tcp_cc_rcv_ack (tc);
 
+  TCP_EVT_DBG (TCP_EVT_ACK_RCVD, tc);
+
   /* If everything has been acked, stop retransmit timer
    * otherwise update */
   if (tc->snd_una == tc->snd_una_max)
@@ -922,6 +924,8 @@ tcp_segment_rcv (tcp_main_t * tm, tcp_connection_t * tc, vlib_buffer_t * b,
    * segments can be enqueued after fifo tail offset changes. */
   error = tcp_session_enqueue_data (tc, b, n_data_bytes);
 
+  TCP_EVT_DBG (TCP_EVT_INPUT, tc, n_data_bytes);
+
   /* Check if ACK can be delayed */
   if (tcp_can_delack (tc))
     {
@@ -1079,6 +1083,7 @@ tcp46_established_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
 	       * wait for session to call close. To avoid lingering
 	       * in CLOSE-WAIT, set timer (reuse WAITCLOSE). */
 	      tc0->state = TCP_STATE_CLOSE_WAIT;
+	      TCP_EVT_DBG (TCP_EVT_FIN_RCVD, tc0);
 	      stream_session_disconnect_notify (&tc0->connection);
 	      tcp_timer_set (tc0, TCP_TIMER_WAITCLOSE, TCP_CLOSEWAIT_TIME);
 	    }
@@ -1134,7 +1139,8 @@ VLIB_REGISTER_NODE (tcp4_established_node) =
   .name = "tcp4-established",
   /* Takes a vector of packets. */
   .vector_size = sizeof (u32),
-  .n_errors = TCP_N_ERROR,.error_strings = tcp_error_strings,
+  .n_errors = TCP_N_ERROR,
+  .error_strings = tcp_error_strings,
   .n_next_nodes = TCP_ESTABLISHED_N_NEXT,
   .next_nodes =
   {
@@ -1363,7 +1369,7 @@ tcp46_syn_sent_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
 	    {
 	      new_tc0->state = TCP_STATE_SYN_RCVD;
 
-	      /* Notify app that we have connection XXX */
+	      /* Notify app that we have connection */
 	      stream_session_connect_notify (&new_tc0->connection, sst, 0);
 
 	      tcp_make_synack (new_tc0, b0);
@@ -1726,7 +1732,7 @@ tcp46_rcv_process_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
 	    case TCP_STATE_FIN_WAIT_2:
 	      /* Got FIN, send ACK! */
 	      tc0->state = TCP_STATE_TIME_WAIT;
-	      tcp_timer_set (tc0, TCP_TIMER_WAITCLOSE, TCP_2MSL_TIME);
+	      tcp_timer_set (tc0, TCP_TIMER_WAITCLOSE, TCP_CLOSEWAIT_TIME);
 	      tcp_make_ack (tc0, b0);
 	      next0 = tcp_next_output (is_ip4);
 	      break;
@@ -1737,6 +1743,7 @@ tcp46_rcv_process_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
 	      tcp_timer_update (tc0, TCP_TIMER_WAITCLOSE, TCP_2MSL_TIME);
 	      break;
 	    }
+	  TCP_EVT_DBG (TCP_EVT_FIN_RCVD, tc0);
 
 	  b0->error = error0 ? node->errors[error0] : 0;
 
@@ -1950,6 +1957,8 @@ tcp46_listen_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
 
 	  tcp_connection_init_vars (child0);
 
+	  TCP_EVT_DBG (TCP_EVT_SYN_RCVD, child0);
+
 	  /* Reuse buffer to make syn-ack and send */
 	  tcp_make_synack (child0, b0);
 	  next0 = tcp_next_output (is_ip4);
@@ -2064,25 +2073,6 @@ typedef struct
   u8 state;
 } tcp_rx_trace_t;
 
-const char *tcp_fsm_states[] = {
-#define _(sym, str) str,
-  foreach_tcp_fsm_state
-#undef _
-};
-
-u8 *
-format_tcp_state (u8 * s, va_list * args)
-{
-  tcp_state_t *state = va_arg (*args, tcp_state_t *);
-
-  if (state[0] < TCP_N_STATES)
-    s = format (s, "%s", tcp_fsm_states[state[0]]);
-  else
-    s = format (s, "UNKNOWN");
-
-  return s;
-}
-
 u8 *
 format_tcp_rx_trace (u8 * s, va_list * args)
 {
diff --git a/src/vnet/tcp/tcp_output.c b/src/vnet/tcp/tcp_output.c
index aa43e9f3..114a5b9e 100644
--- a/src/vnet/tcp/tcp_output.c
+++ b/src/vnet/tcp/tcp_output.c
@@ -452,11 +452,7 @@ tcp_make_fin (tcp_connection_t * tc, vlib_buffer_t * b)
 
   tcp_reuse_buffer (vm, b);
 
-  if (tc->rcv_las == tc->rcv_nxt)
-    flags = TCP_FLAG_FIN;
-  else
-    flags = TCP_FLAG_FIN | TCP_FLAG_ACK;
-
+  flags = TCP_FLAG_FIN | TCP_FLAG_ACK;
   tcp_make_ack_i (tc, b, TCP_STATE_ESTABLISHED, flags);
 
   /* Reset flags, make sure ack is sent */
@@ -828,6 +824,7 @@ tcp_send_fin (tcp_connection_t * tc)
   tcp_make_fin (tc, b);
   tcp_enqueue_to_output (vm, b, bi, tc->c_is_ip4);
   tc->flags |= TCP_CONN_FINSNT;
+  TCP_EVT_DBG (TCP_EVT_FIN_SENT, tc);
 }
 
 always_inline u8
@@ -887,6 +884,7 @@ tcp_push_hdr_i (tcp_connection_t * tc, vlib_buffer_t * b,
   vnet_buffer (b)->tcp.connection_index = tc->c_c_index;
 
   tc->snd_nxt += data_len;
+  TCP_EVT_DBG (TCP_EVT_PKTIZE, tc);
 }
 
 /* Send delayed ACK when timer expires */
@@ -1186,6 +1184,7 @@ tcp46_output_inline (vlib_main_t * vm,
 	    }
 
 	  th0 = vlib_buffer_get_current (b0);
+	  TCP_EVT_DBG (TCP_EVT_OUTPUT, tc0, th0->flags, b0->current_length);
 
 	  if (is_ip4)
 	    {
@@ -1242,22 +1241,6 @@ tcp46_output_inline (vlib_main_t * vm,
 		  tc0->rtt_ts = tcp_time_now ();
 		  tc0->rtt_seq = tc0->snd_nxt;
 		}
-
-	      if (1)
-		{
-		  ELOG_TYPE_DECLARE (e) =
-		  {
-		  .format =
-		      "output: snd_una %u snd_una_max %u",.format_args =
-		      "i4i4",};
-		  struct
-		  {
-		    u32 data[2];
-		  } *ed;
-		  ed = ELOG_DATA (&vm->elog_main, e);
-		  ed->data[0] = tc0->snd_una - tc0->iss;
-		  ed->data[1] = tc0->snd_una_max - tc0->iss;
-		}
 	    }
 
 	  /* Set the retransmit timer if not set already and not
@@ -1275,9 +1258,8 @@ tcp46_output_inline (vlib_main_t * vm,
 	  vnet_buffer (b0)->sw_if_index[VLIB_TX] = (u32) ~ 0;
 
 	  b0->flags |= VNET_BUFFER_LOCALLY_ORIGINATED;
-
 	done:
-	  b0->error = error0 != 0 ? node->errors[error0] : 0;
+	  b0->error = node->errors[error0];
 	  if (PREDICT_FALSE (b0->flags & VLIB_BUFFER_IS_TRACED))
 	    {
 
@@ -1307,34 +1289,50 @@ tcp6_output (vlib_main_t * vm, vlib_node_runtime_t * node,
   return tcp46_output_inline (vm, node, from_frame, 0 /* is_ip4 */ );
 }
 
+/* *INDENT-OFF* */
 VLIB_REGISTER_NODE (tcp4_output_node) =
 {
   .function = tcp4_output,.name = "tcp4-output",
     /* Takes a vector of packets. */
-    .vector_size = sizeof (u32),.n_errors = TCP_N_ERROR,.error_strings =
-    tcp_error_strings,.n_next_nodes = TCP_OUTPUT_N_NEXT,.next_nodes =
-  {
+    .vector_size = sizeof (u32),
+    .n_errors = TCP_N_ERROR,
+    .error_strings = tcp_error_strings,
+    .n_next_nodes = TCP_OUTPUT_N_NEXT,
+    .next_nodes = {
 #define _(s,n) [TCP_OUTPUT_NEXT_##s] = n,
     foreach_tcp4_output_next
 #undef _
-  }
-,.format_buffer = format_tcp_header,.format_trace = format_tcp_tx_trace,};
+    },
+    .format_buffer = format_tcp_header,
+    .format_trace = format_tcp_tx_trace,
+};
+/* *INDENT-ON* */
 
-VLIB_NODE_FUNCTION_MULTIARCH (tcp4_output_node, tcp4_output)
+VLIB_NODE_FUNCTION_MULTIARCH (tcp4_output_node, tcp4_output);
+
+/* *INDENT-OFF* */
 VLIB_REGISTER_NODE (tcp6_output_node) =
 {
-  .function = tcp6_output,.name = "tcp6-output",
+  .function = tcp6_output,
+  .name = "tcp6-output",
     /* Takes a vector of packets. */
-    .vector_size = sizeof (u32),.n_errors = TCP_N_ERROR,.error_strings =
-    tcp_error_strings,.n_next_nodes = TCP_OUTPUT_N_NEXT,.next_nodes =
-  {
+  .vector_size = sizeof (u32),
+  .n_errors = TCP_N_ERROR,
+  .error_strings = tcp_error_strings,
+  .n_next_nodes = TCP_OUTPUT_N_NEXT,
+  .next_nodes = {
 #define _(s,n) [TCP_OUTPUT_NEXT_##s] = n,
     foreach_tcp6_output_next
 #undef _
-  }
-,.format_buffer = format_tcp_header,.format_trace = format_tcp_tx_trace,};
+  },
+  .format_buffer = format_tcp_header,
+  .format_trace = format_tcp_tx_trace,
+};
+/* *INDENT-ON* */
+
+VLIB_NODE_FUNCTION_MULTIARCH (tcp6_output_node, tcp6_output);
 
-VLIB_NODE_FUNCTION_MULTIARCH (tcp6_output_node, tcp6_output) u32
+u32
 tcp_push_header (transport_connection_t * tconn, vlib_buffer_t * b)
 {
   tcp_connection_t *tc;
@@ -1405,7 +1403,7 @@ tcp46_send_reset_inline (vlib_main_t * vm, vlib_node_runtime_t * node,
 	  next0 = TCP_RESET_NEXT_IP_LOOKUP;
 
 	done:
-	  b0->error = error0 != 0 ? node->errors[error0] : 0;
+	  b0->error = node->errors[error0];
 	  b0->flags |= VNET_BUFFER_LOCALLY_ORIGINATED;
 	  if (PREDICT_FALSE (b0->flags & VLIB_BUFFER_IS_TRACED))
 	    {
@@ -1450,6 +1448,8 @@ VLIB_REGISTER_NODE (tcp4_reset_node) = {
 };
 /* *INDENT-ON* */
 
+VLIB_NODE_FUNCTION_MULTIARCH (tcp4_reset_node, tcp4_send_reset);
+
 /* *INDENT-OFF* */
 VLIB_REGISTER_NODE (tcp6_reset_node) = {
   .function = tcp6_send_reset,
@@ -1466,6 +1466,8 @@ VLIB_REGISTER_NODE (tcp6_reset_node) = {
 };
 /* *INDENT-ON* */
 
+VLIB_NODE_FUNCTION_MULTIARCH (tcp6_reset_node, tcp6_send_reset);
+
 /*
  * fd.io coding-style-patch-verification: ON
  *
diff --git a/src/vnet/udp/udp.c b/src/vnet/udp/udp.c
index 9e740466..57e4a60e 100644
--- a/src/vnet/udp/udp.c
+++ b/src/vnet/udp/udp.c
@@ -25,7 +25,7 @@
 udp_uri_main_t udp_uri_main;
 
 u32
-udp_session_bind_ip4 (vlib_main_t * vm, u32 session_index,
+udp_session_bind_ip4 (u32 session_index,
 		      ip46_address_t * ip, u16 port_number_host_byte_order)
 {
   udp_uri_main_t *um = vnet_get_udp_main ();
@@ -42,7 +42,7 @@ udp_session_bind_ip4 (vlib_main_t * vm, u32 session_index,
 }
 
 u32
-udp_session_bind_ip6 (vlib_main_t * vm, u32 session_index,
+udp_session_bind_ip6 (u32 session_index,
 		      ip46_address_t * ip, u16 port_number_host_byte_order)
 {
   udp_uri_main_t *um = vnet_get_udp_main ();
@@ -58,8 +58,9 @@ udp_session_bind_ip6 (vlib_main_t * vm, u32 session_index,
 }
 
 u32
-udp_session_unbind_ip4 (vlib_main_t * vm, u32 listener_index)
+udp_session_unbind_ip4 (u32 listener_index)
 {
+  vlib_main_t *vm = vlib_get_main ();
   udp_connection_t *listener;
   listener = udp_listener_get (listener_index);
 
@@ -69,8 +70,9 @@ udp_session_unbind_ip4 (vlib_main_t * vm, u32 listener_index)
 }
 
 u32
-udp_session_unbind_ip6 (vlib_main_t * vm, u32 listener_index)
+udp_session_unbind_ip6 (u32 listener_index)
 {
+  vlib_main_t *vm = vlib_get_main ();
   udp_connection_t *listener;
 
   listener = udp_listener_get (listener_index);