aboutsummaryrefslogtreecommitdiffstats
path: root/src/plugins/hs_apps/sapi/vpp_echo.c
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/plugins/hs_apps/sapi/vpp_echo.c
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/plugins/hs_apps/sapi/vpp_echo.c')
-rw-r--r--src/plugins/hs_apps/sapi/vpp_echo.c61
1 files changed, 35 insertions, 26 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