X-Git-Url: https://gerrit.fd.io/r/gitweb?a=blobdiff_plain;f=src%2Fvcl%2Fvppcom.c;h=aff81f5351ea466a220371d785c39fd3f76a6897;hb=d3046598b0954f20031852ad55bcf2d4900c01bf;hp=f05b03143e74f5bf13b684ca34ede557fb70c9f4;hpb=badeb95bcbb1352d4e5ab97e6524a5ef6f743240;p=vpp.git

diff --git a/src/vcl/vppcom.c b/src/vcl/vppcom.c
index f05b03143e7..aff81f5351e 100644
--- a/src/vcl/vppcom.c
+++ b/src/vcl/vppcom.c
@@ -23,6 +23,7 @@
 #include <vcl/vppcom.h>
 #include <vlib/unix/unix.h>
 #include <vppinfra/vec_bootstrap.h>
+#include <vppinfra/elog.h>
 
 #define vl_typedefs		/* define message structures */
 #include <vpp/api/vpe_all_api_h.h>
@@ -107,7 +108,7 @@ typedef struct
   u32 sm_seg_index;
   u32 client_context;
   u64 vpp_handle;
-  unix_shared_memory_queue_t *vpp_event_queue;
+  svm_queue_t *vpp_event_queue;
 
   /* Socket configuration state */
   /* TBD: covert 'is_*' vars to bit in u8 flags; */
@@ -127,11 +128,13 @@ typedef struct
   u8 proto;
   u64 client_queue_address;
   u64 options[16];
+  elog_track_t elog_track;
 } session_t;
 
 typedef struct vppcom_cfg_t_
 {
   u64 heapsize;
+  u32 vpp_api_q_length;
   u64 segment_baseva;
   u32 segment_size;
   u32 add_segment_size;
@@ -149,6 +152,8 @@ typedef struct vppcom_cfg_t_
   f64 app_timeout;
   f64 session_timeout;
   f64 accept_timeout;
+  u32 event_ring_size;
+  char *event_log_path;
 } vppcom_cfg_t;
 
 typedef struct vppcom_main_t_
@@ -159,7 +164,7 @@ typedef struct vppcom_main_t_
   int main_cpu;
 
   /* vpe input queue */
-  unix_shared_memory_queue_t *vl_input_queue;
+  svm_queue_t *vl_input_queue;
 
   /* API client handle */
   u32 my_client_index;
@@ -177,7 +182,7 @@ typedef struct vppcom_main_t_
   clib_bitmap_t *ex_bitmap;
 
   /* Our event queue */
-  unix_shared_memory_queue_t *app_event_queue;
+  svm_queue_t *app_event_queue;
 
   /* unique segment name counter */
   u32 unique_segment_index;
@@ -190,6 +195,10 @@ typedef struct vppcom_main_t_
 
   vppcom_cfg_t cfg;
 
+  /* Event logging */
+  elog_main_t elog_main;
+  elog_track_t elog_track;
+
   /* VNET_API_ERROR_FOO -> "Foo" hash table */
   uword *error_string_by_error_number;
 } vppcom_main_t;
@@ -354,26 +363,81 @@ vppcom_session_table_del_listener (u64 listener_handle)
   hash_unset (vcm->session_index_by_vpp_handles, listener_handle);
 }
 
+static void
+write_elog (void)
+{
+  elog_main_t *em = &vcm->elog_main;
+  char *chroot_file;
+  clib_error_t *error = 0;
+
+  chroot_file =
+    (char *) format (0, "%s/%d-%d-vcl-elog%c", vcm->cfg.event_log_path,
+		     vcm->my_client_index, getpid (), 0);
+  error = elog_write_file (em, chroot_file, 1 /* flush ring */ );
+  if (error)
+    {
+      clib_error_report (error);
+    }
+  if (VPPCOM_DEBUG > 0)
+    clib_warning ("[%d] Event Log:'%s' ", getpid (), chroot_file);
+
+}
+
 static int
 vppcom_connect_to_vpp (char *app_name)
 {
   api_main_t *am = &api_main;
+  int rv = VPPCOM_OK;
 
   if (VPPCOM_DEBUG > 0)
     printf ("\nConnecting to VPP api...");
-  if (vl_client_connect_to_vlib ("/vpe-api", app_name, 32) < 0)
+  if (vl_client_connect_to_vlib ("/vpe-api", app_name,
+				 vcm->cfg.vpp_api_q_length) < 0)
     {
       clib_warning ("[%d] connect to vpp (%s) failed!", getpid (), app_name);
-      return VPPCOM_ECONNREFUSED;
+      rv = VPPCOM_ECONNREFUSED;
+    }
+  else
+    {
+
+      vcm->vl_input_queue = am->shmem_hdr->vl_input_queue;
+      vcm->my_client_index = am->my_client_index;
+      vcm->app_state = STATE_APP_CONN_VPP;
+
+      if (VPPCOM_DEBUG > 0)
+	printf (" connected!\n");
     }
 
-  vcm->vl_input_queue = am->shmem_hdr->vl_input_queue;
-  vcm->my_client_index = am->my_client_index;
   if (VPPCOM_DEBUG > 0)
-    printf (" connected!\n");
+    {
+      vcm->elog_main.lock =
+	clib_mem_alloc_aligned (CLIB_CACHE_LINE_BYTES, CLIB_CACHE_LINE_BYTES);
+      vcm->elog_main.lock[0] = 0;
+      vcm->elog_main.event_ring_size = vcm->cfg.event_ring_size;
+      elog_init (&vcm->elog_main, vcm->elog_main.event_ring_size);
+      elog_enable_disable (&vcm->elog_main, 1);
+
+      vcm->elog_track.name =
+	(char *) format (0, "P:%d:C:%d%c", getpid (),
+			 vcm->my_client_index, 0);
+      elog_track_register (&vcm->elog_main, &vcm->elog_track);
 
-  vcm->app_state = STATE_APP_CONN_VPP;
-  return VPPCOM_OK;
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+      {
+	.format = "connect_vpp:rv:%d",
+	.format_args = "i4",
+      };
+      struct
+      {
+	u32 data;
+      } *ed;
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, vcm->elog_track);
+      ed->data = rv;
+      /* *INDENT-ON* */
+    }
+
+  return rv;
 }
 
 static u8 *
@@ -416,6 +480,26 @@ vppcom_wait_for_app_state_change (app_state_t app_state)
   if (VPPCOM_DEBUG > 0)
     clib_warning ("[%d] timeout waiting for state %s (%d)", getpid (),
 		  vppcom_app_state_str (app_state), app_state);
+
+  if (VPPCOM_DEBUG > 0)
+    {
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+	{
+	  .format = "ERR: timeout state:%d",
+	  .format_args = "i4",
+	};
+      struct
+      {
+	u32 data;
+      } *ed;
+
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, vcm->elog_track);
+
+      ed->data = app_state;
+      /* *INDENT-ON* */
+    }
+
   return VPPCOM_ETIMEDOUT;
 }
 
@@ -455,6 +539,26 @@ vppcom_wait_for_session_state_change (u32 session_index,
   if (VPPCOM_DEBUG > 0)
     clib_warning ("[%d] timeout waiting for state 0x%x (%s)", getpid (),
 		  state, vppcom_session_state_str (state));
+
+  if (VPPCOM_DEBUG > 0)
+    {
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+	{
+	  .format = "ERR: timeout state:%d",
+	  .format_args = "i4",
+	};
+      struct
+      {
+	u32 data;
+      } *ed;
+
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, session->elog_track);
+
+      ed->data = state;
+      /* *INDENT-ON* */
+    }
+
   return VPPCOM_ETIMEDOUT;
 }
 
@@ -475,6 +579,26 @@ vppcom_wait_for_client_session_index (f64 wait_for_time)
 
   if (VPPCOM_DEBUG > 0)
     clib_warning ("[%d] timeout waiting for client_session_index", getpid ());
+
+  if (VPPCOM_DEBUG > 0)
+    {
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+	{
+	  .format = "ERR: timeout waiting for session index :%d",
+	  .format_args = "i4",
+	};
+      struct
+      {
+	u32 data;
+      } *ed;
+
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, vcm->elog_track);
+
+      ed->data = getpid();
+      /* *INDENT-ON* */
+    }
+
   return VPPCOM_ETIMEDOUT;
 }
 
@@ -507,8 +631,9 @@ vppcom_app_session_enable (void)
       if (PREDICT_FALSE (rv))
 	{
 	  if (VPPCOM_DEBUG > 0)
-	    clib_warning ("[%d] Session enable timed out, rv = %s (%d)",
-			  getpid (), vppcom_retval_str (rv), rv);
+	    clib_warning ("[%d] application session enable timed out! "
+			  "returning %d (%s)",
+			  getpid (), rv, vppcom_retval_str (rv));
 	  return rv;
 	}
     }
@@ -550,10 +675,13 @@ vppcom_app_send_attach (void)
   bmp->options[APP_OPTIONS_PROXY_TRANSPORT] =
     (vcm->cfg.app_proxy_transport_tcp ? 1 << TRANSPORT_PROTO_TCP : 0) |
     (vcm->cfg.app_proxy_transport_udp ? 1 << TRANSPORT_PROTO_UDP : 0);
