From d810a6e218e9af3c3bccd58c9a2d925a7f12242e Mon Sep 17 00:00:00 2001 From: Steven Luong Date: Tue, 25 Oct 2022 13:09:11 -0700 Subject: session: add session event log for session state To aid sesipon debug, add session event log in SM debug to track the session state. Type: improvement Signed-off-by: Steven Luong Change-Id: I6909cf969cd5b6a3ea5a06d08ae32c2f1d48f686 --- src/vnet/session/application_local.c | 10 +++---- src/vnet/session/session.c | 52 +++++++++++++++++------------------- src/vnet/session/session.h | 7 +++++ src/vnet/session/session_debug.h | 28 +++++++++++++++++++ src/vnet/session/session_node.c | 6 ++--- 5 files changed, 68 insertions(+), 35 deletions(-) (limited to 'src/vnet') diff --git a/src/vnet/session/application_local.c b/src/vnet/session/application_local.c index 8590d041600..d2a69dc282b 100644 --- a/src/vnet/session/application_local.c +++ b/src/vnet/session/application_local.c @@ -363,7 +363,7 @@ ct_session_connect_notify (session_t *ss, session_error_t err) ss = session_get (ss_index, thread_index); cs->session_type = ss->session_type; cs->listener_handle = SESSION_INVALID_HANDLE; - cs->session_state = SESSION_STATE_CONNECTING; + session_set_state (cs, SESSION_STATE_CONNECTING); cs->app_wrk_index = client_wrk->wrk_index; cs->connection_index = cct->c_c_index; cct->c_s_index = cs->session_index; @@ -379,7 +379,7 @@ ct_session_connect_notify (session_t *ss, session_error_t err) goto connect_error; } - cs->session_state = SESSION_STATE_CONNECTING; + session_set_state (cs, SESSION_STATE_CONNECTING); if (app_worker_connect_notify (client_wrk, cs, 0, opaque)) { @@ -390,7 +390,7 @@ ct_session_connect_notify (session_t *ss, session_error_t err) } cs = session_get (cct->c_s_index, cct->c_thread_index); - cs->session_state = SESSION_STATE_READY; + session_set_state (cs, SESSION_STATE_READY); return 0; @@ -701,7 +701,7 @@ ct_accept_one (u32 thread_index, u32 ho_index) sct->c_is_ip4); ss->connection_index = sct->c_c_index; ss->listener_handle = listen_session_get_handle (ll); - ss->session_state = SESSION_STATE_CREATED; + session_set_state (ss, SESSION_STATE_CREATED); server_wrk = application_listener_select_worker (ll); ss->app_wrk_index = server_wrk->wrk_index; @@ -726,7 +726,7 @@ ct_accept_one (u32 thread_index, u32 ho_index) cct->client_tx_fifo->refcnt++; cct->segment_handle = sct->segment_handle; - ss->session_state = SESSION_STATE_ACCEPTING; + session_set_state (ss, SESSION_STATE_ACCEPTING); if (app_worker_accept_notify (server_wrk, ss)) { ct_session_connect_notify (ss, SESSION_E_REFUSED); diff --git a/src/vnet/session/session.c b/src/vnet/session/session.c index 4c57b1ac9bb..a56ff9fe800 100644 --- a/src/vnet/session/session.c +++ b/src/vnet/session/session.c @@ -299,7 +299,7 @@ session_cleanup_half_open (session_handle_t ho_handle) * session should be removed. */ if (ho->connection_index == ~0) { - ho->session_state = SESSION_STATE_CLOSED; + session_set_state (ho, SESSION_STATE_CLOSED); return; } /* Migrated transports are no longer half-opens */ @@ -386,7 +386,7 @@ session_alloc_for_connection (transport_connection_t * tc) s = session_alloc (thread_index); s->session_type = session_type_from_proto_and_ip (tc->proto, tc->is_ip4); - s->session_state = SESSION_STATE_CLOSED; + session_set_state (s, SESSION_STATE_CLOSED); /* Attach transport to session and vice versa */ s->connection_index = tc->c_index; @@ -894,7 +894,7 @@ session_stream_connect_notify (transport_connection_t * tc, return app_worker_connect_notify (app_wrk, s, err, opaque); s = session_alloc_for_connection (tc); - s->session_state = SESSION_STATE_CONNECTING; + session_set_state (s, SESSION_STATE_CONNECTING); s->app_wrk_index = app_wrk->wrk_index; new_si = s->session_index; new_ti = s->thread_index; @@ -907,7 +907,7 @@ session_stream_connect_notify (transport_connection_t * tc, } s = session_get (new_si, new_ti); - s->session_state = SESSION_STATE_READY; + session_set_state (s, SESSION_STATE_READY); session_lookup_add_connection (tc, session_handle (s)); if (app_worker_connect_notify (app_wrk, s, SESSION_E_NONE, opaque)) @@ -1037,7 +1037,7 @@ session_dgram_connect_notify (transport_connection_t * tc, */ new_s = session_clone_safe (tc->s_index, old_thread_index); new_s->connection_index = tc->c_index; - new_s->session_state = SESSION_STATE_READY; + session_set_state (new_s, SESSION_STATE_READY); new_s->flags |= SESSION_F_IS_MIGRATING; if (!(tc->flags & TRANSPORT_CONNECTION_F_NO_LOOKUP)) @@ -1091,11 +1091,11 @@ session_transport_closing_notify (transport_connection_t * tc) * accept might be rejected */ if (s->session_state == SESSION_STATE_ACCEPTING) { - s->session_state = SESSION_STATE_TRANSPORT_CLOSING; + session_set_state (s, SESSION_STATE_TRANSPORT_CLOSING); return; } - s->session_state = SESSION_STATE_TRANSPORT_CLOSING; + session_set_state (s, SESSION_STATE_TRANSPORT_CLOSING); app_wrk = app_worker_get (s->app_wrk_index); app_worker_close_notify (app_wrk, s); } @@ -1136,7 +1136,7 @@ session_transport_delete_notify (transport_connection_t * tc) * because transport will soon be closed and closed sessions * are assumed to have been removed from the lookup table */ session_lookup_del_session (s); - s->session_state = SESSION_STATE_TRANSPORT_DELETED; + session_set_state (s, SESSION_STATE_TRANSPORT_DELETED); session_cleanup_notify (s, SESSION_CLEANUP_TRANSPORT); svm_fifo_dequeue_drop_all (s->tx_fifo); break; @@ -1147,7 +1147,7 @@ session_transport_delete_notify (transport_connection_t * tc) * session is just removed because both transport and app have * confirmed the close*/ session_lookup_del_session (s); - s->session_state = SESSION_STATE_TRANSPORT_DELETED; + session_set_state (s, SESSION_STATE_TRANSPORT_DELETED); session_cleanup_notify (s, SESSION_CLEANUP_TRANSPORT); svm_fifo_dequeue_drop_all (s->tx_fifo); session_program_transport_ctrl_evt (s, SESSION_CTRL_EVT_CLOSE); @@ -1191,17 +1191,15 @@ session_transport_closed_notify (transport_connection_t * tc) { session_transport_closing_notify (tc); svm_fifo_dequeue_drop_all (s->tx_fifo); - s->session_state = SESSION_STATE_TRANSPORT_CLOSED; + session_set_state (s, SESSION_STATE_TRANSPORT_CLOSED); } /* If app close has not been received or has not yet resulted in * a transport close, only mark the session transport as closed */ else if (s->session_state <= SESSION_STATE_CLOSING) - { - s->session_state = SESSION_STATE_TRANSPORT_CLOSED; - } + session_set_state (s, SESSION_STATE_TRANSPORT_CLOSED); /* If app also closed, switch to closed */ else if (s->session_state == SESSION_STATE_APP_CLOSED) - s->session_state = SESSION_STATE_CLOSED; + session_set_state (s, SESSION_STATE_CLOSED); app_wrk = app_worker_get_if_valid (s->app_wrk_index); if (app_wrk) @@ -1223,10 +1221,10 @@ session_transport_reset_notify (transport_connection_t * tc) return; if (s->session_state == SESSION_STATE_ACCEPTING) { - s->session_state = SESSION_STATE_TRANSPORT_CLOSING; + session_set_state (s, SESSION_STATE_TRANSPORT_CLOSING); return; } - s->session_state = SESSION_STATE_TRANSPORT_CLOSING; + session_set_state (s, SESSION_STATE_TRANSPORT_CLOSING); app_wrk = app_worker_get (s->app_wrk_index); app_worker_reset_notify (app_wrk, s); } @@ -1243,12 +1241,12 @@ session_stream_accept_notify (transport_connection_t * tc) return -1; if (s->session_state != SESSION_STATE_CREATED) return 0; - s->session_state = SESSION_STATE_ACCEPTING; + session_set_state (s, SESSION_STATE_ACCEPTING); if (app_worker_accept_notify (app_wrk, s)) { /* On transport delete, no notifications should be sent. Unless, the * accept is retried and successful. */ - s->session_state = SESSION_STATE_CREATED; + session_set_state (s, SESSION_STATE_CREATED); return -1; } return 0; @@ -1266,7 +1264,7 @@ session_stream_accept (transport_connection_t * tc, u32 listener_index, s = session_alloc_for_connection (tc); s->listener_handle = ((u64) thread_index << 32) | (u64) listener_index; - s->session_state = SESSION_STATE_CREATED; + session_set_state (s, SESSION_STATE_CREATED); if ((rv = app_worker_init_accepted (s))) { @@ -1310,7 +1308,7 @@ session_dgram_accept (transport_connection_t * tc, u32 listener_index, } session_lookup_add_connection (tc, session_handle (s)); - s->session_state = SESSION_STATE_ACCEPTING; + session_set_state (s, SESSION_STATE_ACCEPTING); app_wrk = app_worker_get (s->app_wrk_index); if ((rv = app_worker_accept_notify (app_wrk, s))) @@ -1348,7 +1346,7 @@ session_open_cl (session_endpoint_cfg_t *rmt, session_handle_t *rsh) app_wrk = app_worker_get (rmt->app_wrk_index); s = session_alloc_for_connection (tc); s->app_wrk_index = app_wrk->wrk_index; - s->session_state = SESSION_STATE_OPENED; + session_set_state (s, SESSION_STATE_OPENED); if (app_worker_init_connected (app_wrk, s)) { session_free (s); @@ -1543,7 +1541,7 @@ session_close (session_t * s) /* App closed so stop propagating dequeue notifications */ svm_fifo_clear_deq_ntf (s->tx_fifo); - s->session_state = SESSION_STATE_CLOSING; + session_set_state (s, SESSION_STATE_CLOSING); session_program_transport_ctrl_evt (s, SESSION_CTRL_EVT_CLOSE); } @@ -1557,7 +1555,7 @@ session_reset (session_t * s) return; /* Drop all outstanding tx data */ svm_fifo_dequeue_drop_all (s->tx_fifo); - s->session_state = SESSION_STATE_CLOSING; + session_set_state (s, SESSION_STATE_CLOSING); session_program_transport_ctrl_evt (s, SESSION_CTRL_EVT_RESET); } @@ -1592,7 +1590,7 @@ session_transport_close (session_t * s) if (s->session_state >= SESSION_STATE_APP_CLOSED) { if (s->session_state == SESSION_STATE_TRANSPORT_CLOSED) - s->session_state = SESSION_STATE_CLOSED; + session_set_state (s, SESSION_STATE_CLOSED); /* If transport is already deleted, just free the session */ else if (s->session_state >= SESSION_STATE_TRANSPORT_DELETED) session_free_w_fifos (s); @@ -1605,7 +1603,7 @@ session_transport_close (session_t * s) * delete notify. This will finally lead to the complete cleanup of the * session. */ - s->session_state = SESSION_STATE_APP_CLOSED; + session_set_state (s, SESSION_STATE_APP_CLOSED); transport_close (session_get_transport_proto (s), s->connection_index, s->thread_index); @@ -1620,13 +1618,13 @@ session_transport_reset (session_t * s) if (s->session_state >= SESSION_STATE_APP_CLOSED) { if (s->session_state == SESSION_STATE_TRANSPORT_CLOSED) - s->session_state = SESSION_STATE_CLOSED; + session_set_state (s, SESSION_STATE_CLOSED); else if (s->session_state >= SESSION_STATE_TRANSPORT_DELETED) session_free_w_fifos (s); return; } - s->session_state = SESSION_STATE_APP_CLOSED; + session_set_state (s, SESSION_STATE_APP_CLOSED); transport_reset (session_get_transport_proto (s), s->connection_index, s->thread_index); } diff --git a/src/vnet/session/session.h b/src/vnet/session/session.h index 4fa9194077e..54740e64cf0 100644 --- a/src/vnet/session/session.h +++ b/src/vnet/session/session.h @@ -527,6 +527,13 @@ int session_tx_fifo_peek_bytes (transport_connection_t * tc, u8 * buffer, u32 offset, u32 max_bytes); u32 session_tx_fifo_dequeue_drop (transport_connection_t * tc, u32 max_bytes); +always_inline void +session_set_state (session_t *s, session_state_t session_state) +{ + s->session_state = session_state; + SESSION_EVT (SESSION_EVT_STATE_CHANGE, s); +} + always_inline u32 transport_max_rx_enqueue (transport_connection_t * tc) { diff --git a/src/vnet/session/session_debug.h b/src/vnet/session/session_debug.h index 588d58c790c..614ffc95a7b 100644 --- a/src/vnet/session/session_debug.h +++ b/src/vnet/session/session_debug.h @@ -28,6 +28,7 @@ _ (DISPATCH_START, CLOCKS_EVT_DBG, 1, "dispatch start") \ _ (DISPATCH_END, CLOCKS_EVT_DBG, 1, "dispatch end") \ _ (DSP_CNTRS, CLOCKS_EVT_DBG, 1, "dispatch counters") \ + _ (STATE_CHANGE, SM, 1, "session state change") \ _ (FREE, SM, 1, "session free") \ _ (IO_EVT_COUNTS, COUNTS_EVT_DBG, 1, "io evt counts") \ _ (COUNTS, COUNTS_EVT_DBG, 1, "ctrl evt counts") @@ -165,6 +166,32 @@ extern session_dbg_main_t session_dbg_main; ed = ELOG_DATA (&vlib_global_main.elog_main, _e) #if SESSION_SM +#define SESSION_EVT_STATE_CHANGE_HANDLER(_s) \ + { \ + ELOG_TYPE_DECLARE (_e) = { \ + .format = "%s: idx %u", \ + .format_args = "t4i4", \ + .n_enum_strings = 12, \ + .enum_strings = { \ + "created", \ + "listening", \ + "connecting", \ + "accepting", \ + "ready", \ + "opened", \ + "transport closing", \ + "closing", \ + "app closed", \ + "transport closed", \ + "closed", \ + "transport deleted", \ + }, \ + }; \ + DEC_SESSION_ETD (_s, _e, 2); \ + ed->data[0] = _s->session_state; \ + ed->data[1] = _s->session_index; \ + } + #define SESSION_EVT_FREE_HANDLER(_s) \ { \ ELOG_TYPE_DECLARE (_e) = { \ @@ -175,6 +202,7 @@ extern session_dbg_main_t session_dbg_main; ed->data[0] = _s->session_index; \ } #else +#define SESSION_EVT_STATE_CHANGE_HANDLER(_s) #define SESSION_EVT_FREE_HANDLER(_s) #endif diff --git a/src/vnet/session/session_node.c b/src/vnet/session/session_node.c index c29e0590aa8..8f6503d2806 100644 --- a/src/vnet/session/session_node.c +++ b/src/vnet/session/session_node.c @@ -486,13 +486,13 @@ session_mq_accepted_reply_handler (session_worker_t *wrk, /* Special handling for cut-through sessions */ if (!session_has_transport (s)) { - s->session_state = SESSION_STATE_READY; + session_set_state (s, SESSION_STATE_READY); ct_session_connect_notify (s, SESSION_E_NONE); return; } old_state = s->session_state; - s->session_state = SESSION_STATE_READY; + session_set_state (s, SESSION_STATE_READY); if (!svm_fifo_is_empty_prod (s->rx_fifo)) app_worker_lock_and_send_event (app_wrk, s, SESSION_IO_EVT_RX); @@ -501,7 +501,7 @@ session_mq_accepted_reply_handler (session_worker_t *wrk, if (old_state >= SESSION_STATE_TRANSPORT_CLOSING) { app_worker_close_notify (app_wrk, s); - s->session_state = old_state; + session_set_state (s, old_state); return; } } -- cgit 1.2.3-korg