diff options
author | Andrei <andrei.elkin@mariadb.com> | 2022-05-11 13:12:48 +0300 |
---|---|---|
committer | Sergei Golubchik <serg@mariadb.org> | 2022-05-18 09:48:57 +0200 |
commit | 98ca71ab28fffbb65c4590cda904f1f0dfd975bb (patch) | |
tree | ca5328fabb095485459669c8ecaa4450b821e120 /mysql-test/suite/binlog | |
parent | e03e72234aa59016c71c51b7adc5a59ae7b126b2 (diff) | |
download | mariadb-git-98ca71ab28fffbb65c4590cda904f1f0dfd975bb.tar.gz |
MDEV-28461 semisync-slave server recovery fails to rollback prepared transaction
that is not in binlog.
Post-crash recovery of --rpl-semi-sync-slave-enabled server
failed to recognize a transaction in-doubt that needed rolled back.
A prepared-but-not-in-binlog transaction gets committed instead
to possibly create inconsistency with a master (e.g the way it was observed
in the bug report).
The semisync recovery is corrected now with initializing binlog coordinates
of any transaction in-doubt to the maximum offset which is
unreachable.
In effect when a prepared transaction that is not found in binlog
it will be decided to rollback because it's guaranteed to reside
in a truncated tail area of binlog.
Mtr tests are reinforced to cover the described scenario.
Diffstat (limited to 'mysql-test/suite/binlog')
5 files changed, 108 insertions, 23 deletions
diff --git a/mysql-test/suite/binlog/r/binlog_truncate_active_log.result b/mysql-test/suite/binlog/r/binlog_truncate_active_log.result index e76c3c3911b..85d37534c0b 100644 --- a/mysql-test/suite/binlog/r/binlog_truncate_active_log.result +++ b/mysql-test/suite/binlog/r/binlog_truncate_active_log.result @@ -4,11 +4,13 @@ RESET MASTER; SET @@global.sync_binlog=1; CREATE TABLE t (f INT) ENGINE=INNODB; CREATE TABLE t2 (f INT) ENGINE=INNODB; +CREATE TABLE t4 (f INT) ENGINE=INNODB; CREATE TABLE tm (f INT) ENGINE=Aria; # Case A. connect master1,localhost,root,,; connect master2,localhost,root,,; connect master3,localhost,root,,; +connect master4,localhost,root,,; connection default; INSERT INTO t VALUES (10); INSERT INTO tm VALUES (10); @@ -23,14 +25,23 @@ connection master3; SET DEBUG_SYNC= "now WAIT_FOR master2_ready"; SELECT @@global.gtid_binlog_pos as 'Before the crash'; Before the crash -0-1-7 +0-1-8 +connection master4; +SET DEBUG_SYNC= "ha_commit_trans_before_log_and_order SIGNAL master4_ready WAIT_FOR signal_never_arrives"; +INSERT INTO t4 VALUES (13); +connection master3; +SET DEBUG_SYNC= "now WAIT_FOR master4_ready"; +SELECT @@global.gtid_binlog_pos as 'Before the crash and never logged trx'; +Before the crash and never logged trx +0-1-8 connection default; # Kill the server disconnect master1; disconnect master2; disconnect master3; -# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 -FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-6/ in mysqld.1.err +disconnect master4; +# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 --log-warnings=3 +FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-7/ in mysqld.1.err Pre-crash binlog file content: include/show_binlog_events.inc Log_name Pos Event_type Server_id End_log_pos Info @@ -39,6 +50,8 @@ master-bin.000001 # Query # # use `test`; CREATE TABLE t (f INT) ENGINE=INNODB master-bin.000001 # Gtid # # GTID #-#-# master-bin.000001 # Query # # use `test`; CREATE TABLE t2 (f INT) ENGINE=INNODB master-bin.000001 # Gtid # # GTID #-#-# +master-bin.000001 # Query # # use `test`; CREATE TABLE t4 (f INT) ENGINE=INNODB +master-bin.000001 # Gtid # # GTID #-#-# master-bin.000001 # Query # # use `test`; CREATE TABLE tm (f INT) ENGINE=Aria master-bin.000001 # Gtid # # BEGIN GTID #-#-# master-bin.000001 # Query # # use `test`; INSERT INTO t VALUES (10) @@ -48,16 +61,20 @@ master-bin.000001 # Query # # use `test`; INSERT INTO tm VALUES (10) master-bin.000001 # Query # # COMMIT SELECT @@global.gtid_binlog_pos as 'After the crash'; After the crash -0-1-5 +0-1-6 "One row should be present in table 't'" SELECT * FROM t; f 10 +"No row should be present in table 't4'" +SELECT * FROM t4; +f DELETE FROM t; # Case B. connect master1,localhost,root,,; connect master2,localhost,root,,; connect master3,localhost,root,,; +connect master4,localhost,root,,; connection default; INSERT INTO t VALUES (10); INSERT INTO tm VALUES (10); @@ -72,14 +89,23 @@ connection master3; SET DEBUG_SYNC= "now WAIT_FOR master2_ready"; SELECT @@global.gtid_binlog_pos as 'Before the crash'; Before the crash -0-1-10 +0-1-11 +connection master4; +SET DEBUG_SYNC= "ha_commit_trans_before_log_and_order SIGNAL master4_ready WAIT_FOR signal_never_arrives"; +INSERT INTO t4 VALUES (13); +connection master3; +SET DEBUG_SYNC= "now WAIT_FOR master4_ready"; +SELECT @@global.gtid_binlog_pos as 'Before the crash and never logged trx'; +Before the crash and never logged trx +0-1-11 connection default; # Kill the server disconnect master1; disconnect master2; disconnect master3; -# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 -FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-10/ in mysqld.1.err +disconnect master4; +# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 --log-warnings=3 +FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-11/ in mysqld.1.err Pre-crash binlog file content: include/show_binlog_events.inc Log_name Pos Event_type Server_id End_log_pos Info @@ -97,11 +123,14 @@ master-bin.000002 # Query # # use `test`; DELETE FROM t2 WHERE f = 0 master-bin.000002 # Query # # COMMIT SELECT @@global.gtid_binlog_pos as 'After the crash'; After the crash -0-1-9 +0-1-10 "One row should be present in table 't'" SELECT * FROM t; f 10 +"No row should be present in table 't4'" +SELECT * FROM t4; +f DELETE FROM t; # Case C. CREATE PROCEDURE sp_blank_xa() @@ -114,6 +143,7 @@ END| connect master1,localhost,root,,; connect master2,localhost,root,,; connect master3,localhost,root,,; +connect master4,localhost,root,,; connection default; INSERT INTO t VALUES (10); INSERT INTO tm VALUES (10); @@ -128,14 +158,23 @@ connection master3; SET DEBUG_SYNC= "now WAIT_FOR master2_ready"; SELECT @@global.gtid_binlog_pos as 'Before the crash'; Before the crash -0-1-15 +0-1-16 +connection master4; +SET DEBUG_SYNC= "ha_commit_trans_before_log_and_order SIGNAL master4_ready WAIT_FOR signal_never_arrives"; +INSERT INTO t4 VALUES (13); +connection master3; +SET DEBUG_SYNC= "now WAIT_FOR master4_ready"; +SELECT @@global.gtid_binlog_pos as 'Before the crash and never logged trx'; +Before the crash and never logged trx +0-1-16 connection default; # Kill the server disconnect master1; disconnect master2; disconnect master3; -# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 -FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-14/ in mysqld.1.err +disconnect master4; +# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 --log-warnings=3 +FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-15/ in mysqld.1.err Pre-crash binlog file content: include/show_binlog_events.inc Log_name Pos Event_type Server_id End_log_pos Info @@ -158,11 +197,14 @@ master-bin.000003 # Query # # use `test`; INSERT INTO tm VALUES (10) master-bin.000003 # Query # # COMMIT SELECT @@global.gtid_binlog_pos as 'After the crash'; After the crash -0-1-13 +0-1-14 "One row should be present in table 't'" SELECT * FROM t; f 10 +"No row should be present in table 't4'" +SELECT * FROM t4; +f DELETE FROM t; DROP PROCEDURE sp_blank_xa; # Case D. @@ -176,6 +218,7 @@ END| connect master1,localhost,root,,; connect master2,localhost,root,,; connect master3,localhost,root,,; +connect master4,localhost,root,,; connection default; INSERT INTO t VALUES (10); INSERT INTO tm VALUES (10); @@ -190,14 +233,23 @@ connection master3; SET DEBUG_SYNC= "now WAIT_FOR master2_ready"; SELECT @@global.gtid_binlog_pos as 'Before the crash'; Before the crash -0-1-20 +0-1-21 +connection master4; +SET DEBUG_SYNC= "ha_commit_trans_before_log_and_order SIGNAL master4_ready WAIT_FOR signal_never_arrives"; +INSERT INTO t4 VALUES (13); +connection master3; +SET DEBUG_SYNC= "now WAIT_FOR master4_ready"; +SELECT @@global.gtid_binlog_pos as 'Before the crash and never logged trx'; +Before the crash and never logged trx +0-1-21 connection default; # Kill the server disconnect master1; disconnect master2; disconnect master3; -# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 -FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-20/ in mysqld.1.err +disconnect master4; +# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 --log-warnings=3 +FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-21/ in mysqld.1.err Pre-crash binlog file content: include/show_binlog_events.inc Log_name Pos Event_type Server_id End_log_pos Info @@ -226,11 +278,14 @@ master-bin.000004 # Query # # XA END X'786964',X'',1 master-bin.000004 # XA_prepare # # XA PREPARE X'786964',X'',1 SELECT @@global.gtid_binlog_pos as 'After the crash'; After the crash -0-1-19 +0-1-20 "One row should be present in table 't'" SELECT * FROM t; f 10 +"No row should be present in table 't4'" +SELECT * FROM t4; +f DELETE FROM t; DROP PROCEDURE sp_xa; # Cleanup diff --git a/mysql-test/suite/binlog/r/binlog_truncate_multi_log.result b/mysql-test/suite/binlog/r/binlog_truncate_multi_log.result index ae292c04c32..271e3c50b19 100644 --- a/mysql-test/suite/binlog/r/binlog_truncate_multi_log.result +++ b/mysql-test/suite/binlog/r/binlog_truncate_multi_log.result @@ -22,6 +22,11 @@ SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master2_ready WAIT INSERT INTO ti VALUES (3, "not gonna survive"); connection default; SET DEBUG_SYNC= "now WAIT_FOR master2_ready"; +connect master3,localhost,root,,; +SET DEBUG_SYNC= "ha_commit_trans_before_log_and_order SIGNAL master3_ready WAIT_FOR master3_go_never_arrives"; +INSERT INTO ti VALUES (4, "not gonna be log therefore survive"),(5, "ditto"); +connection default; +SET DEBUG_SYNC= "now WAIT_FOR master3_ready"; "List of binary logs before crash" show binary logs; Log_name File_size @@ -36,7 +41,8 @@ connection default; # Kill the server disconnect master1; disconnect master2; -# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 +disconnect master3; +# restart: --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 --log-warnings=3 FOUND 1 /truncated binlog file:.*master.*000002/ in mysqld.1.err "One record should be present in table" SELECT * FROM ti; diff --git a/mysql-test/suite/binlog/t/binlog_truncate_active_log.inc b/mysql-test/suite/binlog/t/binlog_truncate_active_log.inc index 75a8310c220..68ac752725e 100644 --- a/mysql-test/suite/binlog/t/binlog_truncate_active_log.inc +++ b/mysql-test/suite/binlog/t/binlog_truncate_active_log.inc @@ -1,6 +1,7 @@ connect(master1,localhost,root,,); connect(master2,localhost,root,,); connect(master3,localhost,root,,); +connect(master4,localhost,root,,); --connection default @@ -22,16 +23,26 @@ SET DEBUG_SYNC= "commit_before_get_LOCK_after_binlog_sync SIGNAL master2_ready"; SET DEBUG_SYNC= "now WAIT_FOR master2_ready"; SELECT @@global.gtid_binlog_pos as 'Before the crash'; +--connection master4 +# Simulate prepared & not-logged trx; it will never recover. +SET DEBUG_SYNC= "ha_commit_trans_before_log_and_order SIGNAL master4_ready WAIT_FOR signal_never_arrives"; +--send INSERT INTO t4 VALUES (13) + +--connection master3 +SET DEBUG_SYNC= "now WAIT_FOR master4_ready"; +SELECT @@global.gtid_binlog_pos as 'Before the crash and never logged trx'; + --connection default --source include/kill_mysqld.inc --disconnect master1 --disconnect master2 --disconnect master3 +--disconnect master4 # # Server restart # ---let $restart_parameters= --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 +--let $restart_parameters= --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 --log-warnings=3 --source include/start_mysqld.inc # Check error log for a successful truncate message. @@ -49,6 +60,8 @@ SELECT @@global.gtid_binlog_pos as 'Before the crash'; SELECT @@global.gtid_binlog_pos as 'After the crash'; --echo "One row should be present in table 't'" SELECT * FROM t; +--echo "No row should be present in table 't4'" +SELECT * FROM t4; # prepare binlog file index for the next test --inc $binlog_file_index diff --git a/mysql-test/suite/binlog/t/binlog_truncate_active_log.test b/mysql-test/suite/binlog/t/binlog_truncate_active_log.test index 920679e99e9..7c63a853da6 100644 --- a/mysql-test/suite/binlog/t/binlog_truncate_active_log.test +++ b/mysql-test/suite/binlog/t/binlog_truncate_active_log.test @@ -25,6 +25,7 @@ RESET MASTER; SET @@global.sync_binlog=1; CREATE TABLE t (f INT) ENGINE=INNODB; CREATE TABLE t2 (f INT) ENGINE=INNODB; +CREATE TABLE t4 (f INT) ENGINE=INNODB; CREATE TABLE tm (f INT) ENGINE=Aria; # Old (pre-crash) binlog file index initial value. @@ -42,14 +43,14 @@ CREATE TABLE tm (f INT) ENGINE=Aria; # 'query1' onwards will be removed from the binary log. # Show-binlog-events is to prove that. ---let $truncate_gtid_pos = 0-1-6 +--let $truncate_gtid_pos = 0-1-7 --let $query1 = INSERT INTO t VALUES (20) --let $query2 = DELETE FROM t2 WHERE f = 0 /* no such record */ --source binlog_truncate_active_log.inc --echo # Case B. # The inverted sequence ends up to truncate starting from $query2 ---let $truncate_gtid_pos = 0-1-10 +--let $truncate_gtid_pos = 0-1-11 --let $query1 = DELETE FROM t2 WHERE f = 0 --let $query2 = INSERT INTO t VALUES (20) --source binlog_truncate_active_log.inc @@ -68,7 +69,7 @@ delimiter ;| # The same as in A with $query2 being the zero-engine XA transaction. # Both $query1 and $query2 are going to be truncated. ---let $truncate_gtid_pos = 0-1-14 +--let $truncate_gtid_pos = 0-1-15 --let $query1 = INSERT INTO t VALUES (20) --let $query2 = CALL sp_blank_xa --source binlog_truncate_active_log.inc @@ -89,7 +90,7 @@ delimiter ;| # The same as in B with $query1 being the prepared XA transaction. # Truncation must occurs at $query2. ---let $truncate_gtid_pos = 0-1-20 +--let $truncate_gtid_pos = 0-1-21 --let $query1 = CALL sp_xa --let $query2 = INSERT INTO t2 VALUES (20) --source binlog_truncate_active_log.inc diff --git a/mysql-test/suite/binlog/t/binlog_truncate_multi_log.test b/mysql-test/suite/binlog/t/binlog_truncate_multi_log.test index a7068885871..079c79b2984 100644 --- a/mysql-test/suite/binlog/t/binlog_truncate_multi_log.test +++ b/mysql-test/suite/binlog/t/binlog_truncate_multi_log.test @@ -40,6 +40,15 @@ SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master2_ready WAIT --connection default SET DEBUG_SYNC= "now WAIT_FOR master2_ready"; + +connect(master3,localhost,root,,); +# The 3nd trx for recovery, it won't get into binlog nor therefore recover +SET DEBUG_SYNC= "ha_commit_trans_before_log_and_order SIGNAL master3_ready WAIT_FOR master3_go_never_arrives"; +--send INSERT INTO ti VALUES (4, "not gonna be log therefore survive"),(5, "ditto") + +--connection default +SET DEBUG_SYNC= "now WAIT_FOR master3_ready"; + --echo "List of binary logs before crash" --source include/show_binary_logs.inc --echo # The gtid binlog state prior the crash will be truncated at the end of the test @@ -49,11 +58,12 @@ SELECT @@global.gtid_binlog_state; --source include/kill_mysqld.inc --disconnect master1 --disconnect master2 +--disconnect master3 # # Server restart # ---let $restart_parameters= --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 +--let $restart_parameters= --rpl-semi-sync-slave-enabled=1 --sync-binlog=1 --log-warnings=3 --source include/start_mysqld.inc # Check error log for a successful truncate message. |