-  bmp->options[SESSION_OPTIONS_SEGMENT_SIZE] = vcm->cfg.segment_size;
-  bmp->options[SESSION_OPTIONS_ADD_SEGMENT_SIZE] = vcm->cfg.add_segment_size;
-  bmp->options[SESSION_OPTIONS_RX_FIFO_SIZE] = vcm->cfg.rx_fifo_size;
-  bmp->options[SESSION_OPTIONS_TX_FIFO_SIZE] = vcm->cfg.tx_fifo_size;
+  bmp->options[APP_OPTIONS_SEGMENT_SIZE] = vcm->cfg.segment_size;
+  bmp->options[APP_OPTIONS_ADD_SEGMENT_SIZE] = vcm->cfg.add_segment_size;
+  bmp->options[APP_OPTIONS_RX_FIFO_SIZE] = vcm->cfg.rx_fifo_size;
+  bmp->options[APP_OPTIONS_TX_FIFO_SIZE] = vcm->cfg.tx_fifo_size;
+  bmp->options[APP_OPTIONS_PREALLOC_FIFO_PAIRS] =
+    vcm->cfg.preallocated_fifo_pairs;
+  bmp->options[APP_OPTIONS_EVT_QUEUE_SIZE] = vcm->cfg.event_queue_size;
   if (nsid_len)
     {
       bmp->namespace_id_len = nsid_len;
@@ -573,8 +701,8 @@ vppcom_app_attach (void)
   if (PREDICT_FALSE (rv))
     {
       if (VPPCOM_DEBUG > 0)
-	clib_warning ("[%d] application attach timed out, rv = %s (%d)",
-		      getpid (), vppcom_retval_str (rv), rv);
+	clib_warning ("[%d] application attach timed out! returning %d (%s)",
+		      getpid (), rv, vppcom_retval_str (rv));
       return rv;
     }
   return VPPCOM_OK;
@@ -631,8 +759,7 @@ vl_api_application_attach_reply_t_handler (vl_api_application_attach_reply_t *
     }
 
   vcm->app_event_queue =
-    uword_to_pointer (mp->app_event_queue_address,
-		      unix_shared_memory_queue_t *);
+    uword_to_pointer (mp->app_event_queue_address, svm_queue_t *);
 
   vcm->app_state = STATE_APP_ATTACHED;
 }
@@ -699,7 +826,7 @@ vl_api_disconnect_session_t_handler (vl_api_disconnect_session_t * mp)
 
       if (VPPCOM_DEBUG > 1)
 	clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
-		      "setting state to %d (%s)",
+		      "setting state to 0x%x (%s)",
 		      getpid (), mp->handle, session_index, session->state,
 		      vppcom_session_state_str (session->state));
       clib_spinlock_unlock (&vcm->sessions_lockp);
@@ -733,9 +860,10 @@ vl_api_reset_session_t_handler (vl_api_reset_session_t * mp)
       if (PREDICT_FALSE (rval))
 	{
 	  rv = VNET_API_ERROR_INVALID_VALUE_2;
-	  clib_warning ("[%d] ERROR: sid %u: session lookup failed! "
-			"returning %d %U",
-			getpid (), p[0], rv, format_api_error, rv);
+	  clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+			"session lookup failed! returning %d %U",
+			getpid (), mp->handle, p[0],
+			rv, format_api_error, rv);
 	}
       else
 	{
@@ -771,34 +899,37 @@ vl_api_reset_session_t_handler (vl_api_reset_session_t * mp)
 static void
 vl_api_connect_session_reply_t_handler (vl_api_connect_session_reply_t * mp)
 {
-  session_t *session;
+  session_t *session = 0;
   u32 session_index;
   svm_fifo_t *rx_fifo, *tx_fifo;
   u8 is_cut_thru = 0;
   int rv;
 
   session_index = mp->context;
+  VCL_LOCK_AND_GET_SESSION (session_index, &session);
+done:
   if (mp->retval)
     {
-      clib_warning ("[%d] ERROR: sid %u: connect failed! %U",
-		    getpid (), session_index, format_api_error,
-		    ntohl (mp->retval));
-      return;
+      clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+		    "connect failed! %U",
+		    getpid (), mp->handle, session_index,
+		    format_api_error, ntohl (mp->retval));
+      if (rv == VPPCOM_OK)
+	{
+	  session->state = STATE_FAILED;
+	  session->vpp_handle = mp->handle;
+	}
+      else
+	{
+	  clib_warning ("[%s] ERROR: vpp handle 0x%llx, sid %u: "
+			"Invalid session index (%u)!",
+			getpid (), mp->handle, session_index);
+	}
+      goto done_unlock;
     }
 
-  if (VPPCOM_DEBUG > 1)
-    clib_warning ("[%d] sid %u: got a connect reply!",
-		  getpid (), session_index);
-
-  clib_spinlock_lock (&vcm->sessions_lockp);
-  if (pool_is_free_index (vcm->sessions, session_index))
-    {
-      clib_spinlock_unlock (&vcm->sessions_lockp);
-      if (VPPCOM_DEBUG > 1)
-	clib_warning ("[%d] sid %d: session lookup failed!",
-		      getpid (), session_index);
-      return;
-    }
+  if (rv)
+    goto done_unlock;
 
   /* We've been redirected */
   if (mp->segment_name_length > 0)
@@ -817,20 +948,18 @@ vl_api_connect_session_reply_t_handler (vl_api_connect_session_reply_t * mp)
       vec_reset_length (a->new_segment_indices);
       if (PREDICT_FALSE (rv))
 	{
-	  clib_spinlock_unlock (&vcm->sessions_lockp);
 	  clib_warning ("[%d] sm_fifo_segment_attach ('%s') failed",
 			getpid (), a->segment_name);
-	  return;
+	  goto done_unlock;
 	}
     }
 
   /*
    * Setup session
    */
-  session = pool_elt_at_index (vcm->sessions, session_index);
   session->is_cut_thru = is_cut_thru;
   session->vpp_event_queue = uword_to_pointer (mp->vpp_event_queue_address,
-					       unix_shared_memory_queue_t *);
+					       svm_queue_t *);
 
   rx_fifo = uword_to_pointer (mp->server_rx_fifo, svm_fifo_t *);
   rx_fifo->client_session_index = session_index;
@@ -850,14 +979,14 @@ vl_api_connect_session_reply_t_handler (vl_api_connect_session_reply_t * mp)
   hash_set (vcm->session_index_by_vpp_handles, mp->handle, session_index);
 
   if (VPPCOM_DEBUG > 1)
-    clib_warning ("[%d] client sid %d, vpp handle 0x%llx\n"
-		  "  session_rx_fifo %p, refcnt %d\n"
-		  "  session_tx_fifo %p, refcnt %d",
-		  getpid (), session_index, mp->handle,
+    clib_warning ("[%d] vpp handle 0x%llx, sid %u: connect succeeded!"
+		  " session_rx_fifo %p, refcnt %d,"
+		  " session_tx_fifo %p, refcnt %d",
+		  getpid (), mp->handle, session_index,
 		  session->server_rx_fifo,
 		  session->server_rx_fifo->refcnt,
 		  session->server_tx_fifo, session->server_tx_fifo->refcnt);
-
+done_unlock:
   clib_spinlock_unlock (&vcm->sessions_lockp);
 }
 
@@ -926,34 +1055,41 @@ vl_api_bind_sock_reply_t_handler (vl_api_bind_sock_reply_t * mp)
   u32 session_index = mp->context;
   int rv;
 
+  VCL_LOCK_AND_GET_SESSION (session_index, &session);
+done:
   if (mp->retval)
     {
-      clib_warning ("[%d] ERROR: sid %u: bind failed: %U",
-		    getpid (), session_index, format_api_error,
+      clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: bind failed: %U",
+		    getpid (), mp->handle, session_index, format_api_error,
 		    ntohl (mp->retval));
       rv = vppcom_session_at_index (session_index, &session);
       if (rv == VPPCOM_OK)
-	session->state = STATE_FAILED;
-      return;
+	{
+	  session->state = STATE_FAILED;
+	  session->vpp_handle = mp->handle;
+	}
+      else
+	{
+	  clib_warning ("[%s] ERROR: vpp handle 0x%llx, sid %u: "
+			"Invalid session index (%u)!",
+			getpid (), mp->handle, session_index);
+	}
+      goto done_unlock;
     }
 
-  clib_spinlock_lock (&vcm->sessions_lockp);
-  rv = vppcom_session_at_index (session_index, &session);
-  if (rv == VPPCOM_OK)
-    {
-      session->vpp_handle = mp->handle;
-      session->lcl_addr.is_ip4 = mp->lcl_is_ip4;
-      clib_memcpy (&session->lcl_addr.ip46, mp->lcl_ip,
-		   sizeof (session->peer_addr.ip46));
-      session->lcl_port = mp->lcl_port;
-      vppcom_session_table_add_listener (mp->handle, session_index);
-      session->is_listen = 1;
-      session->state = STATE_LISTEN;
+  session->vpp_handle = mp->handle;
+  session->lcl_addr.is_ip4 = mp->lcl_is_ip4;
+  clib_memcpy (&session->lcl_addr.ip46, mp->lcl_ip,
+	       sizeof (session->peer_addr.ip46));
+  session->lcl_port = mp->lcl_port;
+  vppcom_session_table_add_listener (mp->handle, session_index);
+  session->is_listen = 1;
+  session->state = STATE_LISTEN;
 
-      if (VPPCOM_DEBUG > 1)
-	clib_warning ("[%d] sid %u: bind succeeded! ", getpid (),
-		      mp->context);
-    }
+  if (VPPCOM_DEBUG > 1)
+    clib_warning ("[%d] vpp handle 0x%llx, sid %u: bind succeeded!",
+		  getpid (), mp->handle, mp->context);
+done_unlock:
   clib_spinlock_unlock (&vcm->sessions_lockp);
 }
 
