aboutsummaryrefslogtreecommitdiffstats
path: root/src
diff options
context:
space:
mode:
authorNathan Skrzypczak <nathan.skrzypczak@gmail.com>2019-12-03 17:13:09 +0100
committerFlorin Coras <florin.coras@gmail.com>2019-12-03 17:38:30 +0000
commit08f26641fa920d5a9629140430660adcf736a1c7 (patch)
tree4321531b380ab66a62962df2bba2209b2464775b /src
parent692bfc85f2c41c6e25e73931a7b6fe6a1c5dd6c6 (diff)
hsa: Less verbose logging for many sessions
Type: feature ECHO_LOG has the following levels 0 -> global progression (many connections) 1 -> Connection global evts (some conn, much data) 2 -> More connection events 3 -> Data related logging Change-Id: I69eeaa0dd02a4b8ebcfefa1c7a218ef57f217d2b Signed-off-by: Nathan Skrzypczak <nathan.skrzypczak@gmail.com>
Diffstat (limited to 'src')
-rw-r--r--src/plugins/hs_apps/sapi/vpp_echo.c61
-rw-r--r--src/plugins/hs_apps/sapi/vpp_echo_bapi.c8
-rw-r--r--src/plugins/hs_apps/sapi/vpp_echo_common.c14
-rw-r--r--src/plugins/hs_apps/sapi/vpp_echo_common.h3
-rw-r--r--src/plugins/hs_apps/sapi/vpp_echo_proto_quic.c45
-rw-r--r--src/plugins/hs_apps/sapi/vpp_echo_proto_tcp.c2
6 files changed, 83 insertions, 50 deletions
diff --git a/src/plugins/hs_apps/sapi/vpp_echo.c b/src/plugins/hs_apps/sapi/vpp_echo.c
index cfe1a3d37be..18a0280e6b2 100644
--- a/src/plugins/hs_apps/sapi/vpp_echo.c
+++ b/src/plugins/hs_apps/sapi/vpp_echo.c
@@ -160,6 +160,10 @@ print_global_json_stats (echo_main_t * em)
em->stats.active_count.q, em->stats.active_count.s);
fformat (stdout, " \"clean\": { \"q\": %d, \"s\": %d }\n",
em->stats.clean_count.q, em->stats.clean_count.s);
+ fformat (stdout, " \"accepted\": { \"q\": %d, \"s\": %d }\n",
+ em->stats.accepted_count.q, em->stats.accepted_count.s);
+ fformat (stdout, " \"connected\": { \"q\": %d, \"s\": %d }\n",
+ em->stats.connected_count.q, em->stats.connected_count.s);
fformat (stdout, " }\n");
fformat (stdout, " \"results\": {\n");
fformat (stdout, " \"has_failed\": \"%d\"\n", em->has_failed);
@@ -220,6 +224,11 @@ print_global_stats (echo_main_t * em)
em->stats.active_count.s, em->stats.active_count.q);
fformat (stdout, "Discarded %d streams (and %d Quic conn)\n",
em->stats.clean_count.s, em->stats.clean_count.q);
+ fformat (stdout, "--------------------\n");
+ fformat (stdout, "Got accept on %d streams (and %d Quic conn)\n",
+ em->stats.accepted_count.s, em->stats.accepted_count.q);
+ fformat (stdout, "Got connected on %d streams (and %d Quic conn)\n",
+ em->stats.connected_count.s, em->stats.connected_count.q);
if (em->has_failed)
fformat (stdout, "\nFailure Return Status: %d\n%v", em->has_failed,
em->fail_descr);
@@ -231,7 +240,7 @@ void
echo_update_count_on_session_close (echo_main_t * em, echo_session_t * s)
{
- ECHO_LOG (1, "[%lu/%lu] -> %U -> [%lu/%lu]",
+ ECHO_LOG (2, "[%lu/%lu] -> %U -> [%lu/%lu]",
s->bytes_received, s->bytes_received + s->bytes_to_receive,
echo_format_session, s, s->bytes_sent,
s->bytes_sent + s->bytes_to_send);
@@ -278,12 +287,12 @@ test_recv_bytes (echo_main_t * em, echo_session_t * s, u8 * rx_buf,
expected = (s->bytes_received + i) & 0xff;
if (rx_buf[i] == expected || em->max_test_msg > 0)
continue;
- ECHO_LOG (0, "Session 0x%lx byte %lld was 0x%x expected 0x%x",
+ ECHO_LOG (1, "Session 0x%lx byte %lld was 0x%x expected 0x%x",
s->vpp_session_handle, s->bytes_received + i, rx_buf[i],
expected);
em->max_test_msg--;
if (em->max_test_msg == 0)
- ECHO_LOG (0, "Too many errors, hiding next ones");
+ ECHO_LOG (1, "Too many errors, hiding next ones");
if (em->test_return_packets == RETURN_PACKETS_ASSERT)
ECHO_FAIL (ECHO_FAIL_TEST_BYTES_ERR, "test-bytes errored");
}
@@ -339,7 +348,7 @@ echo_check_closed_listener (echo_main_t * em, echo_session_t * s)
/* if parent has died, terminate gracefully */
if (s->listener_index == SESSION_INVALID_INDEX)
{
- ECHO_LOG (2, "%U: listener_index == SESSION_INVALID_INDEX",
+ ECHO_LOG (3, "%U: listener_index == SESSION_INVALID_INDEX",
echo_format_session, s);
return;
}
@@ -353,7 +362,7 @@ echo_check_closed_listener (echo_main_t * em, echo_session_t * s)
return;
}
- ECHO_LOG (2, "%U died, close child %U", echo_format_session, ls,
+ ECHO_LOG (3, "%U died, close child %U", echo_format_session, ls,
echo_format_session, s);
echo_update_count_on_session_close (em, s);
em->proto_cb_vft->cleanup_cb (s, 1 /* parent_died */ );
@@ -394,7 +403,7 @@ echo_handle_data (echo_main_t * em, echo_session_t * s, u8 * rx_buf)
clib_atomic_fetch_add (&em->stats.clean_count.s, 1);
}
}
- ECHO_LOG (2, "%U: %U", echo_format_session, s,
+ ECHO_LOG (3, "%U: %U", echo_format_session, s,
echo_format_session_state, s->session_state);
return;
}
@@ -407,12 +416,12 @@ echo_handle_data (echo_main_t * em, echo_session_t * s, u8 * rx_buf)
else if (s->idle_cycles++ == 1e7)
{
s->idle_cycles = 0;
- ECHO_LOG (1, "Idle client TX:%dB RX:%dB", s->bytes_to_send,
+ ECHO_LOG (2, "Idle client TX:%dB RX:%dB", s->bytes_to_send,
s->bytes_to_receive);
- ECHO_LOG (1, "Idle FIFOs TX:%dB RX:%dB",
+ ECHO_LOG (2, "Idle FIFOs TX:%dB RX:%dB",
svm_fifo_max_dequeue (s->tx_fifo),
svm_fifo_max_dequeue (s->rx_fifo));
- ECHO_LOG (1, "Session 0x%lx state %U", s->vpp_session_handle,
+ ECHO_LOG (2, "Session 0x%lx state %U", s->vpp_session_handle,
echo_format_session_state, s->session_state);
}
}
@@ -428,7 +437,7 @@ echo_data_thread_fn (void *arg)
u32 idx = (u64) arg;
if (n * idx >= N)
{
- ECHO_LOG (1, "Thread %u exiting, no sessions to care for", idx);
+ ECHO_LOG (2, "Thread %u exiting, no sessions to care for", idx);
pthread_exit (0);
}
u32 thread_n_sessions = clib_min (n, N - n * idx);
@@ -460,13 +469,13 @@ echo_data_thread_fn (void *arg)
echo_check_closed_listener (em, s);
break;
case ECHO_SESSION_STATE_CLOSING:
- ECHO_LOG (2, "%U: %U", echo_format_session, s,
+ ECHO_LOG (3, "%U: %U", echo_format_session, s,
echo_format_session_state, s->session_state);
echo_update_count_on_session_close (em, s);
em->proto_cb_vft->cleanup_cb (s, 0 /* parent_died */ );
break;
case ECHO_SESSION_STATE_CLOSED:
- ECHO_LOG (2, "%U: %U", echo_format_session, s,
+ ECHO_LOG (3, "%U: %U", echo_format_session, s,
echo_format_session_state, s->session_state);
n_closed_sessions++;
break;
@@ -474,7 +483,7 @@ echo_data_thread_fn (void *arg)
if (n_closed_sessions == thread_n_sessions)
break;
}
- ECHO_LOG (1, "Mission accomplished!");
+ ECHO_LOG (2, "Mission accomplished!");
pthread_exit (0);
}
@@ -500,7 +509,7 @@ session_bound_handler (session_bound_msg_t * mp)
clib_net_to_host_u32 (mp->retval));
return;
}
- ECHO_LOG (0, "listening on %U:%u", format_ip46_address, mp->lcl_ip,
+ ECHO_LOG (1, "listening on %U:%u", format_ip46_address, mp->lcl_ip,
mp->lcl_is_ip4 ? IP46_TYPE_IP4 : IP46_TYPE_IP6,
clib_net_to_host_u16 (mp->lcl_port));
@@ -565,7 +574,7 @@ session_accepted_handler (session_accepted_msg_t * mp)
session->listener_index = ls->session_index;
/* Add it to lookup table */
- ECHO_LOG (1, "Accepted session 0x%lx S[%u] -> 0x%lx S[%u]",
+ ECHO_LOG (2, "Accepted session 0x%lx S[%u] -> 0x%lx S[%u]",
mp->handle, session->session_index,
mp->listener_handle, session->listener_index);
echo_session_handle_add_del (em, mp->handle, session->session_index);
@@ -647,17 +656,17 @@ session_disconnected_handler (session_disconnected_msg_t * mp)
echo_session_t *s;
if (!(s = echo_get_session_from_handle (em, mp->handle)))
{
- ECHO_LOG (0, "Invalid vpp_session_handle: 0x%lx", mp->handle);
+ ECHO_LOG (1, "Invalid vpp_session_handle: 0x%lx", mp->handle);
return;
}
if (s->session_state == ECHO_SESSION_STATE_CLOSED)
{
- ECHO_LOG (1, "%U: already in ECHO_SESSION_STATE_CLOSED",
+ ECHO_LOG (2, "%U: already in ECHO_SESSION_STATE_CLOSED",
echo_format_session, s);
}
else
{
- ECHO_LOG (1, "%U: passive close", echo_format_session, s);
+ ECHO_LOG (2, "%U: passive close", echo_format_session, s);
em->proto_cb_vft->disconnected_cb (mp, s);
}
app_alloc_ctrl_evt_to_vpp (s->vpp_evt_q, app_evt,
@@ -678,10 +687,10 @@ session_reset_handler (session_reset_msg_t * mp)
echo_session_t *s = 0;
if (!(s = echo_get_session_from_handle (em, mp->handle)))
{
- ECHO_LOG (0, "Invalid vpp_session_handle: 0x%lx", mp->handle);
+ ECHO_LOG (1, "Invalid vpp_session_handle: 0x%lx", mp->handle);
return;
}
- ECHO_LOG (1, "%U: session reset", echo_format_session, s);
+ ECHO_LOG (2, "%U: session reset", echo_format_session, s);
em->proto_cb_vft->reset_cb (mp, s);
app_alloc_ctrl_evt_to_vpp (s->vpp_evt_q, app_evt,
@@ -713,7 +722,7 @@ handle_mq_event (session_event_t * e)
case SESSION_IO_EVT_RX:
break;
default:
- ECHO_LOG (0, "unhandled event %u", e->event_type);
+ ECHO_LOG (1, "unhandled event %u", e->event_type);
}
}
@@ -797,7 +806,7 @@ clients_run (echo_main_t * em)
for (i = 0; i < em->n_connects; i++)
echo_send_connect (SESSION_INVALID_HANDLE, SESSION_INVALID_INDEX);
wait_for_state_change (em, STATE_READY, 0);
- ECHO_LOG (1, "App is ready");
+ ECHO_LOG (2, "App is ready");
echo_process_rpcs (em);
}
@@ -807,10 +816,10 @@ server_run (echo_main_t * em)
echo_session_t *ls;
echo_send_listen (em);
wait_for_state_change (em, STATE_READY, 0);
- ECHO_LOG (1, "App is ready");
+ ECHO_LOG (2, "App is ready");
echo_process_rpcs (em);
/* Cleanup */
- ECHO_LOG (1, "Unbind listen port");
+ ECHO_LOG (2, "Unbind listen port");
ls = pool_elt_at_index (em->sessions, em->listen_session_index);
echo_send_unbind (em, ls);
if (wait_for_state_change (em, STATE_DISCONNECTED, TIMEOUT))
@@ -1183,7 +1192,7 @@ main (int argc, char **argv)
em->state = STATE_ATTACHED;
else
{
- ECHO_LOG (1, "Adding crypto context %U", echo_format_crypto_engine,
+ ECHO_LOG (2, "Adding crypto context %U", echo_format_crypto_engine,
em->crypto_engine);
echo_send_add_cert_key (em);
if (wait_for_state_change (em, STATE_ATTACHED, TIMEOUT))
@@ -1241,7 +1250,7 @@ main (int argc, char **argv)
vl_client_disconnect_from_vlib ();
echo_assert_test_suceeded (em);
exit_on_error:
- ECHO_LOG (0, "Test complete !\n");
+ ECHO_LOG (1, "Test complete !\n");
if (em->output_json)
print_global_json_stats (em);
else
diff --git a/src/plugins/hs_apps/sapi/vpp_echo_bapi.c b/src/plugins/hs_apps/sapi/vpp_echo_bapi.c
index 2bba9fc0fe2..f343ad12865 100644
--- a/src/plugins/hs_apps/sapi/vpp_echo_bapi.c
+++ b/src/plugins/hs_apps/sapi/vpp_echo_bapi.c
@@ -278,7 +278,7 @@ vl_api_app_attach_reply_t_handler (vl_api_app_attach_reply_t * mp)
u32 n_fds = 0;
u64 segment_handle;
segment_handle = clib_net_to_host_u64 (mp->segment_handle);
- ECHO_LOG (1, "Attached returned app %u", htons (mp->app_index));
+ ECHO_LOG (2, "Attached returned app %u", htons (mp->app_index));
if (mp->retval)
{
@@ -346,7 +346,7 @@ vl_api_app_attach_reply_t_handler (vl_api_app_attach_reply_t * mp)
}
}
echo_segment_handle_add_del (em, segment_handle, 1 /* add */ );
- ECHO_LOG (1, "Mapped segment 0x%lx", segment_handle);
+ ECHO_LOG (2, "Mapped segment 0x%lx", segment_handle);
em->state = STATE_ATTACHED_NO_CERT;
return;
@@ -375,7 +375,7 @@ vl_api_unmap_segment_t_handler (vl_api_unmap_segment_t * mp)
echo_main_t *em = &echo_main;
u64 segment_handle = clib_net_to_host_u64 (mp->segment_handle);
echo_segment_handle_add_del (em, segment_handle, 0 /* add */ );
- ECHO_LOG (1, "Unmaped segment 0x%lx", segment_handle);
+ ECHO_LOG (2, "Unmaped segment 0x%lx", segment_handle);
}
static void
@@ -421,7 +421,7 @@ vl_api_map_another_segment_t_handler (vl_api_map_another_segment_t * mp)
}
}
echo_segment_handle_add_del (em, segment_handle, 1 /* add */ );
- ECHO_LOG (1, "Mapped segment 0x%lx", segment_handle);
+ ECHO_LOG (2, "Mapped segment 0x%lx", segment_handle);
return;
failed:
diff --git a/src/plugins/hs_apps/sapi/vpp_echo_common.c b/src/plugins/hs_apps/sapi/vpp_echo_common.c
index b91203a7bb3..a5bdeb4f27b 100644
--- a/src/plugins/hs_apps/sapi/vpp_echo_common.c
+++ b/src/plugins/hs_apps/sapi/vpp_echo_common.c
@@ -503,12 +503,12 @@ echo_session_handle_add_del (echo_main_t * em, u64 handle, u32 sid)
clib_spinlock_lock (&em->sid_vpp_handles_lock);
if (sid == SESSION_INVALID_INDEX)
{
- ECHO_LOG (2, "hash_unset(0x%lx)", handle);
+ ECHO_LOG (3, "hash_unset(0x%lx)", handle);
hash_unset (em->session_index_by_vpp_handles, handle);
}
else
{
- ECHO_LOG (2, "hash_set(0x%lx) S[%d]", handle, sid);
+ ECHO_LOG (3, "hash_set(0x%lx) S[%d]", handle, sid);
hash_set (em->session_index_by_vpp_handles, handle, sid);
}
clib_spinlock_unlock (&em->sid_vpp_handles_lock);
@@ -558,7 +558,7 @@ echo_get_session_from_handle (echo_main_t * em, u64 handle)
clib_spinlock_unlock (&em->sid_vpp_handles_lock);
if (!p)
{
- ECHO_LOG (1, "unknown handle 0x%lx", handle);
+ ECHO_LOG (2, "unknown handle 0x%lx", handle);
return 0;
}
return pool_elt_at_index (em->sessions, p[0]);
@@ -571,7 +571,7 @@ wait_for_segment_allocation (u64 segment_handle)
f64 timeout;
timeout = clib_time_now (&em->clib_time) + TIMEOUT;
uword *segment_present;
- ECHO_LOG (1, "Waiting for segment 0x%lx...", segment_handle);
+ ECHO_LOG (3, "Waiting for segment 0x%lx...", segment_handle);
while (clib_time_now (&em->clib_time) < timeout)
{
clib_spinlock_lock (&em->segment_handles_lock);
@@ -582,7 +582,7 @@ wait_for_segment_allocation (u64 segment_handle)
if (em->time_to_stop == 1)
return 0;
}
- ECHO_LOG (1, "timeout wait_for_segment_allocation (0x%lx)", segment_handle);
+ ECHO_LOG (2, "timeout wait_for_segment_allocation (0x%lx)", segment_handle);
return -1;
}
@@ -598,7 +598,7 @@ wait_for_state_change (echo_main_t * em, connection_state_t state,
if (em->time_to_stop)
return 1;
}
- ECHO_LOG (1, "timeout waiting for %U", echo_format_app_state, state);
+ ECHO_LOG (2, "timeout waiting for %U", echo_format_app_state, state);
return -1;
}
@@ -618,7 +618,7 @@ void
echo_session_print_stats (echo_main_t * em, echo_session_t * session)
{
f64 deltat = clib_time_now (&em->clib_time) - session->start;
- ECHO_LOG (0, "Session 0x%x done in %.6fs RX[%.4f] TX[%.4f] Gbit/s\n",
+ ECHO_LOG (1, "Session 0x%x done in %.6fs RX[%.4f] TX[%.4f] Gbit/s\n",
session->vpp_session_handle, deltat,
(session->bytes_received * 8.0) / deltat / 1e9,
(session->bytes_sent * 8.0) / deltat / 1e9);
diff --git a/src/plugins/hs_apps/sapi/vpp_echo_common.h b/src/plugins/hs_apps/sapi/vpp_echo_common.h
index 7d134d9a2c2..00d54f83070 100644
--- a/src/plugins/hs_apps/sapi/vpp_echo_common.h
+++ b/src/plugins/hs_apps/sapi/vpp_echo_common.h
@@ -36,6 +36,7 @@
#undef vl_printfun
#define TIMEOUT 10.0
+#define LOGGING_BATCH (100)
#define foreach_echo_fail_code \
_(ECHO_FAIL_NONE, "ECHO_FAIL_NONE") \
@@ -345,6 +346,8 @@ typedef struct
teardown_stat_t close_count; /* received close from vpp */
teardown_stat_t active_count; /* sent close to vpp */
teardown_stat_t clean_count; /* cleaned up stale session */
+ teardown_stat_t connected_count; /* connected sessions count */
+ teardown_stat_t accepted_count; /* connected sessions count */
} stats;
struct /* Event based timing : start & end depend on CLI specified events */
diff --git a/src/plugins/hs_apps/sapi/vpp_echo_proto_quic.c b/src/plugins/hs_apps/sapi/vpp_echo_proto_quic.c
index d20bacb2a5d..18b70dd2257 100644
--- a/src/plugins/hs_apps/sapi/vpp_echo_proto_quic.c
+++ b/src/plugins/hs_apps/sapi/vpp_echo_proto_quic.c
@@ -60,7 +60,7 @@ quic_echo_on_connected_connect (session_connected_msg_t * mp,
for (i = 0; i < eqm->n_stream_clients; i++)
echo_send_rpc (em, echo_send_connect, (void *) mp->handle, session_index);
- ECHO_LOG (0, "Qsession 0x%llx S[%d] connected to %U:%d",
+ ECHO_LOG (1, "Qsession 0x%llx S[%d] connected to %U:%d",
mp->handle, session_index, format_ip46_address, &mp->lcl.ip,
mp->lcl.is_ip4, clib_net_to_host_u16 (mp->lcl.port));
}
@@ -106,7 +106,7 @@ quic_echo_on_accept_connect (session_accepted_msg_t * mp, u32 session_index)
{
echo_main_t *em = &echo_main;
quic_echo_proto_main_t *eqm = &quic_echo_proto_main;
- ECHO_LOG (1, "Accept on QSession 0x%lx S[%u]", mp->handle, session_index);
+ ECHO_LOG (2, "Accept on QSession 0x%lx S[%u]", mp->handle, session_index);
u32 i;
echo_notify_event (em, ECHO_EVT_FIRST_SCONNECT);
@@ -127,7 +127,7 @@ quic_echo_on_accept_log_ip (session_accepted_msg_t * mp, u32 session_index)
{
u8 *ip_str;
ip_str = format (0, "%U", format_ip46_address, &mp->rmt.ip, mp->rmt.is_ip4);
- ECHO_LOG (0, "Accepted session from: %s:%d", ip_str,
+ ECHO_LOG (1, "Accepted session from: %s:%d", ip_str,
clib_net_to_host_u16 (mp->rmt.port));
}
@@ -166,7 +166,7 @@ quic_echo_cleanup_listener (u32 listener_index, echo_main_t * em,
ls = pool_elt_at_index (em->sessions, listener_index);
if (ls->session_type != ECHO_SESSION_TYPE_QUIC)
{
- ECHO_LOG (1, "%U: Invalid listener session type",
+ ECHO_LOG (2, "%U: Invalid listener session type",
echo_format_session, ls);
return;
}
@@ -194,7 +194,7 @@ quic_echo_cleanup_cb (echo_session_t * s, u8 parent_died)
if ((em->state == STATE_DATA_DONE) ||
!(s->session_state < ECHO_SESSION_STATE_CLOSED))
return;
- ECHO_LOG (2, "%U cleanup (parent_died %d)", echo_format_session, s,
+ ECHO_LOG (3, "%U cleanup (parent_died %d)", echo_format_session, s,
parent_died);
s->session_state = ECHO_SESSION_STATE_CLOSED;
if (s->session_type == ECHO_SESSION_TYPE_QUIC)
@@ -214,7 +214,7 @@ quic_echo_cleanup_cb (echo_session_t * s, u8 parent_died)
}
if (!em->n_clients_connected && !eqm->n_quic_clients_connected)
em->state = STATE_DATA_DONE;
- ECHO_LOG (1, "Cleanup sessions (still %uQ %uS): app %U",
+ ECHO_LOG (2, "Cleanup sessions (still %uQ %uS): app %U",
eqm->n_quic_clients_connected, em->n_clients_connected,
echo_format_app_state, em->state);
}
@@ -223,7 +223,7 @@ static void
quic_echo_initiate_qsession_close_no_stream (echo_main_t * em)
{
quic_echo_proto_main_t *eqm = &quic_echo_proto_main;
- ECHO_LOG (1, "Closing Qsessions");
+ ECHO_LOG (2, "Closing Qsessions");
/* Close Quic session without streams */
echo_session_t *s;
@@ -234,19 +234,19 @@ quic_echo_initiate_qsession_close_no_stream (echo_main_t * em)
{
if (eqm->send_quic_disconnects == ECHO_CLOSE_F_ACTIVE)
{
- ECHO_LOG (1,"%U: ACTIVE close", echo_format_session, s);
+ ECHO_LOG (2,"%U: ACTIVE close", echo_format_session, s);
echo_send_rpc (em, echo_send_disconnect_session,
(void *) s->vpp_session_handle, 0);
clib_atomic_fetch_add (&em->stats.active_count.q, 1);
}
else if (eqm->send_quic_disconnects == ECHO_CLOSE_F_NONE)
{
- ECHO_LOG (1,"%U: CLEAN close", echo_format_session, s);
+ ECHO_LOG (2,"%U: CLEAN close", echo_format_session, s);
quic_echo_cleanup_cb (s, 0 /* parent_died */);
clib_atomic_fetch_add (&em->stats.clean_count.q, 1);
}
else
- ECHO_LOG (1,"%U: PASSIVE close", echo_format_session, s);
+ ECHO_LOG (2,"%U: PASSIVE close", echo_format_session, s);
}
}));
/* *INDENT-ON* */
@@ -262,28 +262,39 @@ quic_echo_on_connected (session_connected_msg_t * mp, u32 session_index)
if (session->listener_index == SESSION_INVALID_INDEX)
{
+ clib_atomic_fetch_add (&em->stats.connected_count.q, 1);
session->session_type = ECHO_SESSION_TYPE_QUIC;
- ECHO_LOG (1, "Connected %U -> URI", echo_format_session, session);
+ ECHO_LOG (2, "Connected %U -> URI", echo_format_session, session);
session->accepted_session_count = 0;
if (eqm->cb_vft.quic_connected_cb)
eqm->cb_vft.quic_connected_cb (mp, session->session_index);
clib_atomic_fetch_add (&eqm->n_quic_clients_connected, 1);
+
+ if (em->stats.connected_count.q % LOGGING_BATCH == 0)
+ ECHO_LOG (0, "Connected Q %d / %d", em->stats.connected_count.q,
+ em->n_connects);
}
else
{
+ clib_atomic_fetch_add (&em->stats.connected_count.s, 1);
listen_session =
pool_elt_at_index (em->sessions, session->listener_index);
session->session_type = ECHO_SESSION_TYPE_STREAM;
clib_atomic_fetch_add (&listen_session->accepted_session_count, 1);
- ECHO_LOG (1, "Connected %U -> %U", echo_format_session, session,
+ ECHO_LOG (2, "Connected %U -> %U", echo_format_session, session,
echo_format_session, listen_session);
if (em->i_am_master && eqm->cb_vft.server_stream_connected_cb)
eqm->cb_vft.server_stream_connected_cb (mp, session->session_index);
if (!em->i_am_master && eqm->cb_vft.client_stream_connected_cb)
eqm->cb_vft.client_stream_connected_cb (mp, session->session_index);
clib_atomic_fetch_add (&em->n_clients_connected, 1);
+
+ if (em->stats.connected_count.s % LOGGING_BATCH == 0)
+ ECHO_LOG (0, "Connected S %d / %d", em->stats.connected_count.s,
+ em->n_clients);
}
+
if (em->n_clients_connected == em->n_clients
&& em->n_clients_connected != 0)
echo_notify_event (em, ECHO_EVT_LAST_SCONNECTED);
@@ -320,15 +331,21 @@ quic_echo_accepted_cb (session_accepted_msg_t * mp, echo_session_t * session)
ls = pool_elt_at_index (em->sessions, session->listener_index);
if (ls->session_type == ECHO_SESSION_TYPE_LISTEN)
{
+ clib_atomic_fetch_add (&em->stats.accepted_count.q, 1);
echo_notify_event (em, ECHO_EVT_FIRST_QCONNECT);
session->session_type = ECHO_SESSION_TYPE_QUIC;
session->accepted_session_count = 0;
if (eqm->cb_vft.quic_accepted_cb)
eqm->cb_vft.quic_accepted_cb (mp, session->session_index);
clib_atomic_fetch_add (&eqm->n_quic_clients_connected, 1);
+
+ if (em->stats.accepted_count.q % LOGGING_BATCH == 0)
+ ECHO_LOG (0, "Accepted Q %d / %d", em->stats.accepted_count.q,
+ em->n_connects);
}
else
{
+ clib_atomic_fetch_add (&em->stats.accepted_count.s, 1);
session->session_type = ECHO_SESSION_TYPE_STREAM;
echo_notify_event (em, ECHO_EVT_FIRST_SCONNECT);
clib_atomic_fetch_add (&ls->accepted_session_count, 1);
@@ -337,6 +354,10 @@ quic_echo_accepted_cb (session_accepted_msg_t * mp, echo_session_t * session)
if (!em->i_am_master && eqm->cb_vft.client_stream_accepted_cb)
eqm->cb_vft.client_stream_accepted_cb (mp, session->session_index);
clib_atomic_fetch_add (&em->n_clients_connected, 1);
+
+ if (em->stats.accepted_count.s % LOGGING_BATCH == 0)
+ ECHO_LOG (0, "Accepted S %d / %d", em->stats.accepted_count.s,
+ em->n_clients);
}
if (em->n_clients_connected == em->n_clients
diff --git a/src/plugins/hs_apps/sapi/vpp_echo_proto_tcp.c b/src/plugins/hs_apps/sapi/vpp_echo_proto_tcp.c
index 5b6d74b429c..0a4a0bdbc1f 100644
--- a/src/plugins/hs_apps/sapi/vpp_echo_proto_tcp.c
+++ b/src/plugins/hs_apps/sapi/vpp_echo_proto_tcp.c
@@ -53,7 +53,7 @@ tcp_echo_connected_cb (session_connected_bundled_msg_t * mp,
return; /* Dont handle bapi connect errors for now */
}
- ECHO_LOG (1, "Connected session 0x%lx -> URI",
+ ECHO_LOG (2, "Connected session 0x%lx -> URI",
((session_connected_msg_t *) mp)->handle);
session->session_type = ECHO_SESSION_TYPE_STREAM;
session->accepted_session_count = 0;