diff options
| -rw-r--r-- | src/plugins/hs_apps/sapi/vpp_echo.c | 124 | ||||
| -rw-r--r-- | src/plugins/hs_apps/sapi/vpp_echo_bapi.c | 6 | ||||
| -rw-r--r-- | src/plugins/hs_apps/sapi/vpp_echo_common.c | 86 | ||||
| -rw-r--r-- | src/plugins/hs_apps/sapi/vpp_echo_common.h | 32 | ||||
| -rw-r--r-- | src/plugins/hs_apps/sapi/vpp_echo_proto_quic.c | 51 | ||||
| -rw-r--r-- | src/plugins/quic/test/test_quic.py | 84 |
6 files changed, 268 insertions, 115 deletions
diff --git a/src/plugins/hs_apps/sapi/vpp_echo.c b/src/plugins/hs_apps/sapi/vpp_echo.c index 44e6d1fb36f..085b0fe6083 100644 --- a/src/plugins/hs_apps/sapi/vpp_echo.c +++ b/src/plugins/hs_apps/sapi/vpp_echo.c @@ -42,16 +42,28 @@ echo_session_prealloc (echo_main_t * em) static void echo_assert_test_suceeded (echo_main_t * em) { - CHECK (ECHO_FAIL_TEST_ASSERT_RX_TOTAL, - em->n_clients * em->bytes_to_receive, em->stats.rx_total, - "Invalid amount of data received"); - CHECK (ECHO_FAIL_TEST_ASSERT_TX_TOTAL, - em->n_clients * em->bytes_to_send, em->stats.tx_total, - "Invalid amount of data sent"); + if (em->rx_results_diff) + CHECK_DIFF (ECHO_FAIL_TEST_ASSERT_RX_TOTAL, + em->n_clients * em->bytes_to_receive, em->stats.rx_total, + "Invalid amount of data received"); + else + CHECK_SAME (ECHO_FAIL_TEST_ASSERT_RX_TOTAL, + em->n_clients * em->bytes_to_receive, em->stats.rx_total, + "Invalid amount of data received"); + + if (em->tx_results_diff) + CHECK_DIFF (ECHO_FAIL_TEST_ASSERT_TX_TOTAL, + em->n_clients * em->bytes_to_send, em->stats.tx_total, + "Invalid amount of data sent"); + else + CHECK_SAME (ECHO_FAIL_TEST_ASSERT_TX_TOTAL, + em->n_clients * em->bytes_to_send, em->stats.tx_total, + "Invalid amount of data sent"); + clib_spinlock_lock (&em->sid_vpp_handles_lock); - CHECK (ECHO_FAIL_TEST_ASSERT_ALL_SESSIONS_CLOSED, - 0, hash_elts (em->session_index_by_vpp_handles), - "Some sessions are still open"); + CHECK_SAME (ECHO_FAIL_TEST_ASSERT_ALL_SESSIONS_CLOSED, + 0, hash_elts (em->session_index_by_vpp_handles), + "Some sessions are still open"); clib_spinlock_unlock (&em->sid_vpp_handles_lock); } @@ -118,7 +130,8 @@ print_global_json_stats (echo_main_t * em) u8 *end_evt = format (0, "%U", echo_format_timing_event, em->timing.end_event); u8 start_evt_missing = !(em->timing.events_sent & em->timing.start_event); - u8 end_evt_missing = !(em->timing.events_sent & em->timing.end_event); + u8 end_evt_missing = (em->rx_results_diff || em->tx_results_diff) ? 0 : + !(em->timing.events_sent & em->timing.end_event); f64 deltat = start_evt_missing || end_evt_missing ? 0 : em->timing.end_time - em->timing.start_time; @@ -170,7 +183,8 @@ print_global_stats (echo_main_t * em) u8 *end_evt = format (0, "%U", echo_format_timing_event, em->timing.end_event); u8 start_evt_missing = !(em->timing.events_sent & em->timing.start_event); - u8 end_evt_missing = !(em->timing.events_sent & em->timing.end_event); + u8 end_evt_missing = (em->rx_results_diff || em->tx_results_diff) ? 0 : + !(em->timing.events_sent & em->timing.end_event); f64 deltat = start_evt_missing || end_evt_missing ? 0 : em->timing.end_time - em->timing.start_time; @@ -221,9 +235,9 @@ void echo_update_count_on_session_close (echo_main_t * em, echo_session_t * s) { - ECHO_LOG (1, "[%lu/%lu] -> S(%x) -> [%lu/%lu]", + ECHO_LOG (1, "[%lu/%lu] -> %U -> [%lu/%lu]", s->bytes_received, s->bytes_received + s->bytes_to_receive, - s->session_index, s->bytes_sent, + echo_format_session, s, s->bytes_sent, s->bytes_sent + s->bytes_to_send); clib_atomic_fetch_add (&em->stats.tx_total, s->bytes_sent); clib_atomic_fetch_add (&em->stats.rx_total, s->bytes_received); @@ -329,12 +343,23 @@ echo_check_closed_listener (echo_main_t * em, echo_session_t * s) echo_session_t *ls; /* if parent has died, terminate gracefully */ if (s->listener_index == SESSION_INVALID_INDEX) - return; + { + ECHO_LOG (2, "%U: listener_index == SESSION_INVALID_INDEX", + echo_format_session, s); + return; + } ls = pool_elt_at_index (em->sessions, s->listener_index); if (ls->session_state < ECHO_SESSION_STATE_CLOSING) - return; - ECHO_LOG (2, "Session 0%lx died, close child 0x%lx", ls->vpp_session_handle, - s->vpp_session_handle); + { + ECHO_LOG (3, "%U: ls->session_state (%d) < " + "ECHO_SESSION_STATE_CLOSING (%d)", + echo_format_session, ls, ls->session_state, + ECHO_SESSION_STATE_CLOSING); + return; + } + + ECHO_LOG (2, "%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 */ ); } @@ -348,7 +373,7 @@ echo_handle_data (echo_main_t * em, echo_session_t * s, u8 * rx_buf) int n_read, n_sent = 0; n_read = recv_data_chunk (em, s, rx_buf); - if (em->data_source == ECHO_TEST_DATA_SOURCE) + if ((em->data_source == ECHO_TEST_DATA_SOURCE) && s->bytes_to_send) n_sent = send_data_chunk (s, em->connect_test_data, s->bytes_sent % em->tx_buf_size, em->tx_buf_size); @@ -390,8 +415,8 @@ echo_handle_data (echo_main_t * em, echo_session_t * s, u8 * rx_buf) ECHO_LOG (1, "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, - s->session_state); + ECHO_LOG (1, "Session 0x%lx state %U", s->vpp_session_handle, + echo_format_session_state, s->session_state); } } } @@ -433,19 +458,26 @@ echo_data_thread_fn (void *arg) echo_check_closed_listener (em, s); break; case ECHO_SESSION_STATE_AWAIT_CLOSING: + ECHO_LOG (3, "%U: %U", echo_format_session, s, + echo_format_session_state, s->session_state); echo_check_closed_listener (em, s); break; case ECHO_SESSION_STATE_CLOSING: + ECHO_LOG (2, "%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_format_session_state, s->session_state); n_closed_sessions++; break; } if (n_closed_sessions == thread_n_sessions) break; } + ECHO_LOG (1, "Mission accomplished!"); pthread_exit (0); } @@ -456,6 +488,7 @@ session_unlisten_handler (session_unlisten_msg_t * mp) echo_main_t *em = &echo_main; listen_session = pool_elt_at_index (em->sessions, em->listen_session_index); em->proto_cb_vft->cleanup_cb (listen_session, 0 /* parent_died */ ); + listen_session->session_state = ECHO_SESSION_STATE_CLOSED; em->state = STATE_DISCONNECTED; } @@ -493,9 +526,13 @@ session_accepted_handler (session_accepted_msg_t * mp) svm_fifo_t *rx_fifo, *tx_fifo; echo_main_t *em = &echo_main; echo_session_t *session, *ls; - /* Allocate local session and set it up */ - session = echo_session_new (em); + if (!(ls = echo_get_session_from_handle (em, mp->listener_handle))) + { + ECHO_FAIL (ECHO_FAIL_SESSION_ACCEPTED_BAD_LISTENER, + "Unknown listener handle 0x%lx", mp->listener_handle); + return; + } if (wait_for_segment_allocation (mp->segment_handle)) { ECHO_FAIL (ECHO_FAIL_ACCEPTED_WAIT_FOR_SEG_ALLOC, @@ -503,6 +540,10 @@ session_accepted_handler (session_accepted_msg_t * mp) return; } + /* Allocate local session and set it up */ + session = echo_session_new (em); + session->vpp_session_handle = mp->handle; + rx_fifo = uword_to_pointer (mp->server_rx_fifo, svm_fifo_t *); rx_fifo->client_session_index = session->session_index; tx_fifo = uword_to_pointer (mp->server_tx_fifo, svm_fifo_t *); @@ -524,13 +565,12 @@ session_accepted_handler (session_accepted_msg_t * mp) session->start = clib_time_now (&em->clib_time); session->vpp_evt_q = uword_to_pointer (mp->vpp_event_queue_address, svm_msg_q_t *); - if (!(ls = echo_get_session_from_handle (em, mp->listener_handle))) - return; session->listener_index = ls->session_index; /* Add it to lookup table */ - ECHO_LOG (1, "Accepted session 0x%lx -> 0x%lx", mp->handle, - mp->listener_handle); + ECHO_LOG (1, "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); app_alloc_ctrl_evt_to_vpp (session->vpp_evt_q, app_evt, @@ -606,15 +646,21 @@ session_disconnected_handler (session_disconnected_msg_t * mp) session_disconnected_reply_msg_t *rmp; echo_main_t *em = &echo_main; echo_session_t *s; - ECHO_LOG (1, "passive close session 0x%lx", mp->handle); if (!(s = echo_get_session_from_handle (em, mp->handle))) { - ECHO_FAIL (ECHO_FAIL_SESSION_DISCONNECT, "Session 0x%lx not found", - mp->handle); + ECHO_LOG (0, "Invalid vpp_session_handle: 0x%lx", mp->handle); return; } - em->proto_cb_vft->disconnected_cb (mp, s); - + if (s->session_state == ECHO_SESSION_STATE_CLOSED) + { + ECHO_LOG (1, "%U: already in ECHO_SESSION_STATE_CLOSED", + echo_format_session, s); + } + else + { + ECHO_LOG (1, "%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, SESSION_CTRL_EVT_DISCONNECTED_REPLY); rmp = (session_disconnected_reply_msg_t *) app_evt->evt->data; @@ -631,13 +677,12 @@ session_reset_handler (session_reset_msg_t * mp) echo_main_t *em = &echo_main; session_reset_reply_msg_t *rmp; echo_session_t *s = 0; - ECHO_LOG (1, "Reset session 0x%lx", mp->handle); if (!(s = echo_get_session_from_handle (em, mp->handle))) { - ECHO_FAIL (ECHO_FAIL_SESSION_RESET, "Session 0x%lx not found", - mp->handle); + ECHO_LOG (0, "Invalid vpp_session_handle: 0x%lx", mp->handle); return; } + ECHO_LOG (1, "%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, @@ -779,6 +824,7 @@ server_run (echo_main_t * em) ECHO_LOG (1, "App is ready"); echo_process_rpcs (em); /* Cleanup */ + ECHO_LOG (1, "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)) @@ -821,6 +867,8 @@ print_usage_and_exit (void) " sconnected - last Stream got connected\n" " lastbyte - Last expected byte received\n" " exit - Exiting of the app\n" + " rx-results-diff Rx results different to pass test\n" + " tx-results-diff Tx results different to pass test\n" " json Output global stats in json\n" " log=N Set the log level to [0: no output, 1:errors, 2:log]\n" "\n" @@ -837,7 +885,7 @@ print_usage_and_exit (void) fprintf (stderr, "\nDefault configuration is :\n" " server nclients 1/1 RX=64Kb TX=RX\n" " client nclients 1/1 RX=64Kb TX=64Kb\n"); - exit (1); + exit (ECHO_FAIL_USAGE); } static int @@ -937,6 +985,10 @@ echo_process_opts (int argc, char **argv) ; else if (unformat (a, "RX=%U", unformat_data, &em->bytes_to_receive)) ; + else if (unformat (a, "rx-results-diff")) + em->rx_results_diff = 1; + else if (unformat (a, "tx-results-diff")) + em->tx_results_diff = 1; else if (unformat (a, "json")) em->output_json = 1; else if (unformat (a, "log=%d", &em->log_lvl)) @@ -1146,7 +1198,6 @@ main (int argc, char **argv) clients_run (em); echo_notify_event (em, ECHO_EVT_EXIT); echo_free_sessions (em); - echo_assert_test_suceeded (em); echo_send_detach (em); if (wait_for_state_change (em, STATE_DETACHED, TIMEOUT)) { @@ -1164,6 +1215,7 @@ main (int argc, char **argv) vl_socket_client_disconnect (); else vl_client_disconnect_from_vlib (); + echo_assert_test_suceeded (em); exit_on_error: ECHO_LOG (0, "Test complete !\n"); if (em->output_json) diff --git a/src/plugins/hs_apps/sapi/vpp_echo_bapi.c b/src/plugins/hs_apps/sapi/vpp_echo_bapi.c index a565a91899a..fad0d18ccc6 100644 --- a/src/plugins/hs_apps/sapi/vpp_echo_bapi.c +++ b/src/plugins/hs_apps/sapi/vpp_echo_bapi.c @@ -283,7 +283,11 @@ vl_api_app_attach_reply_t_handler (vl_api_app_attach_reply_t * mp) return; } - ASSERT (mp->app_mq); + if (!mp->app_mq) + { + ECHO_FAIL (ECHO_FAIL_VL_API_NULL_APP_MQ, "NULL app_mq"); + return; + } em->app_mq = uword_to_pointer (mp->app_mq, svm_msg_q_t *); em->ctrl_mq = uword_to_pointer (mp->vpp_ctrl_mq, svm_msg_q_t *); diff --git a/src/plugins/hs_apps/sapi/vpp_echo_common.c b/src/plugins/hs_apps/sapi/vpp_echo_common.c index 0f6c2ec7135..dbe8d92661f 100644 --- a/src/plugins/hs_apps/sapi/vpp_echo_common.c +++ b/src/plugins/hs_apps/sapi/vpp_echo_common.c @@ -167,29 +167,82 @@ init_error_string_table () } u8 * +echo_format_session (u8 * s, va_list * args) +{ + echo_session_t *session = va_arg (*args, echo_session_t *); + + return format (s, "%U 0x%lx S[%u]", echo_format_session_type, + session->session_type, session->vpp_session_handle, + session->session_index); +} + +u8 * +echo_format_session_type (u8 * s, va_list * args) +{ + u32 session_type = va_arg (*args, u32); + switch (session_type) + { + case ECHO_SESSION_TYPE_QUIC: + return format (s, "Qsession"); + case ECHO_SESSION_TYPE_STREAM: + return format (s, "Stream"); + case ECHO_SESSION_TYPE_LISTEN: + return format (s, "Lsession"); + default: + break; + } + return format (s, "BadSession"); +} + +u8 * +echo_format_session_state (u8 * s, va_list * args) +{ + u32 session_state = va_arg (*args, u32); + switch (session_state) + { + case ECHO_SESSION_STATE_INITIAL: + return format (s, "ECHO_SESSION_STATE_INITIAL (%u)", session_state); + case ECHO_SESSION_STATE_READY: + return format (s, "ECHO_SESSION_STATE_READY (%u)", session_state); + case ECHO_SESSION_STATE_AWAIT_CLOSING: + return format (s, "ECHO_SESSION_STATE_AWAIT_CLOSING (%u)", + session_state); + case ECHO_SESSION_STATE_AWAIT_DATA: + return format (s, "ECHO_SESSION_STATE_AWAIT_DATA (%u)", session_state); + case ECHO_SESSION_STATE_CLOSING: + return format (s, "ECHO_SESSION_STATE_CLOSING (%u)", session_state); + case ECHO_SESSION_STATE_CLOSED: + return format (s, "ECHO_SESSION_STATE_CLOSED (%u)", session_state); + default: + break; + } + return format (s, "unknown session state (%u)", session_state); +} + +u8 * echo_format_app_state (u8 * s, va_list * args) { u32 state = va_arg (*args, u32); if (state == STATE_START) - return format (s, "STATE_START"); + return format (s, "STATE_START (%u)", state); if (state == STATE_ATTACHED) - return format (s, "STATE_ATTACHED"); + return format (s, "STATE_ATTACHED (%u)", state); if (state == STATE_ATTACHED_NO_CERT) - return format (s, "STATE_ATTACHED_NO_CERT"); + return format (s, "STATE_ATTACHED_NO_CERT (%u)", state); if (state == STATE_ATTACHED_ONE_CERT) - return format (s, "STATE_ATTACHED_ONE_CERT"); + return format (s, "STATE_ATTACHED_ONE_CERT (%u)", state); if (state == STATE_LISTEN) - return format (s, "STATE_LISTEN"); + return format (s, "STATE_LISTEN (%u)", state); if (state == STATE_READY) - return format (s, "STATE_READY"); + return format (s, "STATE_READY (%u)", state); if (state == STATE_DATA_DONE) - return format (s, "STATE_DATA_DONE"); + return format (s, "STATE_DATA_DONE (%u)", state); if (state == STATE_DISCONNECTED) - return format (s, "STATE_DISCONNECTED"); + return format (s, "STATE_DISCONNECTED (%u)", state); if (state == STATE_DETACHED) - return format (s, "STATE_DETACHED"); + return format (s, "STATE_DETACHED (%u)", state); else - return format (s, "unknown state"); + return format (s, "unknown state (%u)", state); } uword @@ -475,9 +528,15 @@ 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) - hash_unset (em->session_index_by_vpp_handles, handle); + { + ECHO_LOG (2, "hash_unset(0x%lx)", handle); + hash_unset (em->session_index_by_vpp_handles, handle); + } else - hash_set (em->session_index_by_vpp_handles, handle, sid); + { + ECHO_LOG (2, "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); } @@ -525,8 +584,7 @@ echo_get_session_from_handle (echo_main_t * em, u64 handle) clib_spinlock_unlock (&em->sid_vpp_handles_lock); if (!p) { - ECHO_FAIL (ECHO_FAIL_GET_SESSION_FROM_HANDLE, - "unknown handle 0x%lx", handle); + ECHO_LOG (1, "unknown handle 0x%lx", handle); return 0; } return pool_elt_at_index (em->sessions, p[0]); diff --git a/src/plugins/hs_apps/sapi/vpp_echo_common.h b/src/plugins/hs_apps/sapi/vpp_echo_common.h index ea20e2b9e09..a7010d85cb7 100644 --- a/src/plugins/hs_apps/sapi/vpp_echo_common.h +++ b/src/plugins/hs_apps/sapi/vpp_echo_common.h @@ -39,12 +39,15 @@ #define foreach_echo_fail_code \ _(ECHO_FAIL_NONE, "ECHO_FAIL_NONE") \ + _(ECHO_FAIL_USAGE, "ECHO_FAIL_USAGE") \ _(ECHO_FAIL_SEND_IO_EVT, "ECHO_FAIL_SEND_IO_EVT") \ _(ECHO_FAIL_SOCKET_CONNECT, "ECHO_FAIL_SOCKET_CONNECT") \ _(ECHO_FAIL_INIT_SHM_API, "ECHO_FAIL_INIT_SHM_API") \ _(ECHO_FAIL_SHMEM_CONNECT, "ECHO_FAIL_SHMEM_CONNECT") \ _(ECHO_FAIL_TEST_BYTES_ERR, "ECHO_FAIL_TEST_BYTES_ERR") \ _(ECHO_FAIL_BIND, "ECHO_FAIL_BIND") \ + _(ECHO_FAIL_SESSION_ACCEPTED_BAD_LISTENER, \ + "ECHO_FAIL_SESSION_ACCEPTED_BAD_LISTENER") \ _(ECHO_FAIL_ACCEPTED_WAIT_FOR_SEG_ALLOC, \ "ECHO_FAIL_ACCEPTED_WAIT_FOR_SEG_ALLOC") \ _(ECHO_FAIL_SESSION_CONNECT, "ECHO_FAIL_SESSION_CONNECT") \ @@ -65,6 +68,7 @@ _(ECHO_FAIL_VL_API_APP_ATTACH, "ECHO_FAIL_VL_API_APP_ATTACH") \ _(ECHO_FAIL_VL_API_MISSING_SEGMENT_NAME, \ "ECHO_FAIL_VL_API_MISSING_SEGMENT_NAME") \ + _(ECHO_FAIL_VL_API_NULL_APP_MQ, "ECHO_FAIL_VL_API_NULL_APP_MQ") \ _(ECHO_FAIL_VL_API_RECV_FD_MSG, "ECHO_FAIL_VL_API_RECV_FD_MSG") \ _(ECHO_FAIL_VL_API_SVM_FIFO_SEG_ATTACH, \ "ECHO_FAIL_VL_API_SVM_FIFO_SEG_ATTACH") \ @@ -101,15 +105,24 @@ typedef enum extern char *echo_fail_code_str[]; -#define CHECK(fail, expected, result, _fmt, _args...) \ - if (expected != result) \ - ECHO_FAIL (fail, "expected %d, got %d : " _fmt, expected, \ - result, ##_args); \ +#define CHECK_SAME(fail, expected, result, _fmt, _args...) \ +do { \ + if ((expected) != (result)) \ + ECHO_FAIL ((fail), "expected same (%d, got %d) : "_fmt, \ + (expected), (result), ##_args); \ +} while (0) + +#define CHECK_DIFF(fail, expected, result, _fmt, _args...) \ +do { \ + if ((expected) == (result)) \ + ECHO_FAIL ((fail), "expected different (both %d) : "_fmt, \ + (expected), ##_args); \ +} while (0) #define ECHO_FAIL(fail, _fmt, _args...) \ - { \ +do { \ echo_main_t *em = &echo_main; \ - em->has_failed = fail; \ + em->has_failed = (fail); \ if (vec_len(em->fail_descr)) \ em->fail_descr = format(em->fail_descr, " | %s (%d): "_fmt, \ echo_fail_code_str[fail], fail, ##_args); \ @@ -119,7 +132,7 @@ extern char *echo_fail_code_str[]; em->time_to_stop = 1; \ if (em->log_lvl > 0) \ clib_warning ("%v", em->fail_descr); \ - } +} while (0) #define ECHO_LOG(lvl, _fmt,_args...) \ { \ @@ -270,6 +283,8 @@ typedef struct /* State of the connection, shared between msg RX thread and main thread */ volatile connection_state_t state; volatile u8 time_to_stop; /* Signal variables */ + u8 rx_results_diff; /* Rx results will be different than cfg */ + u8 tx_results_diff; /* Tx results will be different than cfg */ u8 has_failed; /* stores the exit code */ u8 *fail_descr; /* vector containing fail description */ @@ -359,6 +374,9 @@ u8 *format_ip46_address (u8 * s, va_list * args); uword unformat_data (unformat_input_t * input, va_list * args); u8 *format_api_error (u8 * s, va_list * args); void init_error_string_table (); +u8 *echo_format_session (u8 * s, va_list * args); +u8 *echo_format_session_type (u8 * s, va_list * args); +u8 *echo_format_session_state (u8 * s, va_list * args); u8 *echo_format_app_state (u8 * s, va_list * args); uword echo_unformat_close (unformat_input_t * input, va_list * args); uword echo_unformat_timing_event (unformat_input_t * input, va_list * args); 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 999cacb5353..a78f949a0ef 100644 --- a/src/plugins/hs_apps/sapi/vpp_echo_proto_quic.c +++ b/src/plugins/hs_apps/sapi/vpp_echo_proto_quic.c @@ -60,8 +60,8 @@ 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 connected to %U:%d", - mp->handle, format_ip46_address, &mp->lcl.ip, + ECHO_LOG (0, "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 %u", mp->handle); + ECHO_LOG (1, "Accept on QSession 0x%lx S[%u]", mp->handle, session_index); u32 i; echo_notify_event (em, ECHO_EVT_FIRST_SCONNECT); @@ -118,8 +118,8 @@ static void quic_echo_on_accept_error (session_accepted_msg_t * mp, u32 session_index) { ECHO_FAIL (ECHO_FAIL_QUIC_WRONG_ACCEPT, - "Got a wrong accept on session %u [%lx]", session_index, - mp->handle); + "Got a wrong accept on session 0x%lx S[%u]", mp->handle, + session_index); } static void @@ -164,7 +164,12 @@ quic_echo_cleanup_listener (u32 listener_index, echo_main_t * em, { echo_session_t *ls; ls = pool_elt_at_index (em->sessions, listener_index); - ASSERT (ls->session_type == ECHO_SESSION_TYPE_QUIC); + if (ls->session_type != ECHO_SESSION_TYPE_QUIC) + { + ECHO_LOG (1, "%U: Invalid listener session type", + echo_format_session, ls); + return; + } if (!clib_atomic_sub_fetch (&ls->accepted_session_count, 1)) { if (eqm->send_quic_disconnects == ECHO_CLOSE_F_ACTIVE) @@ -186,7 +191,12 @@ quic_echo_cleanup_cb (echo_session_t * s, u8 parent_died) { echo_main_t *em = &echo_main; quic_echo_proto_main_t *eqm = &quic_echo_proto_main; - ASSERT (s->session_state < ECHO_SESSION_STATE_CLOSED); + 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, + parent_died); + s->session_state = ECHO_SESSION_STATE_CLOSED; if (s->session_type == ECHO_SESSION_TYPE_QUIC) { if (parent_died) @@ -202,12 +212,11 @@ quic_echo_cleanup_cb (echo_session_t * s, u8 parent_died) quic_echo_cleanup_listener (s->listener_index, em, eqm); clib_atomic_sub_fetch (&em->n_clients_connected, 1); } - - ECHO_LOG (1, "Cleanup sessions (still %uQ %uS)", - eqm->n_quic_clients_connected, em->n_clients_connected); - s->session_state = ECHO_SESSION_STATE_CLOSED; 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", + eqm->n_quic_clients_connected, em->n_clients_connected, + echo_format_app_state, em->state); } static void @@ -225,18 +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,"ACTIVE close 0x%lx", s->vpp_session_handle); - echo_send_rpc (em, echo_send_disconnect_session, (void *) s->vpp_session_handle, 0); + ECHO_LOG (1,"%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,"Discard close 0x%lx", s->vpp_session_handle); + ECHO_LOG (1,"%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,"Passive close 0x%lx", s->vpp_session_handle); + ECHO_LOG (1,"%U: PASSIVE close", echo_format_session, s); } })); /* *INDENT-ON* */ @@ -249,10 +259,11 @@ quic_echo_on_connected (session_connected_msg_t * mp, u32 session_index) quic_echo_proto_main_t *eqm = &quic_echo_proto_main; echo_session_t *listen_session; echo_session_t *session = pool_elt_at_index (em->sessions, session_index); + if (session->listener_index == SESSION_INVALID_INDEX) { - ECHO_LOG (1, "Connected session 0x%lx -> URI", mp->handle); session->session_type = ECHO_SESSION_TYPE_QUIC; + ECHO_LOG (1, "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); @@ -262,10 +273,10 @@ quic_echo_on_connected (session_connected_msg_t * mp, u32 session_index) { listen_session = pool_elt_at_index (em->sessions, session->listener_index); - ECHO_LOG (1, "Connected session 0x%lx -> 0x%lx", mp->handle, - listen_session->vpp_session_handle); 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_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) @@ -295,14 +306,14 @@ quic_echo_retry_connect (u32 session_index) echo_main_t *em = &echo_main; if (session_index == SESSION_INVALID_INDEX) { - ECHO_LOG (1, "Retrying connect %s", em->uri); + ECHO_LOG (1, "Retrying Qsession connect"); echo_send_rpc (em, echo_send_connect, (void *) SESSION_INVALID_HANDLE, SESSION_INVALID_INDEX); } else { session = pool_elt_at_index (em->sessions, session_index); - ECHO_LOG (1, "Retrying connect 0x%lx", session->vpp_session_handle); + ECHO_LOG (1, "Retrying connect %U", echo_format_session, session); echo_send_rpc (em, echo_send_connect, (void *) session->vpp_session_handle, session_index); } diff --git a/src/plugins/quic/test/test_quic.py b/src/plugins/quic/test/test_quic.py index 0516dc7ceb6..79e5dd1f896 100644 --- a/src/plugins/quic/test/test_quic.py +++ b/src/plugins/quic/test/test_quic.py @@ -231,8 +231,8 @@ class QUICEchoExtQcloseRxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_qclose_rx(self): - self.server("TX=0", "RX=1Kb", "qclose=Y", "sclose=N") - self.client("TX=1Kb", "RX=0", "qclose=W", "sclose=W") + self.server("TX=0", "RX=10Mb", "qclose=Y", "sclose=N") + self.client("TX=10Mb", "RX=0", "qclose=W", "sclose=W") self.validate_ext_test_results() @@ -241,8 +241,9 @@ class QUICEchoExtQcloseTxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_qclose_tx(self): - self.server("TX=0", "RX=1Kb", "qclose=W", "sclose=W") - self.client("TX=1Kb", "RX=0", "qclose=Y", "sclose=N") + self.server("TX=0", "RX=10Mb", "qclose=W", "sclose=W", + "rx-results-diff") + self.client("TX=10Mb", "RX=0", "qclose=Y", "sclose=N") self.validate_ext_test_results() @@ -251,8 +252,9 @@ class QUICEchoExtEarlyQcloseRxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_early_qclose_rx(self): - self.server("TX=0", "RX=1Kb", "qclose=Y", "sclose=N") - self.client("TX=2Kb", "RX=0", "qclose=W", "sclose=W") + self.server("TX=0", "RX=10Mb", "qclose=Y", "sclose=N") + self.client("TX=20Mb", "RX=0", "qclose=W", "sclose=W", + "tx-results-diff") self.validate_ext_test_results() @@ -261,8 +263,9 @@ class QUICEchoExtEarlyQcloseTxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_early_qclose_tx(self): - self.server("TX=0", "RX=2Kb", "qclose=W", "sclose=W") - self.client("TX=1Kb", "RX=0", "qclose=Y", "sclose=N") + self.server("TX=0", "RX=20Mb", "qclose=W", "sclose=W", + "rx-results-diff") + self.client("TX=10Mb", "RX=0", "qclose=Y", "sclose=N") self.validate_ext_test_results() @@ -271,8 +274,8 @@ class QUICEchoExtScloseRxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_sclose_rx(self): - self.server("TX=0", "RX=1Kb", "qclose=N", "sclose=Y") - self.client("TX=1Kb", "RX=0", "qclose=W", "sclose=W") + self.server("TX=0", "RX=10Mb", "qclose=N", "sclose=Y") + self.client("TX=10Mb", "RX=0", "qclose=W", "sclose=W") self.validate_ext_test_results() @@ -281,8 +284,8 @@ class QUICEchoExtScloseTxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_sclose_tx(self): - self.server("TX=0", "RX=1Kb", "qclose=W", "sclose=W") - self.client("TX=1Kb", "RX=0", "qclose=N", "sclose=Y") + self.server("TX=0", "RX=10Mb", "qclose=W", "sclose=W") + self.client("TX=10Mb", "RX=0", "qclose=Y", "sclose=Y") self.validate_ext_test_results() @@ -291,18 +294,20 @@ class QUICEchoExtEarlyScloseRxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_early_sclose_rx(self): - self.server("TX=0", "RX=1Kb", "qclose=N", "sclose=Y") - self.client("TX=2Kb", "RX=0", "qclose=W", "sclose=W") + self.server("TX=0", "RX=10Mb", "qclose=N", "sclose=Y") + self.client("TX=20Mb", "RX=0", "qclose=W", "sclose=W", + "tx-results-diff") self.validate_ext_test_results() class QUICEchoExtEarlyScloseTxTestCase(QUICEchoExtTestCase): - """QUIC Echo External Transfer Early Sclose RTx Test Case""" + """QUIC Echo External Transfer Early Sclose Tx Test Case""" @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_early_sclose_tx(self): - self.server("TX=0", "RX=2Kb", "qclose=W", "sclose=W") - self.client("TX=1Kb", "RX=0", "qclose=N", "sclose=Y") + self.server("TX=0", "RX=20Mb", "qclose=W", "sclose=W", + "rx-results-diff") + self.client("TX=10Mb", "RX=0", "qclose=Y", "sclose=Y") self.validate_ext_test_results() @@ -311,8 +316,8 @@ class QUICEchoExtServerStreamTestCase(QUICEchoExtTestCase): quic_setup = "serverstream" def test_quic_ext_transfer_server_stream(self): - self.server("TX=1Kb", "RX=0") - self.client("TX=0", "RX=1Kb") + self.server("TX=10Mb", "RX=0") + self.client("TX=0", "RX=10Mb") self.validate_ext_test_results() @@ -322,8 +327,8 @@ class QUICEchoExtServerStreamQcloseRxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_server_stream_qclose_rx(self): - self.server("TX=1Kb", "RX=0", "qclose=W", "sclose=W") - self.client("TX=0", "RX=1Kb", "qclose=Y", "sclose=N") + self.server("TX=10Mb", "RX=0", "qclose=W", "sclose=W") + self.client("TX=0", "RX=10Mb", "qclose=Y", "sclose=N") self.validate_ext_test_results() @@ -333,8 +338,9 @@ class QUICEchoExtServerStreamQcloseTxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_server_stream_qclose_tx(self): - self.server("TX=1Kb", "RX=0", "qclose=Y", "sclose=N") - self.client("TX=0", "RX=1Kb", "qclose=W", "sclose=W") + self.server("TX=10Mb", "RX=0", "qclose=Y", "sclose=N") + self.client("TX=0", "RX=10Mb", "qclose=W", "sclose=W", + "rx-results-diff") self.validate_ext_test_results() @@ -344,8 +350,9 @@ class QUICEchoExtServerStreamEarlyQcloseRxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_server_stream_early_qclose_rx(self): - self.server("TX=2Kb", "RX=0", "qclose=W", "sclose=W") - self.client("TX=0", "RX=1Kb", "qclose=Y", "sclose=N") + self.server("TX=20Mb", "RX=0", "qclose=W", "sclose=W", + "tx-results-diff") + self.client("TX=0", "RX=10Mb", "qclose=Y", "sclose=N") self.validate_ext_test_results() @@ -355,8 +362,9 @@ class QUICEchoExtServerStreamEarlyQcloseTxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_server_stream_early_qclose_tx(self): - self.server("TX=1Kb", "RX=0", "qclose=Y", "sclose=N") - self.client("TX=0", "RX=2Kb", "qclose=W", "sclose=W") + self.server("TX=10Mb", "RX=0", "qclose=Y", "sclose=N") + self.client("TX=0", "RX=20Mb", "qclose=W", "sclose=W", + "rx-results-diff") self.validate_ext_test_results() @@ -366,8 +374,8 @@ class QUICEchoExtServerStreamScloseRxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_server_stream_sclose_rx(self): - self.server("TX=1Kb", "RX=0", "qclose=W", "sclose=W") - self.client("TX=0", "RX=1Kb", "qclose=N", "sclose=Y") + self.server("TX=10Mb", "RX=0", "qclose=W", "sclose=W") + self.client("TX=0", "RX=10Mb", "qclose=N", "sclose=Y") self.validate_ext_test_results() @@ -377,8 +385,8 @@ class QUICEchoExtServerStreamScloseTxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_server_stream_sclose_tx(self): - self.server("TX=1Kb", "RX=0", "qclose=N", "sclose=Y") - self.client("TX=0", "RX=1Kb", "qclose=W", "sclose=W") + self.server("TX=10Mb", "RX=0", "qclose=Y", "sclose=Y") + self.client("TX=0", "RX=10Mb", "qclose=W", "sclose=W") self.validate_ext_test_results() @@ -388,8 +396,9 @@ class QUICEchoExtServerStreamEarlyScloseRxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_server_stream_early_sclose_rx(self): - self.server("TX=2Kb", "RX=0", "qclose=W", "sclose=W") - self.client("TX=0", "RX=1Kb", "qclose=N", "sclose=Y") + self.server("TX=20Mb", "RX=0", "qclose=W", "sclose=W", + "tx-results-diff") + self.client("TX=0", "RX=10Mb", "qclose=N", "sclose=Y") self.validate_ext_test_results() @@ -399,8 +408,9 @@ class QUICEchoExtServerStreamEarlyScloseTxTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_server_stream_early_sclose_tx(self): - self.server("TX=1Kb", "RX=0", "qclose=N", "sclose=Y") - self.client("TX=0", "RX=2Kb", "qclose=W", "sclose=W") + self.server("TX=10Mb", "RX=0", "qclose=Y", "sclose=Y") + self.client("TX=0", "RX=20Mb", "qclose=W", "sclose=W", + "rx-results-diff") self.validate_ext_test_results() @@ -410,8 +420,8 @@ class QUICEchoExtServerStreamWorkersTestCase(QUICEchoExtTestCase): @unittest.skipUnless(running_extended_tests, "part of extended tests") def test_quic_ext_transfer_server_stream_multi_workers(self): - self.server("nclients", "4/4", "TX=1Kb", "RX=0") - self.client("nclients", "4/4", "TX=0", "RX=1Kb") + self.server("nclients", "4/4", "TX=10Mb", "RX=0") + self.client("nclients", "4/4", "TX=0", "RX=10Mb") self.validate_ext_test_results() |