@@ -1053,7 +1189,7 @@ format_ip46_address (u8 * s, va_list * args)
 }
 
 static inline void
-vppcom_send_accept_session_reply (u32 handle, int retval)
+vppcom_send_accept_session_reply (u64 handle, u32 context, int retval)
 {
   vl_api_accept_session_reply_t *rmp;
 
@@ -1061,6 +1197,7 @@ vppcom_send_accept_session_reply (u32 handle, int retval)
   memset (rmp, 0, sizeof (*rmp));
   rmp->_vl_msg_id = ntohs (VL_API_ACCEPT_SESSION_REPLY);
   rmp->retval = htonl (retval);
+  rmp->context = context;
   rmp->handle = handle;
   vl_msg_api_send_shmem (vcm->vl_input_queue, (u8 *) & rmp);
 }
@@ -1076,7 +1213,7 @@ vl_api_accept_session_t_handler (vl_api_accept_session_t * mp)
   if (!clib_fifo_free_elts (vcm->client_session_index_fifo))
     {
       clib_warning ("[%d] client session queue is full!", getpid ());
-      vppcom_send_accept_session_reply (mp->handle,
+      vppcom_send_accept_session_reply (mp->handle, mp->context,
 					VNET_API_ERROR_QUEUE_FULL);
       clib_spinlock_unlock (&vcm->sessions_lockp);
       return;
@@ -1102,10 +1239,11 @@ vl_api_accept_session_t_handler (vl_api_accept_session_t * mp)
   tx_fifo->client_session_index = session_index;
 
   session->vpp_handle = mp->handle;
+  session->client_context = mp->context;
   session->server_rx_fifo = rx_fifo;
   session->server_tx_fifo = tx_fifo;
   session->vpp_event_queue = uword_to_pointer (mp->vpp_event_queue_address,
-					       unix_shared_memory_queue_t *);
+					       svm_queue_t *);
   session->state = STATE_ACCEPT;
   session->is_cut_thru = 0;
   session->is_server = 1;
@@ -1125,26 +1263,74 @@ vl_api_accept_session_t_handler (vl_api_accept_session_t * mp)
   clib_spinlock_unlock (&vcm->sessions_lockp);
 
   if (VPPCOM_DEBUG > 1)
+    clib_warning ("[%d] vpp handle 0x%llx, sid %u: client accept "
+		  "request from %s address %U port %d queue %p!", getpid (),
+		  mp->handle, session_index, mp->is_ip4 ? "IPv4" : "IPv6",
+		  format_ip46_address, &mp->ip, mp->is_ip4,
+		  clib_net_to_host_u16 (mp->port), session->vpp_event_queue);
+
+  if (VPPCOM_DEBUG > 0)
     {
-      u8 *ip_str = format (0, "%U", format_ip46_address, &mp->ip, mp->is_ip4);
-      clib_warning ("[%d] received request to accept session (sid %d) "
-		    "from %s:%d", getpid (), session_index, ip_str,
-		    clib_net_to_host_u16 (mp->port));
-      vec_free (ip_str);
+      session->elog_track.name =
+	(char *) format (0, "C:%d:S:%d%c", vcm->my_client_index,
+			 session_index, 0);
+      elog_track_register (&vcm->elog_main, &session->elog_track);
+
+      if (session->peer_addr.is_ip4)
+	{
+	  /* *INDENT-OFF* */
+	  ELOG_TYPE_DECLARE (e) =
+	  {
+	    .format =
+	    "client_accept:handle:%x addr:%d.%d.%d.%d:%d",
+	    .format_args = "i8i1i1i1i1i2",
+	  };
+
+	  CLIB_PACKED (struct {
+	    u64 handle;	//8
+	    u8 addr[4];	//4
+	    u16 port;	//2
+	  }) * ed;
+
+	  ed = ELOG_TRACK_DATA (&vcm->elog_main, e, session->elog_track);
+
+	  ed->handle = mp->handle;
+	  ed->addr[0] = session->peer_addr.ip46.ip4.as_u8[0];
+	  ed->addr[1] = session->peer_addr.ip46.ip4.as_u8[1];
+	  ed->addr[2] = session->peer_addr.ip46.ip4.as_u8[2];
+	  ed->addr[3] = session->peer_addr.ip46.ip4.as_u8[3];
+	  ed->port = session->peer_port;
+	  /* *INDENT-ON* */
+	}
+      else
+	{
+	  clib_warning ("ip6");
+	}
     }
+
 }
 
 static void
-vppcom_send_connect_session_reply (session_t * session, int retval)
+vppcom_send_connect_session_reply (session_t * session, u32 session_index,
+				   u64 vpp_handle, u32 context, int retval)
 {
   vl_api_connect_session_reply_t *rmp;
   u32 len;
-  unix_shared_memory_queue_t *client_q;
+  svm_queue_t *client_q;
 
   rmp = vl_msg_api_alloc (sizeof (*rmp));
   memset (rmp, 0, sizeof (*rmp));
-
   rmp->_vl_msg_id = ntohs (VL_API_CONNECT_SESSION_REPLY);
+
+  if (!session)
+    {
+      rmp->context = context;
+      rmp->handle = vpp_handle;
+      rmp->retval = htonl (retval);
+      vl_msg_api_send_shmem (vcm->vl_input_queue, (u8 *) & rmp);
+      return;
+    }
+
   rmp->context = session->client_context;
   rmp->retval = htonl (retval);
   rmp->handle = session->vpp_handle;
@@ -1160,8 +1346,7 @@ vppcom_send_connect_session_reply (session_t * session, int retval)
 	       sizeof (rmp->lcl_ip));
   rmp->is_ip4 = session->peer_addr.is_ip4;
   rmp->lcl_port = session->peer_port;
-  client_q = uword_to_pointer (session->client_queue_address,
-			       unix_shared_memory_queue_t *);
+  client_q = uword_to_pointer (session->client_queue_address, svm_queue_t *);
   ASSERT (client_q);
   vl_msg_api_send_shmem (client_q, (u8 *) & rmp);
 }
@@ -1183,8 +1368,10 @@ vl_api_connect_sock_t_handler (vl_api_connect_sock_t * mp)
       if (VPPCOM_DEBUG > 1)
 	clib_warning ("[%d] client session queue is full!", getpid ());
 
-      /* TBD: fix handle missing in api msg. */
-      vppcom_send_accept_session_reply (0, VNET_API_ERROR_QUEUE_FULL);
+      /* TBD: Fix api to include vpp handle */
+      vppcom_send_connect_session_reply (0 /* session */ , 0 /* sid */ ,
+					 0 /* handle */ , mp->context,
+					 VNET_API_ERROR_QUEUE_FULL);
       return;
     }
 
@@ -1213,6 +1400,33 @@ vl_api_connect_sock_t_handler (vl_api_connect_sock_t * mp)
     clib_warning ("[%d] sid %u: Got a cut-thru connect request! "
 		  "clib_fifo_elts %u!\n", getpid (), session_index,
 		  clib_fifo_elts (vcm->client_session_index_fifo));
+
+  if (VPPCOM_DEBUG > 0)
+    {
+      session->elog_track.name =
+	(char *) format (0, "C:%d:S:%d%c", vcm->my_client_index,
+			 session_index, 0);
+      elog_track_register (&vcm->elog_main, &session->elog_track);
+
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+      {
+	.format = "cut-thru-connect:S:%d clib_fifo_elts:%d",
+	.format_args = "i4i4",
+      };
+
+      struct
+      {
+	u32 data[2];
+      } *ed;
+
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, session->elog_track);
+
+      ed->data[0] = session_index;
+      ed->data[1] = clib_fifo_elts (vcm->client_session_index_fifo);
+      /* *INDENT-ON* */
+    }
+
   clib_spinlock_unlock (&vcm->sessions_lockp);
 }
 
@@ -1274,6 +1488,24 @@ vppcom_session_unbind (u32 session_index)
 		  getpid (), vpp_handle, session_index,
 		  session->state, vppcom_session_state_str (session->state));
 
+  if (VPPCOM_DEBUG > 0)
+    {
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+      {
+	.format = "unbind: handle:%x",
+	.format_args = "i8",
+      };
+
+      struct
+      {
+	u64 handle;
+      } *ed;
+
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, session->elog_track);
+      ed->handle = vpp_handle;
+      /* *INDENT-ON* */
+    }
   vppcom_send_unbind_sock (vpp_handle);
 
 done:
@@ -1310,8 +1542,9 @@ vppcom_session_disconnect (u32 session_index)
 
   if (PREDICT_FALSE (is_listen))
     {
-      clib_warning ("[%d] ERROR: sid %u: Cannot disconnect a "
-		    "listen socket!", getpid (), session_index);
+      clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+		    "Cannot disconnect a listen socket!",
+		    getpid (), vpp_handle, session_index);
       rv = VPPCOM_EBADFD;
       goto done;
     }
@@ -1328,8 +1561,9 @@ vppcom_session_disconnect (u32 session_index)
 	  vppcom_send_disconnect_session_reply (vpp_handle,
 						session_index, 0 /* rv */ );
 	  if (VPPCOM_DEBUG > 1)
