From f7d88243796b87eaaecd7e157c7fb327fc78bf19 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ren=C3=A9=20Canna=C3=B2?= Date: Fri, 5 Aug 2022 21:06:15 +0000 Subject: [PATCH] Trying to work around MySQL bug 107875 Because of MySQL bug https://bugs.mysql.com/bug.php?id=107875 , autocommit=0 can "create a transaction" even if SERVER_STATUS_IN_TRANS is not set. This means that a SAVEPOINT can be created in a "transaction" created with autocommit=0 but without SERVER_STATUS_IN_TRANS . This commit takes also care of scenarios when autocommit=0 was switched back to autocommit=1 when a SELECT was executed while variable mysql-enforce_autocommit_on_reads was false. MySQL_Session::NumActiveTransactions() now accepts a flag to check for savepoints. --- include/MySQL_Session.h | 2 +- include/mysql_connection.h | 1 + lib/MySQL_Session.cpp | 44 ++- lib/mysql_connection.cpp | 19 +- test/tap/tests/savepoint-3749-t.cpp | 499 ++++++++++++++++++++++++++++ test/tap/tests/savepoint-948-t.cpp | 82 ++--- 6 files changed, 570 insertions(+), 77 deletions(-) create mode 100644 test/tap/tests/savepoint-3749-t.cpp diff --git a/include/MySQL_Session.h b/include/MySQL_Session.h index 8c06a9179..9139c5576 100644 --- a/include/MySQL_Session.h +++ b/include/MySQL_Session.h @@ -308,7 +308,7 @@ class MySQL_Session void SQLite3_to_MySQL(SQLite3_result *, char *, int , MySQL_Protocol *, bool in_transaction=false, bool deprecate_eof_active=false); void MySQL_Result_to_MySQL_wire(MYSQL *mysql, MySQL_ResultSet *MyRS, MySQL_Data_Stream *_myds=NULL); void MySQL_Stmt_Result_to_MySQL_wire(MYSQL_STMT *stmt, MySQL_Connection *myconn); - unsigned int NumActiveTransactions(); + unsigned int NumActiveTransactions(bool check_savpoint=false); bool HasOfflineBackends(); bool SetEventInOfflineBackends(); int FindOneActiveTransaction(); diff --git a/include/mysql_connection.h b/include/mysql_connection.h index 698c0982d..6283e149f 100644 --- a/include/mysql_connection.h +++ b/include/mysql_connection.h @@ -216,6 +216,7 @@ class MySQL_Connection { } */ bool IsServerOffline(); bool IsAutoCommit(); + bool AutocommitFalse_AndSavepoint(); bool MultiplexDisabled(); bool IsKeepMultiplexEnabledVariables(char *query_digest_text); void ProcessQueryAndSetStatusFlags(char *query_digest_text); diff --git a/lib/MySQL_Session.cpp b/lib/MySQL_Session.cpp index 6f9cddfbb..ca553f2a2 100644 --- a/lib/MySQL_Session.cpp +++ b/lib/MySQL_Session.cpp @@ -806,28 +806,34 @@ void MySQL_Session::writeout() { proxy_debug(PROXY_DEBUG_NET,1,"Thread=%p, Session=%p -- Writeout Session %p\n" , this->thread, this, this); } -// FIXME: This function is currently disabled . See #469 bool MySQL_Session::handler_CommitRollback(PtrSize_t *pkt) { char c=((char *)pkt->ptr)[5]; bool ret=false; if (c=='c' || c=='C') { - if (strncasecmp((char *)"commit",(char *)pkt->ptr+5,6)==0) { + if (pkt->size==strlen("commit")+5) { + if (strncasecmp((char *)"commit",(char *)pkt->ptr+5,6)==0) { __sync_fetch_and_add(&MyHGM->status.commit_cnt, 1); ret=true; } - } else { - if (c=='r' || c=='R') { + } + } else { + if (c=='r' || c=='R') { + if (pkt->size==strlen("rollback")+5) { if ( strncasecmp((char *)"rollback",(char *)pkt->ptr+5,8)==0 ) { __sync_fetch_and_add(&MyHGM->status.rollback_cnt, 1); ret=true; } } } + } if (ret==false) { return false; // quick exit } - unsigned int nTrx=NumActiveTransactions(); + // this is the only part of the code (as at release 2.4.3) where we call + // NumActiveTransactions() with the check_savepoint flag . + // This to try to handle MySQL bug https://bugs.mysql.com/bug.php?id=107875 + unsigned int nTrx=NumActiveTransactions(true); if (nTrx) { // there is an active transaction, we must forward the request return false; @@ -1943,7 +1949,13 @@ bool MySQL_Session::handler_again___verify_backend_autocommit() { } else { if (autocommit == false) { // also IsAutoCommit==false if (mysql_thread___enforce_autocommit_on_reads == false) { - if (mybe->server_myds->myconn->IsActiveTransaction() == false) { + if ( + mybe->server_myds->myconn->IsActiveTransaction() == false + && + // another edge case related to MySQL bug https://bugs.mysql.com/bug.php?id=107875 + // about autocommit=0 and SAVEPOINT + mybe->server_myds->myconn->AutocommitFalse_AndSavepoint() == false + ) { if (CurrentQuery.is_select_NOT_for_update()==true) { // client wants autocommit=0 // enforce_autocommit_on_reads=false @@ -6962,17 +6974,29 @@ void MySQL_Session::set_unhealthy() { } -unsigned int MySQL_Session::NumActiveTransactions() { +unsigned int MySQL_Session::NumActiveTransactions(bool check_savepoint) { unsigned int ret=0; if (mybes==0) return ret; MySQL_Backend *_mybe; unsigned int i; for (i=0; i < mybes->len; i++) { _mybe=(MySQL_Backend *)mybes->index(i); - if (_mybe->server_myds) - if (_mybe->server_myds->myconn) - if (_mybe->server_myds->myconn->IsActiveTransaction()) + if (_mybe->server_myds) { + if (_mybe->server_myds->myconn) { + if (_mybe->server_myds->myconn->IsActiveTransaction()) { ret++; + } else { + // we use check_savepoint to check if we shouldn't ignore COMMIT or ROLLBACK due + // to MySQL bug https://bugs.mysql.com/bug.php?id=107875 related to + // SAVEPOINT and autocommit=0 + if (check_savepoint) { + if (_mybe->server_myds->myconn->AutocommitFalse_AndSavepoint() == true) { + ret++; + } + } + } + } + } } return ret; } diff --git a/lib/mysql_connection.cpp b/lib/mysql_connection.cpp index e92c5f926..5e9523cfa 100644 --- a/lib/mysql_connection.cpp +++ b/lib/mysql_connection.cpp @@ -2260,6 +2260,17 @@ void MySQL_Connection::async_free_result() { } } +// This function check if autocommit=0 and if there are any savepoint. +// this is an attempt to mitigate MySQL bug https://bugs.mysql.com/bug.php?id=107875 +bool MySQL_Connection::AutocommitFalse_AndSavepoint() { + bool ret=false; + if (IsAutoCommit() == false) { + if (get_status(STATUS_MYSQL_CONNECTION_HAS_SAVEPOINT) == true) { + ret = true; + } + } + return ret; +} bool MySQL_Connection::IsActiveTransaction() { bool ret=false; @@ -2525,14 +2536,14 @@ void MySQL_Connection::ProcessQueryAndSetStatusFlags(char *query_digest_text) { ( // make sure we don't have a transaction running // checking just for COMMIT and ROLLBACK is not enough, because `SET autocommit=1` can commit too -// (mysql->server_status & SERVER_STATUS_AUTOCOMMIT) -// && + (mysql->server_status & SERVER_STATUS_AUTOCOMMIT) + && ( (mysql->server_status & SERVER_STATUS_IN_TRANS) == 0 ) ) || - !strcasecmp(query_digest_text,"COMMIT") + (strcasecmp(query_digest_text,"COMMIT") == 0) || - !strcasecmp(query_digest_text,"ROLLBACK") + (strcasecmp(query_digest_text,"ROLLBACK") == 0) ) { set_status(false, STATUS_MYSQL_CONNECTION_HAS_SAVEPOINT); } diff --git a/test/tap/tests/savepoint-3749-t.cpp b/test/tap/tests/savepoint-3749-t.cpp new file mode 100644 index 000000000..9606863af --- /dev/null +++ b/test/tap/tests/savepoint-3749-t.cpp @@ -0,0 +1,499 @@ +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "tap.h" +#include "utils.h" +#include "command_line.h" + + +unsigned long long monotonic_time() { + struct timespec ts; + //clock_gettime(CLOCK_MONOTONIC_COARSE, &ts); // this is faster, but not precise + clock_gettime(CLOCK_MONOTONIC, &ts); + return (((unsigned long long) ts.tv_sec) * 1000000) + (ts.tv_nsec / 1000); +} + +struct cpu_timer +{ + cpu_timer() { + begin = monotonic_time(); + } + ~cpu_timer() + { + unsigned long long end = monotonic_time(); + std::cerr << double( end - begin ) / 1000000 << " secs.\n" ; + begin=end-begin; + }; + unsigned long long begin; +}; + +bool debug_diag = true; +unsigned int num_threads=5; +int count=10; +char *username=NULL; +char *password=NULL; +char *host=(char *)"localhost"; +int port=3306; +char *schema=(char *)"information_schema"; +int silent = 0; +int sysbench = 0; +int local=0; +int transactions=200; +int uniquequeries=0; +int histograms=-1; + +unsigned int g_passed=0; +unsigned int g_failed=0; + +std::atomic cnt_transactions; +std::atomic cnt_SELECT_outside_transactions; +std::atomic cnt_expected_errors; + +unsigned int status_connections = 0; +unsigned int connect_phase_completed = 0; +unsigned int query_phase_completed = 0; + +__thread int g_seed; +std::mutex mtx_; + +inline int fastrand() { + g_seed = (214013*g_seed+2531011); + return (g_seed>>16)&0x7FFF; +} + +void gen_random(char *s, const int len) { + static const char alphanum[] = + "ABCDEFGHIJKLMNOPQRSTUVWXYZ" + "abcdefghijklmnopqrstuvwxyz"; + + for (int i = 0; i < len; ++i) { + s[i] = alphanum[fastrand() % (sizeof(alphanum) - 1)]; + } + + s[len] = 0; +} + +void * my_conn_thread(void *arg) { + g_seed = time(NULL) ^ getpid() ^ pthread_self(); + unsigned int select_OK=0; + unsigned int select_ERR=0; + int i, j; + MYSQL **mysqlconns=(MYSQL **)malloc(sizeof(MYSQL *)*count); + + if (mysqlconns==NULL) { + exit(EXIT_FAILURE); + } + + + for (i=0; i 7) { + q = "RELEASE SAVEPOINT "; + q += buf; + if (debug_diag==true) + diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, q.c_str()); + if (mysql_query(mysql, q.c_str())) { + fprintf(stderr,"Error running query: %s. Error: %s\n", q.c_str(), mysql_error(mysql)); + exit(EXIT_FAILURE); + } + sleepDelay = fastrand()%100; + usleep(sleepDelay * 100); + } + } + { + std::string q; + int f = fr%3; + if (f==0) { + q = "COMMIT"; + } else { + q = "ROLLBACK"; +/* + // FIXME: this code is currently commented because of another bug + if (explicit_transaction==false) { + if (f!=1) { + q = "SET AUTOCOMMIT=1"; + } + } +*/ + } + if (debug_diag==true) + diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, q.c_str()); + if (mysql_query(mysql, q.c_str())) { + fprintf(stderr,"Error running query: %s. Error: %s\n", q.c_str(), mysql_error(mysql)); + exit(EXIT_FAILURE); + } + cnt_transactions++; + sleepDelay = fastrand()%100; + usleep(sleepDelay * 100); + } +/* + // we do not log every single transaction, too verbose + bool testPassed = true; + { + std::lock_guard lock(mtx_); + ok(testPassed, "mysql connection [%p], thread_id [%lu], transaction completed", mysql, mysql->thread_id); + } +*/ + if (fr%7 == 0) { + std::string sel; + sel = sel1; + if (debug_diag==true) + diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, sel.c_str()); + if (mysql_query(mysql, sel.c_str())) { + fprintf(stderr,"Error running query: %s. Error: %s\n", sel.c_str(), mysql_error(mysql)); + } else { + MYSQL_RES *result = mysql_store_result(mysql); + mysql_free_result(result); + select_OK++; + cnt_SELECT_outside_transactions++; + } + sleepDelay = fastrand()%100; + usleep(sleepDelay * 100); + } + + } + for (i=0; i= cnt_transactions+cnt_SELECT_outside_transactions-10) , "Number of transactions [%d] , Queries outside transaction [%d] , total connections returned [%d]", cnt_transactions.load(std::memory_order_relaxed), cnt_SELECT_outside_transactions.load(std::memory_order_relaxed), MyHGM_myconnpoll_get); + ok((MyHGM_myconnpoll_get == cnt_transactions+cnt_SELECT_outside_transactions) , "Number of transactions [%d] , Queries outside transaction [%d] , total connections returned [%d]", cnt_transactions.load(std::memory_order_relaxed), cnt_SELECT_outside_transactions.load(std::memory_order_relaxed), MyHGM_myconnpoll_get); + MYSQL_QUERY(mysqladmin, "DELETE FROM mysql_query_rules"); + MYSQL_QUERY(mysqladmin, "INSERT INTO mysql_query_rules SELECT * FROM mysql_query_rules_948"); + MYSQL_QUERY(mysqladmin, "LOAD MYSQL QUERY RULES TO RUNTIME"); + return exit_status(); +} diff --git a/test/tap/tests/savepoint-948-t.cpp b/test/tap/tests/savepoint-948-t.cpp index 9606863af..4b33a28c5 100644 --- a/test/tap/tests/savepoint-948-t.cpp +++ b/test/tap/tests/savepoint-948-t.cpp @@ -41,9 +41,15 @@ struct cpu_timer unsigned long long begin; }; -bool debug_diag = true; -unsigned int num_threads=5; +bool debug_diag=true; +/* +unsigned int num_threads=4; int count=10; +int transactions=200; +*/ +unsigned int num_threads=1; +int count=1; +int transactions=200; char *username=NULL; char *password=NULL; char *host=(char *)"localhost"; @@ -52,7 +58,6 @@ char *schema=(char *)"information_schema"; int silent = 0; int sysbench = 0; int local=0; -int transactions=200; int uniquequeries=0; int histograms=-1; @@ -61,7 +66,6 @@ unsigned int g_failed=0; std::atomic cnt_transactions; std::atomic cnt_SELECT_outside_transactions; -std::atomic cnt_expected_errors; unsigned int status_connections = 0; unsigned int connect_phase_completed = 0; @@ -145,11 +149,13 @@ void * my_conn_thread(void *arg) { if (fr%2) { q = "START TRANSACTION"; explicit_transaction = true; + if (debug_diag==true) + diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, q.c_str()); } else { q = "SET AUTOCOMMIT=0"; + if (debug_diag==true) + diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, q.c_str()); } - if (debug_diag==true) - diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, q.c_str()); if (mysql_query(mysql, q.c_str())) { fprintf(stderr,"Error running query: %s. Error: %s\n", q.c_str(), mysql_error(mysql)); exit(EXIT_FAILURE); @@ -158,25 +164,18 @@ void * my_conn_thread(void *arg) { usleep(sleepDelay * 100); } - if (fr%3 == 0 || explicit_transaction==false) { - std::string sel; - if (explicit_transaction==false) { - // we need to issue a SELECT FOR UPDATE to trigger a transaction - sel = sel1 + " FOR UPDATE"; - } else { - sel = sel1; - } - if (debug_diag==true) - diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, sel.c_str()); - if (mysql_query(mysql, sel.c_str())) { - fprintf(stderr,"Error running query: %s. Error: %s\n", sel.c_str(), mysql_error(mysql)); + if (fr%3 == 0) { + if (mysql_query(mysql, sel1.c_str())) { + fprintf(stderr,"Error running query: %s. Error: %s\n", sel1.c_str(), mysql_error(mysql)); } else { + if (debug_diag==true) + diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, sel1.c_str()); MYSQL_RES *result = mysql_store_result(mysql); mysql_free_result(result); select_OK++; -// if (explicit_transaction == false) { -// cnt_SELECT_outside_transactions++; -// } + if (explicit_transaction == false) { + cnt_SELECT_outside_transactions++; + } } sleepDelay = fastrand()%100; usleep(sleepDelay * 100); @@ -211,23 +210,6 @@ void * my_conn_thread(void *arg) { usleep(sleepDelay * 100); } int aa = fr%10; - if (aa==2 || aa==3) { // sometime before RELEASE, sometimes before ROLLBACK - std::string q = "ROLLBACK TO SAVEPOINT "; - q+= buf; - q+= "NonExistingSavePoint"; - if (debug_diag==true) - diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, q.c_str()); - int rc = mysql_query(mysql, q.c_str()); - if (rc != 0) { - cnt_expected_errors++; - if (debug_diag==true) - diag("EXPECTED error running query: %s. Error: %s\n", q.c_str(), mysql_error(mysql)); - } else { - ok(rc!=0, "Generating a \"not ok\" . We didn't receive any error for: %s", q.c_str()); - } - sleepDelay = fastrand()%100; - usleep(sleepDelay * 100); - } if (aa < 3) { std::string q; q = "RELEASE SAVEPOINT "; @@ -281,8 +263,6 @@ void * my_conn_thread(void *arg) { } */ } - if (debug_diag==true) - diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, q.c_str()); if (mysql_query(mysql, q.c_str())) { fprintf(stderr,"Error running query: %s. Error: %s\n", q.c_str(), mysql_error(mysql)); exit(EXIT_FAILURE); @@ -299,23 +279,6 @@ void * my_conn_thread(void *arg) { ok(testPassed, "mysql connection [%p], thread_id [%lu], transaction completed", mysql, mysql->thread_id); } */ - if (fr%7 == 0) { - std::string sel; - sel = sel1; - if (debug_diag==true) - diag("Thread %lu , connection %p , query: %s", pthread_self(), mysql, sel.c_str()); - if (mysql_query(mysql, sel.c_str())) { - fprintf(stderr,"Error running query: %s. Error: %s\n", sel.c_str(), mysql_error(mysql)); - } else { - MYSQL_RES *result = mysql_store_result(mysql); - mysql_free_result(result); - select_OK++; - cnt_SELECT_outside_transactions++; - } - sleepDelay = fastrand()%100; - usleep(sleepDelay * 100); - } - } for (i=0; i