#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>
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; */
u8 proto;
u64 client_queue_address;
u64 options[16];
+ elog_track_t elog_track;
} session_t;
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_
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;
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;
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;
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...");
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 *
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;
}
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;
}
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;
}
}
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;
}
*/
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;
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;
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)
+ {
+ 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
{
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));
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);
}
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);
}
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:
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
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))
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;
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;
}
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;
}
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;
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);
}
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:
session_fifo_event_t e;
for (i = 0; i < n_to_dequeue; i++)
- unix_shared_memory_queue_sub_raw (vcm->app_event_queue, (u8 *) & e);
+ svm_queue_sub_raw (vcm->app_event_queue, (u8 *) & e);
pthread_mutex_unlock (&vcm->app_event_queue->mutex);
}
{
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;
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] vpp handle 0x%llx, sid %u: "
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);
}