-	    clib_warning ("[%d] sid %u: sending disconnect REPLY...",
-			  getpid (), session_index);
+	    clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+			  "sending disconnect REPLY...",
+			  getpid (), vpp_handle, session_index);
 	}
 
       /* Otherwise, send a disconnect session msg...
@@ -1337,9 +1571,9 @@ vppcom_session_disconnect (u32 session_index)
       else
 	{
 	  if (VPPCOM_DEBUG > 1)
-	    clib_warning ("[%d] sid %u: sending disconnect...",
-			  getpid (), session_index, state,
-			  vppcom_session_state_str (state));
+	    clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+			  "sending disconnect...",
+			  getpid (), vpp_handle, session_index);
 
 	  vppcom_send_disconnect_session (vpp_handle, session_index);
 	}
@@ -1361,9 +1595,9 @@ vppcom_session_disconnect (u32 session_index)
 
 	  if (VPPCOM_DEBUG > 1)
 	    clib_warning ("[%d] sid %d: freeing cut-thru fifos in "
-			  "sm_seg_index %d\n"
-			  "  server_rx_fifo %p, refcnt = %d\n"
-			  "  server_tx_fifo %p, refcnt = %d",
+			  "sm_seg_index %d! "
+			  " server_rx_fifo %p, refcnt = %d"
+			  " server_tx_fifo %p, refcnt = %d",
 			  getpid (), session_index, session->sm_seg_index,
 			  session->server_rx_fifo,
 			  session->server_rx_fifo->refcnt,
@@ -1425,6 +1659,7 @@ vppcom_cfg_init (vppcom_cfg_t * vcl_cfg)
   ASSERT (vcl_cfg);
 
   vcl_cfg->heapsize = (256ULL << 20);
+  vcl_cfg->vpp_api_q_length = 1024;
   vcl_cfg->segment_baseva = 0x200000000ULL;
   vcl_cfg->segment_size = (256 << 20);
   vcl_cfg->add_segment_size = (128 << 20);
@@ -1436,6 +1671,8 @@ vppcom_cfg_init (vppcom_cfg_t * vcl_cfg)
   vcl_cfg->app_timeout = 10 * 60.0;
   vcl_cfg->session_timeout = 10 * 60.0;
   vcl_cfg->accept_timeout = 60.0;
+  vcl_cfg->event_ring_size = (128 << 10);
+  vcl_cfg->event_log_path = "/dev/shm";
 }
 
 static void
@@ -1587,7 +1824,7 @@ vppcom_cfg_read (char *conf_fname)
   u8 vc_cfg_input = 0;
   u8 *chroot_path;
   struct stat s;
-  u32 uid, gid;
+  u32 uid, gid, q_len;
 
   fd = open (conf_fname, O_RDONLY);
   if (fd < 0)
@@ -1646,6 +1883,23 @@ vppcom_cfg_read (char *conf_fname)
 			      getpid (), chroot_path);
 	      chroot_path = 0;	/* Don't vec_free() it! */
 	    }
+	  else if (unformat (line_input, "vpp-api-q-length %d", &q_len))
+	    {
+	      if (q_len < vcl_cfg->vpp_api_q_length)
+		{
+		  clib_warning ("[%d] ERROR: configured vpp-api-q-length "
+				"(%u) is too small! Using default: %u ",
+				getpid (), q_len, vcl_cfg->vpp_api_q_length);
+		}
+	      else
+		{
+		  vcl_cfg->vpp_api_q_length = q_len;
+
+		  if (VPPCOM_DEBUG > 0)
+		    clib_warning ("[%d] configured vpp-api-q-length %u",
+				  getpid (), vcl_cfg->vpp_api_q_length);
+		}
+	    }
 	  else if (unformat (line_input, "uid %d", &uid))
 	    {
 	      vl_set_memory_uid (uid);
@@ -2057,14 +2311,37 @@ vppcom_app_destroy (void)
     clib_warning ("[%d] detaching from VPP, my_client_index %d (0x%x)",
 		  getpid (), vcm->my_client_index, vcm->my_client_index);
 
+  if (VPPCOM_DEBUG > 0)
+    {
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+      {
+	.format = "app_detach:C:%d",
+	.format_args = "i4",
+      };
+
+      struct
+      {
+	u32 data;
+      } *ed;
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, vcm->elog_track);
+      ed->data = vcm->my_client_index;
+      /* *INDENT-ON* */
+    }
+
   vppcom_app_detach ();
   rv = vppcom_wait_for_app_state_change (STATE_APP_ENABLED);
   if (PREDICT_FALSE (rv))
     {
       if (VPPCOM_DEBUG > 0)
-	clib_warning ("[%d] application detach timed out, rv = %s (%d)",
-		      getpid (), vppcom_retval_str (rv), rv);
+	clib_warning ("[%d] application detach timed out! returning %d (%s)",
+		      getpid (), rv, vppcom_retval_str (rv));
     }
+
+  /* Finished with logging before client gets reset to ~0 */
+  if (VPPCOM_DEBUG > 0)
+    write_elog ();
+
   vl_client_disconnect_from_vlib ();
   vcm->my_client_index = ~0;
   vcm->app_state = STATE_APP_START;
@@ -2091,6 +2368,33 @@ vppcom_session_create (u32 vrf, u8 proto, u8 is_nonblocking)
   if (VPPCOM_DEBUG > 0)
     clib_warning ("[%d] sid %u", getpid (), session_index);
 
+  if (VPPCOM_DEBUG > 0)
+    {
+      session->elog_track.name =
+	(char *) format (0, "C:%d:S:%d%c", vcm->my_client_index,
+			 session_index, 0);
+      elog_track_register (&vcm->elog_main, &session->elog_track);
+
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+      {
+	.format = "session_create:vrf:%d proto:%d state:%d is_nonblocking:%d",
+	.format_args = "i4i4i4i4",
+      };
+
+      struct
+      {
+	u32 data[4];
+      } *ed;
+
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, session->elog_track);
+      ed->data[0] = session->vrf;
+      ed->data[1] = session->proto;
+      ed->data[2] = session->state;
+      ed->data[3] = session->is_nonblocking;
+      /* *INDENT-ON* */
+    }
+
   return (int) session_index;
 }
 
@@ -2104,6 +2408,7 @@ vppcom_session_close (uint32_t session_index)
   u8 is_vep_session;
   u32 next_sid;
   u32 vep_idx;
+  u64 vpp_handle;
   uword *p;
   session_state_t state;
 
@@ -2114,20 +2419,28 @@ vppcom_session_close (uint32_t session_index)
   next_sid = session->vep.next_sid;
   vep_idx = session->vep.vep_idx;
   state = session->state;
+  vpp_handle = session->vpp_handle;
   clib_spinlock_unlock (&vcm->sessions_lockp);
 
   if (VPPCOM_DEBUG > 0)
-    clib_warning ("[%d] sid %d: closing session...", getpid (),
-		  session_index);
+    {
+      if (is_vep)
+	clib_warning ("[%d] vep_idx %u / sid %u: closing epoll session...",
+		      getpid (), session_index, session_index);
+      else
+	clib_warning ("[%d] vpp handle 0x%llx, sid %d: closing session...",
+		      getpid (), vpp_handle, session_index);
+    }
 
   if (is_vep)
     {
       while (next_sid != ~0)
 	{
 	  rv = vppcom_epoll_ctl (session_index, EPOLL_CTL_DEL, next_sid, 0);
-	  if ((VPPCOM_DEBUG > 0) && (rv < 0))
-	    clib_warning ("[%d] sid %u: EPOLL_CTL_DEL vep_idx %u failed, "
-			  "rv = %d (%s)", getpid (), next_sid, vep_idx,
+	  if ((VPPCOM_DEBUG > 0) && PREDICT_FALSE (rv < 0))
+	    clib_warning ("[%d] vpp handle 0x%llx, sid %u: EPOLL_CTL_DEL "
+			  "vep_idx %u failed! rv %d (%s)", getpid (),
+			  vpp_handle, next_sid, vep_idx,
 			  rv, vppcom_retval_str (rv));
 
 	  VCL_LOCK_AND_GET_SESSION (session_index, &session);
@@ -2141,9 +2454,10 @@ vppcom_session_close (uint32_t session_index)
 	{
 	  rv = vppcom_epoll_ctl (vep_idx, EPOLL_CTL_DEL, session_index, 0);
 	  if ((VPPCOM_DEBUG > 0) && (rv < 0))
-	    clib_warning ("[%d] sid %u: EPOLL_CTL_DEL vep_idx %u failed!  "
-			  "rv = %d (%s)", getpid (), session_index, vep_idx,
-			  rv, vppcom_retval_str (rv));
+	    clib_warning ("[%d] vpp handle 0x%llx, sid %u: EPOLL_CTL_DEL "
+			  "vep_idx %u failed! rv %d (%s)",
+			  getpid (), vpp_handle, session_index,
+			  vep_idx, rv, vppcom_retval_str (rv));
 	}
 
       if (is_listen)
@@ -2154,10 +2468,10 @@ vppcom_session_close (uint32_t session_index)
 	      if (PREDICT_FALSE (rv < 0))
 		{
 		  if (VPPCOM_DEBUG > 0)
-		    clib_warning ("[%d] sid %u: listener unbind failed!  "
-				  "rv = %d (%s)",
-				  getpid (), session_index, rv,
-				  vppcom_retval_str (rv));
+		    clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+				  "listener unbind failed! rv %d (%s)",
+				  getpid (), vpp_handle, session_index,
+				  rv, vppcom_retval_str (rv));
 		}
 	    }
 	}
