Skip to content

M
MariaDB
Commit bc12478a authored by Andrei's avatar Andrei
Browse files
Options

MDEV-24660 MYSQL_BIN_LOG::cleanup(): Assertion `b->xid_count == 0' 

The shutdown time assert was caused by untimely deactivation of
the binlog background thread and related structs destruction.
It could specifically occur when a transaction is replication unsafe
and has to be completed with a ROLLBACK event in binlog.

This gets fixed with the binlog background thread stop relocation
to a point and user transactions have been completed.
A test case is added to binlog.binlog_checkpoint which
also receives as a bonus a minor correction to reactivate a MDEV-4322 test
case that originally required a shutdown phase (that ceased to do).
parent 55632020
Hide whitespace changes
Inline Side-by-side
Showing with 110 additions and 14 deletions
mysql-test/suite/binlog/r/binlog_checkpoint.result
View file @ bc12478a
......@@ -129,6 +129,9 @@ master-bin.000004 #
master-bin.000005 #
master-bin.000006 #
SET debug_sync = 'reset';
SET GLOBAL max_binlog_size= @old_max_binlog_size;
SET GLOBAL innodb_flush_log_at_trx_commit= @old_innodb_flush_log_at_trx_commit;
# restart
*** MDEV-7402: 'reset master' hangs, waits for signalled COND_xid_list ***
connect con3,localhost,root,,;
SET debug_sync="reset_logs_after_set_reset_master_pending SIGNAL reset_master_ready WAIT_FOR reset_master_cont";
......@@ -144,7 +147,48 @@ SET debug_sync="now SIGNAL reset_master_cont";
connection con3;
connection default;
SET debug_sync = 'reset';
DROP TABLE t1, t2;
SET GLOBAL max_binlog_size= @old_max_binlog_size;
SET GLOBAL innodb_flush_log_at_trx_commit= @old_innodb_flush_log_at_trx_commit;
SET debug_sync = 'reset';
*** MDEV-24660: MYSQL_BIN_LOG::cleanup(): Assertion `b->xid_count == 0' failed in MYSQL_BIN_LOG::cleanup
SET @old_max_binlog_size= @@global.max_binlog_size;
SET GLOBAL max_binlog_size= 4096;
connect con_24660,localhost,root,,;
FLUSH LOGS;
SET @@session.binlog_format = STATEMENT;
CREATE TABLE tm (a INT) ENGINE = myisam;
call mtr.add_suppression("Table './test/tm' is marked as crashed");
call mtr.add_suppression("Checking table");
XA START 'xa1';
INSERT INTO t1 VALUES (2, 1);
INSERT INTO tm SET a = 1;
XA END 'xa1';
connection default;
SET GLOBAL debug_dbug="+d,only_kill_system_threads_no_loop";
# restart
** Proof of shutdown caused ROLLBACK-completed transaction
include/show_binlog_events.inc
Log_name Pos Event_type Server_id End_log_pos Info
master-bin.000002 # Format_desc # # SERVER_VERSION, BINLOG_VERSION
master-bin.000002 # Gtid_list # # []
master-bin.000002 # Binlog_checkpoint # # master-bin.000001
master-bin.000002 # Binlog_checkpoint # # master-bin.000002
master-bin.000002 # Gtid # # GTID #-#-#
master-bin.000002 # Query # # use `test`; CREATE TABLE tm (a INT) ENGINE = myisam
master-bin.000002 # Gtid # # BEGIN GTID #-#-#
master-bin.000002 # Query # # use `mtr`; INSERT INTO test_suppressions (pattern) VALUES ( NAME_CONST('pattern',_latin1'Table \'./test/tm\' is marked as crashed' COLLATE 'latin1_swedish_ci'))
master-bin.000002 # Query # # COMMIT
master-bin.000002 # Gtid # # BEGIN GTID #-#-#
master-bin.000002 # Query # # use `mtr`; INSERT INTO test_suppressions (pattern) VALUES ( NAME_CONST('pattern',_latin1'Checking table' COLLATE 'latin1_swedish_ci'))
master-bin.000002 # Query # # COMMIT
master-bin.000002 # Gtid # # BEGIN GTID #-#-#
master-bin.000002 # Query # # use `test`; INSERT INTO tm SET a = 1
master-bin.000002 # Query # # COMMIT
master-bin.000002 # Gtid # # BEGIN GTID #-#-#
master-bin.000002 # Query # # use `test`; INSERT INTO t1 VALUES (2, 1)
master-bin.000002 # Query # # use `test`; INSERT INTO t1 VALUES (3, "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx")
master-bin.000002 # Query # # ROLLBACK
master-bin.000002 # Rotate # # master-bin.000003;pos=POS
SELECT * FROM tm;
a
1
SELECT * FROM t1 WHERE a = 3;
a b
DROP TABLE t1, t2, tm;
mysql-test/suite/binlog/t/binlog_checkpoint.test
View file @ bc12478a
......@@ -140,10 +140,15 @@ INSERT INTO t1 VALUES (31, REPEAT("x", 4100));
--source include/show_binary_logs.inc
SET debug_sync = 'reset';
SET GLOBAL max_binlog_size= @old_max_binlog_size;
SET GLOBAL innodb_flush_log_at_trx_commit= @old_innodb_flush_log_at_trx_commit;
--source include/shutdown_mysqld.inc
--source include/start_mysqld.inc
--echo *** MDEV-7402: 'reset master' hangs, waits for signalled COND_xid_list ***
--source include/wait_for_binlog_checkpoint.inc
connect(con3,localhost,root,,);
# Make the binlog background thread wait before clearing the pending checkpoint.
......@@ -169,9 +174,47 @@ REAP;
--connection default
SET debug_sync = 'reset';
--echo *** MDEV-24660: MYSQL_BIN_LOG::cleanup(): Assertion `b->xid_count == 0' failed in MYSQL_BIN_LOG::cleanup
# Test a scenario of forcibly rolled back mixed engine "unsafe" transaction
# at shutdown. That should not let to the assert.
SET @old_max_binlog_size= @@global.max_binlog_size;
SET GLOBAL max_binlog_size= 4096;
--connect(con_24660,localhost,root,,)
# Construct an unsafe xa transaction that is rolled back
# in binlog at the shutdown time. That requires STATEMENT binlog format.
FLUSH LOGS;
--let $binlog_file = query_get_value(SHOW MASTER STATUS, File, 1)
SET @@session.binlog_format = STATEMENT;
CREATE TABLE tm (a INT) ENGINE = myisam;
call mtr.add_suppression("Table './test/tm' is marked as crashed");
call mtr.add_suppression("Checking table");
XA START 'xa1';
--let $a = `SELECT a + 1 FROM t1`
--eval INSERT INTO t1 VALUES ($a, 1)
INSERT INTO tm SET a = 1;
--inc $a
--let $repeat_x = `SELECT REPEAT("x", 4100)`
--disable_query_log
--eval INSERT INTO t1 VALUES ($a, "$repeat_x")
--enable_query_log
XA END 'xa1';
--connection default
# In the patch's base BBT would exit first to win the race against
# the XA transaction's binloging.
SET GLOBAL debug_dbug="+d,only_kill_system_threads_no_loop";
--source include/shutdown_mysqld.inc
--source include/start_mysqld.inc
--echo ** Proof of shutdown caused ROLLBACK-completed transaction
--source include/show_binlog_events.inc
SELECT * FROM tm;
--eval SELECT * FROM t1 WHERE a = $a
# Clean up.
DROP TABLE t1, t2;
SET GLOBAL max_binlog_size= @old_max_binlog_size;
SET GLOBAL innodb_flush_log_at_trx_commit= @old_innodb_flush_log_at_trx_commit;
SET debug_sync = 'reset';
DROP TABLE t1, t2, tm;
sql/log.cc
View file @ bc12478a
......@@ -3412,6 +3412,7 @@ void MYSQL_BIN_LOG::stop_background_thread()
&LOCK_binlog_background_thread);
mysql_mutex_unlock(&LOCK_binlog_background_thread);
binlog_background_thread_started= false;
binlog_background_thread_stop= true; // mark it's not going to restart
}
}
......@@ -3610,7 +3611,8 @@ bool MYSQL_BIN_LOG::open(const char *log_name,
DBUG_RETURN(1);
}
if (!binlog_background_thread_started &&
if ((!binlog_background_thread_started &&
!binlog_background_thread_stop) &&
start_binlog_background_thread())
DBUG_RETURN(1);
}
......@@ -10343,6 +10345,7 @@ binlog_background_thread(void *arg __attribute__((unused)))
thd->store_globals();
thd->security_ctx->skip_grants();
thd->set_command(COM_DAEMON);
THD_count::count--;
/*
Load the slave replication GTID state from the mysql.gtid_slave_pos
......@@ -10432,6 +10435,7 @@ binlog_background_thread(void *arg __attribute__((unused)))
THD_STAGE_INFO(thd, stage_binlog_stopping_background_thread);
/* No need to use mutex as thd is not linked into other threads */
THD_count::count++;
delete thd;
my_thread_end();
......
sql/mysqld.cc
View file @ bc12478a
......@@ -1534,6 +1534,8 @@ static my_bool kill_thread_phase_1(THD *thd, int *n_threads_awaiting_ack)
if (DBUG_EVALUATE_IF("only_kill_system_threads", !thd->system_thread, 0))
return 0;
if (DBUG_EVALUATE_IF("only_kill_system_threads_no_loop", !thd->system_thread, 0))
return 0;
thd->set_killed(KILL_SERVER_HARD);
MYSQL_CALLBACK(thread_scheduler, post_kill_notification, (thd));
......@@ -1755,7 +1757,6 @@ static void close_connections(void)
Events::deinit();
slave_prepare_for_shutdown();
mysql_bin_log.stop_background_thread();
ack_receiver.stop();
/*
......@@ -1776,7 +1777,8 @@ static void close_connections(void)
for (int i= 0; (THD_count::value() - binlog_dump_thread_count -
n_threads_awaiting_ack) &&
i < 1000;
i < 1000 &&
DBUG_EVALUATE_IF("only_kill_system_threads_no_loop", 0, 1);
i++)
my_sleep(20000);
......@@ -1795,9 +1797,12 @@ static void close_connections(void)
THD_count::value() - binlog_dump_thread_count -
n_threads_awaiting_ack));
while (THD_count::value() - binlog_dump_thread_count -
n_threads_awaiting_ack)
while ((THD_count::value() - binlog_dump_thread_count -
n_threads_awaiting_ack) &&
DBUG_EVALUATE_IF("only_kill_system_threads_no_loop", 0, 1))
{
my_sleep(1000);
}
/* Kill phase 2 */
server_threads.iterate(kill_thread_phase_2);
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment
GitLab Nexedi Edition | About GitLab | About Nexedi | 沪ICP备2021021310号-2 | 沪ICP备2021021310号-7