From b912aed9088f13562df7a6526e21f3e884a9d489 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 22 Jan 2024 10:24:35 +0000 Subject: [PATCH 1/9] POC for a new profiler --- include/ProxySQL_Profiler.hpp | 43 +++++++ include/cpp.h | 1 + include/proxysql_admin.h | 2 + include/proxysql_structs.h | 6 + lib/Makefile | 3 +- lib/MySQL_HostGroups_Manager.cpp | 6 + lib/MySQL_Session.cpp | 20 +++ lib/MySQL_Thread.cpp | 6 + lib/ProxySQL_Admin.cpp | 71 ++++++++++ lib/ProxySQL_Profiler.cpp | 214 +++++++++++++++++++++++++++++++ lib/Query_Processor.cpp | 1 + lib/c_tokenizer.cpp | 2 + lib/mysql_connection.cpp | 9 ++ lib/mysql_data_stream.cpp | 5 + src/proxysql_global.cpp | 1 + 15 files changed, 389 insertions(+), 1 deletion(-) create mode 100644 include/ProxySQL_Profiler.hpp create mode 100644 lib/ProxySQL_Profiler.cpp diff --git a/include/ProxySQL_Profiler.hpp b/include/ProxySQL_Profiler.hpp new file mode 100644 index 0000000000..9339b3d399 --- /dev/null +++ b/include/ProxySQL_Profiler.hpp @@ -0,0 +1,43 @@ +#ifndef PROXYSQL_PROFILER +#define PROXYSQL_PROFILER + +#include +#include +#include + + + +// _BLOK0 passes 0 as first argument. This means that the object WON'T measure time BUT it will generate a path +#define PROFILER1_BLOCK0(a) Profiler1 a(0,__FILE__,__LINE__,__func__) +// when _2 suffix is added, a user defined C string can be passed as argument instead of function name +#define PROFILER1_BLOCK0_2(a,b) Profiler1 a(0,__FILE__,__LINE__,b) +// _BLOK0 passes 0 as first argument. This means that the object WILL measure time AND it will generate a path +#define PROFILER1_BLOCK1(a) Profiler1 a(1,__FILE__,__LINE__,__func__) +// when _2 suffix is added, a user defined C string can be passed as argument instead of function name +#define PROFILER1_BLOCK1_2(a,b) Profiler1 a(1,__FILE__,__LINE__,b) + +class CounterProfiling1 { + public: + unsigned long long cnt = 0; + unsigned long long tottime = 0; + CounterProfiling1(unsigned long long t) { + tottime = t; + cnt = 1; + } + void add(unsigned long long t) { + tottime += t; + cnt++; + } +}; + +class Profiler1 { + private: + int log = 0; + timespec begint; + timespec endt; + std::string prev_bt = ""; + public: + Profiler1(int l, const char *__file, int __line, const char *__func); + ~Profiler1(); +}; +#endif // PROXYSQL_PROFILER diff --git a/include/cpp.h b/include/cpp.h index cb4c1dd8cd..d2cefffd6b 100644 --- a/include/cpp.h +++ b/include/cpp.h @@ -35,3 +35,4 @@ #include #include #include +#include "ProxySQL_Profiler.hpp" diff --git a/include/proxysql_admin.h b/include/proxysql_admin.h index d1a2741863..f309ec4de0 100644 --- a/include/proxysql_admin.h +++ b/include/proxysql_admin.h @@ -547,6 +547,8 @@ class ProxySQL_Admin { void stats___mysql_gtid_executed(); void stats___mysql_client_host_cache(bool reset); + void stats___profiling1(bool reset); + // Update prometheus metrics void p_stats___memory_metrics(); void p_update_stmt_metrics(); diff --git a/include/proxysql_structs.h b/include/proxysql_structs.h index 67205cbb09..335dfef2dc 100644 --- a/include/proxysql_structs.h +++ b/include/proxysql_structs.h @@ -544,6 +544,7 @@ class ProxySQL_Node_Address; #define PROXYSQL_STRUCTS #define QUERY_DIGEST_BUF 128 + struct __SQP_query_parser_t { char buf[QUERY_DIGEST_BUF]; uint64_t digest; @@ -766,6 +767,10 @@ EXTERN global_variables glovars; //#endif #ifdef PROXYSQL_EXTERN +#ifndef GLOBAL_PROXYSQL_PROFILING +#define GLOBAL_PROXYSQL_PROFILING +thread_local std::string thread_bt = ""; +#endif // GLOBAL_PROXYSQL_PROFILING #ifndef GLOBAL_DEFINED_OPTS_ENTRIES #define GLOBAL_DEFINED_OPTS_ENTRIES ProxySQL_GlobalVariables GloVars {}; @@ -940,6 +945,7 @@ __thread unsigned int g_seed; #endif /* GLOBAL_DEFINED_HOSTGROUP */ #else +extern thread_local std::string thread_bt; extern ProxySQL_GlobalVariables GloVars; extern MySQL_HostGroups_Manager *MyHGM; extern __thread char *mysql_thread___default_schema; diff --git a/lib/Makefile b/lib/Makefile index 032dea04b1..b38171aee6 100644 --- a/lib/Makefile +++ b/lib/Makefile @@ -122,7 +122,8 @@ default: libproxysql.a .PHONY: default _OBJ_CXX := ProxySQL_GloVars.oo network.oo debug.oo configfile.oo Query_Cache.oo SpookyV2.oo MySQL_Authentication.oo gen_utils.oo sqlite3db.oo mysql_connection.oo MySQL_HostGroups_Manager.oo mysql_data_stream.oo MySQL_Thread.oo MySQL_Session.oo MySQL_Protocol.oo mysql_backend.oo Query_Processor.oo ProxySQL_Admin.oo ProxySQL_Config.oo ProxySQL_Restapi.oo MySQL_Monitor.oo MySQL_Logger.oo thread.oo MySQL_PreparedStatement.oo ProxySQL_Cluster.oo ClickHouse_Authentication.oo ClickHouse_Server.oo ProxySQL_Statistics.oo Chart_bundle_js.oo ProxySQL_HTTP_Server.oo ProxySQL_RESTAPI_Server.oo font-awesome.min.css.oo main-bundle.min.css.oo set_parser.oo MySQL_Variables.oo c_tokenizer.oo proxysql_utils.oo proxysql_coredump.oo proxysql_sslkeylog.oo \ - proxysql_find_charset.oo ProxySQL_Poll.oo + proxysql_find_charset.oo ProxySQL_Poll.oo \ + ProxySQL_Profiler.oo OBJ_CXX := $(patsubst %,$(ODIR)/%,$(_OBJ_CXX)) HEADERS := ../include/*.h ../include/*.hpp diff --git a/lib/MySQL_HostGroups_Manager.cpp b/lib/MySQL_HostGroups_Manager.cpp index e957e0f1dd..90cf1d26a5 100644 --- a/lib/MySQL_HostGroups_Manager.cpp +++ b/lib/MySQL_HostGroups_Manager.cpp @@ -2904,6 +2904,7 @@ void MySQL_HostGroups_Manager::push_MyConn_to_pool_array(MySQL_Connection **ca, } MySrvC *MyHGC::get_random_MySrvC(char * gtid_uuid, uint64_t gtid_trxid, int max_lag_ms, MySQL_Session *sess) { + PROFILER1_BLOCK1(a); MySrvC *mysrvc=NULL; unsigned int j; unsigned int sum=0; @@ -3248,6 +3249,7 @@ MySrvC *MyHGC::get_random_MySrvC(char * gtid_uuid, uint64_t gtid_trxid, int max_ //MySrvC * MySrvList::idx(unsigned int i) { return (MySrvC *)servers->index(i); } void MySrvConnList::get_random_MyConn_inner_search(unsigned int start, unsigned int end, unsigned int& conn_found_idx, unsigned int& connection_quality_level, unsigned int& number_of_matching_session_variables, const MySQL_Connection * client_conn) { + PROFILER1_BLOCK1(a); char *schema = client_conn->userinfo->schemaname; MySQL_Connection * conn=NULL; unsigned int k; @@ -3313,6 +3315,7 @@ void MySrvConnList::get_random_MyConn_inner_search(unsigned int start, unsigned MySQL_Connection * MySrvConnList::get_random_MyConn(MySQL_Session *sess, bool ff) { + PROFILER1_BLOCK1(a); MySQL_Connection * conn=NULL; unsigned int i; unsigned int conn_found_idx; @@ -3508,6 +3511,7 @@ void MySQL_HostGroups_Manager::unshun_server_all_hostgroups(const char * address } MySQL_Connection * MySQL_HostGroups_Manager::get_MyConn_from_pool(unsigned int _hid, MySQL_Session *sess, bool ff, char * gtid_uuid, uint64_t gtid_trxid, int max_lag_ms) { + PROFILER1_BLOCK1(a); MySQL_Connection * conn=NULL; wrlock(); status.myconnpoll_get++; @@ -3531,6 +3535,7 @@ MySQL_Connection * MySQL_HostGroups_Manager::get_MyConn_from_pool(unsigned int _ } void MySQL_HostGroups_Manager::destroy_MyConn_from_pool(MySQL_Connection *c, bool _lock) { + PROFILER1_BLOCK1(a); bool to_del=true; // the default, legacy behavior MySrvC *mysrvc=(MySrvC *)c->parent; if (mysrvc->status==MYSQL_SERVER_STATUS_ONLINE && c->send_quit && queue.size() < __sync_fetch_and_add(&GloMTH->variables.connpoll_reset_queue_length,0)) { @@ -3941,6 +3946,7 @@ void MySQL_HostGroups_Manager::drop_all_idle_connections() { * dropped as well */ int MySQL_HostGroups_Manager::get_multiple_idle_connections(int _hid, unsigned long long _max_last_time_used, MySQL_Connection **conn_list, int num_conn) { + PROFILER1_BLOCK1(a); wrlock(); drop_all_idle_connections(); int num_conn_current=0; diff --git a/lib/MySQL_Session.cpp b/lib/MySQL_Session.cpp index c6097ebca4..f89cbd6e12 100644 --- a/lib/MySQL_Session.cpp +++ b/lib/MySQL_Session.cpp @@ -1304,6 +1304,7 @@ void MySQL_Session::generate_proxysql_internal_session_json(json &j) { } void MySQL_Session::return_proxysql_internal(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); unsigned int l = 0; l = strlen((char *)"PROXYSQL INTERNAL SESSION"); if (pkt->size==(5+l) && strncasecmp((char *)"PROXYSQL INTERNAL SESSION", (char *)pkt->ptr+5, l)==0) { @@ -1399,6 +1400,7 @@ bool MySQL_Session::handler_special_queries_STATUS(PtrSize_t *pkt) { } bool MySQL_Session::handler_special_queries(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); bool deprecate_eof_active = client_myds->myconn->options.client_flag & CLIENT_DEPRECATE_EOF; if ( @@ -2967,6 +2969,7 @@ bool MySQL_Session::handler_again___status_CHANGING_SCHEMA(int *_rc) { bool MySQL_Session::handler_again___status_CONNECTING_SERVER(int *_rc) { + PROFILER1_BLOCK1(a); //fprintf(stderr,"CONNECTING_SERVER\n"); unsigned long long curtime=monotonic_time(); thread->atomic_curtime=curtime; @@ -3832,6 +3835,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___default() { } int MySQL_Session::get_pkts_from_client(bool& wrong_pass, PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); int handler_ret = 0; unsigned char c; @@ -3974,6 +3978,7 @@ int MySQL_Session::get_pkts_from_client(bool& wrong_pass, PtrSize_t& pkt) { case _MYSQL_COM_QUERY: __sync_add_and_fetch(&thread->status_variables.stvar[st_var_queries],1); if (session_type == PROXYSQL_SESSION_MYSQL) { + PROFILER1_BLOCK1(a); bool rc_break=false; bool lock_hostgroup = false; if (session_fast_forward==false) { @@ -4763,6 +4768,7 @@ void MySQL_Session::handler_minus1_HandleBackendConnection(MySQL_Data_Stream *my // this function was inline int MySQL_Session::RunQuery(MySQL_Data_Stream *myds, MySQL_Connection *myconn) { + PROFILER1_BLOCK1(a); PROXY_TRACE2(); int rc = 0; switch (status) { @@ -4814,6 +4820,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA() { } void MySQL_Session::housekeeping_before_pkts() { + PROFILER1_BLOCK1(a); if (mysql_thread___multiplexing) { for (const int hg_id : hgs_expired_conns) { MySQL_Backend* mybe = find_backend(hg_id); @@ -4842,6 +4849,7 @@ void MySQL_Session::housekeeping_before_pkts() { // this function was inline void MySQL_Session::handler_rc0_Process_GTID(MySQL_Connection *myconn) { + PROFILER1_BLOCK1(a); if (myconn->get_gtid(mybe->gtid_uuid,&mybe->gtid_trxid)) { if (mysql_thread___client_session_track_gtid) { gtid_hid = current_hostgroup; @@ -4851,6 +4859,7 @@ void MySQL_Session::handler_rc0_Process_GTID(MySQL_Connection *myconn) { } int MySQL_Session::handler() { + PROFILER1_BLOCK1(a); int handler_ret = 0; bool prepared_stmt_with_no_params = false; bool wrong_pass=false; @@ -5038,6 +5047,7 @@ int MySQL_Session::handler() { goto handler_again; } + PROFILER1_BLOCK1(a); for (auto i = 0; i < SQL_NAME_LAST_LOW_WM; i++) { auto client_hash = client_myds->myconn->var_hash[i]; #ifdef DEBUG @@ -5064,6 +5074,7 @@ int MySQL_Session::handler() { } } } + PROFILER1_BLOCK1(b); MySQL_Connection *c_con = client_myds->myconn; vector::const_iterator it_c = c_con->dynamic_variables_idx.begin(); // client connection iterator for ( ; it_c != c_con->dynamic_variables_idx.end() ; it_c++) { @@ -6082,6 +6093,7 @@ int MySQL_Session::handler_WCD_SS_MCQ_qpo_Parse_SQL_LOG_BIN(PtrSize_t *pkt, bool */ bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY_qpo(PtrSize_t *pkt, bool *lock_hostgroup, ps_type prepare_stmt_type) { + PROFILER1_BLOCK1(a); /* lock_hostgroup: If this variable is set to true, this session will get lock to a @@ -7228,6 +7240,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } void MySQL_Session::handler___client_DSS_QUERY_SENT___server_DSS_NOT_INITIALIZED__get_connection() { + PROFILER1_BLOCK1(a); // Get a MySQL Connection MySQL_Connection *mc=NULL; @@ -7401,6 +7414,7 @@ void MySQL_Session::handler___client_DSS_QUERY_SENT___server_DSS_NOT_INITIALIZED } void MySQL_Session::MySQL_Stmt_Result_to_MySQL_wire(MYSQL_STMT *stmt, MySQL_Connection *myconn) { + PROFILER1_BLOCK1(a); MySQL_ResultSet *MyRS = NULL; if (myconn) { if (myconn->MyRS) { @@ -7449,6 +7463,7 @@ void MySQL_Session::MySQL_Stmt_Result_to_MySQL_wire(MYSQL_STMT *stmt, MySQL_Conn } void MySQL_Session::MySQL_Result_to_MySQL_wire(MYSQL *mysql, MySQL_ResultSet *MyRS, unsigned int warning_count, MySQL_Data_Stream *_myds) { + PROFILER1_BLOCK1(a); if (mysql == NULL) { // error client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1, 2013, (char *)"HY000" ,(char *)"Lost connection to MySQL server during query"); @@ -7628,6 +7643,7 @@ void MySQL_Session::set_unhealthy() { unsigned int MySQL_Session::NumActiveTransactions(bool check_savepoint) { + PROFILER1_BLOCK1(a); unsigned int ret=0; if (mybes==0) return ret; MySQL_Backend *_mybe; @@ -7718,6 +7734,7 @@ int MySQL_Session::FindOneActiveTransaction(bool check_savepoint) { } unsigned long long MySQL_Session::IdleTime() { + PROFILER1_BLOCK1(a); unsigned long long ret = 0; if (client_myds==0) return 0; if (status!=WAITING_CLIENT_DATA && status!=CONNECTING_CLIENT) return 0; @@ -7736,6 +7753,7 @@ unsigned long long MySQL_Session::IdleTime() { // this is called either from RequestEnd(), or at the end of executing // prepared statements void MySQL_Session::LogQuery(MySQL_Data_Stream *myds) { + PROFILER1_BLOCK1(a); // we need to access statistics before calling CurrentQuery.end() // so we track the time here CurrentQuery.end_time=thread->curtime; @@ -7753,6 +7771,7 @@ void MySQL_Session::LogQuery(MySQL_Data_Stream *myds) { } } void MySQL_Session::RequestEnd(MySQL_Data_Stream *myds) { + PROFILER1_BLOCK1(a); // check if multiplexing needs to be disabled char *qdt = NULL; @@ -8002,6 +8021,7 @@ void MySQL_Session::add_ldap_comment_to_pkt(PtrSize_t *_pkt) { } void MySQL_Session::finishQuery(MySQL_Data_Stream *myds, MySQL_Connection *myconn, bool prepared_stmt_with_no_params) { + PROFILER1_BLOCK1(a); myds->myconn->reduce_auto_increment_delay_token(); if (locked_on_hostgroup >= 0) { if (qpo->multiplex == -1) { diff --git a/lib/MySQL_Thread.cpp b/lib/MySQL_Thread.cpp index 47d3169d0b..bcbd9daa06 100644 --- a/lib/MySQL_Thread.cpp +++ b/lib/MySQL_Thread.cpp @@ -2908,6 +2908,7 @@ void MySQL_Thread::run___get_multiple_idle_connections(int& num_idles) { // this function was inline in MySQL_Thread::run() void MySQL_Thread::ProcessAllMyDS_BeforePoll() { + PROFILER1_BLOCK1(a); bool check_if_move_to_idle_thread = false; #ifdef IDLE_THREADS if (GloVars.global.idle_threads) { @@ -2955,6 +2956,7 @@ void MySQL_Thread::ProcessAllMyDS_BeforePoll() { // this function was inline in MySQL_Thread::run() void MySQL_Thread::ProcessAllMyDS_AfterPoll() { + PROFILER1_BLOCK1(a); for (unsigned int n = 0; n < mypolls.len; n++) { proxy_debug(PROXY_DEBUG_NET,3, "poll for fd %d events %d revents %d\n", mypolls.fds[n].fd , mypolls.fds[n].events, mypolls.fds[n].revents); @@ -3004,6 +3006,7 @@ void MySQL_Thread::run___cleanup_mirror_queue() { // main loop void MySQL_Thread::run() { + PROFILER1_BLOCK1(a); unsigned int n; int rc; @@ -3425,6 +3428,7 @@ void MySQL_Thread::worker_thread_gets_sessions_from_idle_thread() { bool MySQL_Thread::process_data_on_data_stream(MySQL_Data_Stream *myds, unsigned int n) { + PROFILER1_BLOCK1(a); if (mypolls.fds[n].revents) { #ifdef IDLE_THREADS if (myds->myds_type==MYDS_FRONTEND) { @@ -3713,6 +3717,7 @@ void MySQL_Thread::ProcessAllSessions_MaintenanceLoop(MySQL_Session *sess, unsig } void MySQL_Thread::process_all_sessions() { + PROFILER1_BLOCK1(a); unsigned int n; unsigned int total_active_transactions_=0; #ifdef IDLE_THREADS @@ -3798,6 +3803,7 @@ void MySQL_Thread::process_all_sessions() { delete sess; } else { if (sess->to_process==1) { + PROFILER1_BLOCK1(a); if (sess->pause_until <= curtime) { rc=sess->handler(); //total_active_transactions_+=sess->active_transactions; diff --git a/lib/ProxySQL_Admin.cpp b/lib/ProxySQL_Admin.cpp index f3d521776a..3ee10f6380 100644 --- a/lib/ProxySQL_Admin.cpp +++ b/lib/ProxySQL_Admin.cpp @@ -105,6 +105,8 @@ char * proxysql_version = NULL; #include "proxysql_find_charset.h" +std::mutex GlobalProfiling1_mutex; +std::unordered_map GlobalProfiling1 = {}; static const vector mysql_servers_tablenames = { "mysql_servers", @@ -360,6 +362,9 @@ extern char * binary_sha1; extern int ProxySQL_create_or_load_TLS(bool bootstrap, std::string& msg); + +extern void GenerateMermaid1(string& output); + #define PANIC(msg) { perror(msg); exit(EXIT_FAILURE); } pthread_mutex_t sock_mutex = PTHREAD_MUTEX_INITIALIZER; @@ -550,6 +555,9 @@ MHD_Result http_handler(void *cls, struct MHD_Connection *connection, const char #define STATS_SQLITE_TABLE_MYSQL_GTID_EXECUTED "CREATE TABLE stats_mysql_gtid_executed (hostname VARCHAR NOT NULL , port INT NOT NULL DEFAULT 3306 , gtid_executed VARCHAR , events INT NOT NULL)" +#define STATS_SQLITE_TABLE_PROFILING1 "CREATE TABLE stats_profiling1 (path VARCHAR NOT NULL , count INT NOT NULL , total_time INT NOT NULL)" +#define STATS_SQLITE_TABLE_PROFILING1_RESET "CREATE TABLE stats_profiling1_reset (path VARCHAR NOT NULL , count INT NOT NULL , total_time INT NOT NULL)" + #define STATS_SQLITE_TABLE_MYSQL_ERRORS "CREATE TABLE stats_mysql_errors (hostgroup INT NOT NULL , hostname VARCHAR NOT NULL , port INT NOT NULL , username VARCHAR NOT NULL , client_address VARCHAR NOT NULL , schemaname VARCHAR NOT NULL , errno INT NOT NULL , count_star INTEGER NOT NULL , first_seen INTEGER NOT NULL , last_seen INTEGER NOT NULL , last_error VARCHAR NOT NULL DEFAULT '' , PRIMARY KEY (hostgroup, hostname, port, username, schemaname, errno) )" #define STATS_SQLITE_TABLE_MYSQL_ERRORS_RESET "CREATE TABLE stats_mysql_errors_reset (hostgroup INT NOT NULL , hostname VARCHAR NOT NULL , port INT NOT NULL , username VARCHAR NOT NULL , client_address VARCHAR NOT NULL , schemaname VARCHAR NOT NULL , errno INT NOT NULL , count_star INTEGER NOT NULL , first_seen INTEGER NOT NULL , last_seen INTEGER NOT NULL , last_error VARCHAR NOT NULL DEFAULT '' , PRIMARY KEY (hostgroup, hostname, port, username, schemaname, errno) )" @@ -3226,6 +3234,10 @@ bool ProxySQL_Admin::GenericRefreshStatistics(const char *query_no_space, unsign //bool stats_proxysql_servers_status = false; // temporary disabled because not implemented + + bool stats_profiling1 = false; + bool stats_profiling1_reset = false; + if (strcasestr(query_no_space,"processlist")) // This will match the following usecases: // SHOW PROCESSLIST @@ -3265,6 +3277,13 @@ bool ProxySQL_Admin::GenericRefreshStatistics(const char *query_no_space, unsign { stats_mysql_global=true; refresh=true; } if (strstr(query_no_space,"stats_memory_metrics")) { stats_memory_metrics=true; refresh=true; } + if (strstr(query_no_space,"stats_profiling1")) { + stats_profiling1 = true; + if (strstr(query_no_space,"stats_profiling1_reset")) { + stats_profiling1_reset = true; + } + refresh = true; + } if (strstr(query_no_space,"stats_mysql_connection_pool_reset")) { stats_mysql_connection_pool_reset=true; refresh=true; @@ -3385,6 +3404,13 @@ bool ProxySQL_Admin::GenericRefreshStatistics(const char *query_no_space, unsign if (refresh==true) { //pthread_mutex_lock(&admin_mutex); //ProxySQL_Admin *SPA=(ProxySQL_Admin *)pa; + if (stats_profiling1_reset) { + stats___profiling1(true); + } else { + if (stats_profiling1) { + stats___profiling1(false); + } + } if (stats_mysql_processlist) stats___mysql_processlist(); if (stats_mysql_query_digest_reset) { @@ -5124,6 +5150,22 @@ void admin_session_handler(MySQL_Session *sess, void *_pa, PtrSize_t *pkt) { goto __end_show_commands; // in the next block there are only SHOW commands } + if (!strncasecmp("SHOW PROFILER MERMAID", query_no_space, strlen("SHOW PROFILIER MERMAID"))) { + char* pta[1]; + pta[0] = NULL; + SQLite3_result* resultset = new SQLite3_result(1); + resultset->add_column_definition(SQLITE_TEXT,"Data"); + string output = ""; + GenerateMermaid1(output); + pta[0] = (char *)output.c_str(); + resultset->add_row(pta); + sess->SQLite3_to_MySQL(resultset, error, affected_rows, &sess->client_myds->myprot); + delete resultset; + run_query = false; + + goto __run_query; + } + if (!strncasecmp("SHOW PROMETHEUS METRICS", query_no_space, strlen("SHOW PROMETHEUS METRICS"))) { char* pta[1]; pta[0] = NULL; @@ -5501,6 +5543,7 @@ void ProxySQL_Admin::vacuum_stats(bool is_admin) { void *child_mysql(void *arg) { + PROFILER1_BLOCK1(a); if (GloMTH == nullptr) { return NULL; } pthread_attr_t thread_attr; @@ -6534,6 +6577,8 @@ bool ProxySQL_Admin::init(const bootstrap_info_t& bootstrap_info) { insert_into_tables_defs(tables_defs_stats,"stats_mysql_errors_reset", STATS_SQLITE_TABLE_MYSQL_ERRORS_RESET); insert_into_tables_defs(tables_defs_stats,"stats_mysql_global", STATS_SQLITE_TABLE_MYSQL_GLOBAL); insert_into_tables_defs(tables_defs_stats,"stats_mysql_gtid_executed", STATS_SQLITE_TABLE_MYSQL_GTID_EXECUTED); + insert_into_tables_defs(tables_defs_stats,"stats_profiling1", STATS_SQLITE_TABLE_PROFILING1); + insert_into_tables_defs(tables_defs_stats,"stats_profiling1_reset", STATS_SQLITE_TABLE_PROFILING1_RESET); insert_into_tables_defs(tables_defs_stats,"stats_memory_metrics", STATS_SQLITE_TABLE_MEMORY_METRICS); insert_into_tables_defs(tables_defs_stats,"stats_mysql_users", STATS_SQLITE_TABLE_MYSQL_USERS); insert_into_tables_defs(tables_defs_stats,"global_variables", ADMIN_SQLITE_TABLE_GLOBAL_VARIABLES); // workaround for issue #708 @@ -12521,6 +12566,32 @@ void ProxySQL_Admin::stats___mysql_users() { free(ads); } + +void ProxySQL_Admin::stats___profiling1(bool reset) { + int rc; + sqlite3_stmt *statement1=NULL; + char *query1=NULL; + query1=(char *)"INSERT INTO stats_profiling1 VALUES (?1, ?2, ?3)"; + rc = statsdb->prepare_v2(query1, &statement1); + ASSERT_SQLITE_OK(rc, statsdb); + statsdb->execute("DELETE FROM stats_profiling1"); + statsdb->execute("DELETE FROM stats_profiling1_reset"); + const std::lock_guard lock(GlobalProfiling1_mutex); + for (auto it = GlobalProfiling1.begin() ; it != GlobalProfiling1.end() ; it++) { + CounterProfiling1& c = it->second; + rc=(*proxy_sqlite3_bind_text)(statement1, 1, it->first.c_str(), -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, statsdb); + rc=(*proxy_sqlite3_bind_int64)(statement1, 2, c.cnt); ASSERT_SQLITE_OK(rc, statsdb); + rc=(*proxy_sqlite3_bind_int64)(statement1, 3, c.tottime); ASSERT_SQLITE_OK(rc, statsdb); + SAFE_SQLITE3_STEP(statement1); + rc=(*proxy_sqlite3_clear_bindings)(statement1); ASSERT_SQLITE_OK(rc, statsdb); + rc=(*proxy_sqlite3_reset)(statement1); ASSERT_SQLITE_OK(rc, statsdb); + } + if (reset == true) { + statsdb->execute("INSERT INTO stats_profiling1_reset SELECT * FROM stats_profiling1"); + GlobalProfiling1.clear(); + } +} + void ProxySQL_Admin::stats___mysql_gtid_executed() { statsdb->execute("DELETE FROM stats_mysql_gtid_executed"); SQLite3_result *resultset=NULL; diff --git a/lib/ProxySQL_Profiler.cpp b/lib/ProxySQL_Profiler.cpp new file mode 100644 index 0000000000..9b63a5aa79 --- /dev/null +++ b/lib/ProxySQL_Profiler.cpp @@ -0,0 +1,214 @@ +#include "ProxySQL_Profiler.hpp" +#include +#include + +using namespace std; + +extern thread_local std::string thread_bt; +extern std::mutex GlobalProfiling1_mutex; +extern std::unordered_map GlobalProfiling1; + + +class Counter2 { + public: + unsigned long long cnt = 0; + unsigned long long tottime = 0; + unsigned long long tottime1 = 0; // used by print_values + unsigned long long tottime2 = 0; + unsigned long long tottime3 = 0; + string name = ""; + string last_word = ""; + unordered_map map = {}; + ~Counter2() { + for (auto it = map.begin(); it != map.end(); it++) { + Counter2* c = it->second; + delete c; + } + } +}; + +int MMID = 1; +static unsigned long long total_leaf_times1 = 0; +static unsigned long long total_leaf_times2 = 0; +static unsigned long long total_leaf_times3 = 0; +static unordered_map MyMap = {}; + + +void getWords(vector& words, string str) { + words = {}; + int n = str.length(); + string word = ""; + for (int i = 0; i < n; i++) { + if (str[i] == ' ' || i == (n - 1)) { + words.push_back(word); + word = ""; + } else { + word += str[i]; + } + } +} + + +void insert_element(unordered_map& MyMap, vector& words, unsigned int idx, CounterProfiling1& c) { + Counter2 * c2 = NULL; + auto it = MyMap.find(words[idx]); + if (it != MyMap.end()) { + c2 = it->second; + } else { + c2 = new Counter2(); + c2->name = "P" + to_string(MMID); + MMID++; + c2->last_word = words[idx]; + MyMap.emplace(c2->last_word,c2); + } + if (idx != words.size() - 1) { + idx++; + insert_element(c2->map, words, idx, c); + } else { + c2->cnt = c.cnt; + c2->tottime = c.tottime; + } +} + +void retrieve_total_leaf_times(unordered_map& MyMap) { + total_leaf_times1 = 0; + total_leaf_times2 = 0; + total_leaf_times3 = 0; + for (auto it = MyMap.begin() ; it != MyMap.end() ; it++) { + Counter2 *c2 = it->second; + c2->tottime1 = c2->tottime; + c2->tottime2 = 0; + c2->tottime3 = c2->tottime;; + if (c2->map.size()) { + retrieve_total_leaf_times(c2->map); + for (auto it2 = c2->map.begin() ; it2 != c2->map.end(); it2++) { + c2->tottime2 += it2->second->tottime2; // time of all the leaves from this branch + c2->tottime3 -= it2->second->tottime; // its own time only + } + } else { + c2->tottime2 = c2->tottime; // time of only leaves + total_leaf_times2 += c2->tottime2; + } + total_leaf_times1 += c2->tottime; + total_leaf_times3 += c2->tottime3; + } +} + +/* +void retrieve_total_leaf_times(unordered_map& MyMap, int algo) { + for (auto it = MyMap.begin() ; it != MyMap.end() ; it++) { + Counter2 *c2 = it->second; + c2->tottime2 = 0; + if (algo == 1) { + if (c2->map.size()) { + retrieve_total_leaf_times(c2->map, algo); + } + c2->tottime2 = c2->tottime; + total_leaf_times += c2->tottime2; + } else if (algo == 2) { + if (c2->map.size()) { + retrieve_total_leaf_times(c2->map, algo); + } + for (auto it2 = c2->map.begin() ; it2 != c2->map.end(); it2++) { + c2->tottime -= it2->second->tottime; + } + } else if (algo == 3) { + } + } +} +*/ +void print_values(string& output, unordered_map& MyMap, string parent, int algo) { + for (auto it = MyMap.begin() ; it != MyMap.end() ; it++) { + Counter2 *c2 = it->second; + string last_word = c2->last_word; + string path = parent + last_word + " "; + if (c2->map.size() == 0) { + if (last_word != "") { + auto it = GlobalProfiling1.find(path); + assert(it != GlobalProfiling1.end()); + CounterProfiling1& c = it->second; + assert(c.cnt == c2->cnt); + assert(c.tottime == c2->tottime); + } + } else { + print_values(output, c2->map, path, algo); + output += c2->name + "[" + last_word + "]\n"; + char buf[10]; + for (auto it2 = c2->map.begin() ; it2 != c2->map.end() ; it2++) { + Counter2 *c3 = it2->second; + double pct = 0; + unsigned long long tt = 0; + switch (algo) { + case 1: + tt = c3->tottime1; + pct = (double)tt * 100 / total_leaf_times1; + break; + case 2: + tt = c3->tottime2; + pct = (double)tt * 100 / total_leaf_times2; + break; + case 3: + tt = c3->tottime3; + pct = (double)tt * 100 / total_leaf_times3; + break; + default: + assert(0); + break; + } + sprintf(buf, "%.2f", pct); + output += c3->name + "[\"" + c3->last_word + "\n" + to_string(tt) + " (" + string(buf) + "%)\"]\n"; + output += c2->name + " -- " + to_string(c3->cnt) + " --> " + c3->name + "\n"; + } + } + } +} + +void GenerateMermaid1(string& output) { + MyMap = {}; + MMID = 1; + output = "```mermaid\nflowchart LR\n"; + const std::lock_guard lock(GlobalProfiling1_mutex); + for (auto it = GlobalProfiling1.begin() ; it != GlobalProfiling1.end() ; it++) { + vector words = {}; + getWords(words, it->first); + CounterProfiling1& c = it->second; + insert_element(MyMap, words, 0, c); + } + retrieve_total_leaf_times(MyMap); + print_values(output, MyMap,"",1); + output += "```\n"; + output += "```mermaid\nflowchart LR\n"; + print_values(output, MyMap,"",2); + output += "```\n"; + output += "```mermaid\nflowchart LR\n"; + print_values(output, MyMap,"",3); + output += "```"; +} + +Profiler1::Profiler1(int l, const char *__file, int __line, const char *__func) { + log = l; + if (log) { + clock_gettime(CLOCK_MONOTONIC,&begint); + //clock_gettime(CLOCK_THREAD_CPUTIME_ID,&begint); + } + prev_bt = thread_bt; + thread_bt += std::string(__file) + ":" + std::to_string(__line) + ":" + std::string(__func) + " "; +} + +Profiler1::~Profiler1() { + if (log) { + clock_gettime(CLOCK_MONOTONIC,&endt); + //clock_gettime(CLOCK_THREAD_CPUTIME_ID,&endt); + unsigned long long delta = (endt.tv_sec*1000000000+endt.tv_nsec) - (begint.tv_sec*1000000000+begint.tv_nsec); + const std::lock_guard lock(GlobalProfiling1_mutex); + auto it = GlobalProfiling1.find(thread_bt); + if (it != GlobalProfiling1.end()) { + CounterProfiling1& c = it->second; + c.add(delta); + } else { + CounterProfiling1 c(delta); + GlobalProfiling1.emplace(thread_bt,c); + } + } + thread_bt = prev_bt; +} diff --git a/lib/Query_Processor.cpp b/lib/Query_Processor.cpp index 85f1b499db..290e79cd76 100644 --- a/lib/Query_Processor.cpp +++ b/lib/Query_Processor.cpp @@ -1717,6 +1717,7 @@ SQLite3_result * Query_Processor::get_query_digests_reset() { Query_Processor_Output * Query_Processor::process_mysql_query(MySQL_Session *sess, void *ptr, unsigned int size, Query_Info *qi) { + PROFILER1_BLOCK1(a); // NOTE: if ptr == NULL , we are calling process_mysql_query() on an STMT_EXECUTE // to avoid unnecssary deallocation/allocation, we initialize qpo witout new allocation Query_Processor_Output *ret=sess->qpo; diff --git a/lib/c_tokenizer.cpp b/lib/c_tokenizer.cpp index c468e0b185..57ab1d5f7f 100644 --- a/lib/c_tokenizer.cpp +++ b/lib/c_tokenizer.cpp @@ -6,6 +6,7 @@ #include #include "c_tokenizer.h" +#include "ProxySQL_Profiler.hpp" extern __thread int mysql_thread___query_digests_max_query_length; @@ -2620,6 +2621,7 @@ char* mysql_query_digest_second_stage(const char* const q, int q_len, char** con * @return A pointer to the start of the supplied buffer, or the allocated memory containing the digest. */ char* mysql_query_digest_and_first_comment_2(const char* const q, int q_len, char** const fst_cmnt, char* const buf) { + PROFILER1_BLOCK1(a); #ifdef DEBUG if (buf != NULL) { memset(buf, 0, 127); diff --git a/lib/mysql_connection.cpp b/lib/mysql_connection.cpp index 458c581858..df4a619517 100644 --- a/lib/mysql_connection.cpp +++ b/lib/mysql_connection.cpp @@ -711,6 +711,7 @@ bool MySQL_Connection::match_tracked_options(const MySQL_Connection *c) { // non blocking API void MySQL_Connection::connect_start() { + PROFILER1_BLOCK1(a); PROXY_TRACE(); mysql=mysql_init(NULL); assert(mysql); @@ -906,6 +907,7 @@ void MySQL_Connection::connect_start() { } void MySQL_Connection::connect_cont(short event) { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_PROTOCOL, 6,"event=%d\n", event); async_exit_status = mysql_real_connect_cont(&ret_mysql, mysql, mysql_status(event, true)); } @@ -1017,17 +1019,20 @@ void MySQL_Connection::set_query(char *stmt, unsigned long length) { } void MySQL_Connection::real_query_start() { + PROFILER1_BLOCK1(a); PROXY_TRACE(); async_exit_status = mysql_real_query_start(&interr , mysql, query.ptr, query.length); } void MySQL_Connection::real_query_cont(short event) { + PROFILER1_BLOCK1(a); if (event == 0) return; proxy_debug(PROXY_DEBUG_MYSQL_PROTOCOL, 6,"event=%d\n", event); async_exit_status = mysql_real_query_cont(&interr ,mysql , mysql_status(event, true)); } void MySQL_Connection::stmt_prepare_start() { + PROFILER1_BLOCK1(a); PROXY_TRACE(); query.stmt=mysql_stmt_init(mysql); my_bool my_arg=true; @@ -1036,11 +1041,13 @@ void MySQL_Connection::stmt_prepare_start() { } void MySQL_Connection::stmt_prepare_cont(short event) { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_PROTOCOL, 6,"event=%d\n", event); async_exit_status = mysql_stmt_prepare_cont(&interr , query.stmt , mysql_status(event, true)); } void MySQL_Connection::stmt_execute_start() { + PROFILER1_BLOCK1(a); PROXY_TRACE(); int _rc=0; assert(query.stmt->mysql); // if we reached here, we hit bug #740 @@ -1058,6 +1065,7 @@ void MySQL_Connection::stmt_execute_start() { } void MySQL_Connection::stmt_execute_cont(short event) { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_PROTOCOL, 6,"event=%d\n", event); async_exit_status = mysql_stmt_execute_cont(&interr , query.stmt , mysql_status(event, true)); } @@ -1091,6 +1099,7 @@ void MySQL_Connection::set_is_client() { #define NEXT_IMMEDIATE(new_st) do { async_state_machine = new_st; goto handler_again; } while (0) MDB_ASYNC_ST MySQL_Connection::handler(short event) { + PROFILER1_BLOCK1(a); unsigned long long processed_bytes=0; // issue #527 : this variable will store the amount of bytes processed during this event if (mysql==NULL) { // it is the first time handler() is being called diff --git a/lib/mysql_data_stream.cpp b/lib/mysql_data_stream.cpp index dd2f2e2d36..0e714fd3c2 100644 --- a/lib/mysql_data_stream.cpp +++ b/lib/mysql_data_stream.cpp @@ -514,6 +514,7 @@ void MySQL_Data_Stream::check_data_flow() { } int MySQL_Data_Stream::read_from_net() { + PROFILER1_BLOCK1(a); if (encrypted) { //proxy_info("Entering\n"); } @@ -688,6 +689,7 @@ int MySQL_Data_Stream::read_from_net() { } int MySQL_Data_Stream::write_to_net() { + PROFILER1_BLOCK1(a); int bytes_io=0; int s = queue_data(queueOUT); int n; @@ -849,6 +851,7 @@ void MySQL_Data_Stream::set_pollout() { } int MySQL_Data_Stream::write_to_net_poll() { + PROFILER1_BLOCK1(a); int rc=0; if (active==0) return rc; /* @@ -953,6 +956,7 @@ int MySQL_Data_Stream::read_pkts() { } int MySQL_Data_Stream::buffer2array() { + PROFILER1_BLOCK1(a); int ret=0; bool fast_mode=sess->session_fast_forward; { @@ -1263,6 +1267,7 @@ void MySQL_Data_Stream::generate_compressed_packet() { int MySQL_Data_Stream::array2buffer() { + PROFILER1_BLOCK1(a); int ret=0; unsigned int idx=0; bool cont=true; diff --git a/src/proxysql_global.cpp b/src/proxysql_global.cpp index 4fae899dca..f966ec7e3e 100644 --- a/src/proxysql_global.cpp +++ b/src/proxysql_global.cpp @@ -4,6 +4,7 @@ #include "cpp.h" //ProxySQL_GlobalVariables GloVars; + SSL_CTX * ProxySQL_GlobalVariables::get_SSL_ctx() { // take the mutex std::lock_guard lock(global.ssl_mutex); From 9fda303e874f3e350ba7c27cb41c4e2f6ab71500 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 22 Jan 2024 12:04:17 +0000 Subject: [PATCH 2/9] Use CLOCK_MONOTONIC for profiling by default --- lib/ProxySQL_Profiler.cpp | 35 ++++++++--------------------------- 1 file changed, 8 insertions(+), 27 deletions(-) diff --git a/lib/ProxySQL_Profiler.cpp b/lib/ProxySQL_Profiler.cpp index 9b63a5aa79..0cde5c1e4d 100644 --- a/lib/ProxySQL_Profiler.cpp +++ b/lib/ProxySQL_Profiler.cpp @@ -8,6 +8,12 @@ extern thread_local std::string thread_bt; extern std::mutex GlobalProfiling1_mutex; extern std::unordered_map GlobalProfiling1; +#define CLOCKID CLOCK_MONOTONIC +//#define CLOCKID CLOCK_REALTIME +//#define CLOCKID CLOCK_MONOTONIC_COARSE +//#define CLOCKID CLOCK_REALTIME_COARSE +//#define CLOCKID CLOCK_THREAD_CPUTIME_ID + class Counter2 { public: @@ -94,29 +100,6 @@ void retrieve_total_leaf_times(unordered_map& MyMap) { } } -/* -void retrieve_total_leaf_times(unordered_map& MyMap, int algo) { - for (auto it = MyMap.begin() ; it != MyMap.end() ; it++) { - Counter2 *c2 = it->second; - c2->tottime2 = 0; - if (algo == 1) { - if (c2->map.size()) { - retrieve_total_leaf_times(c2->map, algo); - } - c2->tottime2 = c2->tottime; - total_leaf_times += c2->tottime2; - } else if (algo == 2) { - if (c2->map.size()) { - retrieve_total_leaf_times(c2->map, algo); - } - for (auto it2 = c2->map.begin() ; it2 != c2->map.end(); it2++) { - c2->tottime -= it2->second->tottime; - } - } else if (algo == 3) { - } - } -} -*/ void print_values(string& output, unordered_map& MyMap, string parent, int algo) { for (auto it = MyMap.begin() ; it != MyMap.end() ; it++) { Counter2 *c2 = it->second; @@ -188,8 +171,7 @@ void GenerateMermaid1(string& output) { Profiler1::Profiler1(int l, const char *__file, int __line, const char *__func) { log = l; if (log) { - clock_gettime(CLOCK_MONOTONIC,&begint); - //clock_gettime(CLOCK_THREAD_CPUTIME_ID,&begint); + clock_gettime(CLOCKID,&begint); } prev_bt = thread_bt; thread_bt += std::string(__file) + ":" + std::to_string(__line) + ":" + std::string(__func) + " "; @@ -197,8 +179,7 @@ Profiler1::Profiler1(int l, const char *__file, int __line, const char *__func) Profiler1::~Profiler1() { if (log) { - clock_gettime(CLOCK_MONOTONIC,&endt); - //clock_gettime(CLOCK_THREAD_CPUTIME_ID,&endt); + clock_gettime(CLOCKID,&endt); unsigned long long delta = (endt.tv_sec*1000000000+endt.tv_nsec) - (begint.tv_sec*1000000000+begint.tv_nsec); const std::lock_guard lock(GlobalProfiling1_mutex); auto it = GlobalProfiling1.find(thread_bt); From 8cc23d8d5386d37cef0d4ee8231d8f4769b408ee Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 22 Jan 2024 13:45:23 +0000 Subject: [PATCH 3/9] Adding profilier to Monitor --- lib/MySQL_Monitor.cpp | 81 ++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 80 insertions(+), 1 deletion(-) diff --git a/lib/MySQL_Monitor.cpp b/lib/MySQL_Monitor.cpp index 747c8e2488..a51f4fc374 100644 --- a/lib/MySQL_Monitor.cpp +++ b/lib/MySQL_Monitor.cpp @@ -294,6 +294,7 @@ void MySQL_Monitor_Connection_Pool::purge_all_connections() { } MYSQL * MySQL_Monitor_Connection_Pool::get_connection(char *hostname, int port, MySQL_Monitor_State_Data *mmsd) { + PROFILER1_BLOCK1(a); std::lock_guard lock(mutex); #ifdef DEBUG pthread_mutex_lock(&m2); @@ -364,6 +365,7 @@ MYSQL * MySQL_Monitor_Connection_Pool::get_connection(char *hostname, int port, } void MySQL_Monitor_Connection_Pool::put_connection(char *hostname, int port, MYSQL *my) { + PROFILER1_BLOCK1(a); unsigned long long now = monotonic_time(); std::lock_guard lock(mutex); #ifdef DEBUG @@ -416,6 +418,7 @@ void MySQL_Monitor_Connection_Pool::put_connection(char *hostname, int port, MYS } void MySQL_Monitor_Connection_Pool::purge_some_connections() { + PROFILER1_BLOCK1(a); unsigned long long now = monotonic_time(); std::lock_guard lock(mutex); #ifdef DEBUG @@ -577,6 +580,7 @@ MySQL_Monitor_State_Data::~MySQL_Monitor_State_Data() { } void MySQL_Monitor_State_Data::init_async() { + PROFILER1_BLOCK1(a); assert(mysql); switch (task_id_) { @@ -702,6 +706,7 @@ void MySQL_Monitor_State_Data::init_async() { } void MySQL_Monitor_State_Data::mark_task_as_timeout(unsigned long long time) { + PROFILER1_BLOCK1(a); task_result_ = MySQL_Monitor_State_Data_Task_Result::TASK_RESULT_TIMEOUT; t2 = time; @@ -1104,6 +1109,7 @@ MySQL_Monitor::~MySQL_Monitor() { }; void MySQL_Monitor::p_update_metrics() { + PROFILER1_BLOCK1(a); if (GloMyMon) { this->metrics.p_gauge_array[p_mon_gauge::mysql_monitor_workers]->Set(GloMyMon->num_threads); this->metrics.p_gauge_array[p_mon_gauge::mysql_monitor_workers_aux]->Set(GloMyMon->aux_threads); @@ -1151,6 +1157,7 @@ void MySQL_Monitor::drop_tables_defs(std::vector *tables_defs) { // This function is copied from ProxySQL_Admin void MySQL_Monitor::check_and_build_standard_tables(SQLite3DB *db, std::vector *tables_defs) { + PROFILER1_BLOCK1(a); table_def_t *td; db->execute("PRAGMA foreign_keys = OFF"); for (std::vector::iterator it=tables_defs->begin(); it!=tables_defs->end(); ++it) { @@ -1161,6 +1168,7 @@ void MySQL_Monitor::check_and_build_standard_tables(SQLite3DB *db, std::vectormysql_servers_mutex); if (resultset != nullptr) { @@ -1220,6 +1228,7 @@ void MySQL_Monitor::update_monitor_mysql_servers(SQLite3_result* resultset) { } void MySQL_Monitor::update_monitor_proxysql_servers(SQLite3_result* resultset) { + PROFILER1_BLOCK1(a); pthread_mutex_lock(&GloMyMon->proxysql_servers_mutex); if (resultset != nullptr) { @@ -1280,6 +1289,7 @@ void MySQL_Monitor::update_monitor_proxysql_servers(SQLite3_result* resultset) { } void * monitor_connect_thread(void *arg) { + PROFILER1_BLOCK1(a); mysql_close(mysql_init(NULL)); MySQL_Monitor_State_Data *mmsd=(MySQL_Monitor_State_Data *)arg; if (!GloMTH) return NULL; // quick exit during shutdown/restart @@ -1341,6 +1351,7 @@ void * monitor_connect_thread(void *arg) { } void * monitor_ping_thread(void *arg) { + PROFILER1_BLOCK1(a); mysql_close(mysql_init(NULL)); MySQL_Monitor_State_Data *mmsd=(MySQL_Monitor_State_Data *)arg; if (!GloMTH) return NULL; // quick exit during shutdown/restart @@ -1484,6 +1495,7 @@ void * monitor_ping_thread(void *arg) { } bool MySQL_Monitor_State_Data::set_wait_timeout() { + PROFILER1_BLOCK1(a); if (mysql_thread___monitor_wait_timeout==false) { return true; } @@ -1523,6 +1535,7 @@ bool MySQL_Monitor_State_Data::set_wait_timeout() { } bool MySQL_Monitor_State_Data::create_new_connection() { + PROFILER1_BLOCK1(a); mysql=mysql_init(NULL); assert(mysql); if (use_ssl) { @@ -1574,6 +1587,7 @@ bool MySQL_Monitor_State_Data::create_new_connection() { } void * monitor_read_only_thread(void *arg) { + PROFILER1_BLOCK1(a); mysql_close(mysql_init(NULL)); bool timeout_reached = false; MySQL_Monitor_State_Data *mmsd=(MySQL_Monitor_State_Data *)arg; @@ -1853,6 +1867,7 @@ VALGRIND_ENABLE_ERROR_REPORTING; } void * monitor_group_replication_thread(void *arg) { + PROFILER1_BLOCK1(a); mysql_close(mysql_init(NULL)); MySQL_Monitor_State_Data *mmsd=(MySQL_Monitor_State_Data *)arg; MySQL_Thread * mysql_thr = new MySQL_Thread(); @@ -2204,6 +2219,7 @@ void * monitor_group_replication_thread(void *arg) { } void * monitor_galera_thread(void *arg) { + PROFILER1_BLOCK1(a); mysql_close(mysql_init(NULL)); MySQL_Monitor_State_Data *mmsd=(MySQL_Monitor_State_Data *)arg; MySQL_Thread * mysql_thr = new MySQL_Thread(); @@ -2604,6 +2620,7 @@ void * monitor_galera_thread(void *arg) { } void * monitor_replication_lag_thread(void *arg) { + PROFILER1_BLOCK1(a); mysql_close(mysql_init(NULL)); MySQL_Monitor_State_Data *mmsd=(MySQL_Monitor_State_Data *)arg; if (!GloMTH) return NULL; // quick exit during shutdown/restart @@ -2894,6 +2911,7 @@ void * monitor_replication_lag_thread(void *arg) { void * MySQL_Monitor::monitor_connect() { + PROFILER1_BLOCK1(a); // initialize the MySQL Thread (note: this is not a real thread, just the structures associated with it) unsigned int MySQL_Monitor__thread_MySQL_Thread_Variables_version; MySQL_Thread * mysql_thr = new MySQL_Thread(); @@ -3021,6 +3039,7 @@ void * MySQL_Monitor::monitor_connect() { } void * MySQL_Monitor::monitor_ping() { + PROFILER1_BLOCK1(a); mysql_close(mysql_init(NULL)); // initialize the MySQL Thread (note: this is not a real thread, just the structures associated with it) // struct event_base *libevent_base; @@ -3248,6 +3267,7 @@ VALGRIND_ENABLE_ERROR_REPORTING; bool MySQL_Monitor::server_responds_to_ping(char *address, int port) { + PROFILER1_BLOCK1(a); bool ret = true; // default char *error=NULL; int cols=0; @@ -3281,6 +3301,7 @@ VALGRIND_ENABLE_ERROR_REPORTING; } void * MySQL_Monitor::monitor_read_only() { + PROFILER1_BLOCK1(a); mysql_close(mysql_init(NULL)); // initialize the MySQL Thread (note: this is not a real thread, just the structures associated with it) unsigned int MySQL_Monitor__thread_MySQL_Thread_Variables_version; @@ -3379,6 +3400,7 @@ void * MySQL_Monitor::monitor_read_only() { } set extract_writer_hgs(SQLite3_result* Group_Replication_Hosts_resultset) { + PROFILER1_BLOCK1(a); set writer_hgs {}; // NOTE: This operation should be at worst `N * log(N)` @@ -3469,6 +3491,7 @@ string create_conn_err_msg(const unique_ptr& mmsd) { unique_ptr init_mmsd_with_conn( const gr_host_def_t srv_def, uint32_t writer_hg, uint64_t start_time ) { + PROFILER1_BLOCK1(a); char* c_hostname = const_cast(srv_def.host.c_str()); unique_ptr mmsd { new MySQL_Monitor_State_Data { MON_GROUP_REPLICATION, c_hostname, srv_def.port, static_cast(srv_def.use_ssl) } @@ -3526,6 +3549,7 @@ struct gr_srv_st_t { vector> parse_gr_members_addrs( const MySQL_Monitor_State_Data* mmsd, const vector& gr_cluster_members ) { + PROFILER1_BLOCK1(a); #ifdef DEBUG nlohmann::ordered_json members { gr_cluster_members }; proxy_debug( @@ -3573,6 +3597,7 @@ vector> parse_gr_members_addrs( } gr_srv_st_t extract_gr_srv_st(MySQL_Monitor_State_Data* mmsd) { + PROFILER1_BLOCK1(a); gr_srv_st_t gr_srv_st {}; if (mmsd->interr == 0 && mmsd->result) { @@ -3701,6 +3726,7 @@ gr_node_info_t gr_update_hosts_map( * @param node_info The fetched server information itself. */ void gr_mon_action_over_resp_srv(MySQL_Monitor_State_Data* mmsd, const gr_node_info_t& node_info) { + PROFILER1_BLOCK1(a); // NOTE: We update MyHGM outside the mutex group_replication_mutex if (mmsd->mysql_error_msg) { // there was an error checking the status of the server, surely we need to reconfigure GR if (node_info.num_timeouts == 0) { @@ -3773,6 +3799,7 @@ void gr_mon_action_over_resp_srv(MySQL_Monitor_State_Data* mmsd, const gr_node_i * @param wr_hg The writer hostgroup from the unresponsive hosts. */ void gr_handle_actions_over_unresp_srvs(const vector& hosts_defs, uint32_t wr_hg) { + PROFILER1_BLOCK1(a); char unresp_err_msg[] = "Server unresponsive to PING requests"; for (const gr_host_def_t& host_def : hosts_defs) { @@ -3793,6 +3820,7 @@ void gr_handle_actions_over_unresp_srvs(const vector& hosts_defs, * @param mmsd The mmsd wrapper holding all information for returning the connection. */ void handle_mmsd_mysql_conn(MySQL_Monitor_State_Data* mmsd) { + PROFILER1_BLOCK1(a); if (mmsd == nullptr) return; if (mmsd->mysql) { @@ -3837,6 +3865,7 @@ void handle_mmsd_mysql_conn(MySQL_Monitor_State_Data* mmsd) { * @param mmsd The 'mmsd' which failures are to be reported. */ void gr_report_fetching_errs(MySQL_Monitor_State_Data* mmsd) { + PROFILER1_BLOCK1(a); if (mmsd->mysql) { if (mmsd->interr || mmsd->mysql_error_msg) { proxy_error( @@ -3868,6 +3897,7 @@ void gr_report_fetching_errs(MySQL_Monitor_State_Data* mmsd) { * hold a valid 'MYSQL_RES' or an error. */ void async_gr_mon_actions_handler(MySQL_Monitor_State_Data* mmsd) { + PROFILER1_BLOCK1(a); // We base 'start_time' on the conn init for 'MySQL_Monitor_State_Data'. If a conn creation was // required, we take into account this time into account, otherwise we assume that 'start_time=t1'. uint64_t start_time = 0; @@ -3899,6 +3929,7 @@ void async_gr_mon_actions_handler(MySQL_Monitor_State_Data* mmsd) { * @return The created and initialized 'MySQL_Thread'. */ unique_ptr init_mysql_thread_struct() { + PROFILER1_BLOCK1(a); unique_ptr mysql_thr { new MySQL_Thread() }; mysql_thr->curtime = monotonic_time(); mysql_thr->refresh_variables(); @@ -3912,6 +3943,7 @@ struct mon_thread_info_t { }; void* monitor_GR_thread_HG(void *arg) { + PROFILER1_BLOCK1(a); uint32_t wr_hg = *(static_cast(arg)); proxy_info("Started Monitor thread for Group Replication writer HG %u\n", wr_hg); @@ -4047,6 +4079,7 @@ void* monitor_GR_thread_HG(void *arg) { * @return A vector of 'mon_thread_info_t' holding info of the created threads. */ vector create_group_replication_worker_threads(const set& writer_hgs) { + PROFILER1_BLOCK1(a); proxy_info("Activating Monitoring of %lu Group Replication clusters\n", writer_hgs.size()); vector threads_info {}; @@ -4070,6 +4103,7 @@ vector create_group_replication_worker_threads(const set(args); @@ -4572,6 +4610,7 @@ void* monitor_dns_resolver_thread(void* args) { } void* MySQL_Monitor::monitor_dns_cache() { + PROFILER1_BLOCK1(a); // initialize the MySQL Thread (note: this is not a real thread, just the structures associated with it) unsigned int MySQL_Monitor__thread_MySQL_Thread_Variables_version = 0; std::unique_ptr mysql_thr(new MySQL_Thread()); @@ -5092,6 +5131,7 @@ MyGR_monitor_node::~MyGR_monitor_node() { } int MyGR_monitor_node::get_lag_behind_count(int txs_behind) { + PROFILER1_BLOCK1(a); int max_lag = 10; if (mysql_thread___monitor_groupreplication_max_transactions_behind_count < max_lag) max_lag = mysql_thread___monitor_groupreplication_max_transactions_behind_count; @@ -5131,6 +5171,7 @@ int MyGR_monitor_node::get_lag_behind_count(int txs_behind) { } int MyGR_monitor_node::get_timeout_count() { + PROFILER1_BLOCK1(a); int num_timeouts = 0; int max_num_timeout = 10; if (mysql_thread___monitor_groupreplication_healthcheck_max_timeout_count < max_num_timeout) @@ -5172,6 +5213,7 @@ int MyGR_monitor_node::get_timeout_count() { // return true if status changed bool MyGR_monitor_node::add_entry(unsigned long long _st, unsigned long long _ct, long long _tb, bool _pp, bool _ro, char *_error) { + PROFILER1_BLOCK1(a); bool ret=false; if (idx_last_entry==-1) ret=true; int prev_last_entry=idx_last_entry; @@ -5284,6 +5326,7 @@ Galera_monitor_node::~Galera_monitor_node() { // return true if status changed bool Galera_monitor_node::add_entry(unsigned long long _st, unsigned long long _ct, long long _tb, bool _pp, bool _ro, int _local_state, bool _desync, bool _reject, bool _sst_donor_reject, bool _pxc_maint_mode, char *_error) { + PROFILER1_BLOCK1(a); bool ret=false; if (idx_last_entry==-1) ret=true; int prev_last_entry=idx_last_entry; @@ -5329,6 +5372,7 @@ bool Galera_monitor_node::add_entry(unsigned long long _st, unsigned long long _ } void MySQL_Monitor::populate_monitor_mysql_server_group_replication_log() { + PROFILER1_BLOCK1(a); //sqlite3 *mondb=monitordb->get_db(); int rc; //char *query=NULL; @@ -5370,6 +5414,7 @@ void MySQL_Monitor::populate_monitor_mysql_server_group_replication_log() { } void MySQL_Monitor::populate_monitor_mysql_server_galera_log() { + PROFILER1_BLOCK1(a); //sqlite3 *mondb=monitordb->get_db(); int rc; //char *query=NULL; @@ -5475,6 +5520,7 @@ char * MySQL_Monitor::galera_find_last_node(int writer_hostgroup) { } std::vector * MySQL_Monitor::galera_find_possible_last_nodes(int writer_hostgroup) { + PROFILER1_BLOCK1(a); std::vector * result = new std::vector(); pthread_mutex_lock(&GloMyMon->galera_mutex); std::map::iterator it2; @@ -5507,6 +5553,7 @@ std::vector * MySQL_Monitor::galera_find_possible_last_nodes(int writer_ } void MySQL_Monitor::populate_monitor_mysql_server_aws_aurora_log() { + PROFILER1_BLOCK1(a); //sqlite3 *mondb=monitordb->get_db(); int rc; //char *query=NULL; @@ -5575,6 +5622,7 @@ void MySQL_Monitor::populate_monitor_mysql_server_aws_aurora_log() { } void MySQL_Monitor::populate_monitor_mysql_server_aws_aurora_check_status() { + PROFILER1_BLOCK1(a); //sqlite3 *mondb=monitordb->get_db(); int rc; //char *query=NULL; @@ -5708,6 +5756,7 @@ AWS_Aurora_monitor_node::~AWS_Aurora_monitor_node() { } bool AWS_Aurora_monitor_node::add_entry(AWS_Aurora_status_entry *ase) { + PROFILER1_BLOCK1(a); bool ret=false; if (idx_last_entry==-1) ret=true; idx_last_entry++; @@ -5841,7 +5890,8 @@ void * monitor_AWS_Aurora_thread_HG(void *arg) { while (GloMyMon->shutdown==false && mysql_thread___monitor_enabled==true && exit_now==false) { - + PROFILER1_BLOCK1(a); + unsigned int glover; t1=monotonic_time(); @@ -6238,6 +6288,7 @@ void * MySQL_Monitor::monitor_aws_aurora() { while (GloMyMon->shutdown==false && mysql_thread___monitor_enabled==true) { + PROFILER1_BLOCK1(a); unsigned int glover; if (!GloMTH) return NULL; // quick exit during shutdown/restart @@ -6321,6 +6372,7 @@ void * MySQL_Monitor::monitor_aws_aurora() { } unsigned int MySQL_Monitor::estimate_lag(char* server_id, AWS_Aurora_status_entry** aase, unsigned int idx, unsigned int add_lag_ms, unsigned int min_lag_ms, unsigned int lag_num_checks) { + PROFILER1_BLOCK1(a); assert(aase); assert(server_id); assert(idx >= 0 && idx < N_L_ASE); @@ -6361,6 +6413,7 @@ void print_aws_aurora_status_entry(AWS_Aurora_status_entry* aase) { } void MySQL_Monitor::evaluate_aws_aurora_results(unsigned int wHG, unsigned int rHG, AWS_Aurora_status_entry **lasts_ase, unsigned int ase_idx, unsigned int max_latency_ms, unsigned int add_lag_ms, unsigned int min_lag_ms, unsigned int lag_num_checks) { + PROFILER1_BLOCK1(a); #ifdef TEST_AURORA unsigned int i = 0; bool verbose = false; @@ -6478,6 +6531,7 @@ void MySQL_Monitor::evaluate_aws_aurora_results(unsigned int wHG, unsigned int r } std::string MySQL_Monitor::dns_lookup(const std::string& hostname, bool return_hostname_if_lookup_fails, size_t* ip_count) { + PROFILER1_BLOCK1(a); static thread_local std::shared_ptr dns_cache_thread; @@ -6508,6 +6562,7 @@ std::string MySQL_Monitor::dns_lookup(const char* hostname, bool return_hostname bool MySQL_Monitor::update_dns_cache_from_mysql_conn(const MYSQL* mysql) { + PROFILER1_BLOCK1(a); assert(mysql); // if port==0, UNIX socket is used @@ -6534,6 +6589,7 @@ bool MySQL_Monitor::update_dns_cache_from_mysql_conn(const MYSQL* mysql) bool MySQL_Monitor::_dns_cache_update(const std::string &hostname, std::vector&& ip_address) { static thread_local std::shared_ptr dns_cache_thread; + PROFILER1_BLOCK1(a); if (!dns_cache_thread && GloMyMon) dns_cache_thread = GloMyMon->dns_cache; @@ -6548,6 +6604,7 @@ bool MySQL_Monitor::_dns_cache_update(const std::string &hostname, std::vectorforce_dns_cache_update = true; proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Triggering DNS cache update sequence.\n"); @@ -6555,6 +6612,7 @@ void MySQL_Monitor::trigger_dns_cache_update() { } bool DNS_Cache::add(const std::string& hostname, std::vector&& ips) { + PROFILER1_BLOCK1(a); if (!enabled) return false; @@ -6574,6 +6632,7 @@ bool DNS_Cache::add(const std::string& hostname, std::vector&& ips) } bool DNS_Cache::add_if_not_exist(const std::string& hostname, std::vector&& ips) { + PROFILER1_BLOCK1(a); if (!enabled) return false; int rc = pthread_rwlock_wrlock(&rwlock_); @@ -6594,6 +6653,7 @@ bool DNS_Cache::add_if_not_exist(const std::string& hostname, std::vector& mmsds) { + PROFILER1_BLOCK1(a); for (auto& mmsd : mmsds) { @@ -7051,6 +7118,7 @@ bool MySQL_Monitor::monitor_ping_process_ready_tasks(const std::vector> mmsds; @@ -7085,6 +7153,7 @@ void MySQL_Monitor::monitor_ping_async(SQLite3_result* resultset) { } MySQL_Monitor_State_Data_Task_Result MySQL_Monitor_State_Data::generic_handler(short event_, short& wait_event) { + PROFILER1_BLOCK1(a); MySQL_Monitor_State_Data_Task_Result result_ret = MySQL_Monitor_State_Data_Task_Result::TASK_RESULT_PENDING; int status = 0; @@ -7193,6 +7262,7 @@ MySQL_Monitor_State_Data_Task_Result MySQL_Monitor_State_Data::generic_handler(s } bool MySQL_Monitor::monitor_read_only_process_ready_tasks(const std::vector& mmsds) { + PROFILER1_BLOCK1(a); std::list mysql_servers; @@ -7328,6 +7398,7 @@ VALGRIND_ENABLE_ERROR_REPORTING; } void MySQL_Monitor::monitor_read_only_async(SQLite3_result* resultset) { + PROFILER1_BLOCK1(a); assert(resultset); std::vector> mmsds; @@ -7379,6 +7450,7 @@ void MySQL_Monitor::monitor_read_only_async(SQLite3_result* resultset) { } bool MySQL_Monitor::monitor_group_replication_process_ready_tasks(const std::vector& mmsds) { + PROFILER1_BLOCK1(a); for (auto& mmsd : mmsds) { @@ -7543,6 +7615,7 @@ bool MySQL_Monitor::monitor_group_replication_process_ready_tasks(const std::vec } void MySQL_Monitor::monitor_group_replication_async() { + PROFILER1_BLOCK1(a); std::vector> mmsds; pthread_mutex_lock(&group_replication_mutex); @@ -7591,6 +7664,7 @@ void MySQL_Monitor::monitor_group_replication_async() { bool MySQL_Monitor::monitor_group_replication_process_ready_tasks_2( const vector& mmsds ) { + PROFILER1_BLOCK1(a); for (MySQL_Monitor_State_Data* mmsd : mmsds) { const MySQL_Monitor_State_Data_Task_Result task_result = mmsd->get_task_result(); assert(task_result != MySQL_Monitor_State_Data_Task_Result::TASK_RESULT_PENDING); @@ -7603,6 +7677,7 @@ bool MySQL_Monitor::monitor_group_replication_process_ready_tasks_2( void MySQL_Monitor::monitor_gr_async_actions_handler( const vector>& mmsds ) { + PROFILER1_BLOCK1(a); Monitor_Poll monitor_poll(mmsds.size()); for (const unique_ptr& mmsd : mmsds) { @@ -7621,6 +7696,7 @@ void MySQL_Monitor::monitor_gr_async_actions_handler( bool MySQL_Monitor::monitor_replication_lag_process_ready_tasks(const std::vector& mmsds) { + PROFILER1_BLOCK1(a); std::list> mysql_servers; for (auto& mmsd : mmsds) { @@ -7740,6 +7816,7 @@ bool MySQL_Monitor::monitor_replication_lag_process_ready_tasks(const std::vecto } void MySQL_Monitor::monitor_replication_lag_async(SQLite3_result* resultset) { + PROFILER1_BLOCK1(a); assert(resultset); std::vector> mmsds; @@ -7780,6 +7857,7 @@ void MySQL_Monitor::monitor_replication_lag_async(SQLite3_result* resultset) { bool MySQL_Monitor::monitor_galera_process_ready_tasks(const std::vector& mmsds) { + PROFILER1_BLOCK1(a); for (auto& mmsd : mmsds) { const auto task_result = mmsd->get_task_result(); @@ -8040,6 +8118,7 @@ bool MySQL_Monitor::monitor_galera_process_ready_tasks(const std::vector> mmsds; std::set checked_servers; pthread_mutex_lock(&galera_mutex); From d5f236ea574c5052baac488839a72b72c69971fd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 22 Jan 2024 13:48:21 +0000 Subject: [PATCH 4/9] Adding profiler to MySQL Logger --- lib/MySQL_Logger.cpp | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index 6dd183846c..da85937d0e 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -106,6 +106,7 @@ void MySQL_Event::set_server(int _hid, const char *ptr, int len) { } uint64_t MySQL_Event::write(std::fstream *f, MySQL_Session *sess) { + PROFILER1_BLOCK1(a); uint64_t total_bytes=0; switch (et) { case PROXYSQL_COM_QUERY: @@ -139,6 +140,7 @@ uint64_t MySQL_Event::write(std::fstream *f, MySQL_Session *sess) { } void MySQL_Event::write_auth(std::fstream *f, MySQL_Session *sess) { + PROFILER1_BLOCK1(a); json j = {}; j["timestamp"] = start_time/1000; { @@ -260,6 +262,7 @@ void MySQL_Event::write_auth(std::fstream *f, MySQL_Session *sess) { } uint64_t MySQL_Event::write_query_format_1(std::fstream *f) { + PROFILER1_BLOCK1(a); uint64_t total_bytes=0; total_bytes+=1; // et total_bytes+=mysql_encode_length(thread_id, NULL); @@ -369,6 +372,7 @@ uint64_t MySQL_Event::write_query_format_1(std::fstream *f) { } uint64_t MySQL_Event::write_query_format_2_json(std::fstream *f) { + PROFILER1_BLOCK1(a); json j = {}; uint64_t total_bytes=0; if (hid!=UINT64_MAX) { @@ -674,6 +678,7 @@ void MySQL_Logger::audit_set_datadir(char *s) { }; void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds) { + PROFILER1_BLOCK1(a); if (events.enabled==false) return; if (events.logfile==NULL) return; // 'MySQL_Session::client_myds' could be NULL in case of 'RequestEnd' being called over a freshly created session @@ -812,6 +817,7 @@ void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds) { } void MySQL_Logger::log_audit_entry(log_event_type _et, MySQL_Session *sess, MySQL_Data_Stream *myds, char *xi) { + PROFILER1_BLOCK1(a); if (audit.enabled==false) return; if (audit.logfile==NULL) return; @@ -971,6 +977,7 @@ void MySQL_Logger::flush() { } unsigned int MySQL_Logger::events_find_next_id() { + PROFILER1_BLOCK1(a); int maxidx=0; DIR *dir; struct dirent *ent; @@ -1017,6 +1024,7 @@ unsigned int MySQL_Logger::events_find_next_id() { } unsigned int MySQL_Logger::audit_find_next_id() { + PROFILER1_BLOCK1(a); int maxidx=0; DIR *dir; struct dirent *ent; From 87ea010524052b2b7678fa77a624aaacb989774a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 22 Jan 2024 13:58:43 +0000 Subject: [PATCH 5/9] Adding profiler to query processor --- lib/Query_Processor.cpp | 45 +++++++++++++++++++++++++++++++++++++++++ 1 file changed, 45 insertions(+) diff --git a/lib/Query_Processor.cpp b/lib/Query_Processor.cpp index 290e79cd76..220482d97b 100644 --- a/lib/Query_Processor.cpp +++ b/lib/Query_Processor.cpp @@ -360,6 +360,7 @@ static unsigned long long mem_used_rule(QP_rule_t *qr) { } static re2_t * compile_query_rule(QP_rule_t *qr, int i) { + PROFILER1_BLOCK1(a); re2_t *r=(re2_t *)malloc(sizeof(re2_t)); r->opt1=NULL; r->re1=NULL; @@ -390,6 +391,7 @@ static re2_t * compile_query_rule(QP_rule_t *qr, int i) { }; static void __delete_query_rule(QP_rule_t *qr) { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_QUERY_PROCESSOR, 5, "Deleting rule in %p : rule_id:%d, active:%d, username=%s, schemaname=%s, flagIN:%d, %smatch_pattern=\"%s\", flagOUT:%d replace_pattern=\"%s\", destination_hostgroup:%d, apply:%d\n", qr, qr->rule_id, qr->active, qr->username, qr->schemaname, qr->flagIN, (qr->negate_match_pattern ? "(!)" : "") , qr->match_pattern, qr->flagOUT, qr->replace_pattern, qr->destination_hostgroup, qr->apply); if (qr->username) free(qr->username); @@ -447,6 +449,7 @@ static void __delete_query_rule(QP_rule_t *qr) { // of freeing the previous resources associated to the 'query_rules' and 'query_rules_fast_routing' out of // the 'Query_Processor' general locking ('wrlock'). void __reset_rules(std::vector * qrs) { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_QUERY_PROCESSOR, 5, "Resetting rules in Query Processor Table %p\n", qrs); if (qrs==NULL) return; QP_rule_t *qr; @@ -664,6 +667,7 @@ unsigned long long Query_Processor::get_new_req_conns_count() { } QP_rule_t * Query_Processor::new_query_rule(int rule_id, bool active, char *username, char *schemaname, int flagIN, char *client_addr, char *proxy_addr, int proxy_port, char *digest, char *match_digest, char *match_pattern, bool negate_match_pattern, char *re_modifiers, int flagOUT, char *replace_pattern, int destination_hostgroup, int cache_ttl, int cache_empty_result, int cache_timeout , int reconnect, int timeout, int retries, int delay, int next_query_flagIN, int mirror_flagOUT, int mirror_hostgroup, char *error_msg, char *OK_msg, int sticky_conn, int multiplex, int gtid_from_hostgroup, int log, bool apply, char *attributes, char *comment) { + PROFILER1_BLOCK1(a); QP_rule_t * newQR=(QP_rule_t *)malloc(sizeof(QP_rule_t)); newQR->rule_id=rule_id; newQR->active=active; @@ -863,6 +867,7 @@ SQLite3_result * Query_Processor::get_stats_commands_counters() { return result; } SQLite3_result * Query_Processor::get_stats_query_rules() { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_QUERY_PROCESSOR, 4, "Dumping query rules statistics, using Global version %d\n", version); SQLite3_result *result=new SQLite3_result(2); pthread_rwlock_rdlock(&rwlock); @@ -883,6 +888,7 @@ SQLite3_result * Query_Processor::get_stats_query_rules() { } SQLite3_result * Query_Processor::get_current_query_rules() { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_QUERY_PROCESSOR, 4, "Dumping current query rules, using Global version %d\n", version); SQLite3_result *result=new SQLite3_result(35); pthread_rwlock_rdlock(&rwlock); @@ -935,6 +941,7 @@ SQLite3_result * Query_Processor::get_current_query_rules() { } int Query_Processor::get_current_query_rules_fast_routing_count() { + PROFILER1_BLOCK1(a); int result = 0; pthread_rwlock_rdlock(&rwlock); result = fast_routing_resultset->rows_count; @@ -954,6 +961,7 @@ SQLite3_result * Query_Processor::get_current_query_rules_inner() { } SQLite3_result * Query_Processor::get_current_query_rules_fast_routing() { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_QUERY_PROCESSOR, 4, "Dumping current query rules fast_routing, using Global version %d\n", version); SQLite3_result *result=new SQLite3_result(5); pthread_rwlock_rdlock(&rwlock); @@ -983,6 +991,7 @@ SQLite3_result * Query_Processor::get_current_query_rules_fast_routing() { int Query_Processor::search_rules_fast_routing_dest_hg( khash_t(khStrInt)** __rules_fast_routing, const char* u, const char* s, int flagIN, bool lock ) { + PROFILER1_BLOCK1(a); int dest_hg = -1; const size_t u_len = strlen(u); size_t keylen = u_len+strlen(rand_del)+strlen(s)+30; // 30 is a big number @@ -1038,6 +1047,7 @@ struct get_query_digests_parallel_args { */ //unsigned long long iget_query_digests_total_size_parallel(umap_query_digest *gu, umap_query_digest_text *gtu, int *m_, unsigned long long *r2) { void * get_query_digests_total_size_parallel(void *_arg) { + PROFILER1_BLOCK1(a); get_query_digests_parallel_args *arg = (get_query_digests_parallel_args *)_arg; unsigned long long i = 0; unsigned long long m = arg->m; @@ -1073,6 +1083,7 @@ void * get_query_digests_total_size_parallel(void *_arg) { } void * get_query_digests_parallel(void *_arg) { + PROFILER1_BLOCK1(a); get_query_digests_parallel_args *arg = (get_query_digests_parallel_args *)_arg; unsigned long long i = 0; unsigned long long m = arg->m; @@ -1121,6 +1132,7 @@ void * get_query_digests_parallel(void *_arg) { void * purge_query_digests_parallel(void *_arg) { get_query_digests_parallel_args *arg = (get_query_digests_parallel_args *)_arg; + PROFILER1_BLOCK1(a); unsigned long long i = 0; unsigned long long r = 0; unsigned long long m = arg->m; @@ -1143,6 +1155,7 @@ void * purge_query_digests_parallel(void *_arg) { } unsigned long long Query_Processor::purge_query_digests(bool async_purge, bool parallel, char **msg) { + PROFILER1_BLOCK1(a); unsigned long long ret = 0; if (async_purge) { ret = purge_query_digests_async(msg); @@ -1153,6 +1166,7 @@ unsigned long long Query_Processor::purge_query_digests(bool async_purge, bool p } unsigned long long Query_Processor::purge_query_digests_async(char **msg) { + PROFILER1_BLOCK1(a); unsigned long long ret = 0; umap_query_digest digest_umap_aux; umap_query_digest_text digest_text_umap_aux; @@ -1192,6 +1206,7 @@ unsigned long long Query_Processor::purge_query_digests_async(char **msg) { unsigned long long Query_Processor::purge_query_digests_sync(bool parallel) { + PROFILER1_BLOCK1(a); unsigned long long ret = 0; pthread_rwlock_wrlock(&digest_rwlock); size_t map_size = digest_umap.size(); @@ -1232,6 +1247,7 @@ unsigned long long Query_Processor::purge_query_digests_sync(bool parallel) { } unsigned long long Query_Processor::get_query_digests_total_size() { + PROFILER1_BLOCK1(a); unsigned long long ret=0; pthread_rwlock_rdlock(&digest_rwlock); size_t map_size = digest_umap.size(); @@ -1287,6 +1303,7 @@ unsigned long long Query_Processor::get_query_digests_total_size() { } std::pair Query_Processor::get_query_digests_v2(const bool use_resultset) { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_QUERY_PROCESSOR, 4, "Dumping current query digest\n"); SQLite3_result *result = NULL; // Create two auxiliary maps and swap its content with the main maps. This @@ -1431,6 +1448,7 @@ std::pair Query_Processor::get_query_digests_v2(const boo } SQLite3_result * Query_Processor::get_query_digests() { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_QUERY_PROCESSOR, 4, "Dumping current query digest\n"); SQLite3_result *result = NULL; pthread_rwlock_rdlock(&digest_rwlock); @@ -1500,6 +1518,7 @@ SQLite3_result * Query_Processor::get_query_digests() { std::pair Query_Processor::get_query_digests_reset_v2( const bool copy, const bool use_resultset ) { + PROFILER1_BLOCK1(a); SQLite3_result *result = NULL; umap_query_digest digest_umap_aux; umap_query_digest_text digest_text_umap_aux; @@ -1615,6 +1634,7 @@ std::pair Query_Processor::get_query_digests_reset_v2( } void Query_Processor::get_query_digests_reset(umap_query_digest *uqd, umap_query_digest_text *uqdt) { + PROFILER1_BLOCK1(a); pthread_rwlock_wrlock(&digest_rwlock); digest_umap.swap(*uqd); digest_text_umap.swap(*uqdt); @@ -1622,6 +1642,7 @@ void Query_Processor::get_query_digests_reset(umap_query_digest *uqd, umap_query } SQLite3_result * Query_Processor::get_query_digests_reset() { + PROFILER1_BLOCK1(a); SQLite3_result *result = NULL; pthread_rwlock_wrlock(&digest_rwlock); unsigned long long curtime1; @@ -1756,6 +1777,7 @@ Query_Processor_Output * Query_Processor::process_mysql_query(MySQL_Session *ses len = qi->stmt_info->query_length; } if (__sync_add_and_fetch(&version,0) > _thr_SQP_version) { + PROFILER1_BLOCK1(a); // update local rules; proxy_debug(PROXY_DEBUG_MYSQL_QUERY_PROCESSOR, 4, "Detected a changed in version. Global:%d , local:%d . Refreshing...\n", version, _thr_SQP_version); pthread_rwlock_rdlock(&rwlock); @@ -1850,6 +1872,7 @@ Query_Processor_Output * Query_Processor::process_mysql_query(MySQL_Session *ses if (sess->next_query_flagIN >= 0) { flagIN=sess->next_query_flagIN; } + PROFILER1_BLOCK1(b); int reiterate=mysql_thread___query_processor_iterations; if (sess->mirror==true) { // we are into a mirror session @@ -2157,6 +2180,7 @@ Query_Processor_Output * Query_Processor::process_mysql_query(MySQL_Session *ses } } if (mysql_thread___firewall_whitelist_enabled) { + PROFILER1_BLOCK1(a); char *username = NULL; char *client_address = NULL; bool check_run = true; @@ -2272,6 +2296,7 @@ void Query_Processor::delete_QP_out(Query_Processor_Output *o) { }; void Query_Processor::update_query_processor_stats() { + PROFILER1_BLOCK1(a); // Note: // this function is called by each thread to update global query statistics // @@ -2308,6 +2333,7 @@ void Query_Processor::update_query_processor_stats() { void Query_Processor::query_parser_init(SQP_par_t *qp, char *query, int query_length, int flags) { + PROFILER1_BLOCK1(a); // trying to get rid of libinjection // instead of initializing qp->sf , we copy query info later in this function qp->digest_text=NULL; @@ -2335,11 +2361,13 @@ void Query_Processor::query_parser_init(SQP_par_t *qp, char *query, int query_le }; enum MYSQL_COM_QUERY_command Query_Processor::query_parser_command_type(SQP_par_t *qp) { + PROFILER1_BLOCK1(a); enum MYSQL_COM_QUERY_command ret=__query_parser_command_type(qp); return ret; } unsigned long long Query_Processor::query_parser_update_counters(MySQL_Session *sess, enum MYSQL_COM_QUERY_command c, SQP_par_t *qp, unsigned long long t) { + PROFILER1_BLOCK1(a); if (c>=MYSQL_COM_QUERY___NONE) return 0; unsigned long long ret=_thr_commands_counters[c]->add_time(t); @@ -2397,6 +2425,7 @@ unsigned long long Query_Processor::query_parser_update_counters(MySQL_Session * } void Query_Processor::update_query_digest(SQP_par_t *qp, int hid, MySQL_Connection_userinfo *ui, unsigned long long t, unsigned long long n, MySQL_STMT_Global_info *_stmt_info, MySQL_Session *sess) { + PROFILER1_BLOCK1(a); pthread_rwlock_wrlock(&digest_rwlock); QP_query_digest_stats *qds; @@ -2474,6 +2503,7 @@ uint64_t Query_Processor::get_digest(SQP_par_t *qp) { } enum MYSQL_COM_QUERY_command Query_Processor::__query_parser_command_type(SQP_par_t *qp) { + PROFILER1_BLOCK1(a); char *text=NULL; // this new variable is a pointer to either qp->digest_text , or to the query if (qp->digest_text) { text=qp->digest_text; @@ -2861,6 +2891,7 @@ enum MYSQL_COM_QUERY_command Query_Processor::__query_parser_command_type(SQP_pa } bool Query_Processor::query_parser_first_comment(Query_Processor_Output *qpo, char *fc) { + PROFILER1_BLOCK1(a); bool ret=false; tokenizer_t tok; tokenizer( &tok, fc, ";", TOKENIZER_NO_EMPTIES ); @@ -2988,6 +3019,7 @@ void Query_Processor::query_parser_free(SQP_par_t *qp) { }; bool Query_Processor::whitelisted_sqli_fingerprint(char *_s) { + PROFILER1_BLOCK1(a); bool ret = false; string s = _s; pthread_mutex_lock(&global_mysql_firewall_whitelist_mutex); @@ -3001,6 +3033,7 @@ bool Query_Processor::whitelisted_sqli_fingerprint(char *_s) { } void Query_Processor::load_mysql_firewall_sqli_fingerprints(SQLite3_result *resultset) { + PROFILER1_BLOCK1(a); global_mysql_firewall_whitelist_sqli_fingerprints.erase(global_mysql_firewall_whitelist_sqli_fingerprints.begin(), global_mysql_firewall_whitelist_sqli_fingerprints.end()); // perform the inserts for (std::vector::iterator it = resultset->rows.begin() ; it != resultset->rows.end(); ++it) { @@ -3016,6 +3049,7 @@ void Query_Processor::load_mysql_firewall_sqli_fingerprints(SQLite3_result *resu } void Query_Processor::load_mysql_firewall_users(SQLite3_result *resultset) { + PROFILER1_BLOCK1(a); unsigned long long tot_size = 0; std::unordered_map::iterator it; for (it = global_mysql_firewall_whitelist_users.begin() ; it != global_mysql_firewall_whitelist_users.end(); ++it) { @@ -3073,6 +3107,7 @@ void Query_Processor::load_mysql_firewall_users(SQLite3_result *resultset) { } void Query_Processor::load_mysql_firewall_rules(SQLite3_result *resultset) { + PROFILER1_BLOCK1(a); unsigned long long tot_size = 0; global_mysql_firewall_whitelist_rules_map___size = 0; //size_t rand_del_size = strlen(rand_del); @@ -3153,6 +3188,7 @@ void Query_Processor::save_query_rules(SQLite3_result *resultset) { } fast_routing_hashmap_t Query_Processor::create_fast_routing_hashmap(SQLite3_result* resultset) { + PROFILER1_BLOCK1(a); khash_t(khStrInt)* fast_routing = nullptr; char* keys_values = nullptr; unsigned long long keys_values_size = 0; @@ -3195,6 +3231,7 @@ fast_routing_hashmap_t Query_Processor::create_fast_routing_hashmap(SQLite3_resu } SQLite3_result* Query_Processor::load_fast_routing(const fast_routing_hashmap_t& fast_routing_hashmap) { + PROFILER1_BLOCK1(a); khash_t(khStrInt)* _rules_fast_routing = fast_routing_hashmap.rules_fast_routing; SQLite3_result* _rules_resultset = fast_routing_hashmap.rules_resultset; @@ -3269,6 +3306,7 @@ int Query_Processor::testing___find_HG_in_mysql_query_rules_fast_routing_dual( } void Query_Processor::get_current_mysql_firewall_whitelist(SQLite3_result **u, SQLite3_result **r, SQLite3_result **sf) { + PROFILER1_BLOCK1(a); pthread_mutex_lock(&global_mysql_firewall_whitelist_mutex); if (global_mysql_firewall_whitelist_rules_runtime) { *r = new SQLite3_result(global_mysql_firewall_whitelist_rules_runtime); @@ -3283,6 +3321,7 @@ void Query_Processor::get_current_mysql_firewall_whitelist(SQLite3_result **u, S } void Query_Processor::load_mysql_firewall(SQLite3_result *u, SQLite3_result *r, SQLite3_result *sf) { + PROFILER1_BLOCK1(a); pthread_mutex_lock(&global_mysql_firewall_whitelist_mutex); if (global_mysql_firewall_whitelist_rules_runtime) { delete global_mysql_firewall_whitelist_rules_runtime; @@ -3308,6 +3347,7 @@ void Query_Processor::load_mysql_firewall(SQLite3_result *u, SQLite3_result *r, } unsigned long long Query_Processor::get_mysql_firewall_memory_users_table() { + PROFILER1_BLOCK1(a); unsigned long long ret = 0; pthread_mutex_lock(&global_mysql_firewall_whitelist_mutex); ret = global_mysql_firewall_whitelist_users_map___size; @@ -3316,6 +3356,7 @@ unsigned long long Query_Processor::get_mysql_firewall_memory_users_table() { } unsigned long long Query_Processor::get_mysql_firewall_memory_users_config() { + PROFILER1_BLOCK1(a); unsigned long long ret = 0; pthread_mutex_lock(&global_mysql_firewall_whitelist_mutex); ret = global_mysql_firewall_whitelist_users_result___size; @@ -3324,6 +3365,7 @@ unsigned long long Query_Processor::get_mysql_firewall_memory_users_config() { } unsigned long long Query_Processor::get_mysql_firewall_memory_rules_table() { + PROFILER1_BLOCK1(a); unsigned long long ret = 0; pthread_mutex_lock(&global_mysql_firewall_whitelist_mutex); ret = global_mysql_firewall_whitelist_rules_map___size; @@ -3332,6 +3374,7 @@ unsigned long long Query_Processor::get_mysql_firewall_memory_rules_table() { } unsigned long long Query_Processor::get_mysql_firewall_memory_rules_config() { + PROFILER1_BLOCK1(a); unsigned long long ret = 0; pthread_mutex_lock(&global_mysql_firewall_whitelist_mutex); ret = global_mysql_firewall_whitelist_rules_result___size; @@ -3340,6 +3383,7 @@ unsigned long long Query_Processor::get_mysql_firewall_memory_rules_config() { } SQLite3_result * Query_Processor::get_mysql_firewall_whitelist_rules() { + PROFILER1_BLOCK1(a); SQLite3_result *ret = NULL; pthread_mutex_lock(&global_mysql_firewall_whitelist_mutex); if (global_mysql_firewall_whitelist_rules_runtime) { @@ -3350,6 +3394,7 @@ SQLite3_result * Query_Processor::get_mysql_firewall_whitelist_rules() { } SQLite3_result * Query_Processor::get_mysql_firewall_whitelist_users() { + PROFILER1_BLOCK1(a); SQLite3_result *ret = NULL; pthread_mutex_lock(&global_mysql_firewall_whitelist_mutex); if (global_mysql_firewall_whitelist_users_runtime) { From 27f608186cec2d963edb6ab8d5ef6274ae63644b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 22 Jan 2024 14:11:34 +0000 Subject: [PATCH 6/9] Adding profiling to MySQL_Session --- lib/MySQL_Session.cpp | 91 +++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 91 insertions(+) diff --git a/lib/MySQL_Session.cpp b/lib/MySQL_Session.cpp index f89cbd6e12..fdb74d85fb 100644 --- a/lib/MySQL_Session.cpp +++ b/lib/MySQL_Session.cpp @@ -334,6 +334,7 @@ Query_Info::~Query_Info() { } void Query_Info::begin(unsigned char *_p, int len, bool mysql_header) { + PROFILER1_BLOCK1(a); MyComQueryCmd=MYSQL_COM_QUERY___NONE; QueryPointer=NULL; QueryLength=0; @@ -360,6 +361,7 @@ void Query_Info::begin(unsigned char *_p, int len, bool mysql_header) { } void Query_Info::end() { + PROFILER1_BLOCK1(a); query_parser_update_counters(); query_parser_free(); if ((end_time-start_time) > (unsigned int)mysql_thread___long_query_time*1000) { @@ -398,19 +400,23 @@ void Query_Info::init(unsigned char *_p, int len, bool mysql_header) { } void Query_Info::query_parser_init() { + PROFILER1_BLOCK1(a); GloQPro->query_parser_init(&QueryParserArgs,(char *)QueryPointer,QueryLength,0); } enum MYSQL_COM_QUERY_command Query_Info::query_parser_command_type() { + PROFILER1_BLOCK1(a); MyComQueryCmd=GloQPro->query_parser_command_type(&QueryParserArgs); return MyComQueryCmd; } void Query_Info::query_parser_free() { + PROFILER1_BLOCK1(a); GloQPro->query_parser_free(&QueryParserArgs); } unsigned long long Query_Info::query_parser_update_counters() { + PROFILER1_BLOCK1(a); if (stmt_info) { MyComQueryCmd=stmt_info->MyComQueryCmd; } @@ -428,6 +434,7 @@ char * Query_Info::get_digest_text() { } bool Query_Info::is_select_NOT_for_update() { + PROFILER1_BLOCK1(a); if (stmt_info) { // we are processing a prepared statement. We already have the information return stmt_info->is_select_NOT_for_update; } @@ -557,6 +564,7 @@ void MySQL_Session::set_status(enum session_status e) { MySQL_Session::MySQL_Session() { + PROFILER1_BLOCK1(a); thread_session_id=0; //handler_ret = 0; pause_until=0; @@ -629,6 +637,7 @@ MySQL_Session::MySQL_Session() { } void MySQL_Session::init() { + PROFILER1_BLOCK1(a); transaction_persistent_hostgroup=-1; transaction_persistent=false; mybes= new PtrArray(4); @@ -637,6 +646,7 @@ void MySQL_Session::init() { } void MySQL_Session::reset() { + PROFILER1_BLOCK1(a); autocommit=true; autocommit_handled=false; sending_set_autocommit=false; @@ -683,6 +693,7 @@ void MySQL_Session::reset() { } MySQL_Session::~MySQL_Session() { + PROFILER1_BLOCK1(a); reset(); // we moved this out to allow CHANGE_USER @@ -737,6 +748,7 @@ MySQL_Session::~MySQL_Session() { // scan the pointer array of mysql backends (mybes) looking for a backend for the specified hostgroup_id MySQL_Backend * MySQL_Session::find_backend(int hostgroup_id) { + PROFILER1_BLOCK1(a); MySQL_Backend *_mybe; unsigned int i; for (i=0; i < mybes->len; i++) { @@ -749,6 +761,7 @@ MySQL_Backend * MySQL_Session::find_backend(int hostgroup_id) { }; void MySQL_Session::update_expired_conns(const vector>& checks) { + PROFILER1_BLOCK1(a); for (uint32_t i = 0; i < mybes->len; i++) { MySQL_Backend* mybe = static_cast(mybes->index(i)); MySQL_Data_Stream* myds = mybe != nullptr ? mybe->server_myds : nullptr; @@ -773,6 +786,7 @@ void MySQL_Session::update_expired_conns(const vectorhostgroup_id=hostgroup_id; @@ -788,12 +802,14 @@ MySQL_Backend * MySQL_Session::create_backend(int hostgroup_id, MySQL_Data_Strea }; MySQL_Backend * MySQL_Session::find_or_create_backend(int hostgroup_id, MySQL_Data_Stream *_myds) { + PROFILER1_BLOCK1(a); MySQL_Backend *_mybe=find_backend(hostgroup_id); proxy_debug(PROXY_DEBUG_NET,4,"HID=%d, _myds=%p, _mybe=%p\n" , hostgroup_id, _myds, _mybe); return ( _mybe ? _mybe : create_backend(hostgroup_id, _myds) ); }; void MySQL_Session::reset_all_backends() { + PROFILER1_BLOCK1(a); MySQL_Backend *mybe; while(mybes->len) { mybe=(MySQL_Backend *)mybes->remove_index_fast(0); @@ -803,6 +819,7 @@ void MySQL_Session::reset_all_backends() { }; void MySQL_Session::writeout() { + PROFILER1_BLOCK1(a); int tps = 10; // throttling per second , by default every 100ms int total_written = 0; unsigned long long last_sent_=0; @@ -892,6 +909,7 @@ void MySQL_Session::writeout() { } bool MySQL_Session::handler_CommitRollback(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); if (pkt->size <= 5) { return false; } char c=((char *)pkt->ptr)[5]; bool ret=false; @@ -955,6 +973,7 @@ bool MySQL_Session::handler_CommitRollback(PtrSize_t *pkt) { bool MySQL_Session::handler_SetAutocommit(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); autocommit_handled=false; sending_set_autocommit=false; size_t sal=strlen("set autocommit"); @@ -1108,6 +1127,7 @@ bool MySQL_Session::handler_SetAutocommit(PtrSize_t *pkt) { } void MySQL_Session::generate_proxysql_internal_session_json(json &j) { + PROFILER1_BLOCK1(a); char buff[32]; sprintf(buff,"%p",this); j["address"] = buff; @@ -1346,6 +1366,7 @@ void MySQL_Session::return_proxysql_internal(PtrSize_t *pkt) { * @return True if the queries are handled */ bool MySQL_Session::handler_special_queries_STATUS(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); if (pkt->size == (SELECT_DB_USER_LEN+5)) { if (strncasecmp(SELECT_DB_USER,(char *)pkt->ptr+5, SELECT_DB_USER_LEN)==0) { SQLite3_result *resultset = new SQLite3_result(2); @@ -1703,6 +1724,7 @@ bool MySQL_Session::handler_special_queries(PtrSize_t *pkt) { } void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY___create_mirror_session() { + PROFILER1_BLOCK1(a); if (pkt.size < 15*1024*1024 && (qpo->mirror_hostgroup >= 0 || qpo->mirror_flagOUT >= 0)) { // check if there are too many mirror sessions in queue if (thread->mirror_queue_mysql_sessions->len >= (unsigned int)mysql_thread___mirror_max_queue_length) { @@ -1798,6 +1820,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } int MySQL_Session::handler_again___status_PINGING_SERVER() { + PROFILER1_BLOCK1(a); assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; MySQL_Connection *myconn=myds->myconn; @@ -1845,6 +1868,7 @@ int MySQL_Session::handler_again___status_PINGING_SERVER() { } int MySQL_Session::handler_again___status_RESETTING_CONNECTION() { + PROFILER1_BLOCK1(a); assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; MySQL_Connection *myconn=myds->myconn; @@ -1918,6 +1942,7 @@ int MySQL_Session::handler_again___status_RESETTING_CONNECTION() { void MySQL_Session::handler_again___new_thread_to_kill_connection() { + PROFILER1_BLOCK1(a); MySQL_Data_Stream *myds=mybe->server_myds; if (myds->myconn && myds->myconn->mysql) { if (myds->killed_at==0) { @@ -1959,6 +1984,7 @@ void MySQL_Session::handler_again___new_thread_to_kill_connection() { #define NEXT_IMMEDIATE_NEW(new_st) do { set_status(new_st); return true; } while (0) bool MySQL_Session::handler_again___verify_backend_multi_statement() { + PROFILER1_BLOCK1(a); if ((client_myds->myconn->options.client_flag & CLIENT_MULTI_STATEMENTS) != (mybe->server_myds->myconn->options.client_flag & CLIENT_MULTI_STATEMENTS)) { if (client_myds->myconn->options.client_flag & CLIENT_MULTI_STATEMENTS) @@ -1988,6 +2014,7 @@ bool MySQL_Session::handler_again___verify_backend_multi_statement() { } bool MySQL_Session::handler_again___verify_init_connect() { + PROFILER1_BLOCK1(a); if (mybe->server_myds->myconn->options.init_connect_sent==false) { // we needs to set it to true mybe->server_myds->myconn->options.init_connect_sent=true; @@ -2023,6 +2050,7 @@ bool MySQL_Session::handler_again___verify_init_connect() { } bool MySQL_Session::handler_again___verify_backend_session_track_gtids() { + PROFILER1_BLOCK1(a); bool ret = false; proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session %p , client: %s , backend: %s\n", this, client_myds->myconn->options.session_track_gtids, mybe->server_myds->myconn->options.session_track_gtids); // we first verify that the backend supports it @@ -2087,6 +2115,7 @@ bool MySQL_Session::handler_again___verify_backend_session_track_gtids() { } bool MySQL_Session::handler_again___verify_ldap_user_variable() { + PROFILER1_BLOCK1(a); bool ret = false; if (mybe->server_myds->myconn->options.ldap_user_variable_sent==false) { ret = true; @@ -2141,6 +2170,7 @@ bool MySQL_Session::handler_again___verify_ldap_user_variable() { } bool MySQL_Session::handler_again___verify_backend_autocommit() { + PROFILER1_BLOCK1(a); if (sending_set_autocommit) { // if sending_set_autocommit==true, the next query proxysql is going // to run defines autocommit, for example: @@ -2247,6 +2277,7 @@ bool MySQL_Session::handler_again___verify_backend_autocommit() { } bool MySQL_Session::handler_again___verify_backend_user_schema() { + PROFILER1_BLOCK1(a); MySQL_Data_Stream *myds=mybe->server_myds; proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session %p , client: %s , backend: %s\n", this, client_myds->myconn->userinfo->username, mybe->server_myds->myconn->userinfo->username); proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Session %p , client: %s , backend: %s\n", this, client_myds->myconn->userinfo->schemaname, mybe->server_myds->myconn->userinfo->schemaname); @@ -2318,6 +2349,7 @@ bool MySQL_Session::handler_again___verify_backend_user_schema() { } bool MySQL_Session::handler_again___status_SETTING_INIT_CONNECT(int *_rc) { + PROFILER1_BLOCK1(a); bool ret=false; assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; @@ -2391,6 +2423,7 @@ bool MySQL_Session::handler_again___status_SETTING_INIT_CONNECT(int *_rc) { } bool MySQL_Session::handler_again___status_SETTING_LDAP_USER_VARIABLE(int *_rc) { + PROFILER1_BLOCK1(a); bool ret=false; assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; @@ -2486,6 +2519,7 @@ bool MySQL_Session::handler_again___status_SETTING_LDAP_USER_VARIABLE(int *_rc) } bool MySQL_Session::handler_again___status_SETTING_SQL_LOG_BIN(int *_rc) { + PROFILER1_BLOCK1(a); bool ret=false; assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; @@ -2568,6 +2602,7 @@ bool MySQL_Session::handler_again___status_SETTING_SQL_LOG_BIN(int *_rc) { } bool MySQL_Session::handler_again___status_CHANGING_CHARSET(int *_rc) { + PROFILER1_BLOCK1(a); assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; MySQL_Connection *myconn=myds->myconn; @@ -2646,6 +2681,7 @@ bool MySQL_Session::handler_again___status_CHANGING_CHARSET(int *_rc) { } bool MySQL_Session::handler_again___status_SETTING_GENERIC_VARIABLE(int *_rc, const char *var_name, const char *var_value, bool no_quote, bool set_transaction) { + PROFILER1_BLOCK1(a); bool ret = false; assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; @@ -2834,6 +2870,7 @@ bool MySQL_Session::handler_again___status_SETTING_GENERIC_VARIABLE(int *_rc, co } bool MySQL_Session::handler_again___status_SETTING_MULTI_STMT(int *_rc) { + PROFILER1_BLOCK1(a); assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; MySQL_Connection *myconn=myds->myconn; @@ -2896,6 +2933,7 @@ bool MySQL_Session::handler_again___status_SETTING_MULTI_STMT(int *_rc) { } bool MySQL_Session::handler_again___status_SETTING_SESSION_TRACK_GTIDS(int *_rc) { + PROFILER1_BLOCK1(a); bool ret=false; assert(mybe->server_myds->myconn); ret = handler_again___status_SETTING_GENERIC_VARIABLE(_rc, (char *)"SESSION_TRACK_GTIDS", mybe->server_myds->myconn->options.session_track_gtids, true); @@ -2903,6 +2941,7 @@ bool MySQL_Session::handler_again___status_SETTING_SESSION_TRACK_GTIDS(int *_rc) } bool MySQL_Session::handler_again___status_CHANGING_SCHEMA(int *_rc) { + PROFILER1_BLOCK1(a); bool ret=false; //fprintf(stderr,"CHANGING_SCHEMA\n"); assert(mybe->server_myds->myconn); @@ -3166,6 +3205,7 @@ bool MySQL_Session::handler_again___status_CONNECTING_SERVER(int *_rc) { return false; } bool MySQL_Session::handler_again___status_CHANGING_USER_SERVER(int *_rc) { + PROFILER1_BLOCK1(a); assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; MySQL_Connection *myconn=myds->myconn; @@ -3254,6 +3294,7 @@ bool MySQL_Session::handler_again___status_CHANGING_USER_SERVER(int *_rc) { } bool MySQL_Session::handler_again___status_CHANGING_AUTOCOMMIT(int *_rc) { + PROFILER1_BLOCK1(a); //fprintf(stderr,"CHANGING_AUTOCOMMIT\n"); assert(mybe->server_myds->myconn); MySQL_Data_Stream *myds=mybe->server_myds; @@ -3346,6 +3387,7 @@ bool MySQL_Session::handler_again___status_CHANGING_AUTOCOMMIT(int *_rc) { // // all break were replaced with a return void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_STMT_PREPARE(PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); if (session_type != PROXYSQL_SESSION_MYSQL) { // only MySQL module supports prepared statement!! l_free(pkt.size,pkt.ptr); client_myds->setDSS_STATE_QUERY_SENT_NET(); @@ -3466,6 +3508,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // // all break were replaced with a return void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_STMT_EXECUTE(PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); if (session_type != PROXYSQL_SESSION_MYSQL) { // only MySQL module supports prepared statement!! l_free(pkt.size,pkt.ptr); client_myds->setDSS_STATE_QUERY_SENT_NET(); @@ -3596,6 +3639,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // ClickHouse doesn't support COM_INIT_DB , so we replace it // with a COM_QUERY running USE void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_INIT_DB_replace_CLICKHOUSE(PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); PtrSize_t _new_pkt; _new_pkt.ptr=malloc(pkt.size+4); // USE + space memcpy(_new_pkt.ptr , pkt.ptr, 4); @@ -3619,6 +3663,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // it processes the session not MYSQL_SESSION // Make sure that handler_function() doesn't free the packet void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY___not_mysql(PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); switch (session_type) { case PROXYSQL_SESSION_ADMIN: case PROXYSQL_SESSION_STATS: @@ -3652,6 +3697,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // it searches for SQL injection // it returns true if it detected an SQL injection bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY_detect_SQLi() { + PROFILER1_BLOCK1(a); if (client_myds->com_field_list == false) { if (qpo->firewall_whitelist_mode != WUS_OFF) { struct libinjection_sqli_state state; @@ -3688,6 +3734,7 @@ bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // // replacing the single goto with return true bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP_MULTI_PACKET(PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); if (client_myds->multi_pkt.ptr==NULL) { // not initialized yet client_myds->multi_pkt.ptr=pkt.ptr; @@ -3769,6 +3816,7 @@ bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // this is triggered when proxysql receives a packet when doesn't expect any // for example while it is supposed to be sending resultset to client void MySQL_Session::handler___status_NONE_or_default(PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); char buf[INET6_ADDRSTRLEN]; switch (client_myds->client_addr->sa_family) { case AF_INET: { @@ -3809,6 +3857,7 @@ void MySQL_Session::handler___status_NONE_or_default(PtrSize_t& pkt) { // where: // status = WAITING_CLIENT_DATA void MySQL_Session::handler___status_WAITING_CLIENT_DATA___default() { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Statuses: WAITING_CLIENT_DATA - STATE_UNKNOWN\n"); if (mirror==false) { char buf[INET6_ADDRSTRLEN]; @@ -4343,6 +4392,7 @@ int MySQL_Session::get_pkts_from_client(bool& wrong_pass, PtrSize_t& pkt) { // -1 : the calling function will return // 1 : call to NEXT_IMMEDIATE int MySQL_Session::handler_ProcessingQueryError_CheckBackendConnectionStatus(MySQL_Data_Stream *myds) { + PROFILER1_BLOCK1(a); MySQL_Connection *myconn = myds->myconn; // the query failed if ( @@ -4406,6 +4456,7 @@ int MySQL_Session::handler_ProcessingQueryError_CheckBackendConnectionStatus(MyS } void MySQL_Session::SetQueryTimeout() { + PROFILER1_BLOCK1(a); mybe->server_myds->wait_until=0; if (qpo) { if (qpo->timeout > 0) { @@ -4428,6 +4479,7 @@ void MySQL_Session::SetQueryTimeout() { // true: NEXT_IMMEDIATE(st) needs to be called // false: continue bool MySQL_Session::handler_rc0_PROCESSING_STMT_PREPARE(enum session_status& st, MySQL_Data_Stream *myds, bool& prepared_stmt_with_no_params) { + PROFILER1_BLOCK1(a); thread->status_variables.stvar[st_var_backend_stmt_prepare]++; GloMyStmt->wrlock(); uint32_t client_stmtid=0; @@ -4485,6 +4537,7 @@ bool MySQL_Session::handler_rc0_PROCESSING_STMT_PREPARE(enum session_status& st, // this function used to be inline void MySQL_Session::handler_rc0_PROCESSING_STMT_EXECUTE(MySQL_Data_Stream *myds) { + PROFILER1_BLOCK1(a); thread->status_variables.stvar[st_var_backend_stmt_execute]++; PROXY_TRACE2(); if (CurrentQuery.mysql_stmt) { @@ -4539,6 +4592,7 @@ void MySQL_Session::handler_rc0_PROCESSING_STMT_EXECUTE(MySQL_Data_Stream *myds) // true: NEXT_IMMEDIATE(CONNECTING_SERVER) needs to be called // false: continue bool MySQL_Session::handler_minus1_ClientLibraryError(MySQL_Data_Stream *myds, int myerr, char **errmsg) { + PROFILER1_BLOCK1(a); MySQL_Connection *myconn = myds->myconn; bool retry_conn=false; // client error, serious @@ -4598,6 +4652,7 @@ bool MySQL_Session::handler_minus1_ClientLibraryError(MySQL_Data_Stream *myds, i // this function was inline void MySQL_Session::handler_minus1_LogErrorDuringQuery(MySQL_Connection *myconn, int myerr, char *errmsg) { + PROFILER1_BLOCK1(a); if (mysql_thread___verbose_query_error) { proxy_warning("Error during query on (%d,%s,%d,%lu) , user \"%s@%s\" , schema \"%s\" , %d, %s . digest_text = \"%s\"\n", myconn->parent->myhgc->hid, myconn->parent->address, myconn->parent->port, myconn->get_mysql_thread_id(), client_myds->myconn->userinfo->username, (client_myds->addr.addr ? client_myds->addr.addr : (char *)"unknown" ), client_myds->myconn->userinfo->schemaname, myerr, ( errmsg ? errmsg : mysql_error(myconn->mysql)), CurrentQuery.QueryParserArgs.digest_text ); } else { @@ -4690,6 +4745,7 @@ bool MySQL_Session::handler_minus1_HandleErrorCodes(MySQL_Data_Stream *myds, int // this function used to be inline. void MySQL_Session::handler_minus1_GenerateErrorMessage(MySQL_Data_Stream *myds, MySQL_Connection *myconn, bool& wrong_pass) { + PROFILER1_BLOCK1(a); switch (status) { case PROCESSING_QUERY: if (myconn) { @@ -4746,6 +4802,7 @@ void MySQL_Session::handler_minus1_GenerateErrorMessage(MySQL_Data_Stream *myds, // this function was inline void MySQL_Session::handler_minus1_HandleBackendConnection(MySQL_Data_Stream *myds, MySQL_Connection *myconn) { + PROFILER1_BLOCK1(a); if (myds->myconn) { myds->myconn->reduce_auto_increment_delay_token(); if (mysql_thread___multiplexing && (myds->myconn->reusable==true) && myds->myconn->IsActiveTransaction()==false && myds->myconn->MultiplexDisabled()==false) { @@ -5007,6 +5064,7 @@ int MySQL_Session::handler() { } NEXT_IMMEDIATE(CONNECTING_SERVER); } else { + PROFILER1_BLOCK1(a); MySQL_Data_Stream *myds=mybe->server_myds; MySQL_Connection *myconn=myds->myconn; mybe->server_myds->max_connect_time=0; @@ -5218,6 +5276,7 @@ int MySQL_Session::handler() { finishQuery(myds,myconn,prepared_stmt_with_no_params); } else { if (rc==-1) { + PROFILER1_BLOCK1(a); // the query failed int myerr=mysql_errno(myconn->mysql); char *errmsg = NULL; @@ -5256,6 +5315,7 @@ int MySQL_Session::handler() { handler_minus1_HandleBackendConnection(myds, myconn); } } else { + PROFILER1_BLOCK1(a); switch (rc) { // rc==1 , query is still running // start sending to frontend if mysql_thread___threshold_resultset_size is reached @@ -5409,6 +5469,7 @@ int MySQL_Session::handler() { bool MySQL_Session::handler_again___multiple_statuses(int *rc) { + PROFILER1_BLOCK1(a); bool ret = false; switch(status) { case CHANGING_USER_SERVER: @@ -5510,6 +5571,7 @@ void MySQL_Session::handler___status_CHANGING_USER_CLIENT___STATE_CLIENT_HANDSHA */ void MySQL_Session::handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE(PtrSize_t *pkt, bool *wrong_pass) { + PROFILER1_BLOCK1(a); bool is_encrypted = client_myds->encrypted; bool handshake_response_return = client_myds->myprot.process_pkt_handshake_response((unsigned char *)pkt->ptr,pkt->size); bool handshake_err = true; @@ -5827,6 +5889,7 @@ void MySQL_Session::handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE( // returning errors to all clients trying to send multi-statements . // see also #1140 void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_SET_OPTION(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); gtid_hid=-1; char v; v=*((char *)pkt->ptr+3); @@ -5864,6 +5927,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_FIELD_LIST(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); if (session_type == PROXYSQL_SESSION_MYSQL) { /* FIXME: temporary */ l_free(pkt->size,pkt->ptr); @@ -5879,6 +5943,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_PROCESS_KILL(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); l_free(pkt->size,pkt->ptr); client_myds->setDSS_STATE_QUERY_SENT_NET(); client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,9003,(char *)"28000",(char *)"Command not supported"); @@ -5886,6 +5951,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_INIT_DB(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); gtid_hid=-1; proxy_debug(PROXY_DEBUG_MYSQL_COM, 5, "Got COM_INIT_DB packet\n"); if (session_type == PROXYSQL_SESSION_MYSQL) { @@ -5913,6 +5979,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // this function was introduced due to isseu #718 // some application (like the one written in Perl) do not use COM_INIT_DB , but COM_QUERY with USE dbname void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY_USE_DB(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); gtid_hid=-1; proxy_debug(PROXY_DEBUG_MYSQL_COM, 5, "Got COM_QUERY with USE dbname\n"); if (session_type == PROXYSQL_SESSION_MYSQL) { @@ -5957,6 +6024,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // this function as inline in handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY_qpo void MySQL_Session::handler_WCD_SS_MCQ_qpo_QueryRewrite(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); // the query was rewritten l_free(pkt->size,pkt->ptr); // free old pkt // allocate new pkt @@ -5987,6 +6055,7 @@ void MySQL_Session::handler_WCD_SS_MCQ_qpo_QueryRewrite(PtrSize_t *pkt) { // this function as inline in handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY_qpo void MySQL_Session::handler_WCD_SS_MCQ_qpo_OK_msg(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); gtid_hid = -1; client_myds->DSS=STATE_QUERY_SENT_NET; unsigned int nTrx=NumActiveTransactions(); @@ -5999,6 +6068,7 @@ void MySQL_Session::handler_WCD_SS_MCQ_qpo_OK_msg(PtrSize_t *pkt) { // this function as inline in handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY_qpo void MySQL_Session::handler_WCD_SS_MCQ_qpo_error_msg(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); client_myds->DSS=STATE_QUERY_SENT_NET; client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,1148,(char *)"42000",qpo->error_msg); RequestEnd(NULL); @@ -6007,6 +6077,7 @@ void MySQL_Session::handler_WCD_SS_MCQ_qpo_error_msg(PtrSize_t *pkt) { // this function as inline in handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY_qpo void MySQL_Session::handler_WCD_SS_MCQ_qpo_LargePacket(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); // ER_NET_PACKET_TOO_LARGE client_myds->DSS=STATE_QUERY_SENT_NET; client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,1153,(char *)"08S01",(char *)"Got a packet bigger than 'max_allowed_packet' bytes", true); @@ -7108,6 +7179,7 @@ bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_STATISTICS(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_COM, 5, "Got COM_STATISTICS packet\n"); l_free(pkt->size,pkt->ptr); client_myds->setDSS_STATE_QUERY_SENT_NET(); @@ -7116,6 +7188,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_CHANGE_USER(PtrSize_t *pkt, bool *wrong_pass) { + PROFILER1_BLOCK1(a); gtid_hid=-1; proxy_debug(PROXY_DEBUG_MYSQL_COM, 5, "Got COM_CHANGE_USER packet\n"); //if (session_type == PROXYSQL_SESSION_MYSQL) { @@ -7193,6 +7266,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_RESET_CONNECTION(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_COM, 5, "Got MYSQL_COM_RESET_CONNECTION packet\n"); if (session_type == PROXYSQL_SESSION_MYSQL || session_type == PROXYSQL_SESSION_SQLITE) { @@ -7542,6 +7616,7 @@ void MySQL_Session::MySQL_Result_to_MySQL_wire(MYSQL *mysql, MySQL_ResultSet *My } void MySQL_Session::SQLite3_to_MySQL(SQLite3_result *result, char *error, int affected_rows, MySQL_Protocol *myprot, bool in_transaction, bool deprecate_eof_active) { + PROFILER1_BLOCK1(a); assert(myprot); MySQL_Data_Stream *myds=myprot->get_myds(); myds->DSS=STATE_QUERY_SENT_DS; @@ -7637,6 +7712,7 @@ void MySQL_Session::SQLite3_to_MySQL(SQLite3_result *result, char *error, int af } void MySQL_Session::set_unhealthy() { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 5, "Sess:%p\n", this); healthy=0; } @@ -7671,6 +7747,7 @@ unsigned int MySQL_Session::NumActiveTransactions(bool check_savepoint) { } bool MySQL_Session::HasOfflineBackends() { + PROFILER1_BLOCK1(a); bool ret=false; if (mybes==0) return ret; MySQL_Backend *_mybe; @@ -7688,6 +7765,7 @@ bool MySQL_Session::HasOfflineBackends() { } bool MySQL_Session::SetEventInOfflineBackends() { + PROFILER1_BLOCK1(a); bool ret=false; if (mybes==0) return ret; MySQL_Backend *_mybe; @@ -7705,6 +7783,7 @@ bool MySQL_Session::SetEventInOfflineBackends() { } int MySQL_Session::FindOneActiveTransaction(bool check_savepoint) { + PROFILER1_BLOCK1(a); int ret=-1; if (mybes==0) return ret; MySQL_Backend *_mybe; @@ -7824,6 +7903,7 @@ void MySQL_Session::RequestEnd(MySQL_Data_Stream *myds) { // this function tries to report all the memory statistics related to the sessions void MySQL_Session::Memory_Stats() { + PROFILER1_BLOCK1(a); if (thread==NULL) return; unsigned int i; @@ -7884,6 +7964,7 @@ void MySQL_Session::Memory_Stats() { void MySQL_Session::create_new_session_and_reset_connection(MySQL_Data_Stream *_myds) { + PROFILER1_BLOCK1(a); MySQL_Data_Stream *new_myds = NULL; MySQL_Connection * mc = _myds->myconn; // we remove the connection from the original data stream @@ -7919,6 +8000,7 @@ void MySQL_Session::create_new_session_and_reset_connection(MySQL_Data_Stream *_ } bool MySQL_Session::handle_command_query_kill(PtrSize_t *pkt) { + PROFILER1_BLOCK1(a); unsigned char command_type=*((unsigned char *)pkt->ptr+sizeof(mysql_hdr)); if (CurrentQuery.QueryParserArgs.digest_text) { if (command_type == _MYSQL_COM_QUERY) { @@ -7972,6 +8054,7 @@ bool MySQL_Session::handle_command_query_kill(PtrSize_t *pkt) { } void MySQL_Session::add_ldap_comment_to_pkt(PtrSize_t *_pkt) { + PROFILER1_BLOCK1(pro1); if (GloMyLdapAuth==NULL) return; if (use_ldap_auth == false) @@ -8097,6 +8180,7 @@ void MySQL_Session::finishQuery(MySQL_Data_Stream *myds, MySQL_Connection *mycon bool MySQL_Session::known_query_for_locked_on_hostgroup(uint64_t digest) { + PROFILER1_BLOCK1(a); bool ret = false; switch (digest) { case 1732998280766099668ULL: // "SET @OLD_CHARACTER_SET_CLIENT=@@CHARACTER_SET_CLIENT" @@ -8131,6 +8215,7 @@ bool MySQL_Session::known_query_for_locked_on_hostgroup(uint64_t digest) { void MySQL_Session::unable_to_parse_set_statement(bool *lock_hostgroup) { + PROFILER1_BLOCK1(a); // we couldn't parse the query string query_str = string((char *)CurrentQuery.QueryPointer,CurrentQuery.QueryLength); string digest_str = string(CurrentQuery.get_digest_text()); @@ -8180,6 +8265,7 @@ bool MySQL_Session::has_any_backend() { } void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_STMT_RESET(PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); uint32_t stmt_global_id=0; memcpy(&stmt_global_id,(char *)pkt.ptr+5,sizeof(uint32_t)); SLDH->reset(stmt_global_id); @@ -8194,6 +8280,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_STMT_CLOSE(PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); uint32_t client_global_id=0; memcpy(&client_global_id,(char *)pkt.ptr+5,sizeof(uint32_t)); // FIXME: no input validation @@ -8214,6 +8301,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_STMT_SEND_LONG_DATA(PtrSize_t& pkt) { + PROFILER1_BLOCK1(a); // FIXME: no input validation uint32_t stmt_global_id=0; memcpy(&stmt_global_id,(char *)pkt.ptr+5,sizeof(uint32_t)); @@ -8226,6 +8314,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C } void MySQL_Session::detected_broken_connection(const char *file, unsigned int line, const char *func, const char *action, MySQL_Connection *myconn, int myerr, const char *message, bool verbose) { + PROFILER1_BLOCK1(a); char *msg = (char *)message; if (msg == NULL) { msg = (char *)"Detected offline server prior to statement execution"; @@ -8244,6 +8333,7 @@ void MySQL_Session::detected_broken_connection(const char *file, unsigned int li } void MySQL_Session::generate_status_one_hostgroup(int hid, std::string& s) { + PROFILER1_BLOCK1(a); SQLite3_result *resultset = MyHGM->SQL3_Connection_Pool(false, &hid); json j_res; if (resultset->rows_count) { @@ -8265,6 +8355,7 @@ void MySQL_Session::generate_status_one_hostgroup(int hid, std::string& s) { void MySQL_Session::reset_warning_hostgroup_flag_and_release_connection() { + PROFILER1_BLOCK1(a); if (warning_in_hg > -1) { // if we've reached this point, it means that warning was found in the previous query, but the // current executed query is not 'SHOW WARNINGS' or 'SHOW COUNT(*) FROM WARNINGS', so we can safely reset warning_in_hg and From 06e5577752edc191a063e8d27fa21c5b14fda748 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 22 Jan 2024 14:23:06 +0000 Subject: [PATCH 7/9] Adding profiler in Hostgroup Manager --- lib/MySQL_HostGroups_Manager.cpp | 84 ++++++++++++++++++++++++++++++++ 1 file changed, 84 insertions(+) diff --git a/lib/MySQL_HostGroups_Manager.cpp b/lib/MySQL_HostGroups_Manager.cpp index 90cf1d26a5..d6475e6557 100644 --- a/lib/MySQL_HostGroups_Manager.cpp +++ b/lib/MySQL_HostGroups_Manager.cpp @@ -723,6 +723,7 @@ void MySrvList::remove(MySrvC *s) { } void MySrvConnList::drop_all_connections() { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_CONNPOOL, 7, "Dropping all connections (%u total) on MySrvConnList %p for server %s:%d , hostgroup=%d , status=%d\n", conns_length(), this, mysrvc->address, mysrvc->port, mysrvc->myhgc->hid, mysrvc->status); while (conns_length()) { MySQL_Connection *conn=(MySQL_Connection *)conns->remove_index_fast(0); @@ -768,6 +769,7 @@ MySrvC::MySrvC( } void MySrvC::connect_error(int err_num, bool get_mutex) { + PROFILER1_BLOCK1(a); // NOTE: this function operates without any mutex // although, it is not extremely important if any counter is lost // as a single connection failure won't make a significant difference @@ -856,6 +858,7 @@ void MySrvC::connect_error(int err_num, bool get_mutex) { } void MySrvC::shun_and_killall() { + PROFILER1_BLOCK1(a); status=MYSQL_SERVER_STATUS_SHUNNED; shunned_automatic=true; shunned_and_kill_all_connections=true; @@ -879,6 +882,7 @@ MySrvList::~MySrvList() { MyHGC::MyHGC(int _hid) { + PROFILER1_BLOCK1(a); hid=_hid; mysrvs=new MySrvList(this); current_time_now = 0; @@ -892,6 +896,7 @@ MyHGC::MyHGC(int _hid) { } void MyHGC::reset_attributes() { + PROFILER1_BLOCK1(a); if (attributes.initialized == false) { attributes.init_connect = NULL; attributes.comment = NULL; @@ -1441,6 +1446,7 @@ void MySQL_HostGroups_Manager::wrlock() { } void MySQL_HostGroups_Manager::p_update_mysql_error_counter(p_mysql_error_type err_type, unsigned int hid, char* address, uint16_t port, unsigned int code) { + PROFILER1_BLOCK1(a); p_hg_dyn_counter::metric metric = p_hg_dyn_counter::mysql_error; if (err_type == p_mysql_error_type::proxysql) { metric = p_hg_dyn_counter::proxysql_mysql_error; @@ -1481,6 +1487,7 @@ void MySQL_HostGroups_Manager::wrunlock() { void MySQL_HostGroups_Manager::wait_servers_table_version(unsigned v, unsigned w) { + PROFILER1_BLOCK1(a); struct timespec ts; clock_gettime(CLOCK_REALTIME, &ts); //ts.tv_sec += w; @@ -1501,6 +1508,7 @@ unsigned int MySQL_HostGroups_Manager::get_servers_table_version() { // we always assume that the calling thread has acquired a rdlock() int MySQL_HostGroups_Manager::servers_add(SQLite3_result *resultset) { + PROFILER1_BLOCK1(a); if (resultset==NULL) { return 0; } @@ -1582,6 +1590,7 @@ int MySQL_HostGroups_Manager::servers_add(SQLite3_result *resultset) { } SQLite3_result * MySQL_HostGroups_Manager::execute_query(char *query, char **error) { + PROFILER1_BLOCK1(a); int cols=0; int affected_rows=0; SQLite3_result *resultset=NULL; @@ -1594,6 +1603,7 @@ SQLite3_result * MySQL_HostGroups_Manager::execute_query(char *query, char **err void MySQL_HostGroups_Manager::CUCFT1( SpookyHash& myhash, bool& init, const string& TableName, const string& ColumnName, uint64_t& raw_checksum ) { + PROFILER1_BLOCK1(a); char *error=NULL; int cols=0; int affected_rows=0; @@ -1618,6 +1628,7 @@ void MySQL_HostGroups_Manager::CUCFT1( } void MySQL_HostGroups_Manager::commit_update_checksums_from_tables(SpookyHash& myhash, bool& init) { + PROFILER1_BLOCK1(a); // Always reset the current table values before recomputing for (size_t i = 0; i < table_resultset_checksum.size(); i++) { if (i != HGM_TABLES::MYSQL_SERVERS && i != HGM_TABLES::MYSQL_SERVERS_V2) { @@ -1640,6 +1651,7 @@ void MySQL_HostGroups_Manager::commit_update_checksums_from_tables(SpookyHash& m * */ void MySQL_HostGroups_Manager::update_hostgroup_manager_mappings() { + PROFILER1_BLOCK1(a); if (hgsm_mysql_servers_checksum != table_resultset_checksum[HGM_TABLES::MYSQL_SERVERS] || hgsm_mysql_replication_hostgroups_checksum != table_resultset_checksum[HGM_TABLES::MYSQL_REPLICATION_HOSTGROUPS]) @@ -1712,6 +1724,7 @@ void MySQL_HostGroups_Manager::update_hostgroup_manager_mappings() { * @return An SQLite3 resultset for the query 'MYHGM_GEN_ADMIN_RUNTIME_SERVERS'. */ unique_ptr get_admin_runtime_mysql_servers(SQLite3DB* mydb) { + PROFILER1_BLOCK1(a); char* error = nullptr; int cols = 0; int affected_rows = 0; @@ -1733,6 +1746,7 @@ unique_ptr get_admin_runtime_mysql_servers(SQLite3DB* mydb) { * @return A resulset holding 'mysql_servers_v2'. */ unique_ptr get_mysql_servers_v2() { + PROFILER1_BLOCK1(a); char* error = nullptr; int cols = 0; int affected_rows = 0; @@ -1755,6 +1769,7 @@ void update_glovars_checksum_with_peers( time_t peer_checksum_epoch, bool update_version ) { + PROFILER1_BLOCK1(a); module_checksum.set_checksum(const_cast(new_checksum.c_str())); if (update_version) @@ -1789,6 +1804,7 @@ void update_glovars_mysql_servers_checksum( const runtime_mysql_servers_checksum_t& peer_checksum = {}, bool update_version = false ) { + PROFILER1_BLOCK1(a); time_t new_epoch = time(NULL); update_glovars_checksum_with_peers( @@ -1820,6 +1836,7 @@ void update_glovars_mysql_servers_v2_checksum( const mysql_servers_v2_checksum_t& peer_checksum = {}, bool update_version = false ) { + PROFILER1_BLOCK1(a); time_t new_epoch = time(NULL); update_glovars_checksum_with_peers( @@ -1833,6 +1850,7 @@ void update_glovars_mysql_servers_v2_checksum( } uint64_t MySQL_HostGroups_Manager::commit_update_checksum_from_mysql_servers(SQLite3_result* runtime_mysql_servers) { + PROFILER1_BLOCK1(a); mydb->execute("DELETE FROM mysql_servers"); generate_mysql_servers_table(); @@ -1850,6 +1868,7 @@ uint64_t MySQL_HostGroups_Manager::commit_update_checksum_from_mysql_servers(SQL } uint64_t MySQL_HostGroups_Manager::commit_update_checksum_from_mysql_servers_v2(SQLite3_result* mysql_servers_v2) { + PROFILER1_BLOCK1(a); if (mysql_servers_v2 == nullptr) { unique_ptr resultset { get_mysql_servers_v2() }; save_mysql_servers_v2(resultset.release()); @@ -1864,6 +1883,7 @@ uint64_t MySQL_HostGroups_Manager::commit_update_checksum_from_mysql_servers_v2( } std::string MySQL_HostGroups_Manager::gen_global_mysql_servers_v2_checksum(uint64_t servers_v2_hash) { + PROFILER1_BLOCK1(a); bool init = false; SpookyHash global_hash {}; @@ -1893,6 +1913,7 @@ bool MySQL_HostGroups_Manager::commit( bool only_commit_runtime_mysql_servers, bool update_version ) { + PROFILER1_BLOCK1(a); // if only_commit_runtime_mysql_servers is true, mysql_servers_v2 resultset will not be entertained and will cause memory leak. if (only_commit_runtime_mysql_servers) { proxy_info("Generating runtime mysql servers records only.\n"); @@ -2216,6 +2237,7 @@ bool MySQL_HostGroups_Manager::commit( * @param runtime_mysql_servers resultset of runtime mysql_servers or can be a nullptr. */ uint64_t MySQL_HostGroups_Manager::get_mysql_servers_checksum(SQLite3_result* runtime_mysql_servers) { + PROFILER1_BLOCK1(a); //Note: GloVars.checksum_mutex needs to be locked SQLite3_result* resultset = nullptr; @@ -2244,6 +2266,7 @@ uint64_t MySQL_HostGroups_Manager::get_mysql_servers_checksum(SQLite3_result* ru } bool MySQL_HostGroups_Manager::gtid_exists(MySrvC *mysrvc, char * gtid_uuid, uint64_t gtid_trxid) { + PROFILER1_BLOCK1(a); bool ret = false; pthread_rwlock_rdlock(>id_rwlock); std::string s1 = mysrvc->address; @@ -2266,6 +2289,7 @@ bool MySQL_HostGroups_Manager::gtid_exists(MySrvC *mysrvc, char * gtid_uuid, uin } void MySQL_HostGroups_Manager::generate_mysql_gtid_executed_tables() { + PROFILER1_BLOCK1(a); pthread_rwlock_wrlock(>id_rwlock); // first, set them all as active = false std::unordered_map::iterator it = gtid_map.begin(); @@ -2342,6 +2366,7 @@ void MySQL_HostGroups_Manager::generate_mysql_gtid_executed_tables() { } void MySQL_HostGroups_Manager::purge_mysql_servers_table() { + PROFILER1_BLOCK1(a); for (unsigned int i=0; ilen; i++) { MyHGC *myhgc=(MyHGC *)MyHostGroups->index(i); MySrvC *mysrvc=NULL; @@ -2362,6 +2387,7 @@ void MySQL_HostGroups_Manager::purge_mysql_servers_table() { void MySQL_HostGroups_Manager::generate_mysql_servers_table(int *_onlyhg) { + PROFILER1_BLOCK1(a); int rc; sqlite3_stmt *statement1=NULL; sqlite3_stmt *statement32=NULL; @@ -2501,6 +2527,7 @@ void MySQL_HostGroups_Manager::generate_mysql_servers_table(int *_onlyhg) { } void MySQL_HostGroups_Manager::generate_mysql_replication_hostgroups_table() { + PROFILER1_BLOCK1(a); if (incoming_replication_hostgroups==NULL) return; if (mysql_thread___hostgroup_manager_verbose) { @@ -2534,6 +2561,7 @@ void MySQL_HostGroups_Manager::generate_mysql_replication_hostgroups_table() { void MySQL_HostGroups_Manager::generate_mysql_group_replication_hostgroups_table() { + PROFILER1_BLOCK1(a); if (incoming_group_replication_hostgroups==NULL) { return; } @@ -2614,6 +2642,7 @@ void MySQL_HostGroups_Manager::generate_mysql_group_replication_hostgroups_table } void MySQL_HostGroups_Manager::generate_mysql_group_replication_hostgroups_monitor_resultset() { + PROFILER1_BLOCK1(a); pthread_mutex_lock(&GloMyMon->group_replication_mutex); { char *error=NULL; @@ -2733,6 +2762,7 @@ void MySQL_HostGroups_Manager::generate_mysql_galera_hostgroups_table() { } void MySQL_HostGroups_Manager::update_table_mysql_servers_for_monitor(bool lock) { + PROFILER1_BLOCK1(a); if (lock) { wrlock(); } @@ -2765,6 +2795,7 @@ void MySQL_HostGroups_Manager::update_table_mysql_servers_for_monitor(bool lock) } SQLite3_result * MySQL_HostGroups_Manager::dump_table_mysql(const string& name) { + PROFILER1_BLOCK1(a); char * query = (char *)""; if (name == "mysql_aws_aurora_hostgroups") { query=(char *)"SELECT writer_hostgroup,reader_hostgroup,active,aurora_port,domain_name,max_lag_ms," @@ -2849,6 +2880,7 @@ void MySQL_HostGroups_Manager::increase_reset_counter() { wrunlock(); } void MySQL_HostGroups_Manager::push_MyConn_to_pool(MySQL_Connection *c, bool _lock) { + PROFILER1_BLOCK1(a); assert(c->parent); MySrvC *mysrvc=NULL; if (_lock) @@ -2890,6 +2922,7 @@ void MySQL_HostGroups_Manager::push_MyConn_to_pool(MySQL_Connection *c, bool _lo } void MySQL_HostGroups_Manager::push_MyConn_to_pool_array(MySQL_Connection **ca, unsigned int cnt) { + PROFILER1_BLOCK1(a); unsigned int i=0; MySQL_Connection *c=NULL; c=ca[i]; @@ -3458,6 +3491,7 @@ MySQL_Connection * MySrvConnList::get_random_MyConn(MySQL_Session *sess, bool ff } void MySQL_HostGroups_Manager::unshun_server_all_hostgroups(const char * address, uint16_t port, time_t t, int max_wait_sec, unsigned int *skip_hid) { + PROFILER1_BLOCK1(a); // we scan all hostgroups looking for a specific server to unshun // if skip_hid is not NULL , the specific hostgroup is skipped if (GloMTH->variables.hostgroup_manager_verbose >= 3) { @@ -3606,6 +3640,7 @@ void MySQL_HostGroups_Manager::destroy_MyConn_from_pool(MySQL_Connection *c, boo inline double get_prometheus_counter_val( std::map& counter_map, const std::string& endpoint_id ) { + PROFILER1_BLOCK1(a); const auto& counter_entry = counter_map.find(endpoint_id); double current_val = 0; @@ -3623,6 +3658,7 @@ void reset_hg_attrs_server_defaults(MySrvC* mysrvc) { } void update_hg_attrs_server_defaults(MySrvC* mysrvc, MyHGC* myhgc) { + PROFILER1_BLOCK1(a); if (mysrvc->weight == -1) { if (myhgc->servers_defaults.weight != -1) { mysrvc->weight = myhgc->servers_defaults.weight; @@ -3650,6 +3686,7 @@ void update_hg_attrs_server_defaults(MySrvC* mysrvc, MyHGC* myhgc) { } void MySQL_HostGroups_Manager::add(MySrvC *mysrvc, unsigned int _hid) { + PROFILER1_BLOCK1(a); proxy_debug(PROXY_DEBUG_MYSQL_CONNPOOL, 7, "Adding MySrvC %p (%s:%d) for hostgroup %d\n", mysrvc, mysrvc->address, mysrvc->port, _hid); // Since metrics for servers are stored per-endpoint; the metrics for a particular endpoint can live longer than the @@ -3670,6 +3707,7 @@ void MySQL_HostGroups_Manager::add(MySrvC *mysrvc, unsigned int _hid) { } void MySQL_HostGroups_Manager::replication_lag_action_inner(MyHGC *myhgc, const char *address, unsigned int port, int current_replication_lag) { + PROFILER1_BLOCK1(a); int j; for (j=0; j<(int)myhgc->mysrvs->cnt(); j++) { MySrvC *mysrvc=(MySrvC *)myhgc->mysrvs->servers->index(j); @@ -3722,6 +3760,7 @@ void MySQL_HostGroups_Manager::replication_lag_action_inner(MyHGC *myhgc, const } void MySQL_HostGroups_Manager::replication_lag_action(const std::list& mysql_servers) { + PROFILER1_BLOCK1(a); //this method does not use admin table, so this lock is not needed. //GloAdmin->mysql_servers_wrlock(); @@ -3774,6 +3813,7 @@ void MySQL_HostGroups_Manager::replication_lag_action(const std::listmysql_servers_wrlock(); wrlock(); @@ -3881,6 +3922,7 @@ void MySQL_HostGroups_Manager::group_replication_lag_action( } void MySQL_HostGroups_Manager::drop_all_idle_connections() { + PROFILER1_BLOCK1(a); // NOTE: the caller should hold wrlock int i, j; for (i=0; i<(int)MyHostGroups->len; i++) { @@ -4051,6 +4093,7 @@ int MySQL_HostGroups_Manager::get_multiple_idle_connections(int _hid, unsigned l } void MySQL_HostGroups_Manager::save_incoming_mysql_table(SQLite3_result *s, const string& name) { + PROFILER1_BLOCK1(a); SQLite3_result ** inc = NULL; if (name == "mysql_aws_aurora_hostgroups") { inc = &incoming_aws_aurora_hostgroups; @@ -4073,6 +4116,7 @@ void MySQL_HostGroups_Manager::save_incoming_mysql_table(SQLite3_result *s, cons } void MySQL_HostGroups_Manager::save_runtime_mysql_servers(SQLite3_result *s) { + PROFILER1_BLOCK1(a); if (runtime_mysql_servers) { delete runtime_mysql_servers; runtime_mysql_servers = nullptr; @@ -4081,6 +4125,7 @@ void MySQL_HostGroups_Manager::save_runtime_mysql_servers(SQLite3_result *s) { } void MySQL_HostGroups_Manager::save_mysql_servers_v2(SQLite3_result* s) { + PROFILER1_BLOCK1(a); if (incoming_mysql_servers_v2) { delete incoming_mysql_servers_v2; incoming_mysql_servers_v2 = nullptr; @@ -4089,6 +4134,7 @@ void MySQL_HostGroups_Manager::save_mysql_servers_v2(SQLite3_result* s) { } SQLite3_result* MySQL_HostGroups_Manager::get_current_mysql_table(const string& name) { + PROFILER1_BLOCK1(a); if (name == "mysql_aws_aurora_hostgroups") { return this->incoming_aws_aurora_hostgroups; } else if (name == "mysql_galera_hostgroups") { @@ -4112,6 +4158,7 @@ SQLite3_result* MySQL_HostGroups_Manager::get_current_mysql_table(const string& SQLite3_result * MySQL_HostGroups_Manager::SQL3_Free_Connections() { + PROFILER1_BLOCK1(a); const int colnum=13; proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 4, "Dumping Free Connections in Pool\n"); SQLite3_result *result=new SQLite3_result(colnum); @@ -4238,6 +4285,7 @@ void MySQL_HostGroups_Manager::p_update_connection_pool_update_counter( const std::string& endpoint_id, const std::map& labels, std::map& m_map, unsigned long long value, p_hg_dyn_counter::metric idx ) { + PROFILER1_BLOCK1(a); const auto& counter_id = m_map.find(endpoint_id); if (counter_id != m_map.end()) { const auto& cur_val = counter_id->second->Value(); @@ -4257,6 +4305,7 @@ void MySQL_HostGroups_Manager::p_update_connection_pool_update_gauge( const std::string& endpoint_id, const std::map& labels, std::map& m_map, unsigned long long value, p_hg_dyn_gauge::metric idx ) { + PROFILER1_BLOCK1(a); const auto& counter_id = m_map.find(endpoint_id); if (counter_id != m_map.end()) { counter_id->second->Set(value); @@ -4272,6 +4321,7 @@ void MySQL_HostGroups_Manager::p_update_connection_pool_update_gauge( } void MySQL_HostGroups_Manager::p_update_connection_pool() { + PROFILER1_BLOCK1(a); std::vector cur_servers_ids {}; wrlock(); for (int i = 0; i < static_cast(MyHostGroups->len); i++) { @@ -4369,6 +4419,7 @@ void MySQL_HostGroups_Manager::p_update_connection_pool() { } SQLite3_result * MySQL_HostGroups_Manager::SQL3_Connection_Pool(bool _reset, int *hid) { + PROFILER1_BLOCK1(a); const int colnum=14; proxy_debug(PROXY_DEBUG_MYSQL_CONNECTION, 4, "Dumping Connection Pool\n"); SQLite3_result *result=new SQLite3_result(colnum); @@ -4493,6 +4544,7 @@ SQLite3_result * MySQL_HostGroups_Manager::SQL3_Connection_Pool(bool _reset, int } void MySQL_HostGroups_Manager::read_only_action(char *hostname, int port, int read_only) { + PROFILER1_BLOCK1(a); // define queries const char *Q1B=(char *)"SELECT hostgroup_id,status FROM ( SELECT DISTINCT writer_hostgroup FROM mysql_replication_hostgroups JOIN mysql_servers WHERE (hostgroup_id=writer_hostgroup) AND hostname='%s' AND port=%d UNION SELECT DISTINCT writer_hostgroup FROM mysql_replication_hostgroups JOIN mysql_servers WHERE (hostgroup_id=reader_hostgroup) AND hostname='%s' AND port=%d) LEFT JOIN mysql_servers ON hostgroup_id=writer_hostgroup AND hostname='%s' AND port=%d"; const char *Q2A=(char *)"DELETE FROM mysql_servers WHERE hostname='%s' AND port=%d AND hostgroup_id IN (SELECT writer_hostgroup FROM mysql_replication_hostgroups WHERE writer_hostgroup=mysql_servers.hostgroup_id) AND status='OFFLINE_HARD'"; @@ -4845,6 +4897,7 @@ void MySQL_HostGroups_Manager::read_only_action(char *hostname, int port, int re * */ void MySQL_HostGroups_Manager::read_only_action_v2(const std::list& mysql_servers) { + PROFILER1_BLOCK1(a); bool update_mysql_servers_table = false; @@ -4993,6 +5046,7 @@ void MySQL_HostGroups_Manager::read_only_action_v2(const std::listlen; i++) { @@ -5069,6 +5124,7 @@ void MySQL_HostGroups_Manager::set_server_current_latency_us(char *hostname, int } void MySQL_HostGroups_Manager::p_update_metrics() { + PROFILER1_BLOCK1(a); p_update_counter(status.p_counter_array[p_hg_counter::servers_table_version], status.servers_table_version); // Update *server_connections* related metrics status.p_gauge_array[p_hg_gauge::server_connections_connected]->Set(status.server_connections_connected); @@ -5119,6 +5175,7 @@ void MySQL_HostGroups_Manager::p_update_metrics() { } SQLite3_result * MySQL_HostGroups_Manager::SQL3_Get_ConnPool_Stats() { + PROFILER1_BLOCK1(a); const int colnum=2; char buf[256]; char **pta=(char **)malloc(sizeof(char *)*colnum); @@ -5165,6 +5222,7 @@ SQLite3_result * MySQL_HostGroups_Manager::SQL3_Get_ConnPool_Stats() { unsigned long long MySQL_HostGroups_Manager::Get_Memory_Stats() { + PROFILER1_BLOCK1(a); unsigned long long intsize=0; wrlock(); MySrvC *mysrvc=NULL; @@ -5275,6 +5333,7 @@ bool Group_Replication_Info::update(int b, int r, int o, int mw, int mtb, bool _ } void MySQL_HostGroups_Manager::update_group_replication_set_offline(char *_hostname, int _port, int _writer_hostgroup, char *_error) { + PROFILER1_BLOCK1(a); int cols=0; int affected_rows=0; SQLite3_result *resultset=NULL; @@ -5378,6 +5437,7 @@ void MySQL_HostGroups_Manager::update_group_replication_set_offline(char *_hostn * @param _error Reason why the server has beens et as 'read_only'. */ void MySQL_HostGroups_Manager::update_group_replication_set_read_only(char *_hostname, int _port, int _writer_hostgroup, char *_error) { + PROFILER1_BLOCK1(a); int cols=0; int affected_rows=0; SQLite3_result *resultset=NULL; @@ -5495,6 +5555,7 @@ void MySQL_HostGroups_Manager::update_group_replication_set_read_only(char *_hos * @param _writer_hostgroup 'writer_hostgroup' of the cluster in which server is going to be placed as writer. */ void MySQL_HostGroups_Manager::update_group_replication_set_writer(char *_hostname, int _port, int _writer_hostgroup) { + PROFILER1_BLOCK1(a); int cols=0; int affected_rows=0; SQLite3_result *resultset=NULL; @@ -5680,6 +5741,7 @@ void MySQL_HostGroups_Manager::update_group_replication_set_writer(char *_hostna * @param _writer_hostgroup Target hostgroup on which perform the final server placement. */ void MySQL_HostGroups_Manager::converge_group_replication_config(int _writer_hostgroup) { + PROFILER1_BLOCK1(a); // we first gather info about the cluster pthread_mutex_lock(&Group_Replication_Info_mutex); @@ -5918,6 +5980,7 @@ Galera_Info::~Galera_Info() { } bool Galera_Info::update(int b, int r, int o, int mw, int mtb, bool _a, int _w, char *c) { + PROFILER1_BLOCK1(a); bool ret=false; __active=true; if (backup_writer_hostgroup!=b) { @@ -5968,6 +6031,7 @@ bool Galera_Info::update(int b, int r, int o, int mw, int mtb, bool _a, int _w, } void print_galera_nodes_last_status() { + PROFILER1_BLOCK1(a); std::unique_ptr result { new SQLite3_result(13) }; result->add_column_definition(SQLITE_TEXT,"hostname"); @@ -6026,6 +6090,7 @@ void print_galera_nodes_last_status() { } void MySQL_HostGroups_Manager::update_galera_set_offline(char *_hostname, int _port, int _writer_hostgroup, char *_error, bool soft) { + PROFILER1_BLOCK1(a); bool set_offline = false; int cols=0; int affected_rows=0; @@ -6182,6 +6247,7 @@ void MySQL_HostGroups_Manager::update_galera_set_offline(char *_hostname, int _p } void MySQL_HostGroups_Manager::update_galera_set_read_only(char *_hostname, int _port, int _writer_hostgroup, char *_error) { + PROFILER1_BLOCK1(a); int cols=0; int affected_rows=0; SQLite3_result *resultset=NULL; @@ -6261,6 +6327,7 @@ void MySQL_HostGroups_Manager::update_galera_set_read_only(char *_hostname, int } Galera_Info *MySQL_HostGroups_Manager::get_galera_node_info(int hostgroup) { + PROFILER1_BLOCK1(a); pthread_mutex_lock(&Galera_Info_mutex); auto it2 = Galera_Info_Map.find(hostgroup); Galera_Info *info = nullptr; @@ -6273,6 +6340,7 @@ Galera_Info *MySQL_HostGroups_Manager::get_galera_node_info(int hostgroup) { } void MySQL_HostGroups_Manager::update_galera_set_writer(char *_hostname, int _port, int _writer_hostgroup) { + PROFILER1_BLOCK1(a); std::lock_guard lock(galera_set_writer_mutex); int cols=0; int affected_rows=0; @@ -6488,6 +6556,7 @@ void MySQL_HostGroups_Manager::update_galera_set_writer(char *_hostname, int _po // * mysql_servers_incoming has already entries copied from mysql_servers and ready to be loaded // at this moment, it is only used to check if there are more than one writer void MySQL_HostGroups_Manager::converge_galera_config(int _writer_hostgroup) { + PROFILER1_BLOCK1(a); // we first gather info about the cluster pthread_mutex_lock(&Galera_Info_mutex); @@ -6761,6 +6830,7 @@ void MySQL_HostGroups_Manager::p_update_mysql_gtid_executed() { } SQLite3_result * MySQL_HostGroups_Manager::get_stats_mysql_gtid_executed() { + PROFILER1_BLOCK1(a); const int colnum = 4; SQLite3_result * result = new SQLite3_result(colnum); result->add_column_definition(SQLITE_TEXT,"hostname"); @@ -6928,6 +6998,7 @@ class MySQL_Errors_stats { }; void MySQL_HostGroups_Manager::add_mysql_errors(int hostgroup, char *hostname, int port, char *username, char *address, char *schemaname, int err_no, char *last_error) { + PROFILER1_BLOCK1(a); SpookyHash myhash; uint64_t hash1; uint64_t hash2; @@ -6983,6 +7054,7 @@ void MySQL_HostGroups_Manager::add_mysql_errors(int hostgroup, char *hostname, i } SQLite3_result * MySQL_HostGroups_Manager::get_mysql_errors(bool reset) { + PROFILER1_BLOCK1(a); SQLite3_result *result=new SQLite3_result(11); pthread_mutex_lock(&mysql_errors_mutex); result->add_column_definition(SQLITE_TEXT,"hid"); @@ -7206,6 +7278,7 @@ void init_myhgc_servers_defaults(char* servers_defaults, MyHGC* myhgc) { } void MySQL_HostGroups_Manager::generate_mysql_hostgroup_attributes_table() { + PROFILER1_BLOCK1(a); if (incoming_hostgroup_attributes==NULL) { return; } @@ -7326,6 +7399,7 @@ void MySQL_HostGroups_Manager::generate_mysql_hostgroup_attributes_table() { } void MySQL_HostGroups_Manager::generate_mysql_aws_aurora_hostgroups_table() { + PROFILER1_BLOCK1(a); if (incoming_aws_aurora_hostgroups==NULL) { return; } @@ -7425,6 +7499,7 @@ void MySQL_HostGroups_Manager::generate_mysql_aws_aurora_hostgroups_table() { //void MySQL_HostGroups_Manager::aws_aurora_replication_lag_action(int _whid, int _rhid, char *address, unsigned int port, float current_replication_lag, bool enable, bool verbose) { // this function returns false is the server is in the wrong HG bool MySQL_HostGroups_Manager::aws_aurora_replication_lag_action(int _whid, int _rhid, char *_server_id, float current_replication_lag_ms, bool enable, bool is_writer, bool verbose) { + PROFILER1_BLOCK1(a); bool ret = false; // return false by default bool reader_found_in_whg = false; if (is_writer) { @@ -7530,6 +7605,7 @@ bool MySQL_HostGroups_Manager::aws_aurora_replication_lag_action(int _whid, int int MySQL_HostGroups_Manager::create_new_server_in_hg( uint32_t hid, const srv_info_t& srv_info, const srv_opts_t& srv_opts ) { + PROFILER1_BLOCK1(a); int32_t res = -1; MySrvC* mysrvc = find_server_in_hg(hid, srv_info.addr, srv_info.port); @@ -7573,6 +7649,7 @@ int MySQL_HostGroups_Manager::create_new_server_in_hg( } int MySQL_HostGroups_Manager::remove_server_in_hg(uint32_t hid, const string& addr, uint16_t port) { + PROFILER1_BLOCK1(a); MySrvC* mysrvc = find_server_in_hg(hid, addr, port); if (mysrvc == nullptr) { return -1; @@ -7609,6 +7686,7 @@ int MySQL_HostGroups_Manager::remove_server_in_hg(uint32_t hid, const string& ad // FIXME: complete this!! void MySQL_HostGroups_Manager::update_aws_aurora_set_writer(int _whid, int _rhid, char *_server_id, bool verbose) { + PROFILER1_BLOCK1(a); int cols=0; int affected_rows=0; SQLite3_result *resultset=NULL; @@ -7843,6 +7921,7 @@ void MySQL_HostGroups_Manager::update_aws_aurora_set_writer(int _whid, int _rhid } void MySQL_HostGroups_Manager::update_aws_aurora_set_reader(int _whid, int _rhid, char *_server_id) { + PROFILER1_BLOCK1(a); int cols=0; int affected_rows=0; SQLite3_result *resultset=NULL; @@ -7969,6 +8048,7 @@ const char SELECT_AWS_AURORA_SERVERS_FOR_MONITOR[] { }; void MySQL_HostGroups_Manager::update_aws_aurora_hosts_monitor_resultset(bool lock) { + PROFILER1_BLOCK1(a); if (lock) { pthread_mutex_lock(&AWS_Aurora_Info_mutex); pthread_mutex_lock(&GloMyMon->aws_aurora_mutex); @@ -7997,6 +8077,7 @@ void MySQL_HostGroups_Manager::update_aws_aurora_hosts_monitor_resultset(bool lo } MySrvC* MySQL_HostGroups_Manager::find_server_in_hg(unsigned int _hid, const std::string& addr, int port) { + PROFILER1_BLOCK1(a); MySrvC* f_server = nullptr; MyHGC* myhgc = nullptr; @@ -8022,6 +8103,7 @@ MySrvC* MySQL_HostGroups_Manager::find_server_in_hg(unsigned int _hid, const std } void MySQL_HostGroups_Manager::HostGroup_Server_Mapping::copy_if_not_exists(Type dest_type, Type src_type) { + PROFILER1_BLOCK1(a); assert(dest_type != src_type); @@ -8074,6 +8156,7 @@ void MySQL_HostGroups_Manager::HostGroup_Server_Mapping::copy_if_not_exists(Type } void MySQL_HostGroups_Manager::HostGroup_Server_Mapping::remove(Type type, size_t index) { + PROFILER1_BLOCK1(a); std::vector& nodes = mapping[type]; @@ -8110,6 +8193,7 @@ unsigned int MySQL_HostGroups_Manager::HostGroup_Server_Mapping::get_hostgroup_i } MySrvC* MySQL_HostGroups_Manager::HostGroup_Server_Mapping::insert_HGM(unsigned int hostgroup_id, const MySrvC* srv) { + PROFILER1_BLOCK1(a); MyHGC* myhgc = myHGM->MyHGC_lookup(hostgroup_id); From 82aaadbb967de67ae39307f994b1350fa0be6e4b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Wed, 24 Jan 2024 04:31:38 +0000 Subject: [PATCH 8/9] Allows c_tokenizer to be compiled with TAP tests --- lib/c_tokenizer.cpp | 9 +++++++++ test/tap/tests/Makefile | 8 ++++---- 2 files changed, 13 insertions(+), 4 deletions(-) diff --git a/lib/c_tokenizer.cpp b/lib/c_tokenizer.cpp index 57ab1d5f7f..5d4a4b2c12 100644 --- a/lib/c_tokenizer.cpp +++ b/lib/c_tokenizer.cpp @@ -1,6 +1,15 @@ /* c_tokenizer.c */ // Borrowed from http://www.cplusplus.com/faq/sequences/strings/split/ + +#ifdef PROXYSQL_PROFILER_TAP +// c_tokenizer.cpp is being compiled with a TAP test +// thus disable the profiler +#define PROXYSQL_PROFILER +#define PROFILER1_BLOCK1(a) +#endif // PROXYSQL_PROFILER_TAP + + #include #include #include diff --git a/test/tap/tests/Makefile b/test/tap/tests/Makefile index 422ead51cc..384d742cad 100644 --- a/test/tap/tests/Makefile +++ b/test/tap/tests/Makefile @@ -232,11 +232,11 @@ generate_set_session_csv: generate_set_session_csv.cpp aurora: aurora.cpp $(TAP_LDIR)/libtap.so g++ -DTEST_AURORA $< ../tap/SQLite3_Server.cpp $(IDIRS) $(LDIRS) $(OPT) $(OBJ) $(MYLIBSJEMALLOC) $(MYLIBS) $(STATIC_LIBS) -o $@ -test_tokenizer-t: test_tokenizer-t.cpp $(TAP_LDIR)/libtap.so - g++ $< $(IDIRS) $(LDIRS) $(OPT) $(MYLIBS) -o $@ +test_tokenizer-t: test_tokenizer-t.cpp $(PROXYSQL_LDIR)/c_tokenizer.cpp + g++ $^ -DPROXYSQL_PROFILER_TAP $(IDIRS) $(LDIRS) $(OPT) $(MYLIBS) -o $@ -test_mysql_query_digests_stages-t: test_mysql_query_digests_stages-t.cpp $(TAP_LDIR)/libtap.so - g++ $< $(IDIRS) $(LDIRS) $(OPT) $(MYLIBS) -o $@ +test_mysql_query_digests_stages-t: test_mysql_query_digests_stages-t.cpp $(PROXYSQL_LDIR)/c_tokenizer.cpp + g++ $^ -DPROXYSQL_PROFILER_TAP $(IDIRS) $(LDIRS) $(OPT) $(MYLIBS) -o $@ sqlite3-t: sqlite3-t.cpp $(TAP_LDIR)/libtap.so g++ $< $(IDIRS) $(LDIRS) $(OPT) $(MYLIBS) $(LIBCOREDUMPERAR) -o $@ From cde8432d45a520560e35c2c57ceaf7f1c0029918 Mon Sep 17 00:00:00 2001 From: Rene Cannao Date: Wed, 24 Jan 2024 11:46:22 +0000 Subject: [PATCH 9/9] Improved profiling --- lib/ProxySQL_Profiler.cpp | 104 +++++++++++++++++++++----------------- 1 file changed, 58 insertions(+), 46 deletions(-) diff --git a/lib/ProxySQL_Profiler.cpp b/lib/ProxySQL_Profiler.cpp index 0cde5c1e4d..99a89c01dd 100644 --- a/lib/ProxySQL_Profiler.cpp +++ b/lib/ProxySQL_Profiler.cpp @@ -76,27 +76,27 @@ void insert_element(unordered_map& MyMap, vector& wo } } -void retrieve_total_leaf_times(unordered_map& MyMap) { - total_leaf_times1 = 0; - total_leaf_times2 = 0; - total_leaf_times3 = 0; +void retrieve_total_leaf_times(unordered_map& MyMap, bool root) { for (auto it = MyMap.begin() ; it != MyMap.end() ; it++) { Counter2 *c2 = it->second; - c2->tottime1 = c2->tottime; + c2->tottime1 = 0; c2->tottime2 = 0; - c2->tottime3 = c2->tottime;; + c2->tottime3 = 0; if (c2->map.size()) { - retrieve_total_leaf_times(c2->map); + retrieve_total_leaf_times(c2->map, false); for (auto it2 = c2->map.begin() ; it2 != c2->map.end(); it2++) { - c2->tottime2 += it2->second->tottime2; // time of all the leaves from this branch - c2->tottime3 -= it2->second->tottime; // its own time only + c2->tottime1 += it2->second->tottime; + //c2->tottime2 += it2->second->tottime2; // time of all the leaves from this branch + //c2->tottime3 += it2->second->tottime; // its own time only } } else { c2->tottime2 = c2->tottime; // time of only leaves - total_leaf_times2 += c2->tottime2; + //total_leaf_times2 += c2->tottime2; + } + if (root == false) { + total_leaf_times1 += c2->tottime - c2->tottime1; // its own time only + total_leaf_times3 += c2->tottime3; } - total_leaf_times1 += c2->tottime; - total_leaf_times3 += c2->tottime3; } } @@ -105,6 +105,9 @@ void print_values(string& output, unordered_map& MyMap, stri Counter2 *c2 = it->second; string last_word = c2->last_word; string path = parent + last_word + " "; + if (parent == "") { + output += "```mermaid\nflowchart LR\n"; + } if (c2->map.size() == 0) { if (last_word != "") { auto it = GlobalProfiling1.find(path); @@ -115,33 +118,42 @@ void print_values(string& output, unordered_map& MyMap, stri } } else { print_values(output, c2->map, path, algo); - output += c2->name + "[" + last_word + "]\n"; - char buf[10]; - for (auto it2 = c2->map.begin() ; it2 != c2->map.end() ; it2++) { - Counter2 *c3 = it2->second; - double pct = 0; - unsigned long long tt = 0; - switch (algo) { - case 1: - tt = c3->tottime1; - pct = (double)tt * 100 / total_leaf_times1; - break; - case 2: - tt = c3->tottime2; - pct = (double)tt * 100 / total_leaf_times2; - break; - case 3: - tt = c3->tottime3; - pct = (double)tt * 100 / total_leaf_times3; - break; - default: - assert(0); - break; - } - sprintf(buf, "%.2f", pct); - output += c3->name + "[\"" + c3->last_word + "\n" + to_string(tt) + " (" + string(buf) + "%)\"]\n"; - output += c2->name + " -- " + to_string(c3->cnt) + " --> " + c3->name + "\n"; - } + } + char buf[64]; +/* + output += c2->name + "[\"" + last_word + "\"]\n"; +*/ + double pct = 0; + unsigned long long tt = 0; + if (parent != "" ) { + switch (algo) { + case 1: + tt = c2->tottime; + pct = tt * 100; + pct /= total_leaf_times1; + //pct = (double)tt * 100 / total_leaf_times1; + break; + case 2: + tt = c2->tottime2; + pct = (double)tt * 100 / total_leaf_times2; + break; + case 3: + tt = c2->tottime3; + pct = (double)tt * 100 / total_leaf_times3; + break; + default: + assert(0); + break; + } + } + sprintf(buf, "%.2f", pct); + output += c2->name + "[\"" + c2->last_word + "\n" + to_string(tt) + " (" + string(buf) + "%)\"]\n"; + for (auto it2 = c2->map.begin() ; it2 != c2->map.end() ; it2++) { + Counter2 *c3 = it2->second; + output += c2->name + " -- " + to_string(c3->cnt) + " --> " + c3->name + "\n"; + } + if (parent == "") { + output += "```\n"; } } } @@ -149,7 +161,7 @@ void print_values(string& output, unordered_map& MyMap, stri void GenerateMermaid1(string& output) { MyMap = {}; MMID = 1; - output = "```mermaid\nflowchart LR\n"; + output = ""; const std::lock_guard lock(GlobalProfiling1_mutex); for (auto it = GlobalProfiling1.begin() ; it != GlobalProfiling1.end() ; it++) { vector words = {}; @@ -157,15 +169,15 @@ void GenerateMermaid1(string& output) { CounterProfiling1& c = it->second; insert_element(MyMap, words, 0, c); } - retrieve_total_leaf_times(MyMap); + total_leaf_times1 = 0; + total_leaf_times2 = 0; + total_leaf_times3 = 0; + retrieve_total_leaf_times(MyMap, true); print_values(output, MyMap,"",1); - output += "```\n"; - output += "```mermaid\nflowchart LR\n"; +/* // DO NOT USE THIS FOR NOW , MATH IS WRONG print_values(output, MyMap,"",2); - output += "```\n"; - output += "```mermaid\nflowchart LR\n"; print_values(output, MyMap,"",3); - output += "```"; +*/ } Profiler1::Profiler1(int l, const char *__file, int __line, const char *__func) {