diff --git a/mysql-test/suite/binlog_gtid/r/binlog_gtid_log_status_mismatch.result b/mysql-test/suite/binlog_gtid/r/binlog_gtid_log_status_mismatch.result new file mode 100644 index 00000000000..e6729756c7d --- /dev/null +++ b/mysql-test/suite/binlog_gtid/r/binlog_gtid_log_status_mismatch.result @@ -0,0 +1,30 @@ +# Connection default +RESET MASTER; +CREATE TABLE t1(c1 INT); +INSERT INTO t1 VALUES(1); +INSERT INTO t1 VALUES(2); +FLUSH BINARY LOGS; +SET debug_sync = "process_commit_stage_queue_before_handle_gtid SIGNAL insert_in_sync WAIT_FOR insert_continue"; +INSERT INTO t1 VALUES(3); +# Connection 1 +SET DEBUG_SYNC= 'now WAIT_FOR insert_in_sync'; +SET debug_sync = "log_resource_gtid_lock SIGNAL gtid_in_sync WAIT_FOR gtid_continue"; +SELECT REPLACE(LOCAL->"$.gtid_executed", '"', '') INTO @ps_log_status FROM performance_schema.log_status; +# Connection 2 +SET DEBUG_SYNC= 'now WAIT_FOR gtid_in_sync'; +SET DEBUG_SYNC= 'now SIGNAL gtid_continue'; +SET DEBUG_SYNC= 'now SIGNAL insert_continue'; +# Connection 1 +include/assert.inc [Gtid_executed is updated with GTID 4] +SET debug_sync = "process_commit_stage_queue_before_handle_gtid SIGNAL insert_in_sync WAIT_FOR insert_continue"; +INSERT INTO t1 VALUES(4); +# Connection 1 +SET DEBUG_SYNC= 'now WAIT_FOR insert_in_sync'; +SET debug_sync = "log_resource_gtid_lock SIGNAL gtid_in_sync WAIT_FOR gtid_continue"; +SELECT REPLACE(LOCAL->"$.gtid_executed", '"', '') INTO @ps_log_status FROM performance_schema.log_status; +# Connection 2 +SET DEBUG_SYNC= 'now WAIT_FOR gtid_in_sync'; +SET DEBUG_SYNC= 'now SIGNAL gtid_continue'; +include/assert.inc [SELECT is waiting on LOCK_commit] +SET DEBUG_SYNC= 'now SIGNAL insert_continue'; +DROP TABLE t1; diff --git a/mysql-test/suite/binlog_gtid/t/binlog_gtid_log_status_mismatch.test b/mysql-test/suite/binlog_gtid/t/binlog_gtid_log_status_mismatch.test new file mode 100644 index 00000000000..6ed3e269593 --- /dev/null +++ b/mysql-test/suite/binlog_gtid/t/binlog_gtid_log_status_mismatch.test @@ -0,0 +1,83 @@ +--source include/have_debug.inc +--source include/have_debug_sync.inc +# This test case is binary log format agnostic +--source include/have_binlog_format_row.inc +--source include/count_sessions.inc + +--connect (con1,localhost,root,,) +--connect (con2,localhost,root,,) +--echo # Connection default +--connection default +RESET MASTER; +--let $server_uuid= `SELECT @@GLOBAL.SERVER_UUID` +CREATE TABLE t1(c1 INT); +INSERT INTO t1 VALUES(1); +INSERT INTO t1 VALUES(2); +FLUSH BINARY LOGS; + +# +# Test 1 - Check we get correct GTID from log_status +# + +SET debug_sync = "process_commit_stage_queue_before_handle_gtid SIGNAL insert_in_sync WAIT_FOR insert_continue"; +--send INSERT INTO t1 VALUES(3) + +--echo # Connection 1 +--connection con1 +SET DEBUG_SYNC= 'now WAIT_FOR insert_in_sync'; +SET debug_sync = "log_resource_gtid_lock SIGNAL gtid_in_sync WAIT_FOR gtid_continue"; + +--send SELECT REPLACE(LOCAL->"$.gtid_executed", '"', '') INTO @ps_log_status FROM performance_schema.log_status + +--echo # Connection 2 +--connection con2 +SET DEBUG_SYNC= 'now WAIT_FOR gtid_in_sync'; +SET DEBUG_SYNC= 'now SIGNAL gtid_continue'; +SET DEBUG_SYNC= 'now SIGNAL insert_continue'; + +--echo # Connection 1 +--connection con1 +--reap +--let $assert_text= Gtid_executed is updated with GTID 4 +--let $assert_cond= "[SELECT @ps_log_status]" = "$server_uuid:1-4" +--source include/assert.inc + + +--connection default +--reap + +# +# Test 2 - Check the query to log_status is waiting on LOCK_commit +# + +SET debug_sync = "process_commit_stage_queue_before_handle_gtid SIGNAL insert_in_sync WAIT_FOR insert_continue"; +--send INSERT INTO t1 VALUES(4) + +--echo # Connection 1 +--connection con1 +SET DEBUG_SYNC= 'now WAIT_FOR insert_in_sync'; +SET debug_sync = "log_resource_gtid_lock SIGNAL gtid_in_sync WAIT_FOR gtid_continue"; + +--send SELECT REPLACE(LOCAL->"$.gtid_executed", '"', '') INTO @ps_log_status FROM performance_schema.log_status + +--echo # Connection 2 +--connection con2 +SET DEBUG_SYNC= 'now WAIT_FOR gtid_in_sync'; +SET DEBUG_SYNC= 'now SIGNAL gtid_continue'; +--let $assert_text= SELECT is waiting on LOCK_commit +--let $assert_cond= "[SELECT COUNT(*) FROM performance_schema.threads T, performance_schema.events_waits_current W WHERE T.THREAD_ID=W.THREAD_ID AND W.EVENT_NAME LIKE \"%MYSQL_BIN_LOG::LOCK_commit\" AND T.PROCESSLIST_INFO LIKE \"%FROM%log_status%\"]" = 1 +--source include/assert.inc +SET DEBUG_SYNC= 'now SIGNAL insert_continue'; + + + +# Cleanup +--connection con1 +--reap +--connection default +--reap +DROP TABLE t1; + +--disconnect con1 +--disconnect con2 +--source include/wait_until_count_sessions.inc diff --git a/sql/binlog.cc b/sql/binlog.cc index b3078ef5170..516228dbf80 100644 --- a/sql/binlog.cc +++ b/sql/binlog.cc @@ -8733,6 +8733,7 @@ void MYSQL_BIN_LOG::process_commit_stage_queue(THD *thd, THD *first) { head->commit_error, YESNO(head->tx_commit_pending))); } + DEBUG_SYNC(thd, "process_commit_stage_queue_before_handle_gtid"); /* Handle the GTID of the threads. gtid_executed table is kept updated even though transactions fail to be diff --git a/sql/binlog.h b/sql/binlog.h index 8abe0c3f42d..17bdfd0b5fb 100644 --- a/sql/binlog.h +++ b/sql/binlog.h @@ -842,6 +842,7 @@ class MYSQL_BIN_LOG : public TC_LOG { const char *get_name() const { return name; } inline mysql_mutex_t *get_log_lock() { return &LOCK_log; } inline mysql_mutex_t *get_commit_lock() { return &LOCK_commit; } + inline mysql_mutex_t *get_sync_lock() { return &LOCK_sync; } inline mysql_cond_t *get_log_cond() { return &update_cond; } inline Binlog_ofile *get_binlog_file() { return m_binlog_file; } diff --git a/sql/log_resource.cc b/sql/log_resource.cc index adc9b2a5f86..c0e355152d8 100644 --- a/sql/log_resource.cc +++ b/sql/log_resource.cc @@ -21,6 +21,7 @@ Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA */ #include "sql/log_resource.h" +#include "debug_sync.h" #include "sql/json_dom.h" int MY_ATTRIBUTE((visibility("default"))) @@ -100,12 +101,23 @@ bool Log_resource_binlog_wrapper::collect_info() { return error; } -void Log_resource_gtid_state_wrapper::lock() { global_sid_lock->wrlock(); } +void Log_resource_gtid_state_wrapper::lock() { + DEBUG_SYNC(current_thd, "log_resource_gtid_lock"); + mysql_mutex_lock(binlog->get_sync_lock()); + mysql_mutex_lock(binlog->get_commit_lock()); + global_sid_lock->wrlock(); +} -void Log_resource_gtid_state_wrapper::unlock() { global_sid_lock->unlock(); } +void Log_resource_gtid_state_wrapper::unlock() { + global_sid_lock->unlock(); + mysql_mutex_unlock(binlog->get_commit_lock()); + mysql_mutex_unlock(binlog->get_sync_lock()); +} bool Log_resource_gtid_state_wrapper::collect_info() { bool error = false; + mysql_mutex_assert_owner(binlog->get_sync_lock()); + mysql_mutex_assert_owner(binlog->get_commit_lock()); global_sid_lock->assert_some_wrlock(); char *gtid_executed_string; @@ -150,9 +162,10 @@ Log_resource *Log_resource_factory::get_wrapper(MYSQL_BIN_LOG *binlog, } Log_resource *Log_resource_factory::get_wrapper(Gtid_state *gtid_state, + MYSQL_BIN_LOG *binlog, Json_dom *json) { Log_resource_gtid_state_wrapper *wrapper; - wrapper = new Log_resource_gtid_state_wrapper(gtid_state, json); + wrapper = new Log_resource_gtid_state_wrapper(gtid_state, binlog, json); return wrapper; } diff --git a/sql/log_resource.h b/sql/log_resource.h index 10843ebd74c..863c63a67c3 100644 --- a/sql/log_resource.h +++ b/sql/log_resource.h @@ -175,19 +175,23 @@ class Log_resource_binlog_wrapper : public Log_resource { */ class Log_resource_gtid_state_wrapper : public Log_resource { Gtid_state *gtid_state = nullptr; + MYSQL_BIN_LOG *binlog = nullptr; public: /** Log_resource_gtid_state_wrapper constructor. @param[in] gtid_state_arg the pointer to the Gtid_state object resource. + @param[in] binlog_arg the pointer to the MYSQL_BIN_LOG object resource. @param[in] json_arg the pointer to the JSON object to be populated with the resource log information. */ Log_resource_gtid_state_wrapper(Gtid_state *gtid_state_arg, - Json_dom *json_arg) - : Log_resource(json_arg), gtid_state(gtid_state_arg) {} + MYSQL_BIN_LOG *binlog_arg, Json_dom *json_arg) + : Log_resource(json_arg), + gtid_state(gtid_state_arg), + binlog(binlog_arg) {} void lock() override; void unlock() override; @@ -253,12 +257,14 @@ class Log_resource_factory { Creates a Log_resource wrapper based on a Gtid_state object. @param[in] gtid_state the pointer to the Gtid_state object resource. + @param[in] binlog the pointer to the MYSQL_BIN_LOG object resource. @param[in] json the pointer to the JSON object to be populated with the resource log information. @return the pointer to the new Log_resource. */ - static Log_resource *get_wrapper(Gtid_state *gtid_state, Json_dom *json); + static Log_resource *get_wrapper(Gtid_state *gtid_state, + MYSQL_BIN_LOG *binlog, Json_dom *json); /** Creates a Log_resource wrapper based on a handlerton. diff --git a/storage/perfschema/table_log_status.cc b/storage/perfschema/table_log_status.cc index fa90ab77673..330c0241e76 100644 --- a/storage/perfschema/table_log_status.cc +++ b/storage/perfschema/table_log_status.cc @@ -222,7 +222,8 @@ int table_log_status::make_row() { */ { Log_resource *res; - res = Log_resource_factory::get_wrapper(gtid_state, &json_local); + res = Log_resource_factory::get_wrapper(gtid_state, &mysql_bin_log, + &json_local); if ((error = DBUG_EVALUATE_IF("log_status_oom_gtid", 1, !res))) { my_error(ER_UNABLE_TO_COLLECT_LOG_STATUS, MYF(0), "LOCAL", "failed to allocate memory to collect "