From 0314fe1db33e45fa9cfeca914557c6459db474cd Mon Sep 17 00:00:00 2001 From: obdev Date: Tue, 4 Apr 2023 04:11:48 +0000 Subject: [PATCH] sql nio support sql disconnect reason log --- src/observer/mysql/obsm_conn_callback.cpp | 51 +++++++++++++++-------- src/observer/mysql/obsm_handler.cpp | 43 +++++++++++-------- src/sql/session/ob_basic_session_info.h | 4 +- src/sql/session/ob_sql_session_mgr.cpp | 1 + 4 files changed, 62 insertions(+), 37 deletions(-) diff --git a/src/observer/mysql/obsm_conn_callback.cpp b/src/observer/mysql/obsm_conn_callback.cpp index 153800267..11e51944d 100644 --- a/src/observer/mysql/obsm_conn_callback.cpp +++ b/src/observer/mysql/obsm_conn_callback.cpp @@ -145,25 +145,29 @@ static void sm_conn_unlock_tenant(ObSMConnection& conn) } } -static void sm_conn_log_close(ObSMConnection& conn, int ret) -{ - LOG_INFO("connection close", - "sessid", conn.sessid_, - "proxy_sessid", conn.proxy_sessid_, - "tenant_id", conn.tenant_id_, - "server_id", GCTX.server_id_, - "from_proxy", conn.is_proxy_, - "from_java_client", conn.is_java_client_, - "c/s protocol", get_cs_protocol_type_name(conn.get_cs_protocol_type()), - "is_need_clear_sessid_", conn.is_need_clear_sessid_, - K(ret)); -} - void ObSMConnectionCallback::destroy(ObSMConnection& conn) { int ret = OB_SUCCESS; bool is_need_clear = false; + sql::ObDisconnectState disconnect_state; + ObCurTraceId::TraceId trace_id; if (conn.is_sess_alloc_ && !conn.is_sess_free_) { + { + int tmp_ret = OB_SUCCESS; + sql::ObSQLSessionInfo *sess_info = NULL; + sql::ObSessionGetterGuard guard(*GCTX.session_mgr_, conn.sessid_); + if (OB_UNLIKELY(OB_SUCCESS != (tmp_ret = guard.get_session(sess_info)))) { + LOG_WARN_RET(tmp_ret, "fail to get session", K(tmp_ret), K(conn.sessid_), + "proxy_sessid", conn.proxy_sessid_); + } else if (OB_ISNULL(sess_info)) { + tmp_ret = OB_ERR_UNEXPECTED; + LOG_WARN_RET(tmp_ret, "session info is NULL", K(tmp_ret), K(conn.sessid_), + "proxy_sessid", conn.proxy_sessid_); + } else { + disconnect_state = sess_info->get_disconnect_state(); + trace_id = sess_info->get_current_trace_id(); + } + } sql::ObFreeSessionCtx ctx; ctx.tenant_id_ = conn.tenant_id_; ctx.sessid_ = conn.sessid_; @@ -201,15 +205,28 @@ void ObSMConnectionCallback::destroy(ObSMConnection& conn) } else if (is_need_clear) { GCTX.session_mgr_->mark_sessid_unused(conn.sessid_); } + sm_conn_unlock_tenant(conn); - sm_conn_log_close(conn, ret); + share::ObTaskController::get().allow_next_syslog(); + LOG_INFO("connection close", + "sessid", conn.sessid_, + "proxy_sessid", conn.proxy_sessid_, + "tenant_id", conn.tenant_id_, + "server_id", GCTX.server_id_, + "from_proxy", conn.is_proxy_, + "from_java_client", conn.is_java_client_, + "c/s protocol", get_cs_protocol_type_name(conn.get_cs_protocol_type()), + "is_need_clear_sessid_", conn.is_need_clear_sessid_, + K(ret), + K(trace_id), + K(conn.pkt_rec_wrapper_), + K(disconnect_state)); conn.~ObSMConnection(); } int ObSMConnectionCallback::on_disconnect(observer::ObSMConnection& conn) { int ret = OB_SUCCESS; - if (conn.is_sess_alloc_ && !conn.is_sess_free_ && ObSMConnection::INITIAL_SESSID != conn.sessid_) { @@ -228,7 +245,7 @@ int ObSMConnectionCallback::on_disconnect(observer::ObSMConnection& conn) } } LOG_INFO("kill and revert session", K(conn.sessid_), - "proxy_sessid", conn.proxy_sessid_, "server_id", GCTX.server_id_, K(ret)); + "proxy_sessid", conn.proxy_sessid_, "server_id", GCTX.server_id_, K(ret)); return ret; } diff --git a/src/observer/mysql/obsm_handler.cpp b/src/observer/mysql/obsm_handler.cpp index 01d1d008f..932188108 100644 --- a/src/observer/mysql/obsm_handler.cpp +++ b/src/observer/mysql/obsm_handler.cpp @@ -148,10 +148,6 @@ int ObSMHandler::on_disconnect(easy_connection_t *c) eret = EASY_ERROR; LOG_ERROR_RET(OB_ERR_UNEXPECTED, "conn is null", K(eret)); } else { - // get reason for disconnect. - sql::ObDisconnectState dis_state; - // get trace_id for disconnect. - ObCurTraceId::TraceId trace_id; //set session shadow if (conn->is_sess_alloc_ && !conn->is_sess_free_ @@ -166,23 +162,13 @@ int ObSMHandler::on_disconnect(easy_connection_t *c) LOG_WARN_RET(tmp_ret, "session info is NULL", K(tmp_ret), K(conn->sessid_), "proxy_sessid", conn->proxy_sessid_); } else { - // tcp disconnect - if (EASY_CONN_CLOSE_BY_PEER == c->status) { - if(sql::DIS_INIT == sess_info->get_disconnect_state()) { - sess_info->set_disconnect_state(sql::CLIENT_FORCE_DISCONNECT); - } - } sess_info->set_session_state(sql::SESSION_KILLED); sess_info->set_shadow(true); - dis_state = sess_info->get_disconnect_state(); - trace_id = sess_info->get_current_trace_id(); } } - share::ObTaskController::get().allow_next_syslog(); LOG_INFO("kill and revert session", K(conn->sessid_), - "proxy_sessid", conn->proxy_sessid_, "server_id", GCTX.server_id_, - K(tmp_ret), K(eret), K(dis_state), K(trace_id), - K(conn->get_cs_protocol_type()), K(conn->pkt_rec_wrapper_)); + "proxy_sessid", conn->proxy_sessid_, "server_id", GCTX.server_id_, + K(tmp_ret), K(eret)); } return eret; } @@ -193,6 +179,8 @@ int ObSMHandler::on_close(easy_connection_t *c) int ret = OB_SUCCESS; bool is_need_clear = false; ObSMConnection *conn = NULL; + sql::ObDisconnectState disconnect_state; + ObCurTraceId::TraceId trace_id; if (OB_ISNULL(c) || OB_ISNULL(gctx_.session_mgr_)) { ret = OB_ERR_UNEXPECTED; LOG_ERROR("easy_connection_t or session_mgr is null", @@ -205,6 +193,22 @@ int ObSMHandler::on_close(easy_connection_t *c) } else { //free session if (conn->is_sess_alloc_ && !conn->is_sess_free_) { + { + int tmp_ret = OB_SUCCESS; + sql::ObSQLSessionInfo *sess_info = NULL; + sql::ObSessionGetterGuard guard(*gctx_.session_mgr_, conn->sessid_); + if (OB_UNLIKELY(OB_SUCCESS != (tmp_ret = guard.get_session(sess_info)))) { + LOG_WARN_RET(tmp_ret, "fail to get session", K(tmp_ret), K(conn->sessid_), + "proxy_sessid", conn->proxy_sessid_); + } else if (OB_ISNULL(sess_info)) { + tmp_ret = OB_ERR_UNEXPECTED; + LOG_WARN_RET(tmp_ret, "session info is NULL", K(tmp_ret), K(conn->sessid_), + "proxy_sessid", conn->proxy_sessid_); + } else { + disconnect_state = sess_info->get_disconnect_state(); + trace_id = sess_info->get_current_trace_id(); + } + } sql::ObFreeSessionCtx ctx; ctx.tenant_id_ = conn->tenant_id_; ctx.sessid_ = conn->sessid_; @@ -258,7 +262,7 @@ int ObSMHandler::on_close(easy_connection_t *c) LOG_INFO("unlock session of tenant", K(conn->sessid_), "proxy_sessid", conn->proxy_sessid_, K(conn->tenant_id_)); } - + share::ObTaskController::get().allow_next_syslog(); LOG_INFO("connection close", K(easy_connection_str(c)), "sessid", conn->sessid_, @@ -269,7 +273,10 @@ int ObSMHandler::on_close(easy_connection_t *c) "from_java_client", conn->is_java_client_, "c/s protocol", get_cs_protocol_type_name(conn->get_cs_protocol_type()), "is_need_clear_sessid_", conn->is_need_clear_sessid_, - K(ret)); + K(ret), + K(trace_id), + K(conn->pkt_rec_wrapper_), + K(disconnect_state)); conn->~ObSMConnection(); conn = nullptr; } diff --git a/src/sql/session/ob_basic_session_info.h b/src/sql/session/ob_basic_session_info.h index b8de34ee8..4c6830177 100644 --- a/src/sql/session/ob_basic_session_info.h +++ b/src/sql/session/ob_basic_session_info.h @@ -1354,7 +1354,7 @@ protected: cur_query_len_(0), cur_statement_id_(0), last_active_time_(0), - dis_state_(DIS_INIT), + dis_state_(CLIENT_FORCE_DISCONNECT), state_(SESSION_SLEEP), is_interactive_(false), sock_desc_(), @@ -1389,7 +1389,7 @@ protected: cur_query_len_ = 0; cur_statement_id_ = 0; last_active_time_ = 0; - dis_state_ = DIS_INIT; + dis_state_ = CLIENT_FORCE_DISCONNECT; state_ = SESSION_SLEEP; is_interactive_ = false; sock_desc_.clear_sql_session_info(); diff --git a/src/sql/session/ob_sql_session_mgr.cpp b/src/sql/session/ob_sql_session_mgr.cpp index d254fd054..4fa29c806 100644 --- a/src/sql/session/ob_sql_session_mgr.cpp +++ b/src/sql/session/ob_sql_session_mgr.cpp @@ -577,6 +577,7 @@ int ObSQLSessionMgr::kill_session(ObSQLSessionInfo &session) } session.update_last_active_time(); + session.set_disconnect_state(NORMAL_KILL_SESSION); rpc::ObSqlSockDesc &sock_desc = session.get_sock_desc(); if (OB_LIKELY(NULL != sock_desc.sock_desc_)) { SQL_REQ_OP.disconnect_by_sql_sock_desc(sock_desc);