@@ -2166,27 +2480,54 @@ vppcom_session_close (uint32_t session_index)
 	{
 	  rv = vppcom_session_disconnect (session_index);
 	  if (PREDICT_FALSE (rv < 0))
-	    clib_warning ("[%d] ERROR: sid %u: session disconnect failed!  "
-			  "rv %d (%s)", getpid (), session_index, rv,
-			  vppcom_retval_str (rv));
+	    clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+			  "session disconnect failed! rv %d (%s)",
+			  getpid (), vpp_handle, session_index,
+			  rv, vppcom_retval_str (rv));
 	}
     }
 
   VCL_LOCK_AND_GET_SESSION (session_index, &session);
-
-  if (session->vpp_handle != ~0)
+  vpp_handle = session->vpp_handle;
+  if (vpp_handle != ~0)
     {
-      p = hash_get (vcm->session_index_by_vpp_handles, session->vpp_handle);
+      p = hash_get (vcm->session_index_by_vpp_handles, vpp_handle);
       if (p)
-	hash_unset (vcm->session_index_by_vpp_handles, session->vpp_handle);
+	hash_unset (vcm->session_index_by_vpp_handles, vpp_handle);
     }
   pool_put_index (vcm->sessions, session_index);
   clib_spinlock_unlock (&vcm->sessions_lockp);
 
   if (VPPCOM_DEBUG > 0)
-    clib_warning ("[%d] sid %u: session removed.", getpid (), session_index);
-
+    {
+      if (is_vep)
+	clib_warning ("[%d] vep_idx %u / sid %u: epoll session removed.",
+		      getpid (), session_index, session_index);
+      else
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: session removed.",
+		      getpid (), vpp_handle, session_index);
+    }
 done:
+
+  if (VPPCOM_DEBUG > 0)
+    {
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+      {
+	.format = "session_close:rv:%d",
+	.format_args = "i4",
+      };
+
+      struct
+      {
+	u32 data;
+      } *ed;
+
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, session->elog_track);
+      ed->data = rv;
+      /* *INDENT-ON* */
+    }
+
   return rv;
 }
 
@@ -2216,13 +2557,44 @@ vppcom_session_bind (uint32_t session_index, vppcom_endpt_t * ep)
   session->lcl_port = ep->port;
 
   if (VPPCOM_DEBUG > 0)
-    clib_warning ("[%d] sid %u: bound to local address %U "
-		  "port %u, proto %s",
-		  getpid (), session_index, format_ip46_address,
-		  &session->lcl_addr.ip46, session->lcl_addr.is_ip4,
+    clib_warning ("[%d] sid %u: binding to local %s address %U "
+		  "port %u, proto %s", getpid (), session_index,
+		  session->lcl_addr.is_ip4 ? "IPv4" : "IPv6",
+		  format_ip46_address, &session->lcl_addr.ip46,
+		  session->lcl_addr.is_ip4,
 		  clib_net_to_host_u16 (session->lcl_port),
 		  session->proto ? "UDP" : "TCP");
 
+  if (VPPCOM_DEBUG > 0)
+    {
+      if (session->lcl_addr.is_ip4)
+	{
+	  /* *INDENT-OFF* */
+	  ELOG_TYPE_DECLARE (e) =
+	  {
+	    .format = "bind local:%s:%d.%d.%d.%d:%d ",
+	    .format_args = "t1i1i1i1i1i2",
+	    .n_enum_strings = 2,
+	    .enum_strings = {"TCP", "UDP",},
+	  };
+
+	  CLIB_PACKED (struct {
+	    u8 proto;
+	    u8 addr[4];
+	    u16 port;
+	  }) * ed;
+
+	  ed = ELOG_TRACK_DATA (&vcm->elog_main, e, session->elog_track);
+	  ed->proto = session->proto;
+	  ed->addr[0] = session->lcl_addr.ip46.ip4.as_u8[0];
+	  ed->addr[1] = session->lcl_addr.ip46.ip4.as_u8[1];
+	  ed->addr[2] = session->lcl_addr.ip46.ip4.as_u8[2];
+	  ed->addr[3] = session->lcl_addr.ip46.ip4.as_u8[3];
+	  ed->port = clib_net_to_host_u16 (session->lcl_port);
+	  /* *INDENT-ON* */
+	}
+    }
+
   clib_spinlock_unlock (&vcm->sessions_lockp);
 done:
   return rv;
@@ -2232,7 +2604,8 @@ int
 vppcom_session_listen (uint32_t listen_session_index, uint32_t q_len)
 {
   session_t *listen_session = 0;
-  int rv;
+  u64 listen_vpp_handle;
+  int rv, retval;
 
   VCL_LOCK_AND_GET_SESSION (listen_session_index, &listen_session);
 
@@ -2245,34 +2618,41 @@ vppcom_session_listen (uint32_t listen_session_index, uint32_t q_len)
       goto done;
     }
 
+  listen_vpp_handle = listen_session->vpp_handle;
   if (listen_session->is_listen)
     {
       clib_spinlock_unlock (&vcm->sessions_lockp);
       if (VPPCOM_DEBUG > 0)
-	clib_warning ("[%d] sid %u: already in listen state!",
-		      getpid (), listen_session_index);
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+		      "already in listen state!",
+		      getpid (), listen_vpp_handle, listen_session_index);
       rv = VPPCOM_OK;
       goto done;
     }
 
   if (VPPCOM_DEBUG > 0)
-    clib_warning ("[%d] sid %u: sending bind request...",
-		  getpid (), listen_session_index);
+    clib_warning ("[%d] vpp handle 0x%llx, sid %u: sending bind request...",
+		  getpid (), listen_vpp_handle, listen_session_index);
 
   vppcom_send_bind_sock (listen_session, listen_session_index);
   clib_spinlock_unlock (&vcm->sessions_lockp);
-  rv =
+  retval =
     vppcom_wait_for_session_state_change (listen_session_index, STATE_LISTEN,
 					  vcm->cfg.session_timeout);
-  if (PREDICT_FALSE (rv))
+
+  VCL_LOCK_AND_GET_SESSION (listen_session_index, &listen_session);
+  if (PREDICT_FALSE (retval))
     {
       if (VPPCOM_DEBUG > 0)
-	clib_warning ("[%d] sid %u: bind failed! returning %d (%d)",
-		      getpid (), vppcom_retval_str (rv), rv);
-      return rv;
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: bind failed! "
+		      "returning %d (%s)", getpid (),
+		      listen_session->vpp_handle, listen_session_index,
+		      retval, vppcom_retval_str (retval));
+      clib_spinlock_unlock (&vcm->sessions_lockp);
+      rv = retval;
+      goto done;
     }
 
-  VCL_LOCK_AND_GET_SESSION (listen_session_index, &listen_session);
   clib_fifo_validate (vcm->client_session_index_fifo, q_len);
   clib_spinlock_unlock (&vcm->sessions_lockp);
 done:
