From 6a2d52f610440d05d5a1e412d7734754953483fb Mon Sep 17 00:00:00 2001 From: Rene Cannao Date: Sat, 10 Aug 2024 12:24:12 +0000 Subject: [PATCH 01/19] Adding a circular buffer to MySQL_Logger --- include/MySQL_Logger.hpp | 27 +++++ include/MySQL_Thread.h | 1 + include/proxysql_structs.h | 2 + lib/MySQL_Logger.cpp | 235 +++++++++++++++++++++++++++++++++---- lib/MySQL_Thread.cpp | 10 ++ 5 files changed, 249 insertions(+), 26 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index 57f5c4bed7..f6c182da2d 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -2,6 +2,7 @@ #define __CLASS_MYSQL_LOGGER_H #include "proxysql.h" #include "cpp.h" +#include #define PROXYSQL_LOGGER_PTHREAD_MUTEX @@ -29,6 +30,7 @@ class MySQL_Event { bool have_affected_rows; bool have_rows_sent; bool have_gtid; + bool free_on_delete; // this bool defines if pointers should be freed when the destructor is called uint64_t affected_rows; uint64_t last_insert_id; uint64_t rows_sent; @@ -36,6 +38,8 @@ class MySQL_Event { const char * gtid; public: MySQL_Event(log_event_type _et, uint32_t _thread_id, char * _username, char * _schemaname , uint64_t _start_time , uint64_t _end_time , uint64_t _query_digest, char *_client, size_t _client_len); + MySQL_Event(const MySQL_Event &other); + ~MySQL_Event(); uint64_t write(std::fstream *f, MySQL_Session *sess); uint64_t write_query_format_1(std::fstream *f); uint64_t write_query_format_2_json(std::fstream *f); @@ -49,6 +53,28 @@ class MySQL_Event { void set_gtid(MySQL_Session *sess); }; +class MySQL_Logger_CircularBuffer { +private: + MySQL_Event **event_buffer; + size_t head; + size_t tail; + std::mutex mutex; + +public: + // we allow potential dirty read of buffer_size. + // this is not a problem because operation on the object are + // then performed holding the mutex + std::atomic buffer_size; + MySQL_Logger_CircularBuffer(size_t size); + + ~MySQL_Logger_CircularBuffer(); + + void insert(MySQL_Event *event); + std::pair get_all_events(); + void resize(size_t new_size); +}; + + class MySQL_Logger { private: struct { @@ -94,6 +120,7 @@ class MySQL_Logger { void flush(); void wrlock(); void wrunlock(); + MySQL_Logger_CircularBuffer * MyLogCB; }; diff --git a/include/MySQL_Thread.h b/include/MySQL_Thread.h index ddd663056d..3cfa58eaae 100644 --- a/include/MySQL_Thread.h +++ b/include/MySQL_Thread.h @@ -534,6 +534,7 @@ class MySQL_Threads_Handler int connpoll_reset_queue_length; char *eventslog_filename; int eventslog_filesize; + int eventslog_memory_history_size; int eventslog_default_log; int eventslog_format; char *auditlog_filename; diff --git a/include/proxysql_structs.h b/include/proxysql_structs.h index deac187de0..3a1cfee2b3 100644 --- a/include/proxysql_structs.h +++ b/include/proxysql_structs.h @@ -892,6 +892,7 @@ __thread char * mysql_thread___ssl_p2s_crlpath; /* variables used by events log */ __thread char * mysql_thread___eventslog_filename; __thread int mysql_thread___eventslog_filesize; +__thread int mysql_thread___eventslog_memory_history_size; __thread int mysql_thread___eventslog_default_log; __thread int mysql_thread___eventslog_format; @@ -1064,6 +1065,7 @@ extern __thread char * mysql_thread___ssl_p2s_crlpath; /* variables used by events log */ extern __thread char * mysql_thread___eventslog_filename; extern __thread int mysql_thread___eventslog_filesize; +extern __thread int mysql_thread___eventslog_memory_history_size; extern __thread int mysql_thread___eventslog_default_log; extern __thread int mysql_thread___eventslog_format; diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index 6dd183846c..c4047a6c7a 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -1,6 +1,7 @@ #include #include "proxysql.h" #include "cpp.h" +#include #include "MySQL_Data_Stream.h" #include "query_processor.h" @@ -62,6 +63,66 @@ MySQL_Event::MySQL_Event (log_event_type _et, uint32_t _thread_id, char * _usern rows_sent=0; client_stmt_id=0; gtid = NULL; + free_on_delete = false; // by default, this is false. This because pointers do not belong to this object +} + +MySQL_Event::MySQL_Event(const MySQL_Event &other) { + + // Initialize basic members using memcpy + memcpy(this, &other, sizeof(MySQL_Event)); + + // Copy char pointers using strdup (if not null) + if (other.username != nullptr) { + username = strdup(other.username); + } + if (other.schemaname != nullptr) { + schemaname = strdup(other.schemaname); + } + // query_ptr is NOT null terminated + if (other.query_ptr != nullptr) { + query_ptr = (char *)malloc(query_len+1); + memcpy(query_ptr, other.query_ptr, query_len); + query_ptr[query_len] = '\0'; + } + // server is NOT null terminated + if (other.server != nullptr) { + server = (char *)malloc(server_len+1); + memcpy(server, other.server, server_len); + server[server_len] = '\0'; + } + // client is NOT null terminated + if (other.client != nullptr) { + client = (char *)malloc(client_len+1); + memcpy(client, other.client, client_len); + client[client_len] = '\0'; + } + if (other.extra_info != nullptr) { + extra_info = strdup(other.extra_info); + } + free_on_delete = true; // pointers belong to this object +} + +MySQL_Event::~MySQL_Event() { + if (free_on_delete == true) { + if (username != nullptr) { + free(username); username = nullptr; + } + if (schemaname != nullptr) { + free(schemaname); schemaname = nullptr; + } + if (query_ptr != nullptr) { + free(query_ptr); query_ptr = nullptr; + } + if (server != nullptr) { + free(server); server = nullptr; + } + if (client != nullptr) { + free(client); client = nullptr; + } + if (extra_info != nullptr) { + free(extra_info); extra_info = nullptr; + } + } } void MySQL_Event::set_client_stmt_id(uint32_t client_stmt_id) { @@ -289,7 +350,7 @@ uint64_t MySQL_Event::write_query_format_1(std::fstream *f) { // for performance reason, we are moving the write lock // right before the write to disk //GloMyLogger->wrlock(); - //move wrlock() function to log_request() function, avoid to get a null pointer in a multithreaded environment + //move wrlock() function to log_request() function, avoid to get a null pointer in a multithreaded environment // write total length , fixed size f->write((const char *)&total_bytes,sizeof(uint64_t)); @@ -459,7 +520,7 @@ uint64_t MySQL_Event::write_query_format_2_json(std::fstream *f) { // for performance reason, we are moving the write lock // right before the write to disk //GloMyLogger->wrlock(); - //move wrlock() function to log_request() function, avoid to get a null pointer in a multithreaded environment + //move wrlock() function to log_request() function, avoid to get a null pointer in a multithreaded environment *f << j.dump(-1, ' ', false, json::error_handler_t::replace) << std::endl; return total_bytes; // always 0 @@ -487,6 +548,7 @@ MySQL_Logger::MySQL_Logger() { audit.logfile=NULL; audit.log_file_id=0; audit.max_log_file_size=100*1024*1024; + MyLogCB = new MySQL_Logger_CircularBuffer(0); }; MySQL_Logger::~MySQL_Logger() { @@ -498,13 +560,14 @@ MySQL_Logger::~MySQL_Logger() { free(audit.datadir); } free(audit.base_filename); + delete MyLogCB; }; void MySQL_Logger::wrlock() { #ifdef PROXYSQL_LOGGER_PTHREAD_MUTEX pthread_mutex_lock(&wmutex); #else - spin_wrlock(&rwlock); + spin_wrlock(&rwlock); #endif }; @@ -512,7 +575,7 @@ void MySQL_Logger::wrunlock() { #ifdef PROXYSQL_LOGGER_PTHREAD_MUTEX pthread_mutex_unlock(&wmutex); #else - spin_wrunlock(&rwlock); + spin_wrunlock(&rwlock); #endif }; @@ -674,8 +737,11 @@ void MySQL_Logger::audit_set_datadir(char *s) { }; void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds) { - if (events.enabled==false) return; - if (events.logfile==NULL) return; + int elmhs = mysql_thread___eventslog_memory_history_size; + if (elmhs == 0) { + 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 // due to a failed 'CONNECTION_RESET'. Because this scenario isn't a client request, we just return. if (sess->client_myds==NULL || sess->client_myds->myconn== NULL) return; @@ -791,17 +857,30 @@ void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds) { // right before the write to disk //wrlock(); - //add a mutex lock in a multithreaded environment, avoid to get a null pointer of events.logfile that leads to the program coredump - GloMyLogger->wrlock(); - me.write(events.logfile, sess); + if ((events.enabled == true) && (events.logfile != nullptr)) { + //add a mutex lock in a multithreaded environment, avoid to get a null pointer of events.logfile that leads to the program coredump + GloMyLogger->wrlock(); + + me.write(events.logfile, sess); - unsigned long curpos=events.logfile->tellp(); - if (curpos > events.max_log_file_size) { - events_flush_log_unlocked(); + unsigned long curpos=events.logfile->tellp(); + if (curpos > events.max_log_file_size) { + events_flush_log_unlocked(); + } + wrunlock(); + } + if (MyLogCB->buffer_size != 0) { + MySQL_Event *me2 = new MySQL_Event(me); + MyLogCB->insert(me2); +#if 1 + for (int i=0; i<10000; i++) { + MySQL_Event *me2 = new MySQL_Event(me); + MyLogCB->insert(me2); + } +#endif // 1 } - wrunlock(); if (cl && sess->client_myds->addr.port) { free(ca); @@ -816,7 +895,7 @@ void MySQL_Logger::log_audit_entry(log_event_type _et, MySQL_Session *sess, MySQ if (audit.logfile==NULL) return; if (sess == NULL) return; - if (sess->client_myds == NULL) return; + if (sess->client_myds == NULL) return; MySQL_Connection_userinfo *ui= NULL; if (sess) { @@ -941,7 +1020,7 @@ void MySQL_Logger::log_audit_entry(log_event_type _et, MySQL_Session *sess, MySQ //wrlock(); //add a mutex lock in a multithreaded environment, avoid to get a null pointer of events.logfile that leads to the program coredump - GloMyLogger->wrlock(); + GloMyLogger->wrlock(); me.write(audit.logfile, sess); @@ -1004,15 +1083,15 @@ unsigned int MySQL_Logger::events_find_next_id() { free(eval_dirname); free(eval_filename); } - if (eval_pathname) { - free(eval_pathname); - } + if (eval_pathname) { + free(eval_pathname); + } return maxidx; } else { - /* could not open directory */ + /* could not open directory */ proxy_error("Unable to open datadir: %s\n", eval_dirname); exit(EXIT_FAILURE); - } + } return 0; } @@ -1050,19 +1129,123 @@ unsigned int MySQL_Logger::audit_find_next_id() { free(eval_dirname); free(eval_filename); } - if (eval_pathname) { - free(eval_pathname); - } + if (eval_pathname) { + free(eval_pathname); + } return maxidx; } else { - /* could not open directory */ + /* could not open directory */ proxy_error("Unable to open datadir: %s\n", eval_dirname); exit(EXIT_FAILURE); - } + } return 0; } void MySQL_Logger::print_version() { - fprintf(stderr,"Standard ProxySQL MySQL Logger rev. %s -- %s -- %s\n", PROXYSQL_MYSQL_LOGGER_VERSION, __FILE__, __TIMESTAMP__); + fprintf(stderr,"Standard ProxySQL MySQL Logger rev. %s -- %s -- %s\n", PROXYSQL_MYSQL_LOGGER_VERSION, __FILE__, __TIMESTAMP__); }; +MySQL_Logger_CircularBuffer::MySQL_Logger_CircularBuffer(size_t size) { + head = 0; + tail = 0; + buffer_size = size; + event_buffer = new MySQL_Event*[buffer_size]; +} + +MySQL_Logger_CircularBuffer::~MySQL_Logger_CircularBuffer() { + for (size_t i = 0; i < buffer_size; ++i) { + if (event_buffer[i] != nullptr) { + delete event_buffer[i]; + } + } + delete[] event_buffer; +} + +void MySQL_Logger_CircularBuffer::resize(size_t new_size) { + std::lock_guard lock(mutex); + + if (new_size == buffer_size) { + return; // No need to resize + } + + // Create the new buffer + MySQL_Event **new_buffer = new MySQL_Event*[new_size]; + + // Handle the case when initial buffer size is 0 + if (buffer_size == 0) { + // No need to copy or delete; just update the members + delete[] event_buffer; + event_buffer = new_buffer; + buffer_size = new_size; + head = 0; + tail = 0; + return; + } + + // Copy events from the old buffer and delete those not copied + size_t num_events = (head >= tail) ? (head - tail) : (buffer_size + head - tail); + size_t copy_count = std::min(num_events, new_size); + + size_t i = 0; + for (size_t j = (tail + buffer_size - copy_count) % buffer_size; j != tail; j = (j + 1) % buffer_size) { + new_buffer[i++] = event_buffer[j]; + } + + // Delete events that were not copied + for (size_t j = 0; j < buffer_size; ++j) { + if (event_buffer[j] != nullptr && event_buffer[j] != new_buffer[j % new_size]) { + delete event_buffer[j]; + } + } + + // Delete the old buffer + delete[] event_buffer; + + // Update the members + event_buffer = new_buffer; + buffer_size = new_size; + head = copy_count; + tail = 0; +} + + +void MySQL_Logger_CircularBuffer::insert(MySQL_Event *event) { + std::lock_guard lock(mutex); + + // Insert the new event + event_buffer[head] = event; + + // Move head forward + head = (head + 1) % buffer_size; + + // Update tail if necessary (if head is about to overwrite tail) + if (head == tail) { + // Delete the oldest element if it's not null + if (event_buffer[tail] != nullptr) { + delete event_buffer[tail]; + } + + // Move tail forward + tail = (tail + 1) % buffer_size; + } +} + + +std::pair MySQL_Logger_CircularBuffer::get_all_events() { + std::lock_guard lock(mutex); + + size_t num_events = (head >= tail) ? (head - tail) : (buffer_size + head - tail); + MySQL_Event **events = new MySQL_Event*[num_events]; + + size_t i = 0; + // Iterate from tail to head, copying the events + for (size_t j = tail; j != head; j = (j + 1) % buffer_size) { + events[i++] = event_buffer[j]; + } + + // Reset head and tail + head = tail; // Set head to tail to mark the buffer as empty + + return std::make_pair(events, num_events); +} + diff --git a/lib/MySQL_Thread.cpp b/lib/MySQL_Thread.cpp index 4df3d97429..e5036c994f 100644 --- a/lib/MySQL_Thread.cpp +++ b/lib/MySQL_Thread.cpp @@ -349,6 +349,7 @@ static char * mysql_thread_variables_names[]= { (char *)"enable_load_data_local_infile", (char *)"eventslog_filename", (char *)"eventslog_filesize", + (char *)"eventslog_memory_history_size", (char *)"eventslog_default_log", (char *)"eventslog_format", (char *)"auditlog_filename", @@ -1069,6 +1070,7 @@ MySQL_Threads_Handler::MySQL_Threads_Handler() { variables.server_version=strdup((char *)"8.0.11"); // changed in 2.6.0 , was 5.5.30 variables.eventslog_filename=strdup((char *)""); // proxysql-mysql-eventslog is recommended variables.eventslog_filesize=100*1024*1024; + variables.eventslog_memory_history_size=0; variables.eventslog_default_log=0; variables.eventslog_format=1; variables.auditlog_filename=strdup((char *)""); @@ -2240,6 +2242,7 @@ char ** MySQL_Threads_Handler::get_variables_list() { // logs VariablesPointers_int["auditlog_filesize"] = make_tuple(&variables.auditlog_filesize, 1024*1024, 1*1024*1024*1024, false); VariablesPointers_int["eventslog_filesize"] = make_tuple(&variables.eventslog_filesize, 1024*1024, 1*1024*1024*1024, false); + VariablesPointers_int["eventslog_memory_history_size"] = make_tuple(&variables.eventslog_memory_history_size, 0, 8*1024*1024, false); VariablesPointers_int["eventslog_default_log"] = make_tuple(&variables.eventslog_default_log, 0, 1, false); // various VariablesPointers_int["long_query_time"] = make_tuple(&variables.long_query_time, 0, 20*24*3600*1000, false); @@ -4368,6 +4371,13 @@ void MySQL_Thread::refresh_variables() { REFRESH_VARIABLE_CHAR(server_version); REFRESH_VARIABLE_INT(eventslog_filesize); + REFRESH_VARIABLE_INT(eventslog_memory_history_size); + { + int elmhs = mysql_thread___eventslog_memory_history_size; + if (GloMyLogger->MyLogCB->buffer_size != elmhs) { + GloMyLogger->MyLogCB->resize(elmhs); + } + } REFRESH_VARIABLE_INT(eventslog_default_log); REFRESH_VARIABLE_INT(eventslog_format); REFRESH_VARIABLE_CHAR(eventslog_filename); From d92e57f83a470433aef29f92a92da4bb80f3c1e2 Mon Sep 17 00:00:00 2001 From: Rene Cannao Date: Sat, 10 Aug 2024 16:01:07 +0000 Subject: [PATCH 02/19] Renamed mysql-eventslog_memory_history_size to mysql-eventslog_buffer_history_size --- include/MySQL_Thread.h | 2 +- include/proxysql_structs.h | 4 ++-- lib/MySQL_Logger.cpp | 2 +- lib/MySQL_Thread.cpp | 10 +++++----- 4 files changed, 9 insertions(+), 9 deletions(-) diff --git a/include/MySQL_Thread.h b/include/MySQL_Thread.h index 3cfa58eaae..eb4ad1a48d 100644 --- a/include/MySQL_Thread.h +++ b/include/MySQL_Thread.h @@ -534,7 +534,7 @@ class MySQL_Threads_Handler int connpoll_reset_queue_length; char *eventslog_filename; int eventslog_filesize; - int eventslog_memory_history_size; + int eventslog_buffer_history_size; int eventslog_default_log; int eventslog_format; char *auditlog_filename; diff --git a/include/proxysql_structs.h b/include/proxysql_structs.h index 3a1cfee2b3..9809527299 100644 --- a/include/proxysql_structs.h +++ b/include/proxysql_structs.h @@ -892,7 +892,7 @@ __thread char * mysql_thread___ssl_p2s_crlpath; /* variables used by events log */ __thread char * mysql_thread___eventslog_filename; __thread int mysql_thread___eventslog_filesize; -__thread int mysql_thread___eventslog_memory_history_size; +__thread int mysql_thread___eventslog_buffer_history_size; __thread int mysql_thread___eventslog_default_log; __thread int mysql_thread___eventslog_format; @@ -1065,7 +1065,7 @@ extern __thread char * mysql_thread___ssl_p2s_crlpath; /* variables used by events log */ extern __thread char * mysql_thread___eventslog_filename; extern __thread int mysql_thread___eventslog_filesize; -extern __thread int mysql_thread___eventslog_memory_history_size; +extern __thread int mysql_thread___eventslog_buffer_history_size; extern __thread int mysql_thread___eventslog_default_log; extern __thread int mysql_thread___eventslog_format; diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index c4047a6c7a..e896891009 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -737,7 +737,7 @@ void MySQL_Logger::audit_set_datadir(char *s) { }; void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds) { - int elmhs = mysql_thread___eventslog_memory_history_size; + int elmhs = mysql_thread___eventslog_buffer_history_size; if (elmhs == 0) { if (events.enabled==false) return; if (events.logfile==NULL) return; diff --git a/lib/MySQL_Thread.cpp b/lib/MySQL_Thread.cpp index e5036c994f..4ce926b84a 100644 --- a/lib/MySQL_Thread.cpp +++ b/lib/MySQL_Thread.cpp @@ -349,7 +349,7 @@ static char * mysql_thread_variables_names[]= { (char *)"enable_load_data_local_infile", (char *)"eventslog_filename", (char *)"eventslog_filesize", - (char *)"eventslog_memory_history_size", + (char *)"eventslog_buffer_history_size", (char *)"eventslog_default_log", (char *)"eventslog_format", (char *)"auditlog_filename", @@ -1070,7 +1070,7 @@ MySQL_Threads_Handler::MySQL_Threads_Handler() { variables.server_version=strdup((char *)"8.0.11"); // changed in 2.6.0 , was 5.5.30 variables.eventslog_filename=strdup((char *)""); // proxysql-mysql-eventslog is recommended variables.eventslog_filesize=100*1024*1024; - variables.eventslog_memory_history_size=0; + variables.eventslog_buffer_history_size=0; variables.eventslog_default_log=0; variables.eventslog_format=1; variables.auditlog_filename=strdup((char *)""); @@ -2242,7 +2242,7 @@ char ** MySQL_Threads_Handler::get_variables_list() { // logs VariablesPointers_int["auditlog_filesize"] = make_tuple(&variables.auditlog_filesize, 1024*1024, 1*1024*1024*1024, false); VariablesPointers_int["eventslog_filesize"] = make_tuple(&variables.eventslog_filesize, 1024*1024, 1*1024*1024*1024, false); - VariablesPointers_int["eventslog_memory_history_size"] = make_tuple(&variables.eventslog_memory_history_size, 0, 8*1024*1024, false); + VariablesPointers_int["eventslog_buffer_history_size"] = make_tuple(&variables.eventslog_buffer_history_size, 0, 8*1024*1024, false); VariablesPointers_int["eventslog_default_log"] = make_tuple(&variables.eventslog_default_log, 0, 1, false); // various VariablesPointers_int["long_query_time"] = make_tuple(&variables.long_query_time, 0, 20*24*3600*1000, false); @@ -4371,9 +4371,9 @@ void MySQL_Thread::refresh_variables() { REFRESH_VARIABLE_CHAR(server_version); REFRESH_VARIABLE_INT(eventslog_filesize); - REFRESH_VARIABLE_INT(eventslog_memory_history_size); + REFRESH_VARIABLE_INT(eventslog_buffer_history_size); { - int elmhs = mysql_thread___eventslog_memory_history_size; + int elmhs = mysql_thread___eventslog_buffer_history_size; if (GloMyLogger->MyLogCB->buffer_size != elmhs) { GloMyLogger->MyLogCB->resize(elmhs); } From 61c189b8c3216d5c0f8025722d8fb35bd9c0a768 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Sun, 13 Oct 2024 15:25:04 +0000 Subject: [PATCH 03/19] Reimplementation of the circular buffer for Query Logging --- include/MySQL_Logger.hpp | 59 ++++++++++++++++++---- lib/MySQL_Logger.cpp | 106 +++++++-------------------------------- lib/MySQL_Thread.cpp | 4 +- 3 files changed, 67 insertions(+), 102 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index f6c182da2d..39c90044b9 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -53,28 +53,65 @@ class MySQL_Event { void set_gtid(MySQL_Session *sess); }; +/** + * @class MySQL_Logger_CircularBuffer + * @brief A thread-safe circular buffer for storing MySQL events. + * + * This class implements a circular buffer that stores pointers to MySQL_Event objects. + * It provides thread-safe methods for inserting events and retrieving all stored events. + * The buffer automatically manages memory for the stored events. Once an event is inserted, the buffer assumes ownership. + */ class MySQL_Logger_CircularBuffer { private: - MySQL_Event **event_buffer; - size_t head; - size_t tail; - std::mutex mutex; + std::deque event_buffer; ///< The internal deque storing event pointers. + std::mutex mutex; ///< Mutex for thread safety. public: - // we allow potential dirty read of buffer_size. - // this is not a problem because operation on the object are - // then performed holding the mutex - std::atomic buffer_size; + std::atomic buffer_size; ///< Atomic variable to store the buffer size. (Public for direct access) + /** + * @brief Constructor for the MySQL_Logger_CircularBuffer class. + * @param size The initial size of the circular buffer. + */ MySQL_Logger_CircularBuffer(size_t size); + /** + * @brief Destructor for the MySQL_Logger_CircularBuffer class. + * + * This destructor deallocates the memory used by the buffer and the MySQL_Event objects it contains. + */ ~MySQL_Logger_CircularBuffer(); - void insert(MySQL_Event *event); - std::pair get_all_events(); - void resize(size_t new_size); + /** + * @brief Inserts a new MySQL_Event into the circular buffer. + * @param event A pointer to the MySQL_Event object to insert. The buffer takes ownership. + * + * If the buffer is full, the oldest event is removed before inserting the new event. + */ + void insert(MySQL_Event* event); + + /** + * @brief Retrieves all events from the circular buffer. + * @return A deque containing all the events in the buffer. The caller takes ownership of the events and is responsible for deleting them. + * + * This method clears the buffer after retrieving the events. + */ + std::deque get_all_events(); + + /** + * @brief Gets the current size of the buffer. + * @return The current size of the circular buffer. + */ + size_t getBufferSize() const; + + /** + * @brief Sets the size of the buffer. + * @param newSize The new size of the circular buffer. + */ + void setBufferSize(size_t newSize); }; + class MySQL_Logger { private: struct { diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index e896891009..c67fb96567 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -1145,107 +1145,35 @@ void MySQL_Logger::print_version() { fprintf(stderr,"Standard ProxySQL MySQL Logger rev. %s -- %s -- %s\n", PROXYSQL_MYSQL_LOGGER_VERSION, __FILE__, __TIMESTAMP__); }; -MySQL_Logger_CircularBuffer::MySQL_Logger_CircularBuffer(size_t size) { - head = 0; - tail = 0; - buffer_size = size; - event_buffer = new MySQL_Event*[buffer_size]; -} +MySQL_Logger_CircularBuffer::MySQL_Logger_CircularBuffer(size_t size) : buffer_size(size), event_buffer(size) {} MySQL_Logger_CircularBuffer::~MySQL_Logger_CircularBuffer() { - for (size_t i = 0; i < buffer_size; ++i) { - if (event_buffer[i] != nullptr) { - delete event_buffer[i]; - } + std::lock_guard lock(mutex); + for (MySQL_Event* event : event_buffer) { + delete event; } - delete[] event_buffer; } -void MySQL_Logger_CircularBuffer::resize(size_t new_size) { +void MySQL_Logger_CircularBuffer::insert(MySQL_Event* event) { std::lock_guard lock(mutex); - - if (new_size == buffer_size) { - return; // No need to resize - } - - // Create the new buffer - MySQL_Event **new_buffer = new MySQL_Event*[new_size]; - - // Handle the case when initial buffer size is 0 - if (buffer_size == 0) { - // No need to copy or delete; just update the members - delete[] event_buffer; - event_buffer = new_buffer; - buffer_size = new_size; - head = 0; - tail = 0; - return; + if (event_buffer.size() == buffer_size) { + delete event_buffer.front(); + event_buffer.pop_front(); } - - // Copy events from the old buffer and delete those not copied - size_t num_events = (head >= tail) ? (head - tail) : (buffer_size + head - tail); - size_t copy_count = std::min(num_events, new_size); - - size_t i = 0; - for (size_t j = (tail + buffer_size - copy_count) % buffer_size; j != tail; j = (j + 1) % buffer_size) { - new_buffer[i++] = event_buffer[j]; - } - - // Delete events that were not copied - for (size_t j = 0; j < buffer_size; ++j) { - if (event_buffer[j] != nullptr && event_buffer[j] != new_buffer[j % new_size]) { - delete event_buffer[j]; - } - } - - // Delete the old buffer - delete[] event_buffer; - - // Update the members - event_buffer = new_buffer; - buffer_size = new_size; - head = copy_count; - tail = 0; + event_buffer.push_back(event); } - -void MySQL_Logger_CircularBuffer::insert(MySQL_Event *event) { +std::deque MySQL_Logger_CircularBuffer::get_all_events() { std::lock_guard lock(mutex); - - // Insert the new event - event_buffer[head] = event; - - // Move head forward - head = (head + 1) % buffer_size; - - // Update tail if necessary (if head is about to overwrite tail) - if (head == tail) { - // Delete the oldest element if it's not null - if (event_buffer[tail] != nullptr) { - delete event_buffer[tail]; - } - - // Move tail forward - tail = (tail + 1) % buffer_size; - } + std::deque events = std::move(event_buffer); + return events; } +size_t MySQL_Logger_CircularBuffer::getBufferSize() const { + return buffer_size; +} -std::pair MySQL_Logger_CircularBuffer::get_all_events() { +void MySQL_Logger_CircularBuffer::setBufferSize(size_t newSize) { std::lock_guard lock(mutex); - - size_t num_events = (head >= tail) ? (head - tail) : (buffer_size + head - tail); - MySQL_Event **events = new MySQL_Event*[num_events]; - - size_t i = 0; - // Iterate from tail to head, copying the events - for (size_t j = tail; j != head; j = (j + 1) % buffer_size) { - events[i++] = event_buffer[j]; - } - - // Reset head and tail - head = tail; // Set head to tail to mark the buffer as empty - - return std::make_pair(events, num_events); + buffer_size = newSize; } - diff --git a/lib/MySQL_Thread.cpp b/lib/MySQL_Thread.cpp index 4ce926b84a..767b02c04c 100644 --- a/lib/MySQL_Thread.cpp +++ b/lib/MySQL_Thread.cpp @@ -4374,8 +4374,8 @@ void MySQL_Thread::refresh_variables() { REFRESH_VARIABLE_INT(eventslog_buffer_history_size); { int elmhs = mysql_thread___eventslog_buffer_history_size; - if (GloMyLogger->MyLogCB->buffer_size != elmhs) { - GloMyLogger->MyLogCB->resize(elmhs); + if (GloMyLogger->MyLogCB->getBufferSize() != elmhs) { + GloMyLogger->MyLogCB->setBufferSize(elmhs); } } REFRESH_VARIABLE_INT(eventslog_default_log); From a8310f42a67ee2c1889e38835947ab89bab4109a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Sun, 13 Oct 2024 15:58:05 +0000 Subject: [PATCH 04/19] Implemented table stats_mysql_query_events --- lib/ProxySQL_Admin.cpp | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/lib/ProxySQL_Admin.cpp b/lib/ProxySQL_Admin.cpp index 709ae3492b..614f7d2481 100644 --- a/lib/ProxySQL_Admin.cpp +++ b/lib/ProxySQL_Admin.cpp @@ -602,6 +602,10 @@ MHD_Result http_handler(void *cls, struct MHD_Connection *connection, const char #define ADMIN_SQLITE_TABLE_STATS_MYSQL_PREPARED_STATEMENTS_INFO "CREATE TABLE stats_mysql_prepared_statements_info (global_stmt_id INT NOT NULL , schemaname VARCHAR NOT NULL , username VARCHAR NOT NULL , digest VARCHAR NOT NULL , ref_count_client INT NOT NULL , ref_count_server INT NOT NULL , num_columns INT NOT NULL, num_params INT NOT NULL, query VARCHAR NOT NULL)" + +#define ADMIN_SQLITE_TABLE_STATS_MYSQL_QUERY_EVENTS "CREATE TABLE stats_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT)" + + static char * admin_variables_names[]= { (char *)"admin_credentials", (char *)"stats_credentials", @@ -6569,6 +6573,8 @@ bool ProxySQL_Admin::init(const bootstrap_info_t& bootstrap_info) { insert_into_tables_defs(tables_defs_stats,"stats_mysql_prepared_statements_info", ADMIN_SQLITE_TABLE_STATS_MYSQL_PREPARED_STATEMENTS_INFO); insert_into_tables_defs(tables_defs_stats,"stats_mysql_client_host_cache", STATS_SQLITE_TABLE_MYSQL_CLIENT_HOST_CACHE); insert_into_tables_defs(tables_defs_stats,"stats_mysql_client_host_cache_reset", STATS_SQLITE_TABLE_MYSQL_CLIENT_HOST_CACHE_RESET); + insert_into_tables_defs(tables_defs_stats,"stats_mysql_query_events", ADMIN_SQLITE_TABLE_STATS_MYSQL_QUERY_EVENTS); + // ProxySQL Cluster insert_into_tables_defs(tables_defs_admin,"proxysql_servers", ADMIN_SQLITE_TABLE_PROXYSQL_SERVERS); From 754f1e52f2ca1ec129151bb5c3c43fbc8a0c6c19 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Sun, 13 Oct 2024 16:29:12 +0000 Subject: [PATCH 05/19] Reimplementation of MySQL_Logger_CircularBuffer::get_all_events() Accept a reference to a vector instead of returning a deque --- include/MySQL_Logger.hpp | 9 +++++---- lib/MySQL_Logger.cpp | 7 ++++--- 2 files changed, 9 insertions(+), 7 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index 39c90044b9..5c27b5b21e 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -90,12 +90,13 @@ class MySQL_Logger_CircularBuffer { void insert(MySQL_Event* event); /** - * @brief Retrieves all events from the circular buffer. - * @return A deque containing all the events in the buffer. The caller takes ownership of the events and is responsible for deleting them. + * @brief Retrieves all events from the circular buffer and populates a provided vector. + * @param events A reference to a vector that will be populated with the events from the buffer. The caller takes ownership of the events and is responsible for deleting them. * - * This method clears the buffer after retrieving the events. + * This method clears the buffer after retrieving the events. The function reserves space in the vector to avoid unnecessary reallocations. */ - std::deque get_all_events(); + void get_all_events(std::vector& events); + /** * @brief Gets the current size of the buffer. diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index c67fb96567..f8a999df6c 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -1163,10 +1163,11 @@ void MySQL_Logger_CircularBuffer::insert(MySQL_Event* event) { event_buffer.push_back(event); } -std::deque MySQL_Logger_CircularBuffer::get_all_events() { +void MySQL_Logger_CircularBuffer::get_all_events(std::vector& events) { std::lock_guard lock(mutex); - std::deque events = std::move(event_buffer); - return events; + events.reserve(event_buffer.size()); + events.insert(events.end(), event_buffer.begin(), event_buffer.end()); + event_buffer.clear(); } size_t MySQL_Logger_CircularBuffer::getBufferSize() const { From efb95ca87ec6bf84e8bd99a8f0eee5f2ee229a8d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 14 Oct 2024 01:25:27 +0000 Subject: [PATCH 06/19] First implementation of insertMysqlEventsIntoDb() MySQL_Logger::insertMysqlEventsIntoDb() populate table `stats_mysql_query_events` using mysql query events in the circular buffer --- include/MySQL_Logger.hpp | 4 ++ lib/MySQL_Logger.cpp | 85 +++++++++++++++++++++++++++++++++++++++- 2 files changed, 88 insertions(+), 1 deletion(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index 5c27b5b21e..f9aae93b54 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -6,6 +6,8 @@ #define PROXYSQL_LOGGER_PTHREAD_MUTEX +class MySQL_Logger; + class MySQL_Event { private: uint32_t thread_id; @@ -51,6 +53,7 @@ class MySQL_Event { void set_affected_rows(uint64_t ar, uint64_t lid); void set_rows_sent(uint64_t rs); void set_gtid(MySQL_Session *sess); + friend MySQL_Logger; }; /** @@ -159,6 +162,7 @@ class MySQL_Logger { void wrlock(); void wrunlock(); MySQL_Logger_CircularBuffer * MyLogCB; + void insertMysqlEventsIntoDb(SQLite3DB * db, const std::vector& events); }; diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index f8a999df6c..e04564f98f 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -1145,7 +1145,7 @@ void MySQL_Logger::print_version() { fprintf(stderr,"Standard ProxySQL MySQL Logger rev. %s -- %s -- %s\n", PROXYSQL_MYSQL_LOGGER_VERSION, __FILE__, __TIMESTAMP__); }; -MySQL_Logger_CircularBuffer::MySQL_Logger_CircularBuffer(size_t size) : buffer_size(size), event_buffer(size) {} +MySQL_Logger_CircularBuffer::MySQL_Logger_CircularBuffer(size_t size) : event_buffer(size), buffer_size(size) {} MySQL_Logger_CircularBuffer::~MySQL_Logger_CircularBuffer() { std::lock_guard lock(mutex); @@ -1178,3 +1178,86 @@ void MySQL_Logger_CircularBuffer::setBufferSize(size_t newSize) { std::lock_guard lock(mutex); buffer_size = newSize; } + + +void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::vector& events){ + int rc = 0; + sqlite3_stmt *statement1=NULL; + sqlite3_stmt *statement32=NULL; + char *query1=NULL; + char *query32=NULL; + std::string query32s = ""; + const int numcols = 17; + query1=(char *)"INSERT INTO stats_mysql_query_events VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12, ?13, ?14, ?15, ?16, ?17)"; + query32s = "INSERT INTO stats_mysql_query_events VALUES " + generate_multi_rows_query(32, numcols); + query32 = (char *)query32s.c_str(); + rc = db->prepare_v2(query1, &statement1); + ASSERT_SQLITE_OK(rc, db); + rc = db->prepare_v2(query32, &statement32); + ASSERT_SQLITE_OK(rc, db); + + char digest_hex_str[20]; // 2+sizeof(unsigned long long)*2+2 + + db->execute("BEGIN"); + + int row_idx=0; + int max_bulk_row_idx=events.size()/32; + max_bulk_row_idx=max_bulk_row_idx*32; + for (std::vector::const_iterator it = events.begin() ; it != events.end(); ++it) { + MySQL_Event *event = *it; + int idx=row_idx%32; + if (row_idxthread_id); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+2, event->username, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+3, event->schemaname, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement32, (idx*numcols)+4, event->start_time); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement32, (idx*numcols)+5, event->end_time); ASSERT_SQLITE_OK(rc, db); + sprintf(digest_hex_str, "0x%016llX", (long long unsigned int)event->query_digest); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+6, digest_hex_str, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+7, event->query_ptr, event->query_len, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+8, event->server, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+9, event->client, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int)(statement32, (idx*numcols)+10, (int)event->et); ASSERT_SQLITE_OK(rc, db); // Assuming event_type is an enum mapped to integers + rc = (*proxy_sqlite3_bind_int64)(statement32, (idx*numcols)+11, event->hid); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+12, event->extra_info, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement32, (idx*numcols)+13, event->affected_rows); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement32, (idx*numcols)+14, event->last_insert_id); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement32, (idx*numcols)+15, event->rows_sent); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int)(statement32, (idx*numcols)+16, event->client_stmt_id); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+17, event->gtid, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + if (idx==31) { + SAFE_SQLITE3_STEP2(statement32); + rc=(*proxy_sqlite3_clear_bindings)(statement32); ASSERT_SQLITE_OK(rc, db); + rc=(*proxy_sqlite3_reset)(statement32); ASSERT_SQLITE_OK(rc, db); + } + } else { // single row + //Bind parameters. Handle potential errors in binding. + rc = (*proxy_sqlite3_bind_int)(statement1, 1, event->thread_id); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 2, event->username, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 3, event->schemaname, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement1, 4, event->start_time); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement1, 5, event->end_time); ASSERT_SQLITE_OK(rc, db); + sprintf(digest_hex_str, "0x%016llX", (long long unsigned int)event->query_digest); + rc = (*proxy_sqlite3_bind_text)(statement1, 6, digest_hex_str, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 7, event->query_ptr, event->query_len, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 8, event->server, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 9, event->client, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int)(statement1, 10, (int)event->et); ASSERT_SQLITE_OK(rc, db); // Assuming event_type is an enum mapped to integers + rc = (*proxy_sqlite3_bind_int64)(statement1, 11, event->hid); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 12, event->extra_info, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement1, 13, event->affected_rows); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement1, 14, event->last_insert_id); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int64)(statement1, 15, event->rows_sent); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int)(statement1, 16, event->client_stmt_id); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 17, event->gtid, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + SAFE_SQLITE3_STEP2(statement1); + rc=(*proxy_sqlite3_clear_bindings)(statement1); ASSERT_SQLITE_OK(rc, db); + rc=(*proxy_sqlite3_reset)(statement1); ASSERT_SQLITE_OK(rc, db); + } + row_idx++; + } + (*proxy_sqlite3_finalize)(statement1); + (*proxy_sqlite3_finalize)(statement32); + db->execute("COMMIT"); +} From d7a9254bbdccaed2196af5b5845f92099b3c6aaf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 14 Oct 2024 02:04:11 +0000 Subject: [PATCH 07/19] Add history_mysql_query_events in statsdb_disk --- include/ProxySQL_Statistics.hpp | 1 + lib/ProxySQL_Statistics.cpp | 5 +++++ 2 files changed, 6 insertions(+) diff --git a/include/ProxySQL_Statistics.hpp b/include/ProxySQL_Statistics.hpp index 7e356b8196..7ab170ef1d 100644 --- a/include/ProxySQL_Statistics.hpp +++ b/include/ProxySQL_Statistics.hpp @@ -79,6 +79,7 @@ #define STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_DIGEST "CREATE TABLE history_mysql_query_digest (dump_time INT , hostgroup INT , schemaname VARCHAR NOT NULL , username VARCHAR NOT NULL , client_address VARCHAR NOT NULL , digest VARCHAR NOT NULL , digest_text VARCHAR NOT NULL , count_star INTEGER NOT NULL , first_seen INTEGER NOT NULL , last_seen INTEGER NOT NULL , sum_time INTEGER NOT NULL , min_time INTEGER NOT NULL , max_time INTEGER NOT NULL , sum_rows_affected INTEGER NOT NULL , sum_rows_sent INTEGER NOT NULL)" +#define STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_EVENTS "CREATE TABLE history_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT)" class ProxySQL_Statistics { SQLite3DB *statsdb_mem; // internal statistics DB std::vector *tables_defs_statsdb_mem; diff --git a/lib/ProxySQL_Statistics.cpp b/lib/ProxySQL_Statistics.cpp index 523623109f..df350fd608 100644 --- a/lib/ProxySQL_Statistics.cpp +++ b/lib/ProxySQL_Statistics.cpp @@ -97,6 +97,8 @@ void ProxySQL_Statistics::init() { insert_into_tables_defs(tables_defs_statsdb_disk,"history_mysql_query_digest", STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_DIGEST); + insert_into_tables_defs(tables_defs_statsdb_disk,"history_mysql_query_events", STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_EVENTS); + disk_upgrade_mysql_connections(); check_and_build_standard_tables(statsdb_mem, tables_defs_statsdb_disk); @@ -110,6 +112,9 @@ void ProxySQL_Statistics::init() { // statsdb_disk->execute("CREATE INDEX IF NOT EXISTS idx_history_mysql_query_digest_last_seen ON history_mysql_query_digest (last_seen)"); statsdb_disk->execute("CREATE INDEX IF NOT EXISTS idx_history_mysql_query_digest_dump_time ON history_mysql_query_digest (dump_time)"); statsdb_disk->execute("CREATE INDEX IF NOT EXISTS idx_history_mysql_status_variable_id_timestamp ON history_mysql_status_variables(variable_id,timestamp)"); + + statsdb_disk->execute("CREATE INDEX IF NOT EXISTS idx_history_mysql_query_events_start_time ON history_mysql_query_events(start_time)"); + statsdb_disk->execute("CREATE INDEX IF NOT EXISTS idx_history_mysql_query_events_query_digest ON history_mysql_query_events(query_digest)"); } void ProxySQL_Statistics::disk_upgrade_mysql_connections() { From 23e3244cc563bb4520b20ede2df73bc3d368a1c5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 14 Oct 2024 05:46:38 +0000 Subject: [PATCH 08/19] Implementation of processEvents() and DUMP EVENTSLOG commands MySQL_Logger::processEvents() is responsible for dumping mysql query events from the circular buffer into SQLite tables. DUMP EVENTSLOG commands trigger a call to processEvents(): * DUMP EVENTSLOG FROM BUFFER TO MEMORY: copies events to the in-memory SQLite table * DUMP EVENTSLOG FROM BUFFER TO DISK: copies events to the on-disk SQLite table * DUMP EVENTSLOG FROM BUFFER TO BOTH: copies events to both in-memory and on-disk SQLite tables simultaneously --- include/MySQL_Logger.hpp | 4 ++- lib/MySQL_Logger.cpp | 58 +++++++++++++++++++++++++++++++++++----- lib/ProxySQL_Admin.cpp | 26 ++++++++++++++++++ 3 files changed, 81 insertions(+), 7 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index f9aae93b54..6373e9c639 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -146,6 +146,7 @@ class MySQL_Logger { unsigned int events_find_next_id(); unsigned int audit_find_next_id(); public: + int eventslog_table_memory_size; MySQL_Logger(); ~MySQL_Logger(); void print_version(); @@ -162,7 +163,8 @@ class MySQL_Logger { void wrlock(); void wrunlock(); MySQL_Logger_CircularBuffer * MyLogCB; - void insertMysqlEventsIntoDb(SQLite3DB * db, const std::vector& events); + void insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& tableName, size_t numEvents, std::vector::const_iterator begin); + int processEvents(SQLite3DB * statsdb , SQLite3DB * statsdb_disk); }; diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index e04564f98f..b268b50ebd 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -1180,16 +1180,18 @@ void MySQL_Logger_CircularBuffer::setBufferSize(size_t newSize) { } -void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::vector& events){ +void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& tableName, size_t numEvents, std::vector::const_iterator begin){ int rc = 0; sqlite3_stmt *statement1=NULL; sqlite3_stmt *statement32=NULL; char *query1=NULL; char *query32=NULL; - std::string query32s = ""; const int numcols = 17; - query1=(char *)"INSERT INTO stats_mysql_query_events VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12, ?13, ?14, ?15, ?16, ?17)"; - query32s = "INSERT INTO stats_mysql_query_events VALUES " + generate_multi_rows_query(32, numcols); + std::string query1s = ""; + std::string query32s = ""; + query1s = "INSERT INTO " + tableName + " VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12, ?13, ?14, ?15, ?16, ?17)"; + query32s = "INSERT INTO " + tableName + " VALUES " + generate_multi_rows_query(32, numcols); + query1 = (char *)query1s.c_str(); query32 = (char *)query32s.c_str(); rc = db->prepare_v2(query1, &statement1); ASSERT_SQLITE_OK(rc, db); @@ -1201,9 +1203,9 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::vectorexecute("BEGIN"); int row_idx=0; - int max_bulk_row_idx=events.size()/32; + int max_bulk_row_idx=numEvents/32; max_bulk_row_idx=max_bulk_row_idx*32; - for (std::vector::const_iterator it = events.begin() ; it != events.end(); ++it) { + for (std::vector::const_iterator it = begin ; it != begin + numEvents; ++it) { MySQL_Event *event = *it; int idx=row_idx%32; if (row_idxexecute("COMMIT"); } + + +int MySQL_Logger::processEvents(SQLite3DB * statsdb , SQLite3DB * statsdb_disk) { + std::vector events = {}; + MyLogCB->get_all_events(events); + + if (events.empty()) return 0; + + if (statsdb_disk != nullptr) { + // Write to on-disk database first + insertMysqlEventsIntoDb(statsdb_disk, "history_mysql_query_events", events.size(), events.begin()); + } + + if (statsdb != nullptr) { + + size_t maxInMemorySize = eventslog_table_memory_size; + size_t numEventsToInsert = std::min(events.size(), maxInMemorySize); + + if (events.size() >= maxInMemorySize) { + // delete everything from stats_mysql_query_events + statsdb->execute("DELETE FROM stats_mysql_query_events"); + } else { + // make enough room in stats_mysql_query_events + int current_rows = statsdb->return_one_int((char *)"SELECT COUNT(*) FROM stats_mysql_query_events"); + int rows_to_keep = maxInMemorySize - events.size(); + if (current_rows > rows_to_keep) { + int rows_to_delete = (current_rows - rows_to_keep); + string delete_stmt = "DELETE FROM stats_mysql_query_events ORDER BY id LIMIT " + to_string(rows_to_delete); + statsdb->execute(delete_stmt.c_str()); + } + } + + // Pass iterators to avoid copying + insertMysqlEventsIntoDb(statsdb, "stats_mysql_query_events", numEventsToInsert, events.begin()); + } + + // cleanup of all events + for (MySQL_Event* event : events) { + delete event; + } + size_t ret = events.size(); + return ret; +} + diff --git a/lib/ProxySQL_Admin.cpp b/lib/ProxySQL_Admin.cpp index 614f7d2481..522deffca8 100644 --- a/lib/ProxySQL_Admin.cpp +++ b/lib/ProxySQL_Admin.cpp @@ -3784,6 +3784,32 @@ void admin_session_handler(MySQL_Session *sess, void *_pa, PtrSize_t *pkt) { } } + + if (!strncasecmp("DUMP EVENTSLOG ", query_no_space, strlen("DUMP EVENTSLOG "))) { + int num_rows = 0; + proxy_debug(PROXY_DEBUG_ADMIN, 4, "Received command DUMP EVENTSLOG: %s\n", query_no_space); + proxy_info("Received command DUMP EVENTSLOG: %s\n", query_no_space); + + // Use a map for better efficiency and readability + std::map> commandMap = { + {"DUMP EVENTSLOG FROM BUFFER TO MEMORY", {SPA->statsdb, nullptr}}, + {"DUMP EVENTSLOG FROM BUFFER TO DISK", {nullptr, SPA->statsdb_disk}}, + {"DUMP EVENTSLOG FROM BUFFER TO BOTH", {SPA->statsdb, SPA->statsdb_disk}} + }; + + auto it = commandMap.find(query_no_space); + if (it != commandMap.end()) { + num_rows = GloMyLogger->processEvents(it->second.first, it->second.second); + SPA->send_MySQL_OK(&sess->client_myds->myprot, NULL, num_rows); + } else { + proxy_warning("Received invalid command DUMP EVENTSLOG: %s\n", query_no_space); + SPA->send_MySQL_ERR(&sess->client_myds->myprot, (char *)"Invalid DUMP EVENTSLOG command"); + } + run_query = false; + goto __run_query; + } + + // handle special queries from Cluster // for bug #1188 , ProxySQL Admin needs to know the exact query From 1d30d40e9b47a4af422850f2c32b4bfab727475d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 14 Oct 2024 06:37:25 +0000 Subject: [PATCH 09/19] Added stats_mysql_eventslog_sync_buffer_to_disk Added new Admin variable stats_mysql_eventslog_sync_buffer_to_disk . This variable defines how frequently mysql query eventslog are automatically dumped to disk. --- include/ProxySQL_Statistics.hpp | 3 +++ include/proxysql_admin.h | 1 + lib/ProxySQL_Admin.cpp | 25 +++++++++++++++++++++++++ lib/ProxySQL_Statistics.cpp | 11 +++++++++++ 4 files changed, 40 insertions(+) diff --git a/include/ProxySQL_Statistics.hpp b/include/ProxySQL_Statistics.hpp index 7ab170ef1d..18b792c5a2 100644 --- a/include/ProxySQL_Statistics.hpp +++ b/include/ProxySQL_Statistics.hpp @@ -91,6 +91,7 @@ class ProxySQL_Statistics { unsigned long long next_timer_MySQL_Threads_Handler; unsigned long long next_timer_mysql_query_digest_to_disk; unsigned long long next_timer_system_cpu; + unsigned long long last_timer_mysql_dump_eventslog_to_disk = 0; #ifndef NOJEM unsigned long long next_timer_system_memory; #endif @@ -106,6 +107,7 @@ class ProxySQL_Statistics { int stats_mysql_query_cache; int stats_system_cpu; int stats_mysql_query_digest_to_disk; + int stats_mysql_eventslog_sync_buffer_to_disk; #ifndef NOJEM int stats_system_memory; #endif @@ -118,6 +120,7 @@ class ProxySQL_Statistics { bool MySQL_Threads_Handler_timetoget(unsigned long long); bool mysql_query_digest_to_disk_timetoget(unsigned long long); bool system_cpu_timetoget(unsigned long long); + bool MySQL_Logger_dump_eventslog_timetoget(unsigned long long); #ifndef NOJEM bool system_memory_timetoget(unsigned long long); #endif diff --git a/include/proxysql_admin.h b/include/proxysql_admin.h index 81f7aae6ea..2000787e75 100644 --- a/include/proxysql_admin.h +++ b/include/proxysql_admin.h @@ -255,6 +255,7 @@ class ProxySQL_Admin { int stats_mysql_connections; int stats_mysql_query_cache; int stats_mysql_query_digest_to_disk; + int stats_mysql_eventslog_sync_buffer_to_disk; int stats_system_cpu; int stats_system_memory; int mysql_show_processlist_extended; diff --git a/lib/ProxySQL_Admin.cpp b/lib/ProxySQL_Admin.cpp index 522deffca8..0c28930bd6 100644 --- a/lib/ProxySQL_Admin.cpp +++ b/lib/ProxySQL_Admin.cpp @@ -613,6 +613,7 @@ static char * admin_variables_names[]= { (char *)"stats_mysql_connection_pool", (char *)"stats_mysql_query_cache", (char *)"stats_mysql_query_digest_to_disk", + (char *)"stats_mysql_eventslog_sync_buffer_to_disk", (char *)"stats_system_cpu", (char *)"stats_system_memory", (char *)"mysql_ifaces", @@ -5838,6 +5839,14 @@ static void * admin_main_loop(void *arg) curtime2 = curtime2/1000; proxy_info("Automatically saved stats_mysql_query_digest to disk: %llums to write %d entries\n", curtime2-curtime1, r1); } + if (GloProxyStats->MySQL_Logger_dump_eventslog_timetoget(curtime)) { + unsigned long long curtime1=monotonic_time(); + int r1 = GloMyLogger->processEvents(nullptr, SPA->statsdb_disk); + unsigned long long curtime2=monotonic_time(); + curtime1 = curtime1/1000; + curtime2 = curtime2/1000; + proxy_info("Automatically saved history_mysql_query_events to disk: %llums to write %d entries\n", curtime2-curtime1, r1); + } if (GloProxyStats->system_cpu_timetoget(curtime)) { GloProxyStats->system_cpu_sets(); } @@ -6054,12 +6063,14 @@ ProxySQL_Admin::ProxySQL_Admin() : variables.stats_mysql_connections = 60; variables.stats_mysql_query_cache = 60; variables.stats_mysql_query_digest_to_disk = 0; + variables.stats_mysql_eventslog_sync_buffer_to_disk = 0; variables.stats_system_cpu = 60; variables.stats_system_memory = 60; GloProxyStats->variables.stats_mysql_connection_pool = 60; GloProxyStats->variables.stats_mysql_connections = 60; GloProxyStats->variables.stats_mysql_query_cache = 60; GloProxyStats->variables.stats_mysql_query_digest_to_disk = 0; + GloProxyStats->variables.stats_mysql_eventslog_sync_buffer_to_disk = 0; GloProxyStats->variables.stats_system_cpu = 60; #ifndef NOJEM GloProxyStats->variables.stats_system_memory = 60; @@ -8457,6 +8468,10 @@ char * ProxySQL_Admin::get_variable(char *name) { sprintf(intbuf,"%d",variables.stats_mysql_query_digest_to_disk); return strdup(intbuf); } + if (!strcasecmp(name,"stats_mysql_eventslog_sync_buffer_to_disk")) { + sprintf(intbuf,"%d",variables.stats_mysql_eventslog_sync_buffer_to_disk); + return strdup(intbuf); + } if (!strcasecmp(name,"stats_system_cpu")) { sprintf(intbuf,"%d",variables.stats_system_cpu); return strdup(intbuf); @@ -8762,6 +8777,16 @@ bool ProxySQL_Admin::set_variable(char *name, char *value, bool lock) { // this return false; } } + if (!strcasecmp(name,"stats_mysql_eventslog_sync_buffer_to_disk")) { + int intv=atoi(value); + if (intv >= 0 && intv <= 24*3600) { + variables.stats_mysql_eventslog_sync_buffer_to_disk=intv; + GloProxyStats->variables.stats_mysql_eventslog_sync_buffer_to_disk=intv; + return true; + } else { + return false; + } + } if (!strcasecmp(name,"stats_system_cpu")) { int intv=atoi(value); if (intv >= 0 && intv <= 600) { diff --git a/lib/ProxySQL_Statistics.cpp b/lib/ProxySQL_Statistics.cpp index df350fd608..5836275f91 100644 --- a/lib/ProxySQL_Statistics.cpp +++ b/lib/ProxySQL_Statistics.cpp @@ -179,6 +179,17 @@ void ProxySQL_Statistics::drop_tables_defs(std::vector *tables_de } } +bool ProxySQL_Statistics::MySQL_Logger_dump_eventslog_timetoget(unsigned long long curtime) { + if (variables.stats_mysql_eventslog_sync_buffer_to_disk) { // only proceed if not zero + unsigned long long t = variables.stats_mysql_eventslog_sync_buffer_to_disk; // originally in seconds + t = t * 1000 * 1000; + if (curtime > last_timer_mysql_dump_eventslog_to_disk + t) { + last_timer_mysql_dump_eventslog_to_disk = curtime; + return true; + } + } + return false; +} bool ProxySQL_Statistics::MySQL_Threads_Handler_timetoget(unsigned long long curtime) { unsigned int i = (unsigned int)variables.stats_mysql_connections; From 28982a4e0abdc0bf1b93d9cbac2ea093f68f50d9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 14 Oct 2024 06:55:38 +0000 Subject: [PATCH 10/19] Adding documentation on in memory eventslog --- include/MySQL_Logger.hpp | 25 +++++++++++++++++++++++++ include/ProxySQL_Statistics.hpp | 11 ++++++++++- lib/ProxySQL_Statistics.cpp | 6 +++--- 3 files changed, 38 insertions(+), 4 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index 6373e9c639..50ae406f37 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -163,7 +163,32 @@ class MySQL_Logger { void wrlock(); void wrunlock(); MySQL_Logger_CircularBuffer * MyLogCB; + /** + * @brief Inserts a batch of MySQL events into a specified SQLite table. + * @param db A pointer to the SQLite3DB object representing the database connection. + * @param tableName The name of the SQLite table to insert into. + * @param numEvents The number of events to insert. + * @param begin An iterator pointing to the beginning of the range of MySQL_Event* in the vector to insert. + * @return 0 if the insertion was successful, a negative error code otherwise. + * + * This function inserts a batch of MySQL events into the specified SQLite table using bulk insert techniques for efficiency. + * It handles the conversion of MySQL_Event data to a format suitable for SQLite insertion. Error handling includes logging of errors. + * The function uses a prepared statement for bulk insertion. + * The function assumes that the provided events have been allocated with `new` and will not be deleted by this function. + */ void insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& tableName, size_t numEvents, std::vector::const_iterator begin); + /** + * @brief Processes and inserts MySQL events into in-memory and/or on-disk SQLite databases. + * @param statsdb A pointer to the SQLite3DB object for the in-memory database (can be nullptr). + * @param statsdb_disk A pointer to the SQLite3DB object for the on-disk database (can be nullptr). + * @return The number of events processed. Returns a negative value if an error occurs. + * + * This function retrieves events from the circular buffer, handles in-memory table size limits, and inserts them into the specified SQLite databases. + * If either statsdb or statsdb_disk is nullptr, events are only written to the other database. + * It handles in-memory table size limits by deleting existing entries if necessary. + * The function ensures that the in-memory table size does not exceed a predefined limit (`eventslog_table_memory_size`). + * The function assumes ownership of the MySQL_Event pointers and deletes them after processing. + */ int processEvents(SQLite3DB * statsdb , SQLite3DB * statsdb_disk); }; diff --git a/include/ProxySQL_Statistics.hpp b/include/ProxySQL_Statistics.hpp index 18b792c5a2..30ae1673ed 100644 --- a/include/ProxySQL_Statistics.hpp +++ b/include/ProxySQL_Statistics.hpp @@ -120,7 +120,16 @@ class ProxySQL_Statistics { bool MySQL_Threads_Handler_timetoget(unsigned long long); bool mysql_query_digest_to_disk_timetoget(unsigned long long); bool system_cpu_timetoget(unsigned long long); - bool MySQL_Logger_dump_eventslog_timetoget(unsigned long long); + /** + * @brief Checks if it's time to dump the events log to disk based on the configured interval. + * @param currentTimeMicros The current time in microseconds. + * @return True if it's time to dump the events log, false otherwise. + * + * This function checks if the current time exceeds the last dump time plus the configured dump interval. + * The dump interval is retrieved from the ProxySQL configuration. If the dump interval is 0, no dumping is performed. + */ + bool MySQL_Logger_dump_eventslog_timetoget(unsigned long long currentTimeMicros); + #ifndef NOJEM bool system_memory_timetoget(unsigned long long); #endif diff --git a/lib/ProxySQL_Statistics.cpp b/lib/ProxySQL_Statistics.cpp index 5836275f91..d584f11ad9 100644 --- a/lib/ProxySQL_Statistics.cpp +++ b/lib/ProxySQL_Statistics.cpp @@ -179,12 +179,12 @@ void ProxySQL_Statistics::drop_tables_defs(std::vector *tables_de } } -bool ProxySQL_Statistics::MySQL_Logger_dump_eventslog_timetoget(unsigned long long curtime) { +bool ProxySQL_Statistics::MySQL_Logger_dump_eventslog_timetoget(unsigned long long currentTimeMicros) { if (variables.stats_mysql_eventslog_sync_buffer_to_disk) { // only proceed if not zero unsigned long long t = variables.stats_mysql_eventslog_sync_buffer_to_disk; // originally in seconds t = t * 1000 * 1000; - if (curtime > last_timer_mysql_dump_eventslog_to_disk + t) { - last_timer_mysql_dump_eventslog_to_disk = curtime; + if (currentTimeMicros > last_timer_mysql_dump_eventslog_to_disk + t) { + last_timer_mysql_dump_eventslog_to_disk = currentTimeMicros; return true; } } From 8e768f4e2d171fdc56a3cb41d0597fd6ac86d180 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 14 Oct 2024 07:37:17 +0000 Subject: [PATCH 11/19] Improved documentation --- include/MySQL_Logger.hpp | 384 ++++++++++++++++++++++++++++++++------- 1 file changed, 319 insertions(+), 65 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index 50ae406f37..466e83a0f5 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -8,52 +8,180 @@ class MySQL_Logger; + +/** + * @class MySQL_Event + * @brief Represents a single event logged by the MySQL logger. + * + * This class encapsulates information about a MySQL event, including the query, timestamps, user information, and other relevant details. + * It provides methods for writing the event data to a file in different formats (binary and JSON). The class manages memory dynamically allocated for its members. + */ class MySQL_Event { - private: - uint32_t thread_id; - char *username; - char *schemaname; - size_t username_len; - size_t schemaname_len; - uint64_t start_time; - uint64_t end_time; - uint64_t query_digest; - char *query_ptr; - size_t query_len; - char *server; - char *client; - size_t server_len; - size_t client_len; - //uint64_t total_length; - unsigned char buf[10]; - enum log_event_type et; - uint64_t hid; - char *extra_info; - bool have_affected_rows; - bool have_rows_sent; - bool have_gtid; - bool free_on_delete; // this bool defines if pointers should be freed when the destructor is called - uint64_t affected_rows; - uint64_t last_insert_id; - uint64_t rows_sent; - uint32_t client_stmt_id; - const char * gtid; - public: - MySQL_Event(log_event_type _et, uint32_t _thread_id, char * _username, char * _schemaname , uint64_t _start_time , uint64_t _end_time , uint64_t _query_digest, char *_client, size_t _client_len); - MySQL_Event(const MySQL_Event &other); +private: + uint32_t thread_id; ///< The ID of the thread that executed the query. + char* username; ///< The username associated with the query. Memory managed by the class. + char* schemaname; ///< The schema name associated with the query. Memory managed by the class. + size_t username_len; ///< Length of the username string. + size_t schemaname_len; ///< Length of the schema name string. + uint64_t start_time; ///< Start time of the query in microseconds. + uint64_t end_time; ///< End time of the query in microseconds. + uint64_t query_digest; ///< Digest of the query. + char* query_ptr; ///< Pointer to the query string. Memory managed by the class. + size_t query_len; ///< Length of the query string. + char* server; ///< Server address. Memory managed by the class. + char* client; ///< Client address. Memory managed by the class. + size_t server_len; ///< Length of the server address. + size_t client_len; ///< Length of the client address. + unsigned char buf[10]; ///< Buffer for encoding lengths. + enum log_event_type et; ///< Type of the event. + uint64_t hid; ///< Hostgroup ID. + char* extra_info; ///< Additional information about the event. Memory managed by the class. + bool have_affected_rows; ///< Flag indicating if affected rows are available. + bool have_rows_sent; ///< Flag indicating if rows sent are available. + bool have_gtid; ///< Flag indicating if GTID is available. + bool free_on_delete; ///< Flag indicating whether to free memory in the destructor. + uint64_t affected_rows; ///< Number of rows affected by the query. + uint64_t last_insert_id; ///< Last insert ID. + uint64_t rows_sent; ///< Number of rows sent. + uint32_t client_stmt_id; ///< Client statement ID. + const char* gtid; ///< GTID. + +public: + /** + * @brief Constructor for the MySQL_Event class. + * @param _et The type of the event. + * @param _thread_id The ID of the thread that executed the query. + * @param _username The username associated with the query. + * @param _schemaname The schema name associated with the query. + * @param _start_time The start time of the query in microseconds. + * @param _end_time The end time of the query in microseconds. + * @param _query_digest The digest of the query. + * @param _client The client address. + * @param _client_len The length of the client address. + * + * This constructor initializes the MySQL_Event object with the provided parameters. It does not allocate memory for string members. + */ + MySQL_Event(log_event_type _et, uint32_t _thread_id, char* _username, char* _schemaname, uint64_t _start_time, uint64_t _end_time, uint64_t _query_digest, char* _client, size_t _client_len); + + /** + * @brief Copy constructor for the MySQL_Event class. + * @param other The MySQL_Event object to copy. + * + * This copy constructor creates a deep copy of the provided MySQL_Event object. + */ + MySQL_Event(const MySQL_Event& other); + + /** + * @brief Destructor for the MySQL_Event class. + * + * This destructor deallocates the memory used by the object's string members if `free_on_delete` is true. + */ ~MySQL_Event(); - uint64_t write(std::fstream *f, MySQL_Session *sess); - uint64_t write_query_format_1(std::fstream *f); - uint64_t write_query_format_2_json(std::fstream *f); - void write_auth(std::fstream *f, MySQL_Session *sess); + + /** + * @brief Writes the event data to a file stream. + * @param f A pointer to the file stream. + * @param sess A pointer to the MySQL_Session object. + * @return The total number of bytes written. + * + * This function writes the event data to the specified file stream based on the event type and the configured log format. + */ + uint64_t write(std::fstream* f, MySQL_Session* sess); + + /** + * @brief Writes the event data in binary format (format 1) to a file stream. + * @param f A pointer to the file stream to write to. Must not be NULL. + * @return The total number of bytes written to the stream. + * + * This function serializes the event data into a binary format according to the MySQL event log format 1 specification. + * It encodes lengths using MySQL's length encoding scheme. + * The function writes the event type, thread ID, username, schema name, client address, hostgroup ID (if available), server address (if available), timestamps, client statement ID (if applicable), affected rows, last insert ID, rows sent, query digest, and query string to the file stream. + * The function writes all fields as defined by the MySQL event log format. + * It handles variable-length fields using MySQL's length encoding, which means that the length of each field is written before the field data itself. + * The function carefully handles potential errors during file writing operations. + */ + uint64_t write_query_format_1(std::fstream* f); + + + /** + * @brief Writes the event data in JSON format (format 2) to a file stream. + * @param f A pointer to the file stream to write to. Must not be NULL. + * @return The total number of bytes written to the stream (always 0 in the current implementation). + * + * This function serializes the event data into a JSON format. + * It converts various data fields into a JSON object and writes this object to the file stream. + * The function uses the nlohmann::json library for JSON serialization. + * This function currently always returns 0. + * The function constructs a JSON object containing relevant event information such as the hostgroup ID, thread ID, event type, username, schema name, client and server addresses, affected rows, last insert ID, rows sent, query string, timestamps, query digest, and client statement ID (if applicable). + * After constructing the JSON object, it serializes it into a string using the `dump()` method of the nlohmann::json library and writes the resulting string to the output file stream. + */ + uint64_t write_query_format_2_json(std::fstream* f); + + /** + * @brief Writes authentication-related event data to a file stream. + * @param f A pointer to the file stream. + * @param sess A pointer to the MySQL_Session object. + */ + void write_auth(std::fstream* f, MySQL_Session* sess); + + /** + * @brief Sets the client statement ID for the event. + * @param client_stmt_id The client statement ID. + */ void set_client_stmt_id(uint32_t client_stmt_id); - void set_query(const char *ptr, int len); - void set_server(int _hid, const char *ptr, int len); - void set_extra_info(char *); + + /** + * @brief Sets the query string for the event. + * @param ptr A pointer to the query string. + * @param len The length of the query string. + * + * This method sets the query string for the event. The provided pointer and length are stored; ownership is not transferred. + */ + void set_query(const char* ptr, int len); + + /** + * @brief Sets the server address and hostgroup ID for the event. + * @param _hid The hostgroup ID. + * @param ptr A pointer to the server address string. + * @param len The length of the server address string. + * + * This method sets the server address and hostgroup ID for the event. The provided pointer and length are stored; ownership is not transferred. + */ + void set_server(int _hid, const char* ptr, int len); + + /** + * @brief Sets additional information for the event. + * @param _err A pointer to the extra information string. + * + * This method sets additional information for the event. A copy of the string is made; the original string is not modified. + */ + void set_extra_info(char* _err); + + /** + * @brief Sets the affected rows and last insert ID for the event. + * @param ar The number of affected rows. + * @param lid The last insert ID. + */ void set_affected_rows(uint64_t ar, uint64_t lid); + + /** + * @brief Sets the number of rows sent for the event. + * @param rs The number of rows sent. + */ void set_rows_sent(uint64_t rs); - void set_gtid(MySQL_Session *sess); - friend MySQL_Logger; + + /** + * @brief Sets the GTID for the event from a MySQL session. + * @param sess A pointer to the MySQL_Session object. + * + * This method extracts the GTID from the provided MySQL session and sets it for the event. + */ + void set_gtid(MySQL_Session* sess); + + /** + * @brief Declares MySQL_Logger as a friend class, granting it access to private members of MySQL_Event. + */ + friend class MySQL_Logger; }; /** @@ -115,54 +243,180 @@ class MySQL_Logger_CircularBuffer { }; - +/** + * @class MySQL_Logger + * @brief A class for logging MySQL events and audit entries. + * + * This class manages the logging of MySQL events (queries, connections, etc.) and audit entries to files. It uses circular buffers for efficient event handling. + * It provides methods for configuring log files, opening and closing log files, flushing log buffers, and logging various events. + * The class uses mutexes or rwlocks for thread safety, depending on the compilation settings. + */ class MySQL_Logger { - private: +private: + /** + * @brief Structure to hold configuration and state for event logging. + */ struct { - bool enabled; - char *base_filename; - char *datadir; - unsigned int log_file_id; - unsigned int max_log_file_size; - std::fstream *logfile; + bool enabled; ///< Flag indicating whether event logging is enabled. + char* base_filename; ///< Base filename for event log files. Memory managed by the class. + char* datadir; ///< Directory for event log files. Memory managed by the class. + unsigned int log_file_id; ///< ID of the current event log file. + unsigned int max_log_file_size; ///< Maximum size of an event log file in bytes. + std::fstream* logfile; ///< File stream for event logging. } events; + + /** + * @brief Structure to hold configuration and state for audit logging. + */ struct { - bool enabled; - char *base_filename; - char *datadir; - unsigned int log_file_id; - unsigned int max_log_file_size; - std::fstream *logfile; + bool enabled; ///< Flag indicating whether audit logging is enabled. + char* base_filename; ///< Base filename for audit log files. Memory managed by the class. + char* datadir; ///< Directory for audit log files. Memory managed by the class. + unsigned int log_file_id; ///< ID of the current audit log file. + unsigned int max_log_file_size; ///< Maximum size of an audit log file in bytes. + std::fstream* logfile; ///< File stream for audit logging. } audit; + + // Mutex or rwlock for thread safety #ifdef PROXYSQL_LOGGER_PTHREAD_MUTEX - pthread_mutex_t wmutex; + pthread_mutex_t wmutex; ///< Pthread mutex for thread safety. #else - rwlock_t rwlock; + rwlock_t rwlock; ///< rwlock for thread safety. #endif + + /** + * @brief Closes the event log file. This function should only be called while holding the write lock. + */ void events_close_log_unlocked(); + + /** + * @brief Opens the event log file. This function should only be called while holding the write lock. + */ void events_open_log_unlocked(); + + /** + * @brief Closes the audit log file. This function should only be called while holding the write lock. + */ void audit_close_log_unlocked(); + + /** + * @brief Opens the audit log file. This function should only be called while holding the write lock. + */ void audit_open_log_unlocked(); + + /** + * @brief Finds the next available ID for an event log file. + * @return The next available ID. + */ unsigned int events_find_next_id(); + + /** + * @brief Finds the next available ID for an audit log file. + * @return The next available ID. + */ unsigned int audit_find_next_id(); - public: - int eventslog_table_memory_size; + +public: + int eventslog_table_memory_size; ///< Maximum size of the in-memory event log table. + + /** + * @brief Constructor for the MySQL_Logger class. + * + * This constructor initializes the logger with default settings. + */ MySQL_Logger(); + + /** + * @brief Destructor for the MySQL_Logger class. + * + * This destructor deallocates resources used by the logger, including log files and mutexes. + */ ~MySQL_Logger(); + + /** + * @brief Prints the version information of the logger. + */ void print_version(); + + /** + * @brief Flushes the event and audit log buffers to disk. + */ void flush_log(); + + /** + * @brief Flushes the event log buffer to disk. This function should only be called while holding the write lock. + */ void events_flush_log_unlocked(); + + /** + * @brief Flushes the audit log buffer to disk. This function should only be called while holding the write lock. + */ void audit_flush_log_unlocked(); - void events_set_datadir(char *); + + /** + * @brief Sets the data directory for event log files. + * @param s The path to the data directory. + */ + void events_set_datadir(char* s); + + /** + * @brief Sets the base filename for event log files. + */ void events_set_base_filename(); - void audit_set_datadir(char *); + + /** + * @brief Sets the data directory for audit log files. + * @param s The path to the data directory. + */ + void audit_set_datadir(char* s); + + /** + * @brief Sets the base filename for audit log files. + */ void audit_set_base_filename(); - void log_request(MySQL_Session *, MySQL_Data_Stream *); - void log_audit_entry(log_event_type, MySQL_Session *, MySQL_Data_Stream *, char *e = NULL); + + /** + * @brief Logs a request event. + * @param sess A pointer to the MySQL_Session object. + * @param myds A pointer to the MySQL_Data_Stream object. + * + * This function logs information about a MySQL request, including the query, timestamps, user information, and other relevant details. + * It creates a MySQL_Event object, populates it with data from the session and data stream, and writes it to the event log file and/or the circular buffer. + * The function handles different types of requests (normal queries, prepared statements, etc.) and manages memory carefully. + * The function handles different query types (standard queries, prepared statements). It extracts relevant information from the session object, such as timestamps, user credentials, and query details. + * If the circular buffer is enabled, it creates a copy of the event and adds it to the buffer for later processing. + * The function also checks the size of the log file and flushes it if it exceeds the maximum configured size. + * The function uses mutexes to protect shared resources and avoid race conditions. + * The function assumes ownership of the dynamically allocated memory for the `MySQL_Event` object created within this function. + */ + void log_request(MySQL_Session* sess, MySQL_Data_Stream* myds); + + /** + * @brief Logs an audit entry. + * @param _et The type of the audit event. + * @param sess A pointer to the MySQL_Session object. + * @param myds A pointer to the MySQL_Data_Stream object. + * @param xi Additional information for the audit entry. + */ + void log_audit_entry(log_event_type _et, MySQL_Session* sess, MySQL_Data_Stream* myds, char* xi = NULL); + + /** + * @brief Flushes the log files. + */ void flush(); + + /** + * @brief Acquires a write lock. + */ void wrlock(); + + /** + * @brief Releases a write lock. + */ void wrunlock(); - MySQL_Logger_CircularBuffer * MyLogCB; + + MySQL_Logger_CircularBuffer* MyLogCB; ///< Pointer to the circular buffer for managing events. + /** * @brief Inserts a batch of MySQL events into a specified SQLite table. * @param db A pointer to the SQLite3DB object representing the database connection. @@ -185,7 +439,7 @@ class MySQL_Logger { * * This function retrieves events from the circular buffer, handles in-memory table size limits, and inserts them into the specified SQLite databases. * If either statsdb or statsdb_disk is nullptr, events are only written to the other database. - * It handles in-memory table size limits by deleting existing entries if necessary. + * It handles in-memory table size limits by deleting existing entries if necessary. * The function ensures that the in-memory table size does not exceed a predefined limit (`eventslog_table_memory_size`). * The function assumes ownership of the MySQL_Event pointers and deletes them after processing. */ From 56eb2115d000837fe435b92ace86a456bd53abaf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 14 Oct 2024 07:50:12 +0000 Subject: [PATCH 12/19] Added variable eventslog_buffer_max_query_length In MySQL_Event copy constructor, queries are copied up to eventslog_buffer_max_query_length bytes. --- include/MySQL_Thread.h | 1 + include/proxysql_structs.h | 2 ++ lib/MySQL_Logger.cpp | 13 ++++++++----- lib/MySQL_Thread.cpp | 6 +++++- 4 files changed, 16 insertions(+), 6 deletions(-) diff --git a/include/MySQL_Thread.h b/include/MySQL_Thread.h index eb4ad1a48d..5885c99f23 100644 --- a/include/MySQL_Thread.h +++ b/include/MySQL_Thread.h @@ -535,6 +535,7 @@ class MySQL_Threads_Handler char *eventslog_filename; int eventslog_filesize; int eventslog_buffer_history_size; + int eventslog_buffer_max_query_length; int eventslog_default_log; int eventslog_format; char *auditlog_filename; diff --git a/include/proxysql_structs.h b/include/proxysql_structs.h index 9809527299..57646d1a25 100644 --- a/include/proxysql_structs.h +++ b/include/proxysql_structs.h @@ -893,6 +893,7 @@ __thread char * mysql_thread___ssl_p2s_crlpath; __thread char * mysql_thread___eventslog_filename; __thread int mysql_thread___eventslog_filesize; __thread int mysql_thread___eventslog_buffer_history_size; +__thread int mysql_thread___eventslog_buffer_max_query_length; __thread int mysql_thread___eventslog_default_log; __thread int mysql_thread___eventslog_format; @@ -1066,6 +1067,7 @@ extern __thread char * mysql_thread___ssl_p2s_crlpath; extern __thread char * mysql_thread___eventslog_filename; extern __thread int mysql_thread___eventslog_filesize; extern __thread int mysql_thread___eventslog_buffer_history_size; +extern __thread int mysql_thread___eventslog_buffer_max_query_length; extern __thread int mysql_thread___eventslog_default_log; extern __thread int mysql_thread___eventslog_format; diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index b268b50ebd..25ecce11b9 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -80,9 +80,12 @@ MySQL_Event::MySQL_Event(const MySQL_Event &other) { } // query_ptr is NOT null terminated if (other.query_ptr != nullptr) { - query_ptr = (char *)malloc(query_len+1); - memcpy(query_ptr, other.query_ptr, query_len); - query_ptr[query_len] = '\0'; + size_t maxQueryLen = mysql_thread___eventslog_buffer_max_query_length; + size_t lenToCopy = std::min(other.query_len, maxQueryLen); + query_ptr = (char*)malloc(lenToCopy + 1); // +1 for null terminator + memcpy(query_ptr, other.query_ptr, lenToCopy); + query_ptr[lenToCopy] = '\0'; // Null-terminate the copied string + query_len = lenToCopy; } // server is NOT null terminated if (other.server != nullptr) { @@ -1217,7 +1220,7 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta rc = (*proxy_sqlite3_bind_int64)(statement32, (idx*numcols)+5, event->end_time); ASSERT_SQLITE_OK(rc, db); sprintf(digest_hex_str, "0x%016llX", (long long unsigned int)event->query_digest); rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+6, digest_hex_str, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); - rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+7, event->query_ptr, event->query_len, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+7, event->query_ptr, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); // MySQL_Events from circular-buffer are all null-terminated rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+8, event->server, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+9, event->client, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_int)(statement32, (idx*numcols)+10, (int)event->et); ASSERT_SQLITE_OK(rc, db); // Assuming event_type is an enum mapped to integers @@ -1242,7 +1245,7 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta rc = (*proxy_sqlite3_bind_int64)(statement1, 5, event->end_time); ASSERT_SQLITE_OK(rc, db); sprintf(digest_hex_str, "0x%016llX", (long long unsigned int)event->query_digest); rc = (*proxy_sqlite3_bind_text)(statement1, 6, digest_hex_str, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); - rc = (*proxy_sqlite3_bind_text)(statement1, 7, event->query_ptr, event->query_len, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 7, event->query_ptr, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); // MySQL_Events from circular-buffer are all null-terminated rc = (*proxy_sqlite3_bind_text)(statement1, 8, event->server, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_text)(statement1, 9, event->client, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_int)(statement1, 10, (int)event->et); ASSERT_SQLITE_OK(rc, db); // Assuming event_type is an enum mapped to integers diff --git a/lib/MySQL_Thread.cpp b/lib/MySQL_Thread.cpp index 767b02c04c..70dc9a94d1 100644 --- a/lib/MySQL_Thread.cpp +++ b/lib/MySQL_Thread.cpp @@ -350,6 +350,7 @@ static char * mysql_thread_variables_names[]= { (char *)"eventslog_filename", (char *)"eventslog_filesize", (char *)"eventslog_buffer_history_size", + (char *)"eventslog_buffer_max_query_length", (char *)"eventslog_default_log", (char *)"eventslog_format", (char *)"auditlog_filename", @@ -1071,6 +1072,7 @@ MySQL_Threads_Handler::MySQL_Threads_Handler() { variables.eventslog_filename=strdup((char *)""); // proxysql-mysql-eventslog is recommended variables.eventslog_filesize=100*1024*1024; variables.eventslog_buffer_history_size=0; + variables.eventslog_buffer_max_query_length = 32*1024; variables.eventslog_default_log=0; variables.eventslog_format=1; variables.auditlog_filename=strdup((char *)""); @@ -2242,7 +2244,8 @@ char ** MySQL_Threads_Handler::get_variables_list() { // logs VariablesPointers_int["auditlog_filesize"] = make_tuple(&variables.auditlog_filesize, 1024*1024, 1*1024*1024*1024, false); VariablesPointers_int["eventslog_filesize"] = make_tuple(&variables.eventslog_filesize, 1024*1024, 1*1024*1024*1024, false); - VariablesPointers_int["eventslog_buffer_history_size"] = make_tuple(&variables.eventslog_buffer_history_size, 0, 8*1024*1024, false); + VariablesPointers_int["eventslog_buffer_history_size"] = make_tuple(&variables.eventslog_buffer_history_size, 0, 8*1024*1024, false); + VariablesPointers_int["eventslog_buffer_max_query_length"] = make_tuple(&variables.eventslog_buffer_max_query_length, 128, 32*1024*1024, false); VariablesPointers_int["eventslog_default_log"] = make_tuple(&variables.eventslog_default_log, 0, 1, false); // various VariablesPointers_int["long_query_time"] = make_tuple(&variables.long_query_time, 0, 20*24*3600*1000, false); @@ -4378,6 +4381,7 @@ void MySQL_Thread::refresh_variables() { GloMyLogger->MyLogCB->setBufferSize(elmhs); } } + REFRESH_VARIABLE_INT(eventslog_buffer_max_query_length); REFRESH_VARIABLE_INT(eventslog_default_log); REFRESH_VARIABLE_INT(eventslog_format); REFRESH_VARIABLE_CHAR(eventslog_filename); From 8f0324b9affd538e59f5d0903bc8c9ae61d1a939 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 21 Oct 2024 10:16:07 +0000 Subject: [PATCH 13/19] MySQL_Event log buffering enhancements Added enhancements: * added mysql-eventslog_table_memory_size * liste columns names in insertMysqlEventsIntoDb() * added counters and metrics (not exported yet) --- include/MySQL_Logger.hpp | 56 ++++++++++++++++++++++++++++++++++++-- include/MySQL_Thread.h | 1 + include/proxysql_structs.h | 2 ++ lib/MySQL_Logger.cpp | 54 ++++++++++++++++++++++++++++++------ lib/MySQL_Thread.cpp | 4 +++ lib/ProxySQL_Admin.cpp | 3 +- 6 files changed, 108 insertions(+), 12 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index 466e83a0f5..0ec3bacd64 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -196,6 +196,8 @@ class MySQL_Logger_CircularBuffer { private: std::deque event_buffer; ///< The internal deque storing event pointers. std::mutex mutex; ///< Mutex for thread safety. + std::atomic eventsAddedCount; ///< Total number of events added to the buffer. + std::atomic eventsDroppedCount; ///< Total number of events dropped from the buffer. public: std::atomic buffer_size; ///< Atomic variable to store the buffer size. (Public for direct access) @@ -222,12 +224,18 @@ class MySQL_Logger_CircularBuffer { /** * @brief Retrieves all events from the circular buffer and populates a provided vector. - * @param events A reference to a vector that will be populated with the events from the buffer. The caller takes ownership of the events and is responsible for deleting them. + * @param events A reference to a vector that will be populated with the events from the buffer. + * The caller takes ownership of the events and is responsible for deleting them. * * This method clears the buffer after retrieving the events. The function reserves space in the vector to avoid unnecessary reallocations. */ void get_all_events(std::vector& events); + /** + * @brief Returns the current size of the buffer. + * @return The number of events currently in the buffer. + */ + size_t size(); /** * @brief Gets the current size of the buffer. @@ -240,6 +248,18 @@ class MySQL_Logger_CircularBuffer { * @param newSize The new size of the circular buffer. */ void setBufferSize(size_t newSize); + + /** + * @brief Returns the total number of events added to the buffer. + * @return The total number of events added to the buffer. + */ + unsigned long long getEventsAddedCount() const { return eventsAddedCount; } + + /** + * @brief Returns the total number of events dropped from the buffer. + * @return The total number of events dropped from the buffer. + */ + unsigned long long getEventsDroppedCount() const { return eventsDroppedCount; } }; @@ -277,6 +297,38 @@ class MySQL_Logger { std::fstream* logfile; ///< File stream for audit logging. } audit; + /** + * @brief Structure to hold performance metrics for the MySQL event logger. + * + * This structure keeps track of various metrics related to the performance of the event logging system, + * including the number of times events are copied to memory and disk, the total time spent on + * these operations, and the total number of events copied. + * All members are atomic to ensure thread safety. + */ + struct EventLogMetrics { + /** @brief Number of times events were copied to the in-memory database. */ + std::atomic memoryCopyCount; + /** @brief Number of times events were copied to the on-disk database. */ + std::atomic diskCopyCount; + /** @brief Number of times the `get_all_events` method was called. */ + std::atomic getAllEventsCallsCount; + /** @brief Total number of events retrieved by the `get_all_events` method. */ + std::atomic getAllEventsEventsCount; + /** @brief Total time spent copying events to the in-memory database (microseconds). */ + std::atomic totalMemoryCopyTimeMicros; + /** @brief Total time spent copying events to the on-disk database (microseconds). */ + std::atomic totalDiskCopyTimeMicros; + /** @brief Total time spent in `get_all_events` (microseconds). */ + std::atomic totalGetAllEventsDiskCopyTimeMicros; + /** @brief Total number of events copied to the in-memory database. */ + std::atomic totalEventsCopiedToMemory; + /** @brief Total number of events copied to the on-disk database. */ + std::atomic totalEventsCopiedToDisk; + std::atomic eventsAddedToBufferCount; ///< Total number of events added to the buffer. + std::atomic eventsCurrentlyInBufferCount; ///< Number of events currently in the buffer. + } metrics; + + // Mutex or rwlock for thread safety #ifdef PROXYSQL_LOGGER_PTHREAD_MUTEX pthread_mutex_t wmutex; ///< Pthread mutex for thread safety. @@ -317,8 +369,6 @@ class MySQL_Logger { unsigned int audit_find_next_id(); public: - int eventslog_table_memory_size; ///< Maximum size of the in-memory event log table. - /** * @brief Constructor for the MySQL_Logger class. * diff --git a/include/MySQL_Thread.h b/include/MySQL_Thread.h index 5885c99f23..1fe7e8409d 100644 --- a/include/MySQL_Thread.h +++ b/include/MySQL_Thread.h @@ -535,6 +535,7 @@ class MySQL_Threads_Handler char *eventslog_filename; int eventslog_filesize; int eventslog_buffer_history_size; + int eventslog_table_memory_size; int eventslog_buffer_max_query_length; int eventslog_default_log; int eventslog_format; diff --git a/include/proxysql_structs.h b/include/proxysql_structs.h index 57646d1a25..ba671f0876 100644 --- a/include/proxysql_structs.h +++ b/include/proxysql_structs.h @@ -893,6 +893,7 @@ __thread char * mysql_thread___ssl_p2s_crlpath; __thread char * mysql_thread___eventslog_filename; __thread int mysql_thread___eventslog_filesize; __thread int mysql_thread___eventslog_buffer_history_size; +__thread int mysql_thread___eventslog_table_memory_size; __thread int mysql_thread___eventslog_buffer_max_query_length; __thread int mysql_thread___eventslog_default_log; __thread int mysql_thread___eventslog_format; @@ -1067,6 +1068,7 @@ extern __thread char * mysql_thread___ssl_p2s_crlpath; extern __thread char * mysql_thread___eventslog_filename; extern __thread int mysql_thread___eventslog_filesize; extern __thread int mysql_thread___eventslog_buffer_history_size; +extern __thread int mysql_thread___eventslog_table_memory_size; extern __thread int mysql_thread___eventslog_buffer_max_query_length; extern __thread int mysql_thread___eventslog_default_log; extern __thread int mysql_thread___eventslog_format; diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index 25ecce11b9..06066f24e2 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -531,7 +531,8 @@ uint64_t MySQL_Event::write_query_format_2_json(std::fstream *f) { extern Query_Processor *GloQPro; -MySQL_Logger::MySQL_Logger() { +//MySQL_Logger::MySQL_Logger() : metrics{0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0} { +MySQL_Logger::MySQL_Logger() : metrics{0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0} { events.enabled=false; events.base_filename=NULL; events.datadir=NULL; @@ -877,12 +878,12 @@ void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds) { if (MyLogCB->buffer_size != 0) { MySQL_Event *me2 = new MySQL_Event(me); MyLogCB->insert(me2); -#if 1 +#if 0 for (int i=0; i<10000; i++) { MySQL_Event *me2 = new MySQL_Event(me); MyLogCB->insert(me2); } -#endif // 1 +#endif // 0 } if (cl && sess->client_myds->addr.port) { @@ -1148,7 +1149,9 @@ void MySQL_Logger::print_version() { fprintf(stderr,"Standard ProxySQL MySQL Logger rev. %s -- %s -- %s\n", PROXYSQL_MYSQL_LOGGER_VERSION, __FILE__, __TIMESTAMP__); }; -MySQL_Logger_CircularBuffer::MySQL_Logger_CircularBuffer(size_t size) : event_buffer(size), buffer_size(size) {} +MySQL_Logger_CircularBuffer::MySQL_Logger_CircularBuffer(size_t size) : event_buffer(size), + eventsAddedCount(0), eventsDroppedCount(0), + buffer_size(size) {} MySQL_Logger_CircularBuffer::~MySQL_Logger_CircularBuffer() { std::lock_guard lock(mutex); @@ -1159,13 +1162,21 @@ MySQL_Logger_CircularBuffer::~MySQL_Logger_CircularBuffer() { void MySQL_Logger_CircularBuffer::insert(MySQL_Event* event) { std::lock_guard lock(mutex); + eventsAddedCount++; if (event_buffer.size() == buffer_size) { delete event_buffer.front(); event_buffer.pop_front(); + eventsDroppedCount++; } event_buffer.push_back(event); } + +size_t MySQL_Logger_CircularBuffer::size() { + std::lock_guard lock(mutex); + return event_buffer.size(); +} + void MySQL_Logger_CircularBuffer::get_all_events(std::vector& events) { std::lock_guard lock(mutex); events.reserve(event_buffer.size()); @@ -1192,8 +1203,11 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta const int numcols = 17; std::string query1s = ""; std::string query32s = ""; - query1s = "INSERT INTO " + tableName + " VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12, ?13, ?14, ?15, ?16, ?17)"; - query32s = "INSERT INTO " + tableName + " VALUES " + generate_multi_rows_query(32, numcols); + + std::string coldefs = "(thread_id, username, schemaname, start_time, end_time, query_digest, query, server, client, event_type, hid, extra_info, affected_rows, last_insert_id, rows_sent, client_stmt_id, gtid)"; + + query1s = "INSERT INTO " + tableName + coldefs + " VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12, ?13, ?14, ?15, ?16, ?17)"; + query32s = "INSERT INTO " + tableName + coldefs + " VALUES " + generate_multi_rows_query(32, numcols); query1 = (char *)query1s.c_str(); query32 = (char *)query32s.c_str(); rc = db->prepare_v2(query1, &statement1); @@ -1211,6 +1225,7 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta for (std::vector::const_iterator it = begin ; it != begin + numEvents; ++it) { MySQL_Event *event = *it; int idx=row_idx%32; + if (row_idxthread_id); ASSERT_SQLITE_OK(rc, db); @@ -1269,19 +1284,30 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta int MySQL_Logger::processEvents(SQLite3DB * statsdb , SQLite3DB * statsdb_disk) { + unsigned long long startTimeMicros = monotonic_time(); std::vector events = {}; MyLogCB->get_all_events(events); + metrics.getAllEventsCallsCount++; if (events.empty()) return 0; + unsigned long long afterGetAllEventsTimeMicros = monotonic_time(); + metrics.getAllEventsEventsCount += events.size(); + metrics.totalGetAllEventsDiskCopyTimeMicros += (afterGetAllEventsTimeMicros-startTimeMicros); + if (statsdb_disk != nullptr) { // Write to on-disk database first + unsigned long long diskStartTimeMicros = monotonic_time(); insertMysqlEventsIntoDb(statsdb_disk, "history_mysql_query_events", events.size(), events.begin()); + unsigned long long diskEndTimeMicros = monotonic_time(); + metrics.diskCopyCount++; + metrics.totalDiskCopyTimeMicros += (diskEndTimeMicros - diskStartTimeMicros); + metrics.totalEventsCopiedToDisk += events.size(); } if (statsdb != nullptr) { - - size_t maxInMemorySize = eventslog_table_memory_size; + unsigned long long memoryStartTimeMicros = monotonic_time(); + size_t maxInMemorySize = mysql_thread___eventslog_table_memory_size; size_t numEventsToInsert = std::min(events.size(), maxInMemorySize); if (events.size() >= maxInMemorySize) { @@ -1300,6 +1326,10 @@ int MySQL_Logger::processEvents(SQLite3DB * statsdb , SQLite3DB * statsdb_disk) // Pass iterators to avoid copying insertMysqlEventsIntoDb(statsdb, "stats_mysql_query_events", numEventsToInsert, events.begin()); + unsigned long long memoryEndTimeMicros = monotonic_time(); + metrics.memoryCopyCount++; + metrics.totalMemoryCopyTimeMicros += (memoryEndTimeMicros - memoryStartTimeMicros); + metrics.totalEventsCopiedToMemory += numEventsToInsert; } // cleanup of all events @@ -1307,6 +1337,14 @@ int MySQL_Logger::processEvents(SQLite3DB * statsdb , SQLite3DB * statsdb_disk) delete event; } size_t ret = events.size(); +#if 1 // FIXME: TEMPORARY , TO REMOVE + std::cerr << "Circular:" << endl; + std::cerr << " EventsAddedCount: " << MyLogCB->getEventsAddedCount() << endl; + std::cerr << " EventsDroppedCount: " << MyLogCB->getEventsDroppedCount() << endl; + std::cerr << " Size: " << MyLogCB->size() << endl; + std::cerr << "memoryCopy: Count: " << metrics.memoryCopyCount << " , TimeUs: " << metrics.totalMemoryCopyTimeMicros << endl; + std::cerr << "diskCopy: Count: " << metrics.diskCopyCount << " , TimeUs: " << metrics.totalDiskCopyTimeMicros << endl; +#endif // 1 , FIXME: TEMPORARY , TO REMOVE return ret; } diff --git a/lib/MySQL_Thread.cpp b/lib/MySQL_Thread.cpp index 70dc9a94d1..854c2f16b0 100644 --- a/lib/MySQL_Thread.cpp +++ b/lib/MySQL_Thread.cpp @@ -350,6 +350,7 @@ static char * mysql_thread_variables_names[]= { (char *)"eventslog_filename", (char *)"eventslog_filesize", (char *)"eventslog_buffer_history_size", + (char *)"eventslog_table_memory_size", (char *)"eventslog_buffer_max_query_length", (char *)"eventslog_default_log", (char *)"eventslog_format", @@ -1072,6 +1073,7 @@ MySQL_Threads_Handler::MySQL_Threads_Handler() { variables.eventslog_filename=strdup((char *)""); // proxysql-mysql-eventslog is recommended variables.eventslog_filesize=100*1024*1024; variables.eventslog_buffer_history_size=0; + variables.eventslog_table_memory_size=10000; variables.eventslog_buffer_max_query_length = 32*1024; variables.eventslog_default_log=0; variables.eventslog_format=1; @@ -2245,6 +2247,7 @@ char ** MySQL_Threads_Handler::get_variables_list() { VariablesPointers_int["auditlog_filesize"] = make_tuple(&variables.auditlog_filesize, 1024*1024, 1*1024*1024*1024, false); VariablesPointers_int["eventslog_filesize"] = make_tuple(&variables.eventslog_filesize, 1024*1024, 1*1024*1024*1024, false); VariablesPointers_int["eventslog_buffer_history_size"] = make_tuple(&variables.eventslog_buffer_history_size, 0, 8*1024*1024, false); + VariablesPointers_int["eventslog_table_memory_size"] = make_tuple(&variables.eventslog_table_memory_size, 0, 8*1024*1024, false); VariablesPointers_int["eventslog_buffer_max_query_length"] = make_tuple(&variables.eventslog_buffer_max_query_length, 128, 32*1024*1024, false); VariablesPointers_int["eventslog_default_log"] = make_tuple(&variables.eventslog_default_log, 0, 1, false); // various @@ -4374,6 +4377,7 @@ void MySQL_Thread::refresh_variables() { REFRESH_VARIABLE_CHAR(server_version); REFRESH_VARIABLE_INT(eventslog_filesize); + REFRESH_VARIABLE_INT(eventslog_table_memory_size); REFRESH_VARIABLE_INT(eventslog_buffer_history_size); { int elmhs = mysql_thread___eventslog_buffer_history_size; diff --git a/lib/ProxySQL_Admin.cpp b/lib/ProxySQL_Admin.cpp index 0c28930bd6..dbd56721a9 100644 --- a/lib/ProxySQL_Admin.cpp +++ b/lib/ProxySQL_Admin.cpp @@ -3798,7 +3798,8 @@ void admin_session_handler(MySQL_Session *sess, void *_pa, PtrSize_t *pkt) { {"DUMP EVENTSLOG FROM BUFFER TO BOTH", {SPA->statsdb, SPA->statsdb_disk}} }; - auto it = commandMap.find(query_no_space); + string s = string(query_no_space); + auto it = commandMap.find(s); if (it != commandMap.end()) { num_rows = GloMyLogger->processEvents(it->second.first, it->second.second); SPA->send_MySQL_OK(&sess->client_myds->myprot, NULL, num_rows); From ede0e7f26807eae02272aa42e9d3d8e2b4383925 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 21 Oct 2024 10:40:20 +0000 Subject: [PATCH 14/19] MySQL_Logger::getAllMetrics() Added function MySQL_Logger::getAllMetrics() to export all metrics related to eventlogs --- include/MySQL_Logger.hpp | 17 +++++++++++++++-- lib/MySQL_Logger.cpp | 24 ++++++++++++++++++++++-- 2 files changed, 37 insertions(+), 4 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index 0ec3bacd64..eda0c7cb77 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -324,8 +324,8 @@ class MySQL_Logger { std::atomic totalEventsCopiedToMemory; /** @brief Total number of events copied to the on-disk database. */ std::atomic totalEventsCopiedToDisk; - std::atomic eventsAddedToBufferCount; ///< Total number of events added to the buffer. - std::atomic eventsCurrentlyInBufferCount; ///< Number of events currently in the buffer. + //std::atomic eventsAddedToBufferCount; ///< Total number of events added to the buffer. + //std::atomic eventsCurrentlyInBufferCount; ///< Number of events currently in the buffer. } metrics; @@ -494,6 +494,19 @@ class MySQL_Logger { * The function assumes ownership of the MySQL_Event pointers and deletes them after processing. */ int processEvents(SQLite3DB * statsdb , SQLite3DB * statsdb_disk); + + /** + * @brief Retrieves all performance metrics from the logger and circular buffer. + * @return An unordered map containing all performance metrics. + * The keys are strings representing the metric names, and the values are unsigned long long integers representing the metric values. + * + * This function gathers all relevant performance metrics from the logger's internal EventLogMetrics structure and the circular buffer. + * It returns these metrics as a key-value map for easy access. + * The function ensures thread safety by acquiring a lock on the circular buffer's mutex before accessing its internal metrics. + */ + std::unordered_map getAllMetrics() const; + + }; diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index 06066f24e2..72e283b880 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -531,8 +531,7 @@ uint64_t MySQL_Event::write_query_format_2_json(std::fstream *f) { extern Query_Processor *GloQPro; -//MySQL_Logger::MySQL_Logger() : metrics{0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0} { -MySQL_Logger::MySQL_Logger() : metrics{0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0} { +MySQL_Logger::MySQL_Logger() : metrics{0, 0, 0, 0, 0, 0, 0, 0, 0} { events.enabled=false; events.base_filename=NULL; events.datadir=NULL; @@ -1348,3 +1347,24 @@ int MySQL_Logger::processEvents(SQLite3DB * statsdb , SQLite3DB * statsdb_disk) return ret; } + +std::unordered_map MySQL_Logger::getAllMetrics() const { + std::unordered_map allMetrics; + + allMetrics["memoryCopyCount"] = metrics.memoryCopyCount; + allMetrics["diskCopyCount"] = metrics.diskCopyCount; + allMetrics["getAllEventsCallsCount"] = metrics.getAllEventsCallsCount; + allMetrics["getAllEventsEventsCount"] = metrics.getAllEventsEventsCount; + allMetrics["totalMemoryCopyTimeMicros"] = metrics.totalMemoryCopyTimeMicros; + allMetrics["totalDiskCopyTimeMicros"] = metrics.totalDiskCopyTimeMicros; + allMetrics["totalGetAllEventsDiskCopyTimeMicros"] = metrics.totalGetAllEventsDiskCopyTimeMicros; + allMetrics["totalEventsCopiedToMemory"] = metrics.totalEventsCopiedToMemory; + allMetrics["totalEventsCopiedToDisk"] = metrics.totalEventsCopiedToDisk; + //allMetrics["eventsAddedToBufferCount"] = metrics.eventsAddedToBufferCount; + //allMetrics["eventsDroppedFromBufferCount"] = metrics.eventsDroppedFromBufferCount; + allMetrics["circularBuffereventsAddedCount"] = MyLogCB->getEventsAddedCount(); + allMetrics["circularBufferEventsDroppedCount"] = MyLogCB->getEventsDroppedCount(); + allMetrics["circularBufferEventsSize"] = MyLogCB->size(); + + return allMetrics; +} From 9eeed3c45ba3490b1d0b85ef66b4c742fdcdaecf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Thu, 24 Oct 2024 08:53:17 +0000 Subject: [PATCH 15/19] Drafting handling of errors in MySQL Events log --- include/MySQL_Logger.hpp | 3 ++- include/MySQL_Session.h | 4 ++-- lib/MySQL_Logger.cpp | 2 +- lib/MySQL_Session.cpp | 10 +++++----- 4 files changed, 10 insertions(+), 9 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index eda0c7cb77..b50a1fe9a9 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -429,6 +429,7 @@ class MySQL_Logger { * @brief Logs a request event. * @param sess A pointer to the MySQL_Session object. * @param myds A pointer to the MySQL_Data_Stream object. + * @param errmsg A pointer to an error, if present. * * This function logs information about a MySQL request, including the query, timestamps, user information, and other relevant details. * It creates a MySQL_Event object, populates it with data from the session and data stream, and writes it to the event log file and/or the circular buffer. @@ -439,7 +440,7 @@ class MySQL_Logger { * The function uses mutexes to protect shared resources and avoid race conditions. * The function assumes ownership of the dynamically allocated memory for the `MySQL_Event` object created within this function. */ - void log_request(MySQL_Session* sess, MySQL_Data_Stream* myds); + void log_request(MySQL_Session* sess, MySQL_Data_Stream* myds, const char * errmsg = nullptr); /** * @brief Logs an audit entry. diff --git a/include/MySQL_Session.h b/include/MySQL_Session.h index 2a593d3ce5..8c58ecdba0 100644 --- a/include/MySQL_Session.h +++ b/include/MySQL_Session.h @@ -197,8 +197,8 @@ class MySQL_Session * @param myds If not null, should point to a MySQL_Data_Stream (backend connection) which connection status * should be updated, and previous query resources cleanup. */ - void RequestEnd(MySQL_Data_Stream *); - void LogQuery(MySQL_Data_Stream *); + void RequestEnd(MySQL_Data_Stream * myds, const char * errmsg = nullptr); + void LogQuery(MySQL_Data_Stream * myds, const char * errmsg = nullptr); void handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY___create_mirror_session(); int handler_again___status_PINGING_SERVER(); diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index 72e283b880..dab147ccab 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -739,7 +739,7 @@ void MySQL_Logger::audit_set_datadir(char *s) { flush_log(); }; -void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds) { +void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds, const char * errmsg) { int elmhs = mysql_thread___eventslog_buffer_history_size; if (elmhs == 0) { if (events.enabled==false) return; diff --git a/lib/MySQL_Session.cpp b/lib/MySQL_Session.cpp index b40d922539..099649774b 100644 --- a/lib/MySQL_Session.cpp +++ b/lib/MySQL_Session.cpp @@ -8002,24 +8002,24 @@ 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) { +void MySQL_Session::LogQuery(MySQL_Data_Stream *myds, const char * errmsg) { // we need to access statistics before calling CurrentQuery.end() // so we track the time here CurrentQuery.end_time=thread->curtime; if (qpo) { if (qpo->log==1) { - GloMyLogger->log_request(this, myds); // we send for logging only if logging is enabled for this query + GloMyLogger->log_request(this, myds, errmsg); // we send for logging only if logging is enabled for this query } else { if (qpo->log==-1) { if (mysql_thread___eventslog_default_log==1) { - GloMyLogger->log_request(this, myds); // we send for logging only if enabled by default + GloMyLogger->log_request(this, myds, errmsg); // we send for logging only if enabled by default } } } } } -void MySQL_Session::RequestEnd(MySQL_Data_Stream *myds) { +void MySQL_Session::RequestEnd(MySQL_Data_Stream *myds, const char * errmsg) { // check if multiplexing needs to be disabled char *qdt = NULL; @@ -8040,7 +8040,7 @@ void MySQL_Session::RequestEnd(MySQL_Data_Stream *myds) { break; default: if (session_fast_forward==false) { - LogQuery(myds); + LogQuery(myds, errmsg); } break; } From 234d4e6d5937a04f77452bb133c784749b014e01 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Sat, 26 Oct 2024 02:09:11 +0000 Subject: [PATCH 16/19] Drafting handling of errors in MySQL Events log 2 --- include/MySQL_Logger.hpp | 9 ++++++++- include/ProxySQL_Statistics.hpp | 2 +- lib/MySQL_Logger.cpp | 31 ++++++++++++++++++++++++++++--- lib/ProxySQL_Admin.cpp | 2 +- 4 files changed, 38 insertions(+), 6 deletions(-) diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index b50a1fe9a9..9431f71cc2 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -44,7 +44,8 @@ class MySQL_Event { uint64_t last_insert_id; ///< Last insert ID. uint64_t rows_sent; ///< Number of rows sent. uint32_t client_stmt_id; ///< Client statement ID. - const char* gtid; ///< GTID. + char * gtid; ///< GTID. + char *errmsg; ///< Error message, if generated by ProxySQL (not if generated by the backend) public: /** @@ -178,6 +179,12 @@ class MySQL_Event { */ void set_gtid(MySQL_Session* sess); + /** + * @brief Sets the error message for the event + * @param _errmsg A pointer to the error + */ + void set_errmsg(const char * _errmsg); + /** * @brief Declares MySQL_Logger as a friend class, granting it access to private members of MySQL_Event. */ diff --git a/include/ProxySQL_Statistics.hpp b/include/ProxySQL_Statistics.hpp index 30ae1673ed..ec2daad944 100644 --- a/include/ProxySQL_Statistics.hpp +++ b/include/ProxySQL_Statistics.hpp @@ -79,7 +79,7 @@ #define STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_DIGEST "CREATE TABLE history_mysql_query_digest (dump_time INT , hostgroup INT , schemaname VARCHAR NOT NULL , username VARCHAR NOT NULL , client_address VARCHAR NOT NULL , digest VARCHAR NOT NULL , digest_text VARCHAR NOT NULL , count_star INTEGER NOT NULL , first_seen INTEGER NOT NULL , last_seen INTEGER NOT NULL , sum_time INTEGER NOT NULL , min_time INTEGER NOT NULL , max_time INTEGER NOT NULL , sum_rows_affected INTEGER NOT NULL , sum_rows_sent INTEGER NOT NULL)" -#define STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_EVENTS "CREATE TABLE history_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT)" +#define STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_EVENTS "CREATE TABLE history_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT , error TEXT)" class ProxySQL_Statistics { SQLite3DB *statsdb_mem; // internal statistics DB std::vector *tables_defs_statsdb_mem; diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index dab147ccab..f413c6b131 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -63,6 +63,7 @@ MySQL_Event::MySQL_Event (log_event_type _et, uint32_t _thread_id, char * _usern rows_sent=0; client_stmt_id=0; gtid = NULL; + errmsg = nullptr; free_on_delete = false; // by default, this is false. This because pointers do not belong to this object } @@ -102,6 +103,12 @@ MySQL_Event::MySQL_Event(const MySQL_Event &other) { if (other.extra_info != nullptr) { extra_info = strdup(other.extra_info); } + if (other.gtid != nullptr) { + gtid = strdup(other.gtid); + } + if (other.errmsg != nullptr) { + errmsg = strdup(other.errmsg); + } free_on_delete = true; // pointers belong to this object } @@ -125,6 +132,12 @@ MySQL_Event::~MySQL_Event() { if (extra_info != nullptr) { free(extra_info); extra_info = nullptr; } + if (gtid != nullptr) { + free(gtid); gtid = nullptr; + } + if (errmsg != nullptr) { + free(errmsg); errmsg = nullptr; + } } } @@ -154,6 +167,10 @@ void MySQL_Event::set_gtid(MySQL_Session *sess) { } } +void MySQL_Event::set_errmsg(const char * _errmsg) { + errmsg = strdup(_errmsg); +} + void MySQL_Event::set_extra_info(char *_err) { extra_info = _err; } @@ -488,6 +505,9 @@ uint64_t MySQL_Event::write_query_format_2_json(std::fstream *f) { if (have_gtid == true) { j["last_gtid"] = gtid; } + if (errmsg != nullptr) { + j["error"] = errmsg; + } j["query"] = string(query_ptr,query_len); j["starttime_timestamp_us"] = start_time; { @@ -836,6 +856,9 @@ void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds, con } me.set_rows_sent(sess->CurrentQuery.rows_sent); me.set_gtid(sess); + if (errmsg != nullptr) { + me.set_errmsg(errmsg); + } int sl=0; char *sa=(char *)""; // default @@ -1199,13 +1222,13 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta sqlite3_stmt *statement32=NULL; char *query1=NULL; char *query32=NULL; - const int numcols = 17; + const int numcols = 18; std::string query1s = ""; std::string query32s = ""; - std::string coldefs = "(thread_id, username, schemaname, start_time, end_time, query_digest, query, server, client, event_type, hid, extra_info, affected_rows, last_insert_id, rows_sent, client_stmt_id, gtid)"; + std::string coldefs = "(thread_id, username, schemaname, start_time, end_time, query_digest, query, server, client, event_type, hid, extra_info, affected_rows, last_insert_id, rows_sent, client_stmt_id, gtid, error)"; - query1s = "INSERT INTO " + tableName + coldefs + " VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12, ?13, ?14, ?15, ?16, ?17)"; + query1s = "INSERT INTO " + tableName + coldefs + " VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12, ?13, ?14, ?15, ?16, ?17, ?18)"; query32s = "INSERT INTO " + tableName + coldefs + " VALUES " + generate_multi_rows_query(32, numcols); query1 = (char *)query1s.c_str(); query32 = (char *)query32s.c_str(); @@ -1245,6 +1268,7 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta rc = (*proxy_sqlite3_bind_int64)(statement32, (idx*numcols)+15, event->rows_sent); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_int)(statement32, (idx*numcols)+16, event->client_stmt_id); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+17, event->gtid, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+18, event->errmsg, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); if (idx==31) { SAFE_SQLITE3_STEP2(statement32); rc=(*proxy_sqlite3_clear_bindings)(statement32); ASSERT_SQLITE_OK(rc, db); @@ -1270,6 +1294,7 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta rc = (*proxy_sqlite3_bind_int64)(statement1, 15, event->rows_sent); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_int)(statement1, 16, event->client_stmt_id); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_text)(statement1, 17, event->gtid, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 18, event->errmsg, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); SAFE_SQLITE3_STEP2(statement1); rc=(*proxy_sqlite3_clear_bindings)(statement1); ASSERT_SQLITE_OK(rc, db); rc=(*proxy_sqlite3_reset)(statement1); ASSERT_SQLITE_OK(rc, db); diff --git a/lib/ProxySQL_Admin.cpp b/lib/ProxySQL_Admin.cpp index dbd56721a9..0d788e5c7b 100644 --- a/lib/ProxySQL_Admin.cpp +++ b/lib/ProxySQL_Admin.cpp @@ -603,7 +603,7 @@ MHD_Result http_handler(void *cls, struct MHD_Connection *connection, const char #define ADMIN_SQLITE_TABLE_STATS_MYSQL_PREPARED_STATEMENTS_INFO "CREATE TABLE stats_mysql_prepared_statements_info (global_stmt_id INT NOT NULL , schemaname VARCHAR NOT NULL , username VARCHAR NOT NULL , digest VARCHAR NOT NULL , ref_count_client INT NOT NULL , ref_count_server INT NOT NULL , num_columns INT NOT NULL, num_params INT NOT NULL, query VARCHAR NOT NULL)" -#define ADMIN_SQLITE_TABLE_STATS_MYSQL_QUERY_EVENTS "CREATE TABLE stats_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT)" +#define ADMIN_SQLITE_TABLE_STATS_MYSQL_QUERY_EVENTS "CREATE TABLE stats_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT , error TEXT)" static char * admin_variables_names[]= { From 223573df391f8f69d5d1b11971897f1ba40e3da3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Mon, 28 Oct 2024 05:34:01 +0000 Subject: [PATCH 17/19] Adding some errors in MySQL Events log --- lib/MySQL_Session.cpp | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/lib/MySQL_Session.cpp b/lib/MySQL_Session.cpp index 099649774b..912c9f7db9 100644 --- a/lib/MySQL_Session.cpp +++ b/lib/MySQL_Session.cpp @@ -3204,7 +3204,7 @@ bool MySQL_Session::handler_again___status_CONNECTING_SERVER(int *_rc) { thread->status_variables.stvar[st_var_max_connect_timeout_err]++; } client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,9001,(char *)"HY000", errmsg.c_str(), true); - RequestEnd(mybe->server_myds); + RequestEnd(mybe->server_myds, errmsg.c_str()); string hg_status {}; generate_status_one_hostgroup(current_hostgroup, hg_status); @@ -3337,21 +3337,22 @@ bool MySQL_Session::handler_again___status_CONNECTING_SERVER(int *_rc) { } else { __exit_handler_again___status_CONNECTING_SERVER_with_err: int myerr=mysql_errno(myconn->mysql); + string errmsg = ""; if (myerr) { char sqlstate[10]; + errmsg = string(mysql_error(myconn->mysql)); sprintf(sqlstate,"%s",mysql_sqlstate(myconn->mysql)); - client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,mysql_errno(myconn->mysql),sqlstate,mysql_error(myconn->mysql),true); + client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,mysql_errno(myconn->mysql),sqlstate, errmsg.c_str(), true); } else { - char buf[256]; - sprintf(buf,"Max connect failure while reaching hostgroup %d", current_hostgroup); - client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,9002,(char *)"HY000",buf,true); + errmsg = "Max connect failure while reaching hostgroup " + to_string(current_hostgroup); + client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,9002,(char *)"HY000", errmsg.c_str(), true); if (thread) { thread->status_variables.stvar[st_var_max_connect_timeout_err]++; } } if (session_fast_forward==false) { // see bug #979 - RequestEnd(myds); + RequestEnd(myds, errmsg.c_str()); } while (previous_status.size()) { st=previous_status.top(); From b05f6bdef58a2d476fe7c9d87138124d24ebf5be Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Wed, 30 Oct 2024 08:01:03 +0000 Subject: [PATCH 18/19] Adding more errors in MySQL Events log Adding logging for errors generated directly directly by ProxySQL --- lib/MySQL_Session.cpp | 25 ++++++++++++++----------- 1 file changed, 14 insertions(+), 11 deletions(-) diff --git a/lib/MySQL_Session.cpp b/lib/MySQL_Session.cpp index 912c9f7db9..8eb1f8a81d 100644 --- a/lib/MySQL_Session.cpp +++ b/lib/MySQL_Session.cpp @@ -1436,9 +1436,10 @@ void MySQL_Session::return_proxysql_internal(PtrSize_t *pkt) { } // default client_myds->DSS=STATE_QUERY_SENT_NET; - client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,1064,(char *)"42000",(char *)"Unknown PROXYSQL INTERNAL command",true); + string errmsg = "Unknown PROXYSQL INTERNAL command"; + client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,1064,(char *)"42000", errmsg.c_str() ,true); if (mirror==false) { - RequestEnd(NULL); + RequestEnd(NULL, errmsg.c_str()); } else { client_myds->DSS=STATE_SLEEP; status=WAITING_CLIENT_DATA; @@ -1588,7 +1589,7 @@ bool MySQL_Session::handler_special_queries(PtrSize_t *pkt) { status=WAITING_CLIENT_DATA; if (mirror==false) { - RequestEnd(NULL); + RequestEnd(NULL, err_info.second); } l_free(pkt->size,pkt->ptr); @@ -1787,9 +1788,10 @@ bool MySQL_Session::handler_special_queries(PtrSize_t *pkt) { if ( (pkt->size >= 22 + 5) && (strncasecmp((char *)"LOAD DATA LOCAL INFILE",(char *)pkt->ptr+5, 22)==0) ) { if (mysql_thread___enable_load_data_local_infile == false) { client_myds->DSS=STATE_QUERY_SENT_NET; - client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,1047,(char *)"HY000",(char *)"Unsupported 'LOAD DATA LOCAL INFILE' command",true); + string errmsg = "Unsupported 'LOAD DATA LOCAL INFILE' command"; + client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,1047,(char *)"HY000", errmsg.c_str(), true); if (mirror==false) { - RequestEnd(NULL); + RequestEnd(NULL, errmsg.c_str()); } else { client_myds->DSS=STATE_SLEEP; status=WAITING_CLIENT_DATA; @@ -3614,7 +3616,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C sprintf(buf, err_msg, current_hostgroup, locked_on_hostgroup, nqn.c_str(), end); client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,9005,(char *)"HY000",buf, true); thread->status_variables.stvar[st_var_hostgroup_locked_queries]++; - RequestEnd(NULL); + RequestEnd(NULL, buf); free(buf); l_free(pkt.size,pkt.ptr); return; @@ -3787,7 +3789,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C sprintf(buf, err_msg, current_hostgroup, locked_on_hostgroup, nqn.c_str(), end); client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,9005,(char *)"HY000",buf, true); thread->status_variables.stvar[st_var_hostgroup_locked_queries]++; - RequestEnd(NULL); + RequestEnd(NULL, buf); free(buf); l_free(pkt.size,pkt.ptr); return; @@ -4506,7 +4508,7 @@ int MySQL_Session::get_pkts_from_client(bool& wrong_pass, PtrSize_t& pkt) { sprintf(buf, err_msg, current_hostgroup, locked_on_hostgroup, nqn.c_str(), end); client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,9005,(char *)"HY000",buf, true); thread->status_variables.stvar[st_var_hostgroup_locked_queries]++; - RequestEnd(NULL); + RequestEnd(NULL, buf); free(buf); l_free(pkt.size,pkt.ptr); break; @@ -6264,8 +6266,9 @@ void MySQL_Session::handler_WCD_SS_MCQ_qpo_error_msg(PtrSize_t *pkt) { void MySQL_Session::handler_WCD_SS_MCQ_qpo_LargePacket(PtrSize_t *pkt) { // 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); - RequestEnd(NULL); + string errmsg = "Got a packet bigger than 'max_allowed_packet' bytes"; + client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,1153,(char *)"08S01", errmsg.c_str(), true); + RequestEnd(NULL, errmsg.c_str()); l_free(pkt->size,pkt->ptr); } @@ -7354,7 +7357,7 @@ bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C sprintf(buf,"ProxySQL Error: connection is locked to hostgroup %d but trying to reach hostgroup %d", locked_on_hostgroup, current_hostgroup); client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,9006,(char *)"Y0000",buf); thread->status_variables.stvar[st_var_hostgroup_locked_queries]++; - RequestEnd(NULL); + RequestEnd(NULL, buf); l_free(pkt->size,pkt->ptr); return true; } From 124fb2895f3ff127ac5a56e5fe1db635571e3db6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Tue, 12 Nov 2024 12:35:35 +0000 Subject: [PATCH 19/19] Adding errno into in-memory query logging New `errno` column in tables: - stats_mysql_query_events - history_mysql_query_events Logging into `stats_mysql_errors` also errors generated by ProxySQL (no backend) Added initial TAP test to be extended --- include/MySQL_Logger.hpp | 7 +- include/MySQL_Session.h | 4 +- include/ProxySQL_Statistics.hpp | 2 +- lib/MySQL_Logger.cpp | 26 +- lib/MySQL_Session.cpp | 51 +-- lib/ProxySQL_Admin.cpp | 2 +- .../tests/mysql_query_logging_memory-t.cpp | 316 ++++++++++++++++++ 7 files changed, 370 insertions(+), 38 deletions(-) create mode 100644 test/tap/tests/mysql_query_logging_memory-t.cpp diff --git a/include/MySQL_Logger.hpp b/include/MySQL_Logger.hpp index 9431f71cc2..deab31ad2b 100644 --- a/include/MySQL_Logger.hpp +++ b/include/MySQL_Logger.hpp @@ -46,6 +46,7 @@ class MySQL_Event { uint32_t client_stmt_id; ///< Client statement ID. char * gtid; ///< GTID. char *errmsg; ///< Error message, if generated by ProxySQL (not if generated by the backend) + unsigned int myerrno; ///< MySQL error number public: /** @@ -181,9 +182,10 @@ class MySQL_Event { /** * @brief Sets the error message for the event + * @param _myerrno MySQL error code * @param _errmsg A pointer to the error */ - void set_errmsg(const char * _errmsg); + void set_errmsg(const unsigned int _myerrno, const char * _errmsg); /** * @brief Declares MySQL_Logger as a friend class, granting it access to private members of MySQL_Event. @@ -436,6 +438,7 @@ class MySQL_Logger { * @brief Logs a request event. * @param sess A pointer to the MySQL_Session object. * @param myds A pointer to the MySQL_Data_Stream object. + * @param myerrno MySQL error code, if present. * @param errmsg A pointer to an error, if present. * * This function logs information about a MySQL request, including the query, timestamps, user information, and other relevant details. @@ -447,7 +450,7 @@ class MySQL_Logger { * The function uses mutexes to protect shared resources and avoid race conditions. * The function assumes ownership of the dynamically allocated memory for the `MySQL_Event` object created within this function. */ - void log_request(MySQL_Session* sess, MySQL_Data_Stream* myds, const char * errmsg = nullptr); + void log_request(MySQL_Session* sess, MySQL_Data_Stream* myds , const unsigned int myerrno = 0 , const char * errmsg = nullptr); /** * @brief Logs an audit entry. diff --git a/include/MySQL_Session.h b/include/MySQL_Session.h index da811d7341..fe324949f8 100644 --- a/include/MySQL_Session.h +++ b/include/MySQL_Session.h @@ -197,8 +197,8 @@ class MySQL_Session * @param myds If not null, should point to a MySQL_Data_Stream (backend connection) which connection status * should be updated, and previous query resources cleanup. */ - void RequestEnd(MySQL_Data_Stream * myds, const char * errmsg = nullptr); - void LogQuery(MySQL_Data_Stream * myds, const char * errmsg = nullptr); + void RequestEnd(MySQL_Data_Stream * myds, const unsigned int myerrno = 0, const char * errmsg = nullptr); + void LogQuery(MySQL_Data_Stream * myds, const unsigned int myerrno = 0, const char * errmsg = nullptr); void handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_COM_QUERY___create_mirror_session(); int handler_again___status_PINGING_SERVER(); diff --git a/include/ProxySQL_Statistics.hpp b/include/ProxySQL_Statistics.hpp index ec2daad944..69284c9249 100644 --- a/include/ProxySQL_Statistics.hpp +++ b/include/ProxySQL_Statistics.hpp @@ -79,7 +79,7 @@ #define STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_DIGEST "CREATE TABLE history_mysql_query_digest (dump_time INT , hostgroup INT , schemaname VARCHAR NOT NULL , username VARCHAR NOT NULL , client_address VARCHAR NOT NULL , digest VARCHAR NOT NULL , digest_text VARCHAR NOT NULL , count_star INTEGER NOT NULL , first_seen INTEGER NOT NULL , last_seen INTEGER NOT NULL , sum_time INTEGER NOT NULL , min_time INTEGER NOT NULL , max_time INTEGER NOT NULL , sum_rows_affected INTEGER NOT NULL , sum_rows_sent INTEGER NOT NULL)" -#define STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_EVENTS "CREATE TABLE history_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT , error TEXT)" +#define STATSDB_SQLITE_TABLE_HISTORY_MYSQL_QUERY_EVENTS "CREATE TABLE history_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT , errno INT , error TEXT)" class ProxySQL_Statistics { SQLite3DB *statsdb_mem; // internal statistics DB std::vector *tables_defs_statsdb_mem; diff --git a/lib/MySQL_Logger.cpp b/lib/MySQL_Logger.cpp index f413c6b131..e97ca87841 100644 --- a/lib/MySQL_Logger.cpp +++ b/lib/MySQL_Logger.cpp @@ -64,6 +64,7 @@ MySQL_Event::MySQL_Event (log_event_type _et, uint32_t _thread_id, char * _usern client_stmt_id=0; gtid = NULL; errmsg = nullptr; + myerrno = 0; free_on_delete = false; // by default, this is false. This because pointers do not belong to this object } @@ -167,8 +168,10 @@ void MySQL_Event::set_gtid(MySQL_Session *sess) { } } -void MySQL_Event::set_errmsg(const char * _errmsg) { - errmsg = strdup(_errmsg); +void MySQL_Event::set_errmsg(const unsigned int _myerrno, const char * _errmsg) { + myerrno = _myerrno; + if (_errmsg != nullptr) + errmsg = strdup(_errmsg); } void MySQL_Event::set_extra_info(char *_err) { @@ -505,6 +508,7 @@ uint64_t MySQL_Event::write_query_format_2_json(std::fstream *f) { if (have_gtid == true) { j["last_gtid"] = gtid; } + j["errno"] = myerrno; if (errmsg != nullptr) { j["error"] = errmsg; } @@ -759,7 +763,7 @@ void MySQL_Logger::audit_set_datadir(char *s) { flush_log(); }; -void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds, const char * errmsg) { +void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds, const unsigned int myerrno, const char * errmsg) { int elmhs = mysql_thread___eventslog_buffer_history_size; if (elmhs == 0) { if (events.enabled==false) return; @@ -856,8 +860,8 @@ void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds, con } me.set_rows_sent(sess->CurrentQuery.rows_sent); me.set_gtid(sess); - if (errmsg != nullptr) { - me.set_errmsg(errmsg); + if (myerrno != 0) { + me.set_errmsg(myerrno, errmsg); } int sl=0; @@ -1222,13 +1226,13 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta sqlite3_stmt *statement32=NULL; char *query1=NULL; char *query32=NULL; - const int numcols = 18; + const int numcols = 19; std::string query1s = ""; std::string query32s = ""; - std::string coldefs = "(thread_id, username, schemaname, start_time, end_time, query_digest, query, server, client, event_type, hid, extra_info, affected_rows, last_insert_id, rows_sent, client_stmt_id, gtid, error)"; + std::string coldefs = "(thread_id, username, schemaname, start_time, end_time, query_digest, query, server, client, event_type, hid, extra_info, affected_rows, last_insert_id, rows_sent, client_stmt_id, gtid, errno, error)"; - query1s = "INSERT INTO " + tableName + coldefs + " VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12, ?13, ?14, ?15, ?16, ?17, ?18)"; + query1s = "INSERT INTO " + tableName + coldefs + " VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10, ?11, ?12, ?13, ?14, ?15, ?16, ?17, ?18, ?19)"; query32s = "INSERT INTO " + tableName + coldefs + " VALUES " + generate_multi_rows_query(32, numcols); query1 = (char *)query1s.c_str(); query32 = (char *)query32s.c_str(); @@ -1268,7 +1272,8 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta rc = (*proxy_sqlite3_bind_int64)(statement32, (idx*numcols)+15, event->rows_sent); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_int)(statement32, (idx*numcols)+16, event->client_stmt_id); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+17, event->gtid, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); - rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+18, event->errmsg, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int)(statement32, (idx*numcols)+18, event->myerrno); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement32, (idx*numcols)+19, event->errmsg, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); if (idx==31) { SAFE_SQLITE3_STEP2(statement32); rc=(*proxy_sqlite3_clear_bindings)(statement32); ASSERT_SQLITE_OK(rc, db); @@ -1294,7 +1299,8 @@ void MySQL_Logger::insertMysqlEventsIntoDb(SQLite3DB * db, const std::string& ta rc = (*proxy_sqlite3_bind_int64)(statement1, 15, event->rows_sent); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_int)(statement1, 16, event->client_stmt_id); ASSERT_SQLITE_OK(rc, db); rc = (*proxy_sqlite3_bind_text)(statement1, 17, event->gtid, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); - rc = (*proxy_sqlite3_bind_text)(statement1, 18, event->errmsg, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_int)(statement1, 18, event->myerrno); ASSERT_SQLITE_OK(rc, db); + rc = (*proxy_sqlite3_bind_text)(statement1, 19, event->errmsg, -1, SQLITE_TRANSIENT); ASSERT_SQLITE_OK(rc, db); SAFE_SQLITE3_STEP2(statement1); rc=(*proxy_sqlite3_clear_bindings)(statement1); ASSERT_SQLITE_OK(rc, db); rc=(*proxy_sqlite3_reset)(statement1); ASSERT_SQLITE_OK(rc, db); diff --git a/lib/MySQL_Session.cpp b/lib/MySQL_Session.cpp index a9b83ac4fd..da950ec214 100644 --- a/lib/MySQL_Session.cpp +++ b/lib/MySQL_Session.cpp @@ -1453,9 +1453,10 @@ void MySQL_Session::return_proxysql_internal(PtrSize_t *pkt) { // default client_myds->DSS=STATE_QUERY_SENT_NET; string errmsg = "Unknown PROXYSQL INTERNAL command"; - client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,1064,(char *)"42000", errmsg.c_str() ,true); + client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,1047,(char *)"08S01", errmsg.c_str() ,true); if (mirror==false) { - RequestEnd(NULL, errmsg.c_str()); + MyHGM->add_mysql_errors(current_hostgroup, (char *)"", 0, client_myds->myconn->userinfo->username, (client_myds->addr.addr ? client_myds->addr.addr : (char *)"unknown" ), client_myds->myconn->userinfo->schemaname, 1047, (char *)errmsg.c_str()); + RequestEnd(NULL, 1047, errmsg.c_str()); } else { client_myds->DSS=STATE_SLEEP; status=WAITING_CLIENT_DATA; @@ -1605,7 +1606,7 @@ bool MySQL_Session::handler_special_queries(PtrSize_t *pkt) { status=WAITING_CLIENT_DATA; if (mirror==false) { - RequestEnd(NULL, err_info.second); + RequestEnd(NULL, err_info.first, err_info.second); } l_free(pkt->size,pkt->ptr); @@ -1805,9 +1806,10 @@ bool MySQL_Session::handler_special_queries(PtrSize_t *pkt) { if (mysql_thread___enable_load_data_local_infile == false) { client_myds->DSS=STATE_QUERY_SENT_NET; string errmsg = "Unsupported 'LOAD DATA LOCAL INFILE' command"; - client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,1047,(char *)"HY000", errmsg.c_str(), true); + client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,1047,(char *)"08S01", errmsg.c_str(), true); if (mirror==false) { - RequestEnd(NULL, errmsg.c_str()); + MyHGM->add_mysql_errors(current_hostgroup, (char *)"", 0, client_myds->myconn->userinfo->username, (client_myds->addr.addr ? client_myds->addr.addr : (char *)"unknown" ), client_myds->myconn->userinfo->schemaname, 1047, (char *)errmsg.c_str()); + RequestEnd(NULL, 1047, errmsg.c_str()); } else { client_myds->DSS=STATE_SLEEP; status=WAITING_CLIENT_DATA; @@ -3222,7 +3224,8 @@ bool MySQL_Session::handler_again___status_CONNECTING_SERVER(int *_rc) { thread->status_variables.stvar[st_var_max_connect_timeout_err]++; } client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,1,9001,(char *)"HY000", errmsg.c_str(), true); - RequestEnd(mybe->server_myds, errmsg.c_str()); + MyHGM->add_mysql_errors(current_hostgroup, (char *)"", 0, client_myds->myconn->userinfo->username, (client_myds->addr.addr ? client_myds->addr.addr : (char *)"unknown" ), client_myds->myconn->userinfo->schemaname, 9001, (char *)errmsg.c_str()); + RequestEnd(mybe->server_myds, 9001, errmsg.c_str()); string hg_status {}; generate_status_one_hostgroup(current_hostgroup, hg_status); @@ -3370,7 +3373,8 @@ bool MySQL_Session::handler_again___status_CONNECTING_SERVER(int *_rc) { } if (session_fast_forward==false) { // see bug #979 - RequestEnd(myds, errmsg.c_str()); + MyHGM->add_mysql_errors(current_hostgroup, (char *)"", 0, client_myds->myconn->userinfo->username, (client_myds->addr.addr ? client_myds->addr.addr : (char *)"unknown" ), client_myds->myconn->userinfo->schemaname, 9002, (char *)errmsg.c_str()); + RequestEnd(myds, 9002, errmsg.c_str()); } while (previous_status.size()) { st=previous_status.top(); @@ -3632,7 +3636,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C sprintf(buf, err_msg, current_hostgroup, locked_on_hostgroup, nqn.c_str(), end); client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,9005,(char *)"HY000",buf, true); thread->status_variables.stvar[st_var_hostgroup_locked_queries]++; - RequestEnd(NULL, buf); + RequestEnd(NULL, 9005, buf); free(buf); l_free(pkt.size,pkt.ptr); return; @@ -3805,7 +3809,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C sprintf(buf, err_msg, current_hostgroup, locked_on_hostgroup, nqn.c_str(), end); client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,9005,(char *)"HY000",buf, true); thread->status_variables.stvar[st_var_hostgroup_locked_queries]++; - RequestEnd(NULL, buf); + RequestEnd(NULL, 9005, buf); free(buf); l_free(pkt.size,pkt.ptr); return; @@ -4524,7 +4528,7 @@ int MySQL_Session::get_pkts_from_client(bool& wrong_pass, PtrSize_t& pkt) { sprintf(buf, err_msg, current_hostgroup, locked_on_hostgroup, nqn.c_str(), end); client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,9005,(char *)"HY000",buf, true); thread->status_variables.stvar[st_var_hostgroup_locked_queries]++; - RequestEnd(NULL, buf); + RequestEnd(NULL, 9005, buf); free(buf); l_free(pkt.size,pkt.ptr); break; @@ -5538,7 +5542,7 @@ int MySQL_Session::handler() { return handler_ret; } handler_minus1_GenerateErrorMessage(myds, myconn, wrong_pass); - RequestEnd(myds); + RequestEnd(myds, myerr); handler_minus1_HandleBackendConnection(myds, myconn); } } else { @@ -5676,6 +5680,7 @@ bool MySQL_Session::handler_again___status_SHOW_WARNINGS(MySQL_Data_Stream* myds myds->revents,(char *)"SHOW WARNINGS", strlen((char *)"SHOW WARNINGS") ); if (rc == 0 || rc == -1) { + int myerr = 0; // Cleanup the connection resulset from 'SHOW WARNINGS' for the next query. if (myconn->MyRS != NULL) { delete myconn->MyRS; @@ -5683,13 +5688,13 @@ bool MySQL_Session::handler_again___status_SHOW_WARNINGS(MySQL_Data_Stream* myds } if (rc == -1) { - int myerr = mysql_errno(myconn->mysql); + myerr = mysql_errno(myconn->mysql); proxy_error( "'SHOW WARNINGS' failed to be executed over backend connection with error: '%d'\n", myerr ); } - RequestEnd(myds); + RequestEnd(myds, myerr); finishQuery(myds,myconn,prepared_stmt_with_no_params); return false; @@ -6180,7 +6185,7 @@ void MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C msg = errmsg + ": " + nq; } client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,1148,(char *)"42000", msg.c_str()); - RequestEnd(NULL); + RequestEnd(NULL, 1148, msg.c_str()); } client_myds->DSS=STATE_SLEEP; } else { @@ -6266,7 +6271,8 @@ void MySQL_Session::handler_WCD_SS_MCQ_qpo_OK_msg(PtrSize_t *pkt) { void MySQL_Session::handler_WCD_SS_MCQ_qpo_error_msg(PtrSize_t *pkt) { 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); + MyHGM->add_mysql_errors(current_hostgroup, (char *)"", 0, client_myds->myconn->userinfo->username, (client_myds->addr.addr ? client_myds->addr.addr : (char *)"unknown" ), client_myds->myconn->userinfo->schemaname, 1148, (char *)qpo->error_msg); + RequestEnd(NULL, 1148, qpo->error_msg); l_free(pkt->size,pkt->ptr); } @@ -6285,7 +6291,8 @@ void MySQL_Session::handler_WCD_SS_MCQ_qpo_LargePacket(PtrSize_t *pkt) { client_myds->DSS=STATE_QUERY_SENT_NET; string errmsg = "Got a packet bigger than 'max_allowed_packet' bytes"; client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,1153,(char *)"08S01", errmsg.c_str(), true); - RequestEnd(NULL, errmsg.c_str()); + MyHGM->add_mysql_errors(current_hostgroup, (char *)"", 0, client_myds->myconn->userinfo->username, (client_myds->addr.addr ? client_myds->addr.addr : (char *)"unknown" ), client_myds->myconn->userinfo->schemaname, 1153, (char *)errmsg.c_str()); + RequestEnd(NULL, 1153, errmsg.c_str()); l_free(pkt->size,pkt->ptr); } @@ -7377,7 +7384,7 @@ bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C sprintf(buf,"ProxySQL Error: connection is locked to hostgroup %d but trying to reach hostgroup %d", locked_on_hostgroup, current_hostgroup); client_myds->myprot.generate_pkt_ERR(true,NULL,NULL,client_myds->pkt_sid+1,9006,(char *)"Y0000",buf); thread->status_variables.stvar[st_var_hostgroup_locked_queries]++; - RequestEnd(NULL, buf); + RequestEnd(NULL, 9006, buf); l_free(pkt->size,pkt->ptr); return true; } @@ -8026,24 +8033,24 @@ 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, const char * errmsg) { +void MySQL_Session::LogQuery(MySQL_Data_Stream *myds, const unsigned int myerrno, const char * errmsg) { // we need to access statistics before calling CurrentQuery.end() // so we track the time here CurrentQuery.end_time=thread->curtime; if (qpo) { if (qpo->log==1) { - GloMyLogger->log_request(this, myds, errmsg); // we send for logging only if logging is enabled for this query + GloMyLogger->log_request(this, myds, myerrno, errmsg); // we send for logging only if logging is enabled for this query } else { if (qpo->log==-1) { if (mysql_thread___eventslog_default_log==1) { - GloMyLogger->log_request(this, myds, errmsg); // we send for logging only if enabled by default + GloMyLogger->log_request(this, myds, myerrno, errmsg); // we send for logging only if enabled by default } } } } } -void MySQL_Session::RequestEnd(MySQL_Data_Stream *myds, const char * errmsg) { +void MySQL_Session::RequestEnd(MySQL_Data_Stream *myds, const unsigned int myerrno, const char * errmsg) { // check if multiplexing needs to be disabled char *qdt = NULL; @@ -8064,7 +8071,7 @@ void MySQL_Session::RequestEnd(MySQL_Data_Stream *myds, const char * errmsg) { break; default: if (session_fast_forward==false) { - LogQuery(myds, errmsg); + LogQuery(myds, myerrno, errmsg); } break; } diff --git a/lib/ProxySQL_Admin.cpp b/lib/ProxySQL_Admin.cpp index d08ba61fed..9b1e59bf9f 100644 --- a/lib/ProxySQL_Admin.cpp +++ b/lib/ProxySQL_Admin.cpp @@ -603,7 +603,7 @@ MHD_Result http_handler(void *cls, struct MHD_Connection *connection, const char #define ADMIN_SQLITE_TABLE_STATS_MYSQL_PREPARED_STATEMENTS_INFO "CREATE TABLE stats_mysql_prepared_statements_info (global_stmt_id INT NOT NULL , schemaname VARCHAR NOT NULL , username VARCHAR NOT NULL , digest VARCHAR NOT NULL , ref_count_client INT NOT NULL , ref_count_server INT NOT NULL , num_columns INT NOT NULL, num_params INT NOT NULL, query VARCHAR NOT NULL)" -#define ADMIN_SQLITE_TABLE_STATS_MYSQL_QUERY_EVENTS "CREATE TABLE stats_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT , error TEXT)" +#define ADMIN_SQLITE_TABLE_STATS_MYSQL_QUERY_EVENTS "CREATE TABLE stats_mysql_query_events (id INTEGER PRIMARY KEY AUTOINCREMENT , thread_id INTEGER , username TEXT , schemaname TEXT , start_time INTEGER , end_time INTEGER , query_digest TEXT , query TEXT , server TEXT , client TEXT , event_type INTEGER , hid INTEGER , extra_info TEXT , affected_rows INTEGER , last_insert_id INTEGER , rows_sent INTEGER , client_stmt_id INTEGER , gtid TEXT , errno INT , error TEXT)" static char * admin_variables_names[]= { diff --git a/test/tap/tests/mysql_query_logging_memory-t.cpp b/test/tap/tests/mysql_query_logging_memory-t.cpp new file mode 100644 index 0000000000..9d160d9eb2 --- /dev/null +++ b/test/tap/tests/mysql_query_logging_memory-t.cpp @@ -0,0 +1,316 @@ +/** + * @file mysql_query_logging_memory-t.cpp + * @brief This file contains a TAP test for testing query memory logging + */ + +// TODO: we also need to add checks for stats_mysql_errors + +#include +#include +#include +#include +#include +#include +#include +#include + +#include "mysql.h" +#include "mysqld_error.h" + +#include "tap.h" +#include "command_line.h" +#include "utils.h" + +using std::string; + +/** @brief Expected DDL for the stats_mysql_query_events table. */ +const std::string expected_stats_mysql_query_events = R"(CREATE TABLE stats_mysql_query_events ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + thread_id INTEGER, + username TEXT, + schemaname TEXT, + start_time INTEGER, + end_time INTEGER, + query_digest TEXT, + query TEXT, + server TEXT, + client TEXT, + event_type INTEGER, + hid INTEGER, + extra_info TEXT, + affected_rows INTEGER, + last_insert_id INTEGER, + rows_sent INTEGER, + client_stmt_id INTEGER, + gtid TEXT, + errno INT, + error TEXT))"; + +/** @brief Expected DDL for the history_mysql_query_events table. */ +const std::string expected_history_mysql_query_events = R"(CREATE TABLE history_mysql_query_events ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + thread_id INTEGER, + username TEXT, + schemaname TEXT, + start_time INTEGER, + end_time INTEGER, + query_digest TEXT, + query TEXT, + server TEXT, + client TEXT, + event_type INTEGER, + hid INTEGER, + extra_info TEXT, + affected_rows INTEGER, + last_insert_id INTEGER, + rows_sent INTEGER, + client_stmt_id INTEGER, + gtid TEXT, + errno INT, + error TEXT))"; + +/** + * @brief Removes multiple spaces from a string, replacing them with a single space. + * + * @param str The input string. + * @return The string with multiple spaces replaced by single spaces. + */ +std::string removeMultipleSpacesRegex(std::string str) { + std::replace(str.begin(), str.end(), '\n', ' '); //Replace newlines first + std::regex multipleSpaces("\\s+"); // Matches one or more whitespace characters + std::string result = std::regex_replace(str, multipleSpaces, " "); + return result; +} + +/** + * @brief Checks if the structure of a table matches the expected DDL. + * + * @param conn The MySQL connection. + * @param schemaname The name of the schema. + * @param table_name The name of the table. + * @param expected_ddl The expected DDL for the table. + * @return True if the table structure matches, false otherwise. + */ +bool runAndCheckTable(MYSQL* conn, const std::string& schemaname, const std::string& table_name, std::string expected_ddl) { + std::string query = "SHOW CREATE TABLE " + schemaname + "." + table_name; + if (mysql_query(conn, query.c_str())) { + diag("Error querying table '%s': %s", table_name.c_str(), mysql_error(conn)); + return false; + } + + MYSQL_RES* result = mysql_store_result(conn); + if (!result) { + diag("Error storing result for table '%s': %s", table_name.c_str(), mysql_error(conn)); + return false; + } + + MYSQL_ROW row = mysql_fetch_row(result); + if (!row || row[1] == nullptr) { + diag("Unexpected result for table '%s'", table_name.c_str()); + mysql_free_result(result); + return false; + } + + std::string actual_ddl(row[1]); + mysql_free_result(result); + size_t pos = actual_ddl.find('\n'); + while (pos != std::string::npos) { + actual_ddl.replace(pos, 1, " "); + pos = actual_ddl.find('\n', pos + 1); + } + + actual_ddl = removeMultipleSpacesRegex(actual_ddl); + expected_ddl = removeMultipleSpacesRegex(expected_ddl); + + bool success = (actual_ddl == expected_ddl); + ok(success, "Table '%s' structure %s match expectation", table_name.c_str(), (success ? "matches" : "does not match")); + if (success == false) { + diag("Table structure actual : %s", actual_ddl.c_str()); + diag("Table structure expected: %s", expected_ddl.c_str()); + } + return success; +} + + +/** + * @brief Checks the result of a query against expected results. + * + * @param conn The MySQL connection. + * @param query The query to execute. + * @param expectedResults The expected results as a map of errno to count. + * @return True if the query results match the expected results, false otherwise. + */ +bool checkQueryResult(MYSQL* conn, const std::string& query, const std::map& expectedResults) { + if (mysql_query(conn, query.c_str())) { + diag("Error executing query '%s': %s", query.c_str(), mysql_error(conn)); + return false; + } + + MYSQL_RES* result = mysql_store_result(conn); + if (!result) { + diag("Error storing result for query '%s': %s", query.c_str(), mysql_error(conn)); + return false; + } + + std::map actualResults; + MYSQL_ROW row; + while ((row = mysql_fetch_row(result))) { + actualResults[std::stoi(row[0])] = std::stoi(row[1]); + } + mysql_free_result(result); + + return actualResults == expectedResults; +} + + +int main() { + + + CommandLine cl; + if (cl.getEnv()) { + diag("Failed to get the required environmental variables."); + return -1; + } + + const unsigned int num_selects = 200; // Number of "SELECT 1" queries to run + unsigned int p = 2; // Number of tests for table structure checks + p += num_selects/10; // Number of tests for SELECT 1 queries (one every 10 iterations) + p += 1; // Number of tests for syntax error + p += 1; // Number of tests for empty hostgroup error + p += 1; // Number of tests for non-existing schema error + p += 2; // Number of tests for checking query results in stats and history tables + plan(p); + + MYSQL* admin_conn = mysql_init(nullptr); + if (!admin_conn) { + diag("Failed to initialize MySQL connection."); + return -1; + } + + if (!mysql_real_connect(admin_conn, cl.host, cl.admin_username, cl.admin_password, nullptr, cl.admin_port, nullptr, 0)) { + diag("Failed to connect to ProxySQL admin: %s", mysql_error(admin_conn)); + mysql_close(admin_conn); + return -1; + } + + // Check table structures + runAndCheckTable(admin_conn, "stats", "stats_mysql_query_events", expected_stats_mysql_query_events); + runAndCheckTable(admin_conn, "stats_history", "history_mysql_query_events", expected_history_mysql_query_events); + + // Prepare for testing + MYSQL_QUERY(admin_conn, "SET mysql-eventslog_buffer_history_size=1000000"); + MYSQL_QUERY(admin_conn, "SET mysql-eventslog_default_log=1"); + MYSQL_QUERY(admin_conn, "LOAD MYSQL VARIABLES TO RUNTIME"); + MYSQL_QUERY(admin_conn, "DUMP EVENTSLOG FROM BUFFER TO BOTH"); + MYSQL_QUERY(admin_conn, "DELETE FROM stats_mysql_query_events"); + MYSQL_QUERY(admin_conn, "DELETE FROM history_mysql_query_events"); + + + + MYSQL* proxy = mysql_init(NULL); + if (!proxy) { + diag("Failed to initialize MySQL connection to ProxySQL."); + mysql_close(admin_conn); //Close admin connection before exiting. + return -1; + } + + if (!mysql_real_connect(proxy, cl.host, cl.username, cl.password, NULL, cl.port, NULL, 0)) { + diag("Failed to connect to ProxySQL: %s", mysql_error(proxy)); + mysql_close(admin_conn); + mysql_close(proxy); + return -1; + } + + + // Run 200 "SELECT 1" queries + for (int i = 0; i < 200; ++i) { + if (mysql_query(proxy, "SELECT 1")) { + diag("Error executing 'SELECT 1' query (iteration %d): %s", i, mysql_error(proxy)); + mysql_close(admin_conn); + mysql_close(proxy); + return -1; + } + MYSQL_RES *result = mysql_store_result(proxy); + if (result) mysql_free_result(result); //Clean up result if it exists + if ((i+1)%10 == 0) { // avoid too much logging + ok(1, "SELECT 1 query successful (iteration %d)", i+1); + } + } + + // Test syntax error + if (mysql_query(proxy, "SELEEEEECT 1")) { + //Check if we received a syntax error (adjust error code as needed for your MySQL version). + int error_code = mysql_errno(proxy); + ok(error_code == 1064, "Syntax error detected correctly (error code: %d)", error_code); //1064 is a common syntax error code + } else { + diag("Expected syntax error, but query succeeded."); + mysql_close(admin_conn); + mysql_close(proxy); + return -1; + } + + // Test hostgroup error + if (mysql_query(proxy, "SELECT /* hostgroup=1234 */ 1")) { + int error_code = mysql_errno(proxy); + ok(error_code == 9001, "Hostgroup error detected correctly (error code: %d)", error_code); + } else { + diag("Expected hostgroup error (error code 9001), but query succeeded."); + mysql_close(admin_conn); + mysql_close(proxy); + return -1; + } + + // Test connection to non-existent schema with query + MYSQL* nonExistentSchemaConn = mysql_init(NULL); + if (!nonExistentSchemaConn) { + diag("Failed to initialize MySQL connection for non-existent schema test."); + mysql_close(admin_conn); + mysql_close(proxy); + return -1; + } + + // Replace 'nonexistent_schema' with the actual name of a non-existent schema. + if (!mysql_real_connect(nonExistentSchemaConn, cl.host, cl.username, cl.password, "nonexistent_schema", cl.port, NULL, 0)) { + diag("Failed to connect to non-existent schema 'nonexistent_schema': %s", mysql_error(nonExistentSchemaConn)); + mysql_close(nonExistentSchemaConn); + mysql_close(admin_conn); + mysql_close(proxy); + return -1; + } + + if (mysql_query(nonExistentSchemaConn, "SELECT 1")) { + int error_code = mysql_errno(nonExistentSchemaConn); + ok(error_code == 1044, "Query on non-existent schema returned expected error (1044): %d", error_code); + } else { + diag("Query on non-existent schema succeeded unexpectedly."); + mysql_close(nonExistentSchemaConn); + mysql_close(admin_conn); + mysql_close(proxy); + return -1; + } + + // dump eventslog + MYSQL_QUERY(admin_conn, "DUMP EVENTSLOG FROM BUFFER TO BOTH"); + + + // Expected results for both queries + std::map expectedResults = { + {0, 200}, + {1064, 1}, + {9001, 1}, + {9002, 1} + }; + + // Test history_mysql_query_events + bool historyCheck = checkQueryResult(admin_conn, "SELECT errno, COUNT(*) FROM history_mysql_query_events GROUP BY errno ORDER BY errno", expectedResults); + ok(historyCheck, "history_mysql_query_events query results match expectation"); + + // Test stats_mysql_query_events + bool statsCheck = checkQueryResult(admin_conn, "SELECT errno, COUNT(*) FROM stats_mysql_query_events GROUP BY errno ORDER BY errno", expectedResults); + ok(statsCheck, "stats_mysql_query_events query results match expectation"); + + mysql_close(nonExistentSchemaConn); + mysql_close(proxy); + mysql_close(admin_conn); + return exit_status(); +}