vcl/session: tx notifications for cut-thru sessions
[vpp.git] / src / vcl / vppcom.c
index fa37a1d..e70aa00 100644 (file)
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2017 Cisco and/or its affiliates.
+ * Copyright (c) 2017-2019 Cisco and/or its affiliates.
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this
  * You may obtain a copy of the License at:
@@ -274,9 +274,8 @@ vcl_session_accepted_handler (vcl_worker_t * wrk, session_accepted_msg_t * mp)
   if (!listen_session)
     {
       evt_q = uword_to_pointer (mp->vpp_event_queue_address, svm_msg_q_t *);
-      clib_warning ("VCL<%d>: ERROR: couldn't find listen session: "
-                   "unknown vpp listener handle %llx",
-                   getpid (), mp->listener_handle);
+      VDBG (0, "ERROR: couldn't find listen session: unknown vpp listener "
+           "handle %llx", mp->listener_handle);
       vcl_send_session_accepted_reply (evt_q, mp->context, mp->handle,
                                       VNET_API_ERROR_INVALID_ARGUMENT);
       vcl_session_free (wrk, session);
@@ -288,8 +287,8 @@ vcl_session_accepted_handler (vcl_worker_t * wrk, session_accepted_msg_t * mp)
 
   if (vcl_wait_for_segment (mp->segment_handle))
     {
-      clib_warning ("segment for session %u couldn't be mounted!",
-                   session->session_index);
+      VDBG (0, "segment for session %u couldn't be mounted!",
+           session->session_index);
       return VCL_INVALID_SESSION_INDEX;
     }
 
@@ -321,9 +320,8 @@ vcl_session_accepted_handler (vcl_worker_t * wrk, session_accepted_msg_t * mp)
   session->session_type = listen_session->session_type;
   session->is_dgram = session->session_type == VPPCOM_PROTO_UDP;
 
-  VDBG (1, "VCL<%d>: vpp handle 0x%llx, sid %u: client accept request from %s"
-       " address %U port %d queue %p!", getpid (), mp->handle,
-       session->session_index,
+  VDBG (1, "session %u [0x%llx]: client accept request from %s address %U"
+       " port %d queue %p!", session->session_index, mp->handle,
        mp->is_ip4 ? "IPv4" : "IPv6", format_ip46_address, &mp->ip,
        mp->is_ip4 ? IP46_TYPE_IP4 : IP46_TYPE_IP6,
        clib_net_to_host_u16 (mp->port), session->vpp_evt_q);
@@ -344,15 +342,14 @@ vcl_session_connected_handler (vcl_worker_t * wrk,
   session = vcl_session_get (wrk, session_index);
   if (!session)
     {
-      clib_warning ("[%s] ERROR: vpp handle 0x%llx, sid %u: "
-                   "Invalid session index (%u)!",
-                   getpid (), mp->handle, session_index);
+      VDBG (0, "ERROR: vpp handle 0x%llx has no session index (%u)!",
+           mp->handle, session_index);
       return VCL_INVALID_SESSION_INDEX;
     }
   if (mp->retval)
     {
-      clib_warning ("VCL<%d>: ERROR: sid %u: connect failed! %U", getpid (),
-                   session_index, format_api_error, ntohl (mp->retval));
+      VDBG (0, "ERROR: session index %u: connect failed! %U",
+           session_index, format_api_error, ntohl (mp->retval));
       session->session_state = STATE_FAILED;
       session->vpp_handle = mp->handle;
       return session_index;
@@ -364,6 +361,7 @@ vcl_session_connected_handler (vcl_worker_t * wrk,
     {
       VDBG (0, "segment for session %u couldn't be mounted!",
            session->session_index);
+      session->session_state = STATE_FAILED;
       return VCL_INVALID_SESSION_INDEX;
     }
 
@@ -386,6 +384,7 @@ vcl_session_connected_handler (vcl_worker_t * wrk,
        {
          VDBG (0, "ct segment for session %u couldn't be mounted!",
                session->session_index);
+         session->session_state = STATE_FAILED;
          return VCL_INVALID_SESSION_INDEX;
        }
     }
@@ -403,9 +402,8 @@ vcl_session_connected_handler (vcl_worker_t * wrk,
   /* Add it to lookup table */
   vcl_session_table_add_vpp_handle (wrk, mp->handle, session_index);
 
-  VDBG (1, "VCL<%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->rx_fifo,
+  VDBG (1, "session %u [0x%llx] connected! rx_fifo %p, refcnt %d, tx_fifo %p,"
+       " refcnt %d", session_index, mp->handle, session->rx_fifo,
        session->rx_fifo->refcnt, session->tx_fifo, session->tx_fifo->refcnt);
 
   return session_index;
@@ -468,7 +466,7 @@ vcl_session_bound_handler (vcl_worker_t * wrk, session_bound_msg_t * mp)
   session = vcl_session_get (wrk, sid);
   if (mp->retval)
     {
-      VERR ("vpp handle 0x%llx, sid %u: bind failed: %U", mp->handle, sid,
+      VERR ("session %u [0x%llx]: bind failed: %U", sid, mp->handle,
            format_api_error, mp->retval);
       if (session)
        {
@@ -478,9 +476,8 @@ vcl_session_bound_handler (vcl_worker_t * wrk, session_bound_msg_t * mp)
        }
       else
        {
-         clib_warning ("[%s] ERROR: vpp handle 0x%llx, sid %u: "
-                       "Invalid session index (%u)!",
-                       getpid (), mp->handle, sid);
+         VDBG (0, "ERROR: session %u [0x%llx]: Invalid session index!",
+               sid, mp->handle);
          return VCL_INVALID_SESSION_INDEX;
        }
     }
@@ -792,8 +789,8 @@ vppcom_app_session_enable (void)
       rv = vcl_wait_for_app_state_change (STATE_APP_ENABLED);
       if (PREDICT_FALSE (rv))
        {
-         VDBG (0, "VCL<%d>: application session enable timed out! "
-               "returning %d (%s)", getpid (), rv, vppcom_retval_str (rv));
+         VDBG (0, "application session enable timed out! returning %d (%s)",
+               rv, vppcom_retval_str (rv));
          return rv;
        }
     }
@@ -809,8 +806,8 @@ vppcom_app_attach (void)
   rv = vcl_wait_for_app_state_change (STATE_APP_ATTACHED);
   if (PREDICT_FALSE (rv))
     {
-      VDBG (0, "VCL<%d>: application attach timed out! returning %d (%s)",
-           getpid (), rv, vppcom_retval_str (rv));
+      VDBG (0, "application attach timed out! returning %d (%s)", rv,
+           vppcom_retval_str (rv));
       return rv;
     }
 
@@ -832,9 +829,8 @@ vppcom_session_unbind (u32 session_handle)
   session->vpp_handle = ~0;
   session->session_state = STATE_DISCONNECT;
 
-  VDBG (1, "vpp handle 0x%llx, sid %u: sending unbind msg! new state"
-       " 0x%x (%s)", vpp_handle, session_handle, STATE_DISCONNECT,
-       vppcom_session_state_str (STATE_DISCONNECT));
+  VDBG (1, "session %u [0x%llx]: sending unbind!", session->session_index,
+       vpp_handle);
   vcl_evt (VCL_EVT_UNBIND, session);
   vppcom_send_unbind_sock (wrk, vpp_handle);
 
@@ -857,14 +853,12 @@ vppcom_session_disconnect (u32 session_handle)
   vpp_handle = session->vpp_handle;
   state = session->session_state;
 
-  VDBG (1, "VCL<%d>: vpp handle 0x%llx, sid %u state 0x%x (%s)", getpid (),
-       vpp_handle, session_handle, state, vppcom_session_state_str (state));
+  VDBG (1, "session %u [0x%llx] state 0x%x (%s)", session->session_index,
+       vpp_handle, state, vppcom_session_state_str (state));
 
   if (PREDICT_FALSE (state & STATE_LISTEN))
     {
-      clib_warning ("VCL<%d>: ERROR: vpp handle 0x%llx, sid %u: "
-                   "Cannot disconnect a listen socket!",
-                   getpid (), vpp_handle, session_handle);
+      VDBG (0, "ERROR: Cannot disconnect a listen socket!");
       return VPPCOM_EBADFD;
     }
 
@@ -873,13 +867,13 @@ vppcom_session_disconnect (u32 session_handle)
       vpp_evt_q = vcl_session_vpp_evt_q (wrk, session);
       vcl_send_session_disconnected_reply (vpp_evt_q, wrk->my_client_index,
                                           vpp_handle, 0);
-      VDBG (1, "VCL<%d>: vpp handle 0x%llx, sid %u: sending disconnect "
-           "REPLY...", getpid (), vpp_handle, session_handle);
+      VDBG (1, "session %u [0x%llx]: sending disconnect REPLY...",
+           session->session_index, vpp_handle);
     }
   else
     {
-      VDBG (1, "VCL<%d>: vpp handle 0x%llx, sid %u: sending disconnect...",
-           getpid (), vpp_handle, session_handle);
+      VDBG (1, "session %u [0x%llx]: sending disconnect...",
+           session->session_index, vpp_handle);
       vppcom_send_disconnect_session (vpp_handle);
     }
 
@@ -1025,7 +1019,7 @@ vppcom_session_create (u8 proto, u8 is_nonblocking)
   vcl_evt (VCL_EVT_CREATE, session, session_type, session->session_state,
           is_nonblocking, session_index);
 
-  VDBG (0, "created sid %u", session->session_index);
+  VDBG (0, "created session %u", session->session_index);
 
   return vcl_session_handle (session);
 }
@@ -1054,7 +1048,7 @@ vcl_session_cleanup (vcl_worker_t * wrk, vcl_session_t * session,
        {
          rv = vppcom_epoll_ctl (sh, EPOLL_CTL_DEL, next_sh, 0);
          if (PREDICT_FALSE (rv < 0))
-           VDBG (0, "vpp handle 0x%llx, sid %u: EPOLL_CTL_DEL vep_idx %u"
+           VDBG (0, "vpp handle 0x%llx, sh %u: EPOLL_CTL_DEL vep_idx %u"
                  " failed! rv %d (%s)", vpp_handle, next_sh, vep_sh, rv,
                  vppcom_retval_str (rv));
 
@@ -1142,8 +1136,8 @@ vppcom_session_bind (uint32_t session_handle, vppcom_endpt_t * ep)
 
   if (session->is_vep)
     {
-      clib_warning ("VCL<%d>: ERROR: sid %u: cannot "
-                   "bind to an epoll session!", getpid (), session_handle);
+      VDBG (0, "ERROR: cannot bind to epoll session %u!",
+           session->session_index);
       return VPPCOM_EBADFD;
     }
 
@@ -1156,8 +1150,8 @@ vppcom_session_bind (uint32_t session_handle, vppcom_endpt_t * ep)
                      sizeof (ip6_address_t));
   session->transport.lcl_port = ep->port;
 
-  VDBG (0, "VCL<%d>: sid %u: binding to local %s address %U port %u, "
-       "proto %s", getpid (), session_handle,
+  VDBG (0, "session %u handle %u: binding to local %s address %U port %u, "
+       "proto %s", session->session_index, session_handle,
        session->transport.is_ip4 ? "IPv4" : "IPv6",
        format_ip46_address, &session->transport.lcl_ip,
        session->transport.is_ip4 ? IP46_TYPE_IP4 : IP46_TYPE_IP6,
@@ -1267,25 +1261,20 @@ vppcom_session_tls_add_key (uint32_t session_handle, char *key,
 }
 
 static int
-validate_args_session_accept_ (vcl_worker_t * wrk,
-                              vcl_session_t * listen_session)
+validate_args_session_accept_ (vcl_worker_t * wrk, vcl_session_t * ls)
 {
-  /* Input validation - expects spinlock on sessions_lockp */
-  if (listen_session->is_vep)
+  if (ls->is_vep)
     {
-      clib_warning ("VCL<%d>: ERROR: sid %u: cannot accept on an "
-                   "epoll session!", getpid (),
-                   listen_session->session_index);
+      VDBG (0, "ERROR: cannot accept on epoll session %u!",
+           ls->session_index);
       return VPPCOM_EBADFD;
     }
 
-  if (listen_session->session_state != STATE_LISTEN)
+  if (ls->session_state != STATE_LISTEN)
     {
-      clib_warning ("VCL<%d>: ERROR: vpp handle 0x%llx, sid %u: "
-                   "not in listen state! state 0x%x (%s)", getpid (),
-                   listen_session->vpp_handle, listen_session->session_index,
-                   listen_session->session_state,
-                   vppcom_session_state_str (listen_session->session_state));
+      VDBG (0, "ERROR: session [0x%llx]: not in listen state! state 0x%x"
+           " (%s)", ls->vpp_handle, ls->session_index, ls->session_state,
+           vppcom_session_state_str (ls->session_state));
       return VPPCOM_EBADFD;
     }
   return VPPCOM_OK;
@@ -1301,7 +1290,6 @@ vppcom_session_accept (uint32_t listen_session_handle, vppcom_endpt_t * ep,
   vcl_session_t *listen_session = 0;
   vcl_session_t *client_session = 0;
   vcl_session_msg_t *evt;
-  u64 listen_vpp_handle;
   svm_msg_q_msg_t msg;
   session_event_t *e;
   u8 is_nonblocking;
@@ -1354,13 +1342,11 @@ handle:
   if (flags & O_NONBLOCK)
     VCL_SESS_ATTR_SET (client_session->attr, VCL_SESS_ATTR_NONBLOCK);
 
-  listen_vpp_handle = listen_session->vpp_handle;
-  VDBG (1, "vpp handle 0x%llx, sid %u: Got a client request! "
-       "vpp handle 0x%llx, sid %u, flags %d, is_nonblocking %u",
-       listen_vpp_handle, listen_session_handle,
-       client_session->vpp_handle, client_session_index,
-       flags, VCL_SESS_ATTR_TEST (client_session->attr,
-                                  VCL_SESS_ATTR_NONBLOCK));
+  VDBG (1, "listener %u [0x%llx]: Got a connect request! session %u [0x%llx],"
+       " flags %d, is_nonblocking %u", listen_session->session_index,
+       listen_session->vpp_handle, client_session_index,
+       client_session->vpp_handle, flags,
+       VCL_SESS_ATTR_TEST (client_session->attr, VCL_SESS_ATTR_NONBLOCK));
 
   if (ep)
     {
@@ -1379,7 +1365,7 @@ handle:
                                   client_session->vpp_handle, 0);
 
   VDBG (0, "listener %u [0x%llx] accepted %u [0x%llx] peer: %U:%u "
-       "local: %U:%u", listen_session_handle, listen_vpp_handle,
+       "local: %U:%u", listen_session_handle, listen_session->vpp_handle,
        client_session_index, client_session->vpp_handle,
        format_ip46_address, &client_session->transport.rmt_ip,
        client_session->transport.is_ip4 ? IP46_TYPE_IP4 : IP46_TYPE_IP6,
@@ -1418,9 +1404,8 @@ vppcom_session_connect (uint32_t session_handle, vppcom_endpt_t * server_ep)
 
   if (PREDICT_FALSE (session->is_vep))
     {
-      clib_warning ("VCL<%d>: ERROR: sid %u: cannot "
-                   "connect on an epoll session!", getpid (),
-                   session_handle);
+      VDBG (0, "ERROR: cannot connect epoll session %u!",
+           session->session_index);
       return VPPCOM_EBADFD;
     }
 
@@ -1465,25 +1450,8 @@ vppcom_session_connect (uint32_t session_handle, vppcom_endpt_t * server_ep)
                                             vcm->cfg.session_timeout);
 
   session = vcl_session_get (wrk, session_index);
-
-  if (PREDICT_FALSE (rv))
-    {
-      if (VPPCOM_DEBUG > 0)
-       {
-         if (session)
-           clib_warning ("VCL<%d>: vpp handle 0x%llx, sid %u: connect "
-                         "failed! returning %d (%s)", getpid (),
-                         session->vpp_handle, session_handle, rv,
-                         vppcom_retval_str (rv));
-         else
-           clib_warning ("VCL<%d>: no session for sid %u: connect failed! "
-                         "returning %d (%s)", getpid (),
-                         session_handle, rv, vppcom_retval_str (rv));
-       }
-    }
-  else
-    VDBG (0, "VCL<%d>: vpp handle 0x%llx, sid %u: connected!",
-         getpid (), session->vpp_handle, session_handle);
+  VDBG (0, "session %u [0x%llx]: connect %s!", session->session_index,
+       session->vpp_handle, rv ? "failed" : "succeeded");
 
   return rv;
 }
@@ -1516,7 +1484,7 @@ vppcom_session_read_internal (uint32_t session_handle, void *buf, int n,
 
   if (PREDICT_FALSE (!vcl_session_is_open (s)))
     {
-      VDBG (0, "session handle %u[0x%llx] is not open! state 0x%x (%s)",
+      VDBG (0, "session %u[0x%llx] is not open! state 0x%x (%s)",
            s->session_index, s->vpp_handle, s->session_state,
            vppcom_session_state_str (s->session_state));
       return vcl_session_closed_error (s);
@@ -1528,14 +1496,14 @@ vppcom_session_read_internal (uint32_t session_handle, void *buf, int n,
   rx_fifo = is_ct ? s->ct_rx_fifo : s->rx_fifo;
   s->has_rx_evt = 0;
 
-  if (svm_fifo_is_empty (rx_fifo))
+  if (svm_fifo_is_empty_cons (rx_fifo))
     {
       if (is_nonblocking)
        {
          svm_fifo_unset_event (s->rx_fifo);
          return VPPCOM_EWOULDBLOCK;
        }
-      while (svm_fifo_is_empty (rx_fifo))
+      while (svm_fifo_is_empty_cons (rx_fifo))
        {
          if (vcl_session_is_closing (s))
            return vcl_session_closing_error (s);
@@ -1559,11 +1527,19 @@ vppcom_session_read_internal (uint32_t session_handle, void *buf, int n,
   else
     n_read = app_recv_stream_raw (rx_fifo, buf, n, 0, peek);
 
-  if (svm_fifo_is_empty (rx_fifo))
+  if (svm_fifo_is_empty_cons (rx_fifo))
     svm_fifo_unset_event (s->rx_fifo);
 
-  VDBG (2, "vpp handle 0x%llx, sid %u: read %d bytes from (%p)",
-       s->vpp_handle, session_handle, n_read, rx_fifo);
+  /* Cut-through sessions might request tx notifications on rx fifos */
+  if (PREDICT_FALSE (rx_fifo->want_tx_ntf))
+    {
+      app_send_io_evt_to_vpp (s->vpp_evt_q, s->rx_fifo->master_session_index,
+                             SESSION_IO_EVT_RX, SVM_Q_WAIT);
+      svm_fifo_reset_tx_ntf (s->rx_fifo);
+    }
+
+  VDBG (2, "session %u[0x%llx]: read %d bytes from (%p)", s->session_index,
+       s->vpp_handle, n_read, rx_fifo);
 
   return n_read;
 }
@@ -1609,14 +1585,14 @@ vppcom_session_read_segments (uint32_t session_handle,
   if (is_ct)
     svm_fifo_unset_event (s->rx_fifo);
 
-  if (svm_fifo_is_empty (rx_fifo))
+  if (svm_fifo_is_empty_cons (rx_fifo))
     {
       if (is_nonblocking)
        {
          svm_fifo_unset_event (rx_fifo);
          return VPPCOM_EWOULDBLOCK;
        }
-      while (svm_fifo_is_empty (rx_fifo))
+      while (svm_fifo_is_empty_cons (rx_fifo))
        {
          if (vcl_session_is_closing (s))
            return vcl_session_closing_error (s);
@@ -1681,9 +1657,9 @@ vppcom_session_write_inline (uint32_t session_handle, void *buf, size_t n,
   vcl_worker_t *wrk = vcl_worker_get_current ();
   int n_write, is_nonblocking;
   vcl_session_t *s = 0;
-  svm_fifo_t *tx_fifo = 0;
   session_evt_type_t et;
   svm_msg_q_msg_t msg;
+  svm_fifo_t *tx_fifo;
   session_event_t *e;
   svm_msg_q_t *mq;
   u8 is_ct;
@@ -1713,14 +1689,15 @@ vppcom_session_write_inline (uint32_t session_handle, void *buf, size_t n,
   is_ct = vcl_session_is_ct (s);
   tx_fifo = is_ct ? s->ct_tx_fifo : s->tx_fifo;
   is_nonblocking = VCL_SESS_ATTR_TEST (s->attr, VCL_SESS_ATTR_NONBLOCK);
+
   mq = wrk->app_event_queue;
-  if (svm_fifo_is_full (tx_fifo))
+  if (svm_fifo_is_full_prod (tx_fifo))
     {
       if (is_nonblocking)
        {
          return VPPCOM_EWOULDBLOCK;
        }
-      while (svm_fifo_is_full (tx_fifo))
+      while (svm_fifo_is_full_prod (tx_fifo))
        {
          svm_fifo_add_want_tx_ntf (tx_fifo, SVM_FIFO_WANT_TX_NOTIF);
          if (vcl_session_is_closing (s))
@@ -1746,12 +1723,12 @@ vppcom_session_write_inline (uint32_t session_handle, void *buf, size_t n,
   if (s->is_dgram)
     n_write = app_send_dgram_raw (tx_fifo, &s->transport,
                                  s->vpp_evt_q, buf, n, et,
-                                 !is_ct /* do_evt */ , SVM_Q_WAIT);
+                                 0 /* do_evt */ , SVM_Q_WAIT);
   else
     n_write = app_send_stream_raw (tx_fifo, s->vpp_evt_q, buf, n, et,
-                                  !is_ct /* do_evt */ , SVM_Q_WAIT);
+                                  0 /* do_evt */ , SVM_Q_WAIT);
 
-  if (is_ct && svm_fifo_set_event (s->tx_fifo))
+  if (svm_fifo_set_event (s->tx_fifo))
     app_send_io_evt_to_vpp (s->vpp_evt_q, s->tx_fifo->master_session_index,
                            et, SVM_Q_WAIT);
 
@@ -1810,16 +1787,16 @@ vcl_select_handle_mq_event (vcl_worker_t * wrk, session_event_t * e,
     case SESSION_IO_EVT_RX:
       sid = e->session_index;
       session = vcl_session_get (wrk, sid);
-      vcl_fifo_rx_evt_valid_or_break (session);
       if (!session)
        break;
+      vcl_fifo_rx_evt_valid_or_break (session);
       if (sid < n_bits && read_map)
        {
          clib_bitmap_set_no_check ((uword *) read_map, sid, 1);
          *bits_set += 1;
        }
       break;
-    case FIFO_EVENT_APP_TX:
+    case SESSION_IO_EVT_TX:
       sid = e->session_index;
       session = vcl_session_get (wrk, sid);
       if (!session)
@@ -1940,11 +1917,28 @@ vppcom_select_condvar (vcl_worker_t * wrk, int n_bits,
                       vcl_si_set * except_map, double time_to_wait,
                       u32 * bits_set)
 {
-  time_to_wait = (time_to_wait == -1) ? 1e6 : time_to_wait;
-  vcl_select_handle_mq (wrk, wrk->app_event_queue, n_bits, read_map,
-                       write_map, except_map, (bits_set ? 0 : time_to_wait),
-                       bits_set);
-  return *bits_set;
+  double wait = 0, start = 0;
+
+  if (!*bits_set)
+    {
+      wait = time_to_wait;
+      start = clib_time_now (&wrk->clib_time);
+    }
+
+  do
+    {
+      vcl_select_handle_mq (wrk, wrk->app_event_queue, n_bits, read_map,
+                           write_map, except_map, wait, bits_set);
+      if (*bits_set)
+       return *bits_set;
+      if (wait == -1)
+       continue;
+
+      wait = wait - (clib_time_now (&wrk->clib_time) - start);
+    }
+  while (wait > 0);
+
+  return 0;
 }
 
 static int
@@ -2018,7 +2012,7 @@ vppcom_select (int n_bits, vcl_si_set * read_map, vcl_si_set * write_map,
         continue;
       }
 
-    rv = svm_fifo_is_full (session->tx_fifo);
+    rv = svm_fifo_is_full_prod (session->tx_fifo);
     if (!rv)
       {
         clib_bitmap_set_no_check ((uword*)write_map, sid, 1);
@@ -2078,74 +2072,66 @@ vep_verify_epoll_chain (vcl_worker_t * wrk, u32 vep_idx)
   if (VPPCOM_DEBUG <= 2)
     return;
 
-  /* Assumes caller has acquired spinlock: vcm->sessions_lockp */
   session = vcl_session_get (wrk, vep_idx);
   if (PREDICT_FALSE (!session))
     {
-      clib_warning ("VCL<%d>: ERROR: Invalid vep_idx (%u)!",
-                   getpid (), vep_idx);
+      VDBG (0, "ERROR: Invalid vep_idx (%u)!", vep_idx);
       goto done;
     }
   if (PREDICT_FALSE (!session->is_vep))
     {
-      clib_warning ("VCL<%d>: ERROR: vep_idx (%u) is not a vep!",
-                   getpid (), vep_idx);
+      VDBG (0, "ERROR: vep_idx (%u) is not a vep!", vep_idx);
       goto done;
     }
   vep = &session->vep;
-  clib_warning ("VCL<%d>: vep_idx (%u): Dumping epoll chain\n"
-               "{\n"
-               "   is_vep         = %u\n"
-               "   is_vep_session = %u\n"
-               "   next_sid       = 0x%x (%u)\n"
-               "}\n", getpid (), vep_idx,
-               session->is_vep, session->is_vep_session,
-               vep->next_sh, vep->next_sh);
+  VDBG (0, "vep_idx (%u): Dumping epoll chain\n"
+       "{\n"
+       "   is_vep         = %u\n"
+       "   is_vep_session = %u\n"
+       "   next_sid       = 0x%x (%u)\n"
+       "}\n", vep_idx, session->is_vep, session->is_vep_session,
+       vep->next_sh, vep->next_sh);
 
   for (sid = vep->next_sh; sid != ~0; sid = vep->next_sh)
     {
       session = vcl_session_get (wrk, sid);
       if (PREDICT_FALSE (!session))
        {
-         clib_warning ("VCL<%d>: ERROR: Invalid sid (%u)!", getpid (), sid);
+         VDBG (0, "ERROR: Invalid sid (%u)!", sid);
          goto done;
        }
       if (PREDICT_FALSE (session->is_vep))
-       clib_warning ("VCL<%d>: ERROR: sid (%u) is a vep!",
-                     getpid (), vep_idx);
+       {
+         VDBG (0, "ERROR: sid (%u) is a vep!", vep_idx);
+       }
       else if (PREDICT_FALSE (!session->is_vep_session))
        {
-         clib_warning ("VCL<%d>: ERROR: session (%u) "
-                       "is not a vep session!", getpid (), sid);
+         VDBG (0, "ERROR: session (%u) is not a vep session!", sid);
          goto done;
        }
       vep = &session->vep;
       if (PREDICT_FALSE (vep->vep_sh != vep_idx))
-       clib_warning ("VCL<%d>: ERROR: session (%u) vep_idx (%u) != "
-                     "vep_idx (%u)!", getpid (),
-                     sid, session->vep.vep_sh, vep_idx);
+       VDBG (0, "ERROR: session (%u) vep_idx (%u) != vep_idx (%u)!",
+             sid, session->vep.vep_sh, vep_idx);
       if (session->is_vep_session)
        {
-         clib_warning ("vep_idx[%u]: sid 0x%x (%u)\n"
-                       "{\n"
-                       "   next_sid       = 0x%x (%u)\n"
-                       "   prev_sid       = 0x%x (%u)\n"
-                       "   vep_idx        = 0x%x (%u)\n"
-                       "   ev.events      = 0x%x\n"
-                       "   ev.data.u64    = 0x%llx\n"
-                       "   et_mask        = 0x%x\n"
-                       "}\n",
-                       vep_idx, sid, sid,
-                       vep->next_sh, vep->next_sh,
-                       vep->prev_sh, vep->prev_sh,
-                       vep->vep_sh, vep->vep_sh,
-                       vep->ev.events, vep->ev.data.u64, vep->et_mask);
+         VDBG (0, "vep_idx[%u]: sid 0x%x (%u)\n"
+               "{\n"
+               "   next_sid       = 0x%x (%u)\n"
+               "   prev_sid       = 0x%x (%u)\n"
+               "   vep_idx        = 0x%x (%u)\n"
+               "   ev.events      = 0x%x\n"
+               "   ev.data.u64    = 0x%llx\n"
+               "   et_mask        = 0x%x\n"
+               "}\n",
+               vep_idx, sid, sid, vep->next_sh, vep->next_sh, vep->prev_sh,
+               vep->prev_sh, vep->vep_sh, vep->vep_sh, vep->ev.events,
+               vep->ev.data.u64, vep->et_mask);
        }
     }
 
 done:
-  clib_warning ("VCL<%d>: vep_idx (%u): Dump complete!\n",
-               getpid (), vep_idx);
+  VDBG (0, "vep_idx (%u): Dump complete!\n", vep_idx);
 }
 
 int
@@ -2225,7 +2211,7 @@ vppcom_epoll_ctl (uint32_t vep_handle, int op, uint32_t session_handle,
                                                   vep_session->vep.next_sh);
          if (PREDICT_FALSE (!next_session))
            {
-             VDBG (0, "EPOLL_CTL_ADD: Invalid vep.next_sid (%u) on "
+             VDBG (0, "EPOLL_CTL_ADD: Invalid vep.next_sh (%u) on "
                    "vep_idx (%u)!", vep_session->vep.next_sh, vep_handle);
              return VPPCOM_EBADFD;
            }
@@ -2259,8 +2245,7 @@ vppcom_epoll_ctl (uint32_t vep_handle, int op, uint32_t session_handle,
        }
       else if (PREDICT_FALSE (!session->is_vep_session))
        {
-         VDBG (0, "sid %u EPOLL_CTL_MOD: not a vep session!",
-               session_handle);
+         VDBG (0, "sh %u EPOLL_CTL_MOD: not a vep session!", session_handle);
          rv = VPPCOM_EINVAL;
          goto done;
        }
@@ -2300,7 +2285,7 @@ vppcom_epoll_ctl (uint32_t vep_handle, int op, uint32_t session_handle,
          prev_session = vcl_session_get_w_handle (wrk, session->vep.prev_sh);
          if (PREDICT_FALSE (!prev_session))
            {
-             VDBG (0, "EPOLL_CTL_DEL: Invalid prev_sid (%u) on sid (%u)!",
+             VDBG (0, "EPOLL_CTL_DEL: Invalid prev_sh (%u) on sh (%u)!",
                    session->vep.prev_sh, session_handle);
              return VPPCOM_EBADFD;
            }
@@ -2313,7 +2298,7 @@ vppcom_epoll_ctl (uint32_t vep_handle, int op, uint32_t session_handle,
          next_session = vcl_session_get_w_handle (wrk, session->vep.next_sh);
          if (PREDICT_FALSE (!next_session))
            {
-             VDBG (0, "EPOLL_CTL_DEL: Invalid next_sid (%u) on sid (%u)!",
+             VDBG (0, "EPOLL_CTL_DEL: Invalid next_sh (%u) on sh (%u)!",
                    session->vep.next_sh, session_handle);
              return VPPCOM_EBADFD;
            }
@@ -2330,7 +2315,7 @@ vppcom_epoll_ctl (uint32_t vep_handle, int op, uint32_t session_handle,
       if (session->tx_fifo)
        svm_fifo_del_want_tx_ntf (session->tx_fifo, SVM_FIFO_NO_TX_NOTIF);
 
-      VDBG (1, "EPOLL_CTL_DEL: vep_idx %u, sid %u!", vep_handle,
+      VDBG (1, "EPOLL_CTL_DEL: vep_idx %u, sh %u!", vep_handle,
            session_handle);
       vcl_evt (VCL_EVT_EPOLL_CTLDEL, session, vep_sh);
       break;
@@ -2517,10 +2502,28 @@ static int
 vppcom_epoll_wait_condvar (vcl_worker_t * wrk, struct epoll_event *events,
                           int maxevents, u32 n_evts, double wait_for_time)
 {
-  wait_for_time = (wait_for_time == -1) ? (double) 1e6 : wait_for_time;
-  vcl_epoll_wait_handle_mq (wrk, wrk->app_event_queue, events, maxevents,
-                           (n_evts ? 0 : wait_for_time), &n_evts);
-  return n_evts;
+  double wait = 0, start = 0;
+
+  if (!n_evts)
+    {
+      wait = wait_for_time;
+      start = clib_time_now (&wrk->clib_time);
+    }
+
+  do
+    {
+      vcl_epoll_wait_handle_mq (wrk, wrk->app_event_queue, events, maxevents,
+                               wait, &n_evts);
+      if (n_evts)
+       return n_evts;
+      if (wait == -1)
+       continue;
+
+      wait = wait - (clib_time_now (&wrk->clib_time) - start);
+    }
+  while (wait > 0);
+
+  return 0;
 }
 
 static int
@@ -2559,8 +2562,7 @@ vppcom_epoll_wait (uint32_t vep_handle, struct epoll_event *events,
 
   if (PREDICT_FALSE (maxevents <= 0))
     {
-      clib_warning ("VCL<%d>: ERROR: Invalid maxevents (%d)!",
-                   getpid (), maxevents);
+      VDBG (0, "ERROR: Invalid maxevents (%d)!", maxevents);
       return VPPCOM_EINVAL;
     }
 
@@ -2570,8 +2572,7 @@ vppcom_epoll_wait (uint32_t vep_handle, struct epoll_event *events,
 
   if (PREDICT_FALSE (!vep_session->is_vep))
     {
-      clib_warning ("VCL<%d>: ERROR: vep_idx (%u) is not a vep!",
-                   getpid (), vep_handle);
+      VDBG (0, "ERROR: vep_idx (%u) is not a vep!", vep_handle);
       return VPPCOM_EINVAL;
     }
 
@@ -2618,13 +2619,14 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
     {
     case VPPCOM_ATTR_GET_NREAD:
       rv = vcl_session_read_ready (session);
-      VDBG (2, "VPPCOM_ATTR_GET_NREAD: sid %u, nread = %d", rv);
+      VDBG (2, "VPPCOM_ATTR_GET_NREAD: sh %u, nread = %d", session_handle,
+           rv);
       break;
 
     case VPPCOM_ATTR_GET_NWRITE:
       rv = vcl_session_write_ready (session);
-      VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_NWRITE: sid %u, nwrite = %d",
-           getpid (), session_handle, rv);
+      VDBG (2, "VPPCOM_ATTR_GET_NWRITE: sh %u, nwrite = %d", session_handle,
+           rv);
       break;
 
     case VPPCOM_ATTR_GET_FLAGS:
@@ -2633,9 +2635,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          *flags = O_RDWR | (VCL_SESS_ATTR_TEST (session->attr,
                                                 VCL_SESS_ATTR_NONBLOCK));
          *buflen = sizeof (*flags);
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_FLAGS: sid %u, flags = 0x%08x, "
-               "is_nonblocking = %u", getpid (),
-               session_handle, *flags,
+         VDBG (2, "VPPCOM_ATTR_GET_FLAGS: sh %u, flags = 0x%08x, "
+               "is_nonblocking = %u", session_handle, *flags,
                VCL_SESS_ATTR_TEST (session->attr, VCL_SESS_ATTR_NONBLOCK));
        }
       else
@@ -2650,9 +2651,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          else
            VCL_SESS_ATTR_CLR (session->attr, VCL_SESS_ATTR_NONBLOCK);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_FLAGS: sid %u, flags = 0x%08x,"
-               " is_nonblocking = %u",
-               getpid (), session_handle, *flags,
+         VDBG (2, "VPPCOM_ATTR_SET_FLAGS: sh %u, flags = 0x%08x,"
+               " is_nonblocking = %u", session_handle, *flags,
                VCL_SESS_ATTR_TEST (session->attr, VCL_SESS_ATTR_NONBLOCK));
        }
       else
@@ -2672,10 +2672,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
            clib_memcpy_fast (ep->ip, &session->transport.rmt_ip.ip6,
                              sizeof (ip6_address_t));
          *buflen = sizeof (*ep);
-         VDBG (1, "VCL<%d>: VPPCOM_ATTR_GET_PEER_ADDR: sid %u, is_ip4 = %u, "
-               "addr = %U, port %u", getpid (),
-               session_handle, ep->is_ip4, format_ip46_address,
-               &session->transport.rmt_ip,
+         VDBG (1, "VPPCOM_ATTR_GET_PEER_ADDR: sh %u, is_ip4 = %u, "
+               "addr = %U, port %u", session_handle, ep->is_ip4,
+               format_ip46_address, &session->transport.rmt_ip,
                ep->is_ip4 ? IP46_TYPE_IP4 : IP46_TYPE_IP6,
                clib_net_to_host_u16 (ep->port));
        }
@@ -2696,9 +2695,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
            clib_memcpy_fast (ep->ip, &session->transport.lcl_ip.ip6,
                              sizeof (ip6_address_t));
          *buflen = sizeof (*ep);
-         VDBG (1, "VCL<%d>: VPPCOM_ATTR_GET_LCL_ADDR: sid %u, is_ip4 = %u,"
-               " addr = %U port %d", getpid (),
-               session_handle, ep->is_ip4, format_ip46_address,
+         VDBG (1, "VPPCOM_ATTR_GET_LCL_ADDR: sh %u, is_ip4 = %u, addr = %U"
+               " port %d", session_handle, ep->is_ip4, format_ip46_address,
                &session->transport.lcl_ip,
                ep->is_ip4 ? IP46_TYPE_IP4 : IP46_TYPE_IP6,
                clib_net_to_host_u16 (ep->port));
@@ -2709,8 +2707,7 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
 
     case VPPCOM_ATTR_GET_LIBC_EPFD:
       rv = session->libc_epfd;
-      VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_LIBC_EPFD: libc_epfd %d",
-           getpid (), rv);
+      VDBG (2, "VPPCOM_ATTR_GET_LIBC_EPFD: libc_epfd %d", rv);
       break;
 
     case VPPCOM_ATTR_SET_LIBC_EPFD:
@@ -2720,8 +2717,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          session->libc_epfd = *(int *) buffer;
          *buflen = sizeof (session->libc_epfd);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_LIBC_EPFD: libc_epfd %d, "
-               "buflen %d", getpid (), session->libc_epfd, *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_LIBC_EPFD: libc_epfd %d, buflen %d",
+               session->libc_epfd, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2733,9 +2730,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          *(int *) buffer = session->session_type;
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_PROTOCOL: %d (%s), buflen %d",
-               getpid (), *(int *) buffer, *(int *) buffer ? "UDP" : "TCP",
-               *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_PROTOCOL: %d (%s), buflen %d",
+               *(int *) buffer, *(int *) buffer ? "UDP" : "TCP", *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2748,8 +2744,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                                VCL_SESS_ATTR_LISTEN);
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_LISTEN: %d, buflen %d",
-               getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_LISTEN: %d, buflen %d", *(int *) buffer,
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2761,8 +2757,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          *(int *) buffer = 0;
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_ERROR: %d, buflen %d, #VPP-TBD#",
-               getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_ERROR: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2778,9 +2774,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                vcm->cfg.tx_fifo_size);
          *buflen = sizeof (u32);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_TX_FIFO_LEN: %u (0x%x), "
-               "buflen %d, #VPP-TBD#", getpid (),
-               *(size_t *) buffer, *(size_t *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_TX_FIFO_LEN: %u (0x%x), buflen %d,"
+               " #VPP-TBD#", *(size_t *) buffer, *(size_t *) buffer,
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2791,9 +2787,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
        {
          /* VPP-TBD */
          session->sndbuf_size = *(u32 *) buffer;
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_TX_FIFO_LEN: %u (0x%x), "
-               "buflen %d, #VPP-TBD#", getpid (),
-               session->sndbuf_size, session->sndbuf_size, *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_TX_FIFO_LEN: %u (0x%x), buflen %d,"
+               " #VPP-TBD#", session->sndbuf_size, session->sndbuf_size,
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2809,9 +2805,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                vcm->cfg.rx_fifo_size);
          *buflen = sizeof (u32);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_RX_FIFO_LEN: %u (0x%x), "
-               "buflen %d, #VPP-TBD#", getpid (),
-               *(size_t *) buffer, *(size_t *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_RX_FIFO_LEN: %u (0x%x), buflen %d, "
+               "#VPP-TBD#", *(size_t *) buffer, *(size_t *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2822,9 +2817,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
        {
          /* VPP-TBD */
          session->rcvbuf_size = *(u32 *) buffer;
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_RX_FIFO_LEN: %u (0x%x), "
-               "buflen %d, #VPP-TBD#", getpid (),
-               session->sndbuf_size, session->sndbuf_size, *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_RX_FIFO_LEN: %u (0x%x), buflen %d,"
+               " #VPP-TBD#", session->sndbuf_size, session->sndbuf_size,
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2838,8 +2833,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                                VCL_SESS_ATTR_REUSEADDR);
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_REUSEADDR: %d, "
-               "buflen %d, #VPP-TBD#", getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_REUSEADDR: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2855,10 +2850,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          else
            VCL_SESS_ATTR_CLR (session->attr, VCL_SESS_ATTR_REUSEADDR);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_REUSEADDR: %d, buflen %d,"
-               " #VPP-TBD#", getpid (),
-               VCL_SESS_ATTR_TEST (session->attr,
-                                   VCL_SESS_ATTR_REUSEADDR), *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_REUSEADDR: %d, buflen %d, #VPP-TBD#",
+               VCL_SESS_ATTR_TEST (session->attr, VCL_SESS_ATTR_REUSEADDR),
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2872,8 +2866,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                                VCL_SESS_ATTR_REUSEPORT);
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_REUSEPORT: %d, buflen %d,"
-               " #VPP-TBD#", getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_REUSEPORT: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2889,10 +2883,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          else
            VCL_SESS_ATTR_CLR (session->attr, VCL_SESS_ATTR_REUSEPORT);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_REUSEPORT: %d, buflen %d,"
-               " #VPP-TBD#", getpid (),
-               VCL_SESS_ATTR_TEST (session->attr,
-                                   VCL_SESS_ATTR_REUSEPORT), *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_REUSEPORT: %d, buflen %d, #VPP-TBD#",
+               VCL_SESS_ATTR_TEST (session->attr, VCL_SESS_ATTR_REUSEPORT),
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2906,8 +2899,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                                VCL_SESS_ATTR_BROADCAST);
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_BROADCAST: %d, buflen %d,"
-               " #VPP-TBD#", getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_BROADCAST: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2922,10 +2915,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          else
            VCL_SESS_ATTR_CLR (session->attr, VCL_SESS_ATTR_BROADCAST);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_BROADCAST: %d, buflen %d, "
-               "#VPP-TBD#", getpid (),
-               VCL_SESS_ATTR_TEST (session->attr,
-                                   VCL_SESS_ATTR_BROADCAST), *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_BROADCAST: %d, buflen %d, #VPP-TBD#",
+               VCL_SESS_ATTR_TEST (session->attr, VCL_SESS_ATTR_BROADCAST),
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2939,8 +2931,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                                VCL_SESS_ATTR_V6ONLY);
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_V6ONLY: %d, buflen %d, "
-               "#VPP-TBD#", getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_V6ONLY: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2955,10 +2947,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          else
            VCL_SESS_ATTR_CLR (session->attr, VCL_SESS_ATTR_V6ONLY);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_V6ONLY: %d, buflen %d, "
-               "#VPP-TBD#", getpid (),
-               VCL_SESS_ATTR_TEST (session->attr,
-                                   VCL_SESS_ATTR_V6ONLY), *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_V6ONLY: %d, buflen %d, #VPP-TBD#",
+               VCL_SESS_ATTR_TEST (session->attr, VCL_SESS_ATTR_V6ONLY),
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2972,8 +2963,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                                VCL_SESS_ATTR_KEEPALIVE);
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_KEEPALIVE: %d, buflen %d, "
-               "#VPP-TBD#", getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_KEEPALIVE: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -2988,10 +2979,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          else
            VCL_SESS_ATTR_CLR (session->attr, VCL_SESS_ATTR_KEEPALIVE);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_KEEPALIVE: %d, buflen %d, "
-               "#VPP-TBD#", getpid (),
-               VCL_SESS_ATTR_TEST (session->attr,
-                                   VCL_SESS_ATTR_KEEPALIVE), *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_KEEPALIVE: %d, buflen %d, #VPP-TBD#",
+               VCL_SESS_ATTR_TEST (session->attr, VCL_SESS_ATTR_KEEPALIVE),
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -3005,8 +2995,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                                VCL_SESS_ATTR_TCP_NODELAY);
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_TCP_NODELAY: %d, buflen %d, "
-               "#VPP-TBD#", getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_TCP_NODELAY: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -3021,10 +3011,9 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          else
            VCL_SESS_ATTR_CLR (session->attr, VCL_SESS_ATTR_TCP_NODELAY);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_TCP_NODELAY: %d, buflen %d, "
-               "#VPP-TBD#", getpid (),
-               VCL_SESS_ATTR_TEST (session->attr,
-                                   VCL_SESS_ATTR_TCP_NODELAY), *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_TCP_NODELAY: %d, buflen %d, #VPP-TBD#",
+               VCL_SESS_ATTR_TEST (session->attr, VCL_SESS_ATTR_TCP_NODELAY),
+               *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -3038,8 +3027,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                                VCL_SESS_ATTR_TCP_KEEPIDLE);
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_TCP_KEEPIDLE: %d, buflen %d, "
-               "#VPP-TBD#", getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_TCP_KEEPIDLE: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -3054,8 +3043,7 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          else
            VCL_SESS_ATTR_CLR (session->attr, VCL_SESS_ATTR_TCP_KEEPIDLE);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_TCP_KEEPIDLE: %d, buflen %d, "
-               "#VPP-TBD#", getpid (),
+         VDBG (2, "VPPCOM_ATTR_SET_TCP_KEEPIDLE: %d, buflen %d, #VPP-TBD#",
                VCL_SESS_ATTR_TEST (session->attr,
                                    VCL_SESS_ATTR_TCP_KEEPIDLE), *buflen);
        }
@@ -3071,8 +3059,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
                                                VCL_SESS_ATTR_TCP_KEEPINTVL);
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_TCP_KEEPINTVL: %d, buflen %d, "
-               "#VPP-TBD#", getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_TCP_KEEPINTVL: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -3087,8 +3075,7 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          else
            VCL_SESS_ATTR_CLR (session->attr, VCL_SESS_ATTR_TCP_KEEPINTVL);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_TCP_KEEPINTVL: %d, buflen %d, "
-               "#VPP-TBD#", getpid (),
+         VDBG (2, "VPPCOM_ATTR_SET_TCP_KEEPINTVL: %d, buflen %d, #VPP-TBD#",
                VCL_SESS_ATTR_TEST (session->attr,
                                    VCL_SESS_ATTR_TCP_KEEPINTVL), *buflen);
        }
@@ -3103,8 +3090,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          *(u32 *) buffer = session->user_mss;
          *buflen = sizeof (int);
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_GET_TCP_USER_MSS: %d, buflen %d,"
-               " #VPP-TBD#", getpid (), *(int *) buffer, *buflen);
+         VDBG (2, "VPPCOM_ATTR_GET_TCP_USER_MSS: %d, buflen %d, #VPP-TBD#",
+               *(int *) buffer, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -3116,8 +3103,8 @@ vppcom_session_attr (uint32_t session_handle, uint32_t op,
          /* VPP-TBD */
          session->user_mss = *(u32 *) buffer;
 
-         VDBG (2, "VCL<%d>: VPPCOM_ATTR_SET_TCP_USER_MSS: %u, buflen %d, "
-               "#VPP-TBD#", getpid (), session->user_mss, *buflen);
+         VDBG (2, "VPPCOM_ATTR_SET_TCP_USER_MSS: %u, buflen %d, #VPP-TBD#",
+               session->user_mss, *buflen);
        }
       else
        rv = VPPCOM_EINVAL;
@@ -3164,8 +3151,7 @@ vppcom_session_recvfrom (uint32_t session_handle, void *buffer,
       session = vcl_session_get_w_handle (wrk, session_handle);
       if (PREDICT_FALSE (!session))
        {
-         VDBG (0, "VCL<%d>: invalid session, sid (%u) has been closed!",
-               getpid (), session_handle);
+         VDBG (0, "sh 0x%llx is closed!", session_handle);
          return VPPCOM_EBADFD;
        }
       ep->is_ip4 = session->transport.is_ip4;
@@ -3211,8 +3197,7 @@ vppcom_session_sendto (uint32_t session_handle, void *buffer,
   if (flags)
     {
       // TBD check the flags and do the right thing
-      VDBG (2, "VCL<%d>: handling flags 0x%u (%d) not implemented yet.",
-           getpid (), flags, flags);
+      VDBG (2, "handling flags 0x%u (%d) not implemented yet.", flags, flags);
     }
 
   return (vppcom_session_write_inline (session_handle, buffer, buflen, 1));
@@ -3228,8 +3213,7 @@ vppcom_poll (vcl_poll_t * vp, uint32_t n_sids, double wait_for_time)
   session_event_t *e;
   int rv, num_ev = 0;
 
-  VDBG (3, "VCL<%d>: vp %p, nsids %u, wait_for_time %f",
-       getpid (), vp, n_sids, wait_for_time);
+  VDBG (3, "vp %p, nsids %u, wait_for_time %f", vp, n_sids, wait_for_time);
 
   if (!vp)
     return VPPCOM_EFAULT;
@@ -3318,16 +3302,6 @@ vppcom_poll (vcl_poll_t * vp, uint32_t n_sids, double wait_for_time)
     }
   while ((num_ev == 0) && keep_trying);
 
-  if (VPPCOM_DEBUG > 3)
-    {
-      clib_warning ("VCL<%d>: returning %d", getpid (), num_ev);
-      for (i = 0; i < n_sids; i++)
-       {
-         clib_warning ("VCL<%d>: vp[%d].sid %d (0x%x), .events 0x%x, "
-                       ".revents 0x%x", getpid (), i, vp[i].sh, vp[i].sh,
-                       vp[i].events, vp[i].revents);
-       }
-    }
   return num_ev;
 }