@@ -2289,6 +2669,7 @@ vppcom_session_accept (uint32_t listen_session_index, vppcom_endpt_t * ep,
   int rv;
   f64 wait_for;
   char *cut_thru_str;
+  u64 listen_vpp_handle;
 
   VCL_LOCK_AND_GET_SESSION (listen_session_index, &listen_session);
 
@@ -2301,12 +2682,15 @@ vppcom_session_accept (uint32_t listen_session_index, vppcom_endpt_t * ep,
       goto done;
     }
 
+  listen_vpp_handle = listen_session->vpp_handle;
   if (listen_session->state != STATE_LISTEN)
     {
-      clib_spinlock_unlock (&vcm->sessions_lockp);
-      clib_warning ("[%d] ERROR: sid %u: not in listen state! "
-		    "state 0x%x (%s)", getpid (), listen_session->state,
+      clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+		    "not in listen state! state 0x%x (%s)", getpid (),
+		    listen_vpp_handle, listen_session_index,
+		    listen_session->state,
 		    vppcom_session_state_str (listen_session->state));
+      clib_spinlock_unlock (&vcm->sessions_lockp);
       rv = VPPCOM_EBADFD;
       goto done;
     }
@@ -2321,9 +2705,9 @@ vppcom_session_accept (uint32_t listen_session_index, vppcom_endpt_t * ep,
       if (rv)
 	{
 	  if ((VPPCOM_DEBUG > 0))
-	    clib_warning ("[%d] sid %u: accept failed! "
-			  "returning = %d (%s)",
-			  getpid (), listen_session_index,
+	    clib_warning ("[%d] vpp handle 0x%llx, sid %u: accept failed! "
+			  "returning %d (%s)", getpid (),
+			  listen_vpp_handle, listen_session_index,
 			  rv, vppcom_retval_str (rv));
 	  if ((wait_for == 0) || (wait_for_time > 0))
 	    goto done;
@@ -2335,12 +2719,22 @@ vppcom_session_accept (uint32_t listen_session_index, vppcom_endpt_t * ep,
   clib_spinlock_lock (&vcm->sessions_lockp);
   clib_fifo_sub1 (vcm->client_session_index_fifo, client_session_index);
   rv = vppcom_session_at_index (client_session_index, &client_session);
-  ASSERT (rv == VPPCOM_OK);
+  if (PREDICT_FALSE (rv))
+    {
+      rv = VPPCOM_ECONNABORTED;
+      clib_warning ("[%d] vpp handle 0x%llx, sid %u: client sid %u "
+		    "lookup failed! returning %d (%s)", getpid (),
+		    listen_vpp_handle, listen_session_index,
+		    client_session_index, rv, vppcom_retval_str (rv));
+      goto done;
+    }
 
   client_session->is_nonblocking = (flags & O_NONBLOCK) ? 1 : 0;
   if (VPPCOM_DEBUG > 0)
-    clib_warning ("[%d] sid %u: Got a client request! flags %d, "
-		  "is_nonblocking %u", getpid (), client_session_index,
+    clib_warning ("[%d] vpp handle 0x%llx, sid %u: Got a client request! "
+		  "vpp handle 0x%llx, sid %u, flags %d, is_nonblocking %u",
+		  getpid (), listen_vpp_handle, listen_session_index,
+		  client_session->vpp_handle, client_session_index,
 		  flags, client_session->is_nonblocking);
 
   ep->vrf = client_session->vrf;
@@ -2375,12 +2769,18 @@ vppcom_session_accept (uint32_t listen_session_index, vppcom_endpt_t * ep,
       rv = svm_fifo_segment_create (a);
       if (PREDICT_FALSE (rv))
 	{
-	  clib_warning ("[%d] ERROR: sid %u: "
-			"svm_fifo_segment_create ('%s') failed! rv %d",
-			getpid (), client_session_index, a->segment_name, rv);
+	  clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+			"client sid %u svm_fifo_segment_create ('%s') "
+			"failed! rv %d", getpid (), listen_vpp_handle,
+			listen_session_index, client_session_index,
+			a->segment_name, rv);
 	  vec_reset_length (a->new_segment_indices);
 	  rv = VNET_API_ERROR_URI_FIFO_CREATE_FAILED;
-	  vppcom_send_connect_session_reply (client_session, rv);
+	  vppcom_send_connect_session_reply (client_session,
+					     client_session_index,
+					     client_session->vpp_handle,
+					     client_session->client_context,
+					     rv);
 	  clib_spinlock_unlock (&vcm->sessions_lockp);
 	  rv = VPPCOM_ENOMEM;
 	  goto done;
@@ -2397,12 +2797,17 @@ vppcom_session_accept (uint32_t listen_session_index, vppcom_endpt_t * ep,
       if (PREDICT_FALSE (!client_session->server_rx_fifo))
 	{
 	  svm_fifo_segment_delete (seg);
-	  clib_warning ("[%d] ERROR: sid %u: rx fifo alloc failed! "
-			"size %ld (0x%lx)", getpid (),
-			client_session_index,
+	  clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+			"client sid %u rx fifo alloc failed! "
+			"size %ld (0x%lx)", getpid (), listen_vpp_handle,
+			listen_session_index, client_session_index,
 			vcm->cfg.rx_fifo_size, vcm->cfg.rx_fifo_size);
 	  rv = VNET_API_ERROR_URI_FIFO_CREATE_FAILED;
-	  vppcom_send_connect_session_reply (client_session, rv);
+	  vppcom_send_connect_session_reply (client_session,
+					     client_session_index,
+					     client_session->vpp_handle,
+					     client_session->client_context,
+					     rv);
 	  clib_spinlock_unlock (&vcm->sessions_lockp);
 	  rv = VPPCOM_ENOMEM;
 	  goto done;
@@ -2416,12 +2821,17 @@ vppcom_session_accept (uint32_t listen_session_index, vppcom_endpt_t * ep,
       if (PREDICT_FALSE (!client_session->server_tx_fifo))
 	{
 	  svm_fifo_segment_delete (seg);
-	  clib_warning ("[%d] ERROR: sid %u: tx fifo alloc failed! "
-			"size %ld (0x%lx)",
-			getpid (), client_session_index,
+	  clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+			"client sid %u tx fifo alloc failed! "
+			"size %ld (0x%lx)", getpid (), listen_vpp_handle,
+			listen_session_index, client_session_index,
 			vcm->cfg.tx_fifo_size, vcm->cfg.tx_fifo_size);
 	  rv = VNET_API_ERROR_URI_FIFO_CREATE_FAILED;
-	  vppcom_send_connect_session_reply (client_session, rv);
+	  vppcom_send_connect_session_reply (client_session,
+					     client_session_index,
+					     client_session->vpp_handle,
+					     client_session->client_context,
+					     rv);
 	  clib_spinlock_unlock (&vcm->sessions_lockp);
 	  rv = VPPCOM_ENOMEM;
 	  goto done;
@@ -2430,10 +2840,10 @@ vppcom_session_accept (uint32_t listen_session_index, vppcom_endpt_t * ep,
 	client_session_index;
 
       if (VPPCOM_DEBUG > 1)
-	clib_warning ("[%d] sid %u: created segment '%s', "
-		      "rx_fifo %p, tx_fifo %p",
-		      getpid (), client_session_index,
-		      client_session->segment_name,
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: client sid %u "
+		      "created segment '%s', rx_fifo %p, tx_fifo %p",
+		      getpid (), listen_vpp_handle, listen_session_index,
+		      client_session_index, client_session->segment_name,
 		      client_session->server_rx_fifo,
 		      client_session->server_tx_fifo);
 
@@ -2445,30 +2855,89 @@ vppcom_session_accept (uint32_t listen_session_index, vppcom_endpt_t * ep,
 	ssvm_lock_non_recursive (sh, 1);
 	oldheap = ssvm_push_heap (sh);
 	event_q = client_session->vpp_event_queue =
-	  unix_shared_memory_queue_init (vcm->cfg.event_queue_size,
-					 sizeof (session_fifo_event_t),
-					 getpid (), 0 /* signal not sent */ );
+	  svm_queue_init (vcm->cfg.event_queue_size,
+			  sizeof (session_fifo_event_t),
+			  getpid (), 0 /* signal not sent */ );
 	ssvm_pop_heap (oldheap);
 	ssvm_unlock_non_recursive (sh);
       }
 #endif
-      vppcom_send_connect_session_reply (client_session, 0);
+      vppcom_send_connect_session_reply (client_session,
+					 client_session_index,
+					 client_session->vpp_handle,
+					 client_session->client_context,
+					 0 /* retval OK */ );
     }
   else
     {
       cut_thru_str = " ";
-      vppcom_send_accept_session_reply (client_session->vpp_handle, 0);
+      vppcom_send_accept_session_reply (client_session->vpp_handle,
+					client_session->client_context,
+					0 /* retval OK */ );
     }
 
   if (VPPCOM_DEBUG > 0)
-    clib_warning ("[%d] sid %u: accepted%sconnection to local %s address "
-		  "%U port %u",
-		  getpid (), client_session_index, cut_thru_str,
+    clib_warning ("[%d] vpp handle 0x%llx, sid %u: accepted vpp handle "
+		  "0x%llx, sid %u%sconnection to local %s address "
+		  "%U port %u", getpid (), listen_vpp_handle,
+		  listen_session_index, client_session->vpp_handle,
+		  client_session_index, cut_thru_str,
 		  client_session->lcl_addr.is_ip4 ? "IPv4" : "IPv6",
 		  format_ip46_address, &client_session->lcl_addr.ip46,
 		  client_session->lcl_addr.is_ip4,
 		  clib_net_to_host_u16 (client_session->lcl_port));
 
+  if (VPPCOM_DEBUG > 0)
+    {
+      client_session->elog_track.name =
+	(char *) format (0, "C:%d:S:%d%c", vcm->my_client_index,
+			 client_session_index, 0);
+      elog_track_register (&vcm->elog_main, &client_session->elog_track);
+
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+      {
+	.format = "accept cut-thru: listen_handle:%x from_handle:%x",
+	.format_args = "i8i8",
+      };
+
+      struct
+      {
+	u64 handle[2];
+      } *ed;
+
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, client_session->elog_track);
+      ed->handle[0] = listen_vpp_handle;
+      ed->handle[1] = client_session->vpp_handle;
+      /* *INDENT-ON* */
+
+      if (client_session->lcl_addr.is_ip4)
+	{
+	  /* *INDENT-OFF* */
+	  ELOG_TYPE_DECLARE (e2) =
+	  {
+	    .format = "accept cut-thru: S:%d %d.%d.%d.%d:%d ",
+	    .format_args = "i4i1i1i1i1i2",
+	  };
+
+	  CLIB_PACKED (struct {
+	    u32 session;
+	    u8 addr[4];
+	    u16 port;
+	  }) * ed2;
+
+	  ed2 =
+	    ELOG_TRACK_DATA (&vcm->elog_main, e2, client_session->elog_track);
+	  ed2->session = client_session_index;
+	  ed2->addr[0] = client_session->lcl_addr.ip46.ip4.as_u8[0];
+	  ed2->addr[1] = client_session->lcl_addr.ip46.ip4.as_u8[1];
+	  ed2->addr[2] = client_session->lcl_addr.ip46.ip4.as_u8[2];
+	  ed2->addr[3] = client_session->lcl_addr.ip46.ip4.as_u8[3];
+	  ed2->port = clib_net_to_host_u16 (client_session->lcl_port);
+	  /* *INDENT-ON* */
+	}
+    }
+
   clib_spinlock_unlock (&vcm->sessions_lockp);
   rv = (int) client_session_index;
 done:
@@ -2479,7 +2948,8 @@ int
 vppcom_session_connect (uint32_t session_index, vppcom_endpt_t * server_ep)
 {
   session_t *session = 0;
-  int rv;
+  int rv, retval = VPPCOM_OK;
+  u64 vpp_handle = ~0;
 
   VCL_LOCK_AND_GET_SESSION (session_index, &session);
 
@@ -2492,11 +2962,13 @@ vppcom_session_connect (uint32_t session_index, vppcom_endpt_t * server_ep)
       goto done;
     }
 
+  vpp_handle = session->vpp_handle;
   if (PREDICT_FALSE (session->is_server))
     {
       clib_spinlock_unlock (&vcm->sessions_lockp);
-      clib_warning ("[%d] ERROR: sid %u: is in use as a server session!",
-		    getpid (), session_index);
+      clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: is in use "
+		    "as a server session!", getpid (), vpp_handle,
+		    session_index);
       rv = VPPCOM_EBADFD;
       goto done;
     }
@@ -2504,9 +2976,9 @@ vppcom_session_connect (uint32_t session_index, vppcom_endpt_t * server_ep)
   if (PREDICT_FALSE (session->state & CLIENT_STATE_OPEN))
     {
       if (VPPCOM_DEBUG > 0)
-	clib_warning ("[%d] sid %u: session already connected to "
-		      "%s %U port %d proto %s, state 0x%x (%s)",
-		      getpid (), session_index,
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: session already "
+		      "connected to %s %U port %d proto %s, state 0x%x (%s)",
+		      getpid (), vpp_handle, session_index,
 		      session->peer_addr.is_ip4 ? "IPv4" : "IPv6",
 		      format_ip46_address,
 		      &session->peer_addr.ip46, session->peer_addr.is_ip4,
@@ -2515,7 +2987,6 @@ vppcom_session_connect (uint32_t session_index, vppcom_endpt_t * server_ep)
 		      vppcom_session_state_str (session->state));
 
       clib_spinlock_unlock (&vcm->sessions_lockp);
-      rv = VPPCOM_OK;
       goto done;
     }
 
@@ -2525,8 +2996,9 @@ vppcom_session_connect (uint32_t session_index, vppcom_endpt_t * server_ep)
   session->peer_port = server_ep->port;
 
   if (VPPCOM_DEBUG > 0)
-    clib_warning ("[%d] sid %u: connecting to server %s %U port %d proto %s",
-		  getpid (), session_index,
+    clib_warning ("[%d] vpp handle 0x%llx, sid %u: connecting to server "
+		  "%s %U port %d proto %s",
+		  getpid (), vpp_handle, session_index,
 		  session->peer_addr.is_ip4 ? "IPv4" : "IPv6",
 		  format_ip46_address,
 		  &session->peer_addr.ip46, session->peer_addr.is_ip4,
@@ -2536,18 +3008,27 @@ vppcom_session_connect (uint32_t session_index, vppcom_endpt_t * server_ep)
   vppcom_send_connect_sock (session, session_index);
   clib_spinlock_unlock (&vcm->sessions_lockp);
 
-  rv = vppcom_wait_for_session_state_change (session_index, STATE_CONNECT,
-					     vcm->cfg.session_timeout);
-  if (PREDICT_FALSE (rv))
+  retval =
+    vppcom_wait_for_session_state_change (session_index, STATE_CONNECT,
+					  vcm->cfg.session_timeout);
+
+  VCL_LOCK_AND_GET_SESSION (session_index, &session);
+  vpp_handle = session->vpp_handle;
+  clib_spinlock_unlock (&vcm->sessions_lockp);
+
+done:
+  if (PREDICT_FALSE (retval))
     {
+      rv = retval;
       if (VPPCOM_DEBUG > 0)
-	clib_warning ("[%d] sid %u: connect failed! returning %d (%s)",
-		      getpid (), session_index, rv, vppcom_retval_str (rv));
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: connect failed! "
+		      "returning %d (%s)", getpid (), vpp_handle,
+		      session_index, rv, vppcom_retval_str (rv));
     }
   else if (VPPCOM_DEBUG > 0)
-    clib_warning ("[%d] sid %d: connected!", getpid (), session_index);
+    clib_warning ("[%d] vpp handle 0x%llx, sid %u: connected!",
+		  getpid (), vpp_handle, session_index);
 
-done:
   return rv;
 }
 
@@ -2564,6 +3045,7 @@ vppcom_session_read_internal (uint32_t session_index, void *buf, int n,
   session_state_t state;
   u8 is_server;
   u8 is_nonblocking;
+  u64 vpp_handle;
 
   ASSERT (buf);
 
@@ -2578,6 +3060,7 @@ vppcom_session_read_internal (uint32_t session_index, void *buf, int n,
       goto done;
     }
 
+  vpp_handle = session->vpp_handle;
   is_server = session->is_server;
   is_nonblocking = session->is_nonblocking;
   state = session->state;
@@ -2588,10 +3071,10 @@ vppcom_session_read_internal (uint32_t session_index, void *buf, int n,
 	    VPPCOM_ECONNRESET : VPPCOM_ENOTCONN);
 
       if (VPPCOM_DEBUG > 0)
-	clib_warning ("[%d] sid %u: %s session is not open! "
-		      "state 0x%x (%s), returning %d (%s)",
-		      getpid (), session_index, is_server ?
-		      "server" : "client", state,
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: %s session is "
+		      "not open! state 0x%x (%s), returning %d (%s)",
+		      getpid (), vpp_handle, session_index,
+		      is_server ? "server" : "client", state,
 		      vppcom_session_state_str (state),
 		      rv, vppcom_retval_str (rv));
       goto done;
@@ -2628,10 +3111,10 @@ vppcom_session_read_internal (uint32_t session_index, void *buf, int n,
 
 	  if (VPPCOM_DEBUG > 1)
 	    {
-	      clib_warning ("[%d] sid %u: Empty fifo with %s session "
-			    "state 0x%x (%s)!\n"
-			    "  Setting state to %d (%s), returning %d (%s)",
-			    getpid (), session_index,
+	      clib_warning ("[%d] vpp handle 0x%llx, sid %u: Empty fifo "
+			    "with %s session state 0x%x (%s)!"
+			    "  Setting state to 0x%x (%s), returning %d (%s)",
+			    getpid (), vpp_handle, session_index,
 			    is_server ? "server" : "client",
 			    state, vppcom_session_state_str (state),
 			    new_state, vppcom_session_state_str (new_state),
@@ -2651,11 +3134,13 @@ vppcom_session_read_internal (uint32_t session_index, void *buf, int n,
   if (VPPCOM_DEBUG > 2)
     {
       if (rv > 0)
-	clib_warning ("[%d] sid %u: read %d bytes from %s (%p)", getpid (),
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: read %d bytes "
+		      "from %s (%p)", getpid (), vpp_handle,
 		      session_index, n_read, fifo_str, rx_fifo);
       else
-	clib_warning ("[%d] sid %u: nothing read, returning %d (%s)",
-		      getpid (), session_index, rv, vppcom_retval_str (rv));
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: nothing read! "
+		      "returning %d (%s)", getpid (), vpp_handle,
+		      session_index, rv, vppcom_retval_str (rv));
     }
 done:
   return rv;
@@ -2682,6 +3167,7 @@ vppcom_session_read_ready (session_t * session, u32 session_index)
   int rv;
   u8 is_server = session->is_server;
   session_state_t state = session->state;
+  u64 vpp_handle = session->vpp_handle;
 
   /* Assumes caller has acquired spinlock: vcm->sessions_lockp */
   if (PREDICT_FALSE (session->is_vep))
@@ -2702,9 +3188,10 @@ vppcom_session_read_ready (session_t * session, u32 session_index)
 		VPPCOM_ENOTCONN);
 
 	  if (VPPCOM_DEBUG > 1)
-	    clib_warning ("[%d] sid %u: %s session is not open! "
-			  "state 0x%x (%s), returning %d (%s)", getpid (),
-			  session_index, is_server ? "server" : "client",
+	    clib_warning ("[%d] vpp handle 0x%llx, sid %u: %s session is "
+			  "not open! state 0x%x (%s), returning %d (%s)",
+			  getpid (), vpp_handle, session_index,
+			  is_server ? "server" : "client",
 			  state, vppcom_session_state_str (state),
 			  rv, vppcom_retval_str (rv));
 	  goto done;
@@ -2730,10 +3217,10 @@ vppcom_session_read_ready (session_t * session, u32 session_index)
 
 	  if (VPPCOM_DEBUG > 1)
 	    {
-	      clib_warning ("[%d] sid %u: Empty fifo with %s session "
-			    "state 0x%x (%s)!\n"
-			    "  Setting state to %d (%s), returning %d (%s)",
-			    getpid (), session_index,
+	      clib_warning ("[%d] vpp handle 0x%llx, sid %u: Empty fifo with"
+			    " %s session state 0x%x (%s)! Setting state to "
+			    "0x%x (%s), returning %d (%s)",
+			    getpid (), session_index, vpp_handle,
 			    is_server ? "server" : "client",
 			    state, vppcom_session_state_str (state),
 			    new_state, vppcom_session_state_str (new_state),
@@ -2744,6 +3231,19 @@ vppcom_session_read_ready (session_t * session, u32 session_index)
 	}
     }
   rv = ready;
+
+  if (vcm->app_event_queue->cursize &&
+      !pthread_mutex_trylock (&vcm->app_event_queue->mutex))
+    {
+      u32 i, n_to_dequeue = vcm->app_event_queue->cursize;
+      session_fifo_event_t e;
+
+      for (i = 0; i < n_to_dequeue; i++)
+	svm_queue_sub_raw (vcm->app_event_queue, (u8 *) & e);
+
+      pthread_mutex_unlock (&vcm->app_event_queue->mutex);
+    }
+
 done:
   return rv;
 }
@@ -2753,7 +3253,7 @@ vppcom_session_write (uint32_t session_index, void *buf, int n)
 {
   session_t *session = 0;
   svm_fifo_t *tx_fifo;
-  unix_shared_memory_queue_t *q;
+  svm_queue_t *q;
   session_fifo_event_t evt;
   int rv, n_write;
   char *fifo_str;
@@ -2761,6 +3261,7 @@ vppcom_session_write (uint32_t session_index, void *buf, int n)
   u8 is_server;
   u8 is_nonblocking;
   session_state_t state;
+  u64 vpp_handle;
 
   ASSERT (buf);
 
@@ -2769,8 +3270,9 @@ vppcom_session_write (uint32_t session_index, void *buf, int n)
   if (PREDICT_FALSE (session->is_vep))
     {
       clib_spinlock_unlock (&vcm->sessions_lockp);
-      clib_warning ("[%d] ERROR: sid %u: cannot write to an epoll session!",
-		    getpid (), session_index);
+      clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+		    "cannot write to an epoll session!",
+		    getpid (), session->vpp_handle, session_index);
 
       rv = VPPCOM_EBADFD;
       goto done;
@@ -2778,6 +3280,7 @@ vppcom_session_write (uint32_t session_index, void *buf, int n)
 
   is_server = session->is_server;
   is_nonblocking = session->is_nonblocking;
+  vpp_handle = session->vpp_handle;
   state = session->state;
   if (!(state & (SERVER_STATE_OPEN | CLIENT_STATE_OPEN)))
     {
@@ -2786,9 +3289,10 @@ vppcom_session_write (uint32_t session_index, void *buf, int n)
 
       clib_spinlock_unlock (&vcm->sessions_lockp);
       if (VPPCOM_DEBUG > 1)
-	clib_warning ("[%d] sid %u: %s session is not open! state 0x%x (%s)",
-		      getpid (), session_index, is_server ?
-		      "server" : "client", state,
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+		      "%s session is not open! state 0x%x (%s)",
+		      getpid (), vpp_handle, session_index,
+		      is_server ? "server" : "client", state,
 		      vppcom_session_state_str (state));
       goto done;
     }
@@ -2815,13 +3319,13 @@ vppcom_session_write (uint32_t session_index, void *buf, int n)
       VCL_LOCK_AND_GET_SESSION (session_index, &session);
       q = session->vpp_event_queue;
       ASSERT (q);
-      unix_shared_memory_queue_add (q, (u8 *) & evt,
-				    0 /* do wait for mutex */ );
+      svm_queue_add (q, (u8 *) & evt, 0 /* do wait for mutex */ );
       clib_spinlock_unlock (&vcm->sessions_lockp);
       if (VPPCOM_DEBUG > 1)
-	clib_warning ("[%d] sid %u: added FIFO_EVENT_APP_TX to "
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+		      "added FIFO_EVENT_APP_TX to "
 		      "vpp_event_q %p, n_write %d", getpid (),
-		      session_index, q, n_write);
+		      vpp_handle, session_index, q, n_write);
     }
 
   if (n_write <= 0)
@@ -2840,10 +3344,10 @@ vppcom_session_write (uint32_t session_index, void *buf, int n)
 
 	  if (VPPCOM_DEBUG > 1)
 	    {
-	      clib_warning ("[%d] sid %u: Empty fifo with %s session "
-			    "state 0x%x (%s)!\n"
-			    "  Setting state to %d (%s), returning %d (%s)",
-			    getpid (), session_index,
+	      clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+			    "Empty fifo with %s session state 0x%x (%s)!"
+			    "  Setting state to 0x%x (%s), returning %d (%s)",
+			    getpid (), vpp_handle, session_index,
 			    is_server ? "server" : "client",
 			    state, vppcom_session_state_str (state),
 			    new_state, vppcom_session_state_str (new_state),
@@ -2863,10 +3367,12 @@ vppcom_session_write (uint32_t session_index, void *buf, int n)
   if (VPPCOM_DEBUG > 2)
     {
       if (n_write <= 0)
-	clib_warning ("[%d] sid %u: FIFO-FULL %s (%p)", getpid (),
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+		      "FIFO-FULL %s (%p)", getpid (), vpp_handle,
 		      session_index, fifo_str, tx_fifo);
       else
-	clib_warning ("[%d] sid %u: wrote %d bytes to %s (%p)", getpid (),
+	clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+		      "wrote %d bytes to %s (%p)", getpid (), vpp_handle,
 		      session_index, n_write, fifo_str, tx_fifo);
     }
 done:
@@ -2887,16 +3393,18 @@ vppcom_session_write_ready (session_t * session, u32 session_index)
   /* Assumes caller has acquired spinlock: vcm->sessions_lockp */
   if (PREDICT_FALSE (session->is_vep))
     {
-      clib_warning ("[%d] ERROR: sid %u: cannot write to an "
-		    "epoll session!", getpid (), session_index);
+      clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+		    "cannot write to an epoll session!",
+		    getpid (), session->vpp_handle, session_index);
       rv = VPPCOM_EBADFD;
       goto done;
     }
 
   if (PREDICT_FALSE (session->is_listen))
     {
-      clib_warning ("[%d] ERROR: sid %u: cannot write to a listen session!",
-		    getpid (), session_index);
+      clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+		    "cannot write to a listen session!",
+		    getpid (), session->vpp_handle, session_index);
       rv = VPPCOM_EBADFD;
       goto done;
     }
@@ -2908,8 +3416,9 @@ vppcom_session_write_ready (session_t * session, u32 session_index)
       rv = ((state == STATE_DISCONNECT) ? VPPCOM_ECONNRESET :
 	    VPPCOM_ENOTCONN);
 
-      clib_warning ("[%d] ERROR: sid %u: %s session is not open! "
-		    "state 0x%x (%s), returning %d (%s)", getpid (),
+      clib_warning ("[%d] ERROR: vpp handle 0x%llx, sid %u: "
+		    "%s session is not open! state 0x%x (%s), "
+		    "returning %d (%s)", getpid (), session->vpp_handle,
 		    session_index, is_server ? "server" : "client",
 		    state, vppcom_session_state_str (state),
 		    rv, vppcom_retval_str (rv));
@@ -2924,8 +3433,10 @@ vppcom_session_write_ready (session_t * session, u32 session_index)
   ready = svm_fifo_max_enqueue (tx_fifo);
 
   if (VPPCOM_DEBUG > 3)
-    clib_warning ("[%d] sid %u: peek %s (%p), ready = %d", getpid (),
-		  session_index, fifo_str, tx_fifo, ready);
+    clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+		  "peek %s (%p), ready = %d", getpid (),
+		  session->vpp_handle, session_index,
+		  fifo_str, tx_fifo, ready);
 
   if (ready == 0)
     {
@@ -2941,10 +3452,11 @@ vppcom_session_write_ready (session_t * session, u32 session_index)
 
 	  if (VPPCOM_DEBUG > 1)
 	    {
-	      clib_warning ("[%d] sid %u: Empty fifo with %s session "
-			    "state 0x%x (%s)!\n"
-			    "  Setting state to %d (%s), returning %d (%s)",
-			    getpid (), session_index,
+	      clib_warning ("[%d] vpp handle 0x%llx, sid %u: "
+			    "Empty fifo with %s session "
+			    "state 0x%x (%s)! Setting state to 0x%x (%s), "
+			    "returning %d (%s)", getpid (),
+			    session->vpp_handle, session_index,
 			    is_server ? "server" : "client",
 			    state, vppcom_session_state_str (state),
 			    new_state, vppcom_session_state_str (new_state),
@@ -3196,7 +3708,32 @@ vppcom_epoll_create (void)
   clib_spinlock_unlock (&vcm->sessions_lockp);
 
   if (VPPCOM_DEBUG > 0)
-    clib_warning ("[%d] Created vep_idx %u!", getpid (), vep_idx);
+    clib_warning ("[%d] Created vep_idx %u / sid %u!",
+		  getpid (), vep_idx, vep_idx);
+
+  if (VPPCOM_DEBUG > 0)
+    {
+      vep_session->elog_track.name =
+	(char *) format (0, "C:%d:VEP:%d%c", vcm->my_client_index,
+			 vep_idx, 0);
+      elog_track_register (&vcm->elog_main, &vep_session->elog_track);
+
+      /* *INDENT-OFF* */
+      ELOG_TYPE_DECLARE (e) =
+      {
+	.format = "created epoll session:%d",
+	.format_args = "i4",
+      };
+
+      struct
+      {
+	u32 data;
+      } *ed;
+
+      ed = ELOG_TRACK_DATA (&vcm->elog_main, e, vep_session->elog_track);
+      ed->data = vep_idx;
+      /* *INDENT-ON* */
+    }
 
   return (vep_idx);
 }
@@ -3641,7 +4178,7 @@ vppcom_session_attr (uint32_t session_index, uint32_t op,
       break;
 
     case VPPCOM_ATTR_GET_PEER_ADDR:
-      if (buffer && buflen && (*buflen >= sizeof (*ep)))
+      if (buffer && buflen && (*buflen >= sizeof (*ep)) && ep->ip)
 	{
 	  ep->vrf = session->vrf;
 	  ep->is_ip4 = session->peer_addr.is_ip4;
@@ -3665,7 +4202,7 @@ vppcom_session_attr (uint32_t session_index, uint32_t op,
       break;
 
     case VPPCOM_ATTR_GET_LCL_ADDR:
-      if (buffer && buflen && (*buflen >= sizeof (*ep)))
+      if (buffer && buflen && (*buflen >= sizeof (*ep)) && ep->ip)
 	{
 	  ep->vrf = session->vrf;
 	  ep->is_ip4 = session->lcl_addr.is_ip4;