Commit 6c39eaeb authored by Sujatha's avatar Sujatha Committed by Andrei Elkin

MDEV-21117: refine the server binlog-based recovery for semisync

Problem:
=======
When the semisync master is crashed and restarted as slave it could
recover transactions that former slaves may never have seen.
A known method existed to clear out all prepared transactions
with --tc-heuristic-recover=rollback does not care to adjust
binlog accordingly.

Fix:
===
The binlog-based recovery is made to concern of the slave semisync role of
post-crash restarted server.
No changes in behavior is done to the "normal" binloggging server
and the semisync master.

When the restarted server is configured with
  --rpl-semi-sync-slave-enabled=1
the refined recovery attempts to roll back prepared transactions
and truncate binlog accordingly.
In case of a partially committed (that is committed at least
in one of the engine participants) such transaction gets committed.
It's guaranteed no (partially as well) committed transactions
exist beyond the truncate position.
In case there exists a non-transactional replication event
(being in a way a committed transaction) past the
computed truncate position the recovery ends with an error.

As after master crash and failover to slave, the demoted-to-slave
ex-master must be ready to face and accept its own (generated by)
events, without generally necessary --replicate-same-server-id.
So the acceptance conditions are relaxed for the semisync slave
to accept own events without that option.
While gtid_strict_mode ON ensures no duplicate transaction can be
(re-)executed the master_use_gtid=none slave has to be
configured with --replicate-same-server-id.

*NOTE* for reviewers.

This patch does not handle the user XA which is done
in next git commit.
parent 82c07b17
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
RESET MASTER;
CREATE TABLE t (f INT) ENGINE=INNODB;
CREATE TABLE t2 (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,,;
connection default;
INSERT INTO t VALUES (10);
INSERT INTO tm VALUES (10);
connection master1;
SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master1_ready WAIT_FOR signal_never_arrives";
INSERT INTO t VALUES (20);
connection master2;
SET DEBUG_SYNC= "now WAIT_FOR master1_ready";
SET DEBUG_SYNC= "commit_before_get_LOCK_after_binlog_sync SIGNAL master2_ready";
DELETE FROM t2 WHERE f = 0 /* no such record */;
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
connection default;
# Kill the server
disconnect master1;
disconnect master2;
disconnect master3;
# restart: --rpl-semi-sync-slave-enabled=1
FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-6/ 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
master-bin.000001 # Gtid # # GTID #-#-#
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 tm (f INT) ENGINE=Aria
master-bin.000001 # Gtid # # BEGIN GTID #-#-#
master-bin.000001 # Query # # use `test`; INSERT INTO t VALUES (10)
master-bin.000001 # Xid # # COMMIT /* XID */
master-bin.000001 # Gtid # # BEGIN GTID #-#-#
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
"One row should be present in table 't'"
SELECT * FROM t;
f
10
DELETE FROM t;
# Case B.
connect master1,localhost,root,,;
connect master2,localhost,root,,;
connect master3,localhost,root,,;
connection default;
INSERT INTO t VALUES (10);
INSERT INTO tm VALUES (10);
connection master1;
SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master1_ready WAIT_FOR signal_never_arrives";
DELETE FROM t2 WHERE f = 0;
connection master2;
SET DEBUG_SYNC= "now WAIT_FOR master1_ready";
SET DEBUG_SYNC= "commit_before_get_LOCK_after_binlog_sync SIGNAL master2_ready";
INSERT INTO t VALUES (20);
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
connection default;
# Kill the server
disconnect master1;
disconnect master2;
disconnect master3;
# restart: --rpl-semi-sync-slave-enabled=1
FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-10/ 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
master-bin.000002 # Gtid # # BEGIN GTID #-#-#
master-bin.000002 # Query # # use `test`; DELETE FROM t
master-bin.000002 # Xid # # COMMIT /* XID */
master-bin.000002 # Gtid # # BEGIN GTID #-#-#
master-bin.000002 # Query # # use `test`; INSERT INTO t VALUES (10)
master-bin.000002 # Xid # # COMMIT /* XID */
master-bin.000002 # Gtid # # BEGIN GTID #-#-#
master-bin.000002 # Query # # use `test`; INSERT INTO tm VALUES (10)
master-bin.000002 # Query # # COMMIT
master-bin.000002 # Gtid # # BEGIN GTID #-#-#
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
"One row should be present in table 't'"
SELECT * FROM t;
f
10
DELETE FROM t;
# Case C.
CREATE PROCEDURE sp_blank_xa()
BEGIN
XA START 'blank';
DELETE FROM t2 WHERE f = 0 /* no such record */;
XA END 'blank';
XA PREPARE 'blank';
END|
connect master1,localhost,root,,;
connect master2,localhost,root,,;
connect master3,localhost,root,,;
connection default;
INSERT INTO t VALUES (10);
INSERT INTO tm VALUES (10);
connection master1;
SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master1_ready WAIT_FOR signal_never_arrives";
INSERT INTO t VALUES (20);
connection master2;
SET DEBUG_SYNC= "now WAIT_FOR master1_ready";
SET DEBUG_SYNC= "commit_before_get_LOCK_after_binlog_sync SIGNAL master2_ready";
CALL sp_blank_xa;
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
connection default;
# Kill the server
disconnect master1;
disconnect master2;
disconnect master3;
# restart: --rpl-semi-sync-slave-enabled=1
FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-14/ 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
master-bin.000003 # Gtid # # BEGIN GTID #-#-#
master-bin.000003 # Query # # use `test`; DELETE FROM t
master-bin.000003 # Xid # # COMMIT /* XID */
master-bin.000003 # Gtid # # GTID #-#-#
master-bin.000003 # Query # # use `test`; CREATE DEFINER=`root`@`localhost` PROCEDURE `sp_blank_xa`()
BEGIN
XA START 'blank';
DELETE FROM t2 WHERE f = 0 /* no such record */;
XA END 'blank';
XA PREPARE 'blank';
END
master-bin.000003 # Gtid # # BEGIN GTID #-#-#
master-bin.000003 # Query # # use `test`; INSERT INTO t VALUES (10)
master-bin.000003 # Xid # # COMMIT /* XID */
master-bin.000003 # Gtid # # BEGIN GTID #-#-#
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
"One row should be present in table 't'"
SELECT * FROM t;
f
10
DELETE FROM t;
DROP PROCEDURE sp_blank_xa;
# Case D.
CREATE PROCEDURE sp_xa()
BEGIN
XA START 'xid';
DELETE FROM t WHERE f = 10;
XA END 'xid';
XA PREPARE 'xid';
END|
connect master1,localhost,root,,;
connect master2,localhost,root,,;
connect master3,localhost,root,,;
connection default;
INSERT INTO t VALUES (10);
INSERT INTO tm VALUES (10);
connection master1;
SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master1_ready WAIT_FOR signal_never_arrives";
CALL sp_xa;
connection master2;
SET DEBUG_SYNC= "now WAIT_FOR master1_ready";
SET DEBUG_SYNC= "commit_before_get_LOCK_after_binlog_sync SIGNAL master2_ready";
INSERT INTO t2 VALUES (20);
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
connection default;
# Kill the server
disconnect master1;
disconnect master2;
disconnect master3;
# restart: --rpl-semi-sync-slave-enabled=1
FOUND 1 /Successfully truncated.*to remove transactions starting from GTID 0-1-20/ 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
master-bin.000004 # Gtid # # BEGIN GTID #-#-#
master-bin.000004 # Query # # use `test`; DELETE FROM t
master-bin.000004 # Xid # # COMMIT /* XID */
master-bin.000004 # Gtid # # GTID #-#-#
master-bin.000004 # Query # # use `test`; DROP PROCEDURE sp_blank_xa
master-bin.000004 # Gtid # # GTID #-#-#
master-bin.000004 # Query # # use `test`; CREATE DEFINER=`root`@`localhost` PROCEDURE `sp_xa`()
BEGIN
XA START 'xid';
DELETE FROM t WHERE f = 10;
XA END 'xid';
XA PREPARE 'xid';
END
master-bin.000004 # Gtid # # BEGIN GTID #-#-#
master-bin.000004 # Query # # use `test`; INSERT INTO t VALUES (10)
master-bin.000004 # Xid # # COMMIT /* XID */
master-bin.000004 # Gtid # # BEGIN GTID #-#-#
master-bin.000004 # Query # # use `test`; INSERT INTO tm VALUES (10)
master-bin.000004 # Query # # COMMIT
master-bin.000004 # Gtid # # XA START X'786964',X'',1 GTID #-#-#
master-bin.000004 # Query # # use `test`; DELETE FROM t WHERE f = 10
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
"One row should be present in table 't'"
SELECT * FROM t;
f
10
DELETE FROM t;
DROP PROCEDURE sp_xa;
# Cleanup
DROP TABLE t,t2,tm;
# End of the tests
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
CREATE TABLE t1 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb;
CREATE TABLE t2 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=rocksdb;
#
#
# Case "A" : "neither engine committed => rollback & binlog truncate"
#
RESET MASTER;
FLUSH LOGS;
SET GLOBAL max_binlog_size= 4096;
connect con1,localhost,root,,;
List of binary logs before rotation
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
INSERT INTO t1 VALUES (1, REPEAT("x", 1));
INSERT INTO t2 VALUES (1, REPEAT("x", 1));
BEGIN;
INSERT INTO t2 VALUES (2, REPEAT("x", 4100));
INSERT INTO t1 VALUES (2, REPEAT("x", 4100));
SET DEBUG_SYNC= "commit_after_release_LOCK_log SIGNAL con1_ready WAIT_FOR signal_no_signal";
COMMIT;
connection default;
SET DEBUG_SYNC= "now WAIT_FOR con1_ready";
List of binary logs after rotation
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
master-bin.000003 #
# restart the server with --rpl-semi-sync-slave-enabled=1
# the server is restarted
# restart: --rpl-semi-sync-slave-enabled=1
connection default;
#
# *** Summary: 1 row should be present in both tables; binlog is truncated; number of binlogs at reconnect - 3:
#
SELECT COUNT(*) FROM t1;
COUNT(*)
1
SELECT COUNT(*) FROM t2;
COUNT(*)
1
SELECT @@GLOBAL.gtid_binlog_state;
@@GLOBAL.gtid_binlog_state
0-1-2
SELECT @@GLOBAL.gtid_binlog_pos;
@@GLOBAL.gtid_binlog_pos
0-1-2
List of binary logs at the end of the tests
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
master-bin.000003 #
# ***
DELETE FROM t1;
DELETE FROM t2;
disconnect con1;
#
Proof of the truncated binlog file is readable (two transactions must be seen):
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
START TRANSACTION
/*!*/;
COMMIT/*!*/;
START TRANSACTION
/*!*/;
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
#
#
# Case "B" : "one engine has committed its transaction branch"
#
RESET MASTER;
FLUSH LOGS;
SET GLOBAL max_binlog_size= 4096;
connect con1,localhost,root,,;
List of binary logs before rotation
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
INSERT INTO t1 VALUES (1, REPEAT("x", 1));
INSERT INTO t2 VALUES (1, REPEAT("x", 1));
SET GLOBAL debug_dbug="d,enable_log_write_upto_crash";
BEGIN;
INSERT INTO t2 VALUES (2, REPEAT("x", 4100));
INSERT INTO t1 VALUES (2, REPEAT("x", 4100));
COMMIT;
connection default;
# restart: --rpl-semi-sync-slave-enabled=1
connection default;
#
# *** Summary: 2 rows should be present in both tables; no binlog truncation; one extra binlog file compare with A; number of binlogs at reconnect - 4:
#
SELECT COUNT(*) FROM t1;
COUNT(*)
2
SELECT COUNT(*) FROM t2;
COUNT(*)
2
SELECT @@GLOBAL.gtid_binlog_state;
@@GLOBAL.gtid_binlog_state
0-1-3
SELECT @@GLOBAL.gtid_binlog_pos;
@@GLOBAL.gtid_binlog_pos
0-1-3
List of binary logs at the end of the tests
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
master-bin.000003 #
master-bin.000004 #
# ***
DELETE FROM t1;
DELETE FROM t2;
disconnect con1;
#
#
#
# Case "C" : "both engines have committed its transaction branch"
#
RESET MASTER;
FLUSH LOGS;
SET GLOBAL max_binlog_size= 4096;
connect con1,localhost,root,,;
List of binary logs before rotation
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
INSERT INTO t1 VALUES (1, REPEAT("x", 1));
INSERT INTO t2 VALUES (1, REPEAT("x", 1));
BEGIN;
INSERT INTO t2 VALUES (2, REPEAT("x", 4100));
INSERT INTO t1 VALUES (2, REPEAT("x", 4100));
SET DEBUG_SYNC= "commit_after_run_commit_ordered SIGNAL con1_ready WAIT_FOR signal_no_signal";
COMMIT;
connection default;
SET DEBUG_SYNC= "now WAIT_FOR con1_ready";
List of binary logs after rotation
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
master-bin.000003 #
# restart the server with --rpl-semi-sync-slave-enabled=1
# the server is restarted
# restart: --rpl-semi-sync-slave-enabled=1
connection default;
#
# *** Summary: 2 rows should be present in both tables; no binlog truncation; the same # of binlog files as in B; number of binlogs at reconnect - 4:
#
SELECT COUNT(*) FROM t1;
COUNT(*)
2
SELECT COUNT(*) FROM t2;
COUNT(*)
2
SELECT @@GLOBAL.gtid_binlog_state;
@@GLOBAL.gtid_binlog_state
0-1-3
SELECT @@GLOBAL.gtid_binlog_pos;
@@GLOBAL.gtid_binlog_pos
0-1-3
List of binary logs at the end of the tests
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
master-bin.000003 #
master-bin.000004 #
# ***
DELETE FROM t1;
DELETE FROM t2;
disconnect con1;
#
DROP TABLE t1, t2;
# End of the tests
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
SET @@global.max_binlog_size= 4096;
RESET MASTER;
FLUSH LOGS;
CREATE TABLE ti (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb;
CREATE TABLE tm (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=MyISAM;
connect master1,localhost,root,,;
"List of binary logs before rotation"
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
INSERT INTO ti VALUES(1,"I am gonna survive");
INSERT INTO tm VALUES(1,"me too!");
SET DEBUG_SYNC= "commit_after_release_LOCK_after_binlog_sync SIGNAL master1_ready WAIT_FOR con1_go";
INSERT INTO ti VALUES (2, REPEAT("x", 4100));
connect master2,localhost,root,,;
SET DEBUG_SYNC= "now WAIT_FOR master1_ready";
SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master2_ready WAIT_FOR master2_go";
INSERT INTO ti VALUES (3, "not gonna survive");
connection default;
SET DEBUG_SYNC= "now WAIT_FOR master2_ready";
"List of binary logs before crash"
show binary logs;
Log_name File_size
master-bin.000001 #
master-bin.000002 #
master-bin.000003 #
# The gtid binlog state prior the crash will be truncated at the end of the test
SELECT @@global.gtid_binlog_state;
@@global.gtid_binlog_state
0-1-6
connection default;
# Kill the server
disconnect master1;
disconnect master2;
# restart: --rpl-semi-sync-slave-enabled=1
FOUND 1 /truncated binlog file:.*master.*000002/ in mysqld.1.err
"One record should be present in table"
SELECT * FROM ti;
a b
1 I am gonna survive
# The truncated gtid binlog state
SELECT @@global.gtid_binlog_state;
@@global.gtid_binlog_state
0-1-4
SELECT @@global.gtid_binlog_pos;
@@global.gtid_binlog_pos
0-1-4
# Cleanup
DROP TABLE ti;
# End of the tests
SET @@global.max_binlog_size= 4096;
call mtr.add_suppression("Table '.*tm' is marked as crashed and should be repaired");
call mtr.add_suppression("Got an error from unknown thread");
call mtr.add_suppression("Checking table: '.*tm'");
call mtr.add_suppression("Recovering table: '.*tm'");
call mtr.add_suppression("Cannot truncate the binary log to file");
call mtr.add_suppression("Crash recovery failed");
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
call mtr.add_suppression("Found 1 prepared transactions");
call mtr.add_suppression("mysqld: Table.*tm.*is marked as crashed");
call mtr.add_suppression("Checking table.*tm");
RESET MASTER;
FLUSH LOGS;
CREATE TABLE ti (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb;
CREATE TABLE tm (f INT) ENGINE=MYISAM;
INSERT INTO tm VALUES(1);
connect master1,localhost,root,,;
connect master2,localhost,root,,;
connect master3,localhost,root,,;
connection master1;
SET DEBUG_SYNC= "commit_after_release_LOCK_after_binlog_sync SIGNAL master1_ready WAIT_FOR master1_go";
INSERT INTO ti VALUES (5 - 1, REPEAT("x", 4100));
connection master2;
SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master2_ready WAIT_FOR master2_go";
INSERT INTO ti VALUES (5, REPEAT("x", 1));
connection master3;
SET DEBUG_SYNC= "now WAIT_FOR master2_ready";
SET DEBUG_SYNC= "commit_before_get_LOCK_after_binlog_sync SIGNAL master3_ready";
INSERT INTO tm VALUES (2);
connection default;
SET DEBUG_SYNC= "now WAIT_FOR master3_ready";
# The gtid binlog state prior the crash must be restored at the end of the test;
SELECT @@global.gtid_binlog_state;
@@global.gtid_binlog_state
0-1-9
# Kill the server
# Failed restart as the semisync slave
# Normal restart
# restart
FOUND 1 /Cannot truncate the binary log to file/ in mysqld.1.err
# Proof that the in-doubt transactions are recovered by the 2nd normal server restart
SELECT COUNT(*) = 5 as 'True' FROM ti;
True
1
SELECT COUNT(*) <= 1 FROM tm;
COUNT(*) <= 1
1
# The gtid binlog state prior the crash is restored now
SELECT @@GLOBAL.gtid_binlog_state;
@@GLOBAL.gtid_binlog_state
0-1-9
SELECT @@GLOBAL.gtid_binlog_pos;
@@GLOBAL.gtid_binlog_pos
0-1-9
# Cleanup
DROP TABLE ti, tm;
End of test
connect(master1,localhost,root,,);
connect(master2,localhost,root,,);
connect(master3,localhost,root,,);
--connection default
# First to commit few transactions
INSERT INTO t VALUES (10);
INSERT INTO tm VALUES (10);
--connection master1
# Hold insert after write to binlog and before "run_commit_ordered" in engine
SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master1_ready WAIT_FOR signal_never_arrives";
--send_eval $query1
--connection master2
SET DEBUG_SYNC= "now WAIT_FOR master1_ready";
SET DEBUG_SYNC= "commit_before_get_LOCK_after_binlog_sync SIGNAL master2_ready";
--send_eval $query2
--connection master3
SET DEBUG_SYNC= "now WAIT_FOR master2_ready";
SELECT @@global.gtid_binlog_pos as 'Before the crash';
--connection default
--source include/kill_mysqld.inc
--disconnect master1
--disconnect master2
--disconnect master3
#
# Server restart
#
--let $restart_parameters= --rpl-semi-sync-slave-enabled=1
--source include/start_mysqld.inc
# Check error log for a successful truncate message.
--let $log_error_ = $MYSQLTEST_VARDIR/log/mysqld.1.err
--let SEARCH_FILE=$log_error_
--let SEARCH_PATTERN=Successfully truncated.*to remove transactions starting from GTID $truncate_gtid_pos
--source include/search_pattern_in_file.inc
--echo Pre-crash binlog file content:
--let $binlog_file= query_get_value(show binary logs, Log_name, $binlog_file_index)
--source include/show_binlog_events.inc
SELECT @@global.gtid_binlog_pos as 'After the crash';
--echo "One row should be present in table 't'"
SELECT * FROM t;
# prepare binlog file index for the next test
--inc $binlog_file_index
# Local cleanup
DELETE FROM t;
# ==== Purpose ====
#
# Test verifies the truncation of single binary log file.
#
# ==== References ====
#
# MDEV-21117: recovery for --rpl-semi-sync-slave-enabled server
--source include/have_innodb.inc
--source include/have_aria.inc
# File: binlog_truncate_active_log.inc included in test makes use of
# 'debug_sync' facility.
--source include/have_debug_sync.inc
--source include/have_binlog_format_statement.inc
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
# The following cases are tested:
# A. 2pc transaction is followed by a blank "zero-engines" one
# B. 2pc transaction follows the blank one
# C. Similarly to A, with the XA blank transaction
RESET MASTER;
CREATE TABLE t (f INT) ENGINE=INNODB;
CREATE TABLE t2 (f INT) ENGINE=INNODB;
CREATE TABLE tm (f INT) ENGINE=Aria;
# Old (pre-crash) binlog file index initial value.
# It keeps incremented at the end of each case.
--let $binlog_file_index=1
--echo # Case A.
# Using 'debug_sync' hold 'query1' execution after 'query1' is flushed and
# synced to binary log but not yet committed. In an another connection hold
# 'query2' execution after 'query2' is flushed and synced to binlog.
# Crash and restart server with --rpl-semi-sync-slave-enabled=1
#
# During recovery of binary log 'query1' status is checked with InnoDB engine,
# it will be in prepared but not yet commited. All transactions starting from
# 'query1' onwards will be removed from the binary log.
# Show-binlog-events is to prove that.
--let $truncate_gtid_pos = 0-1-6
--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 $query1 = DELETE FROM t2 WHERE f = 0
--let $query2 = INSERT INTO t VALUES (20)
--source binlog_truncate_active_log.inc
--echo # Case C.
delimiter |;
CREATE PROCEDURE sp_blank_xa()
BEGIN
XA START 'blank';
DELETE FROM t2 WHERE f = 0 /* no such record */;
XA END 'blank';
XA PREPARE 'blank';
END|
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 $query1 = INSERT INTO t VALUES (20)
--let $query2 = CALL sp_blank_xa
--source binlog_truncate_active_log.inc
DROP PROCEDURE sp_blank_xa;
--echo # Case D.
delimiter |;
CREATE PROCEDURE sp_xa()
BEGIN
XA START 'xid';
DELETE FROM t WHERE f = 10;
XA END 'xid';
XA PREPARE 'xid';
END|
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 $query1 = CALL sp_xa
--let $query2 = INSERT INTO t2 VALUES (20)
--source binlog_truncate_active_log.inc
DROP PROCEDURE sp_xa;
--echo # Cleanup
DROP TABLE t,t2,tm;
--echo # End of the tests
#
# Invoked by binlog_truncate_multi_engine.test
# Parameters:
# $debug_sync_action describes debug-sync actions
# $kill_server 1 when to crash, 0 for regular restart
# $restart_parameters the caller may simulate partial commit at recovery
# $test_outcome summary of extected results
# $MYSQLD_DATADIR
--echo #
--echo #
--echo # Case $case : $description
--echo #
RESET MASTER;
FLUSH LOGS;
SET GLOBAL max_binlog_size= 4096;
connect(con1,localhost,root,,);
--echo List of binary logs before rotation
--source include/show_binary_logs.inc
INSERT INTO t1 VALUES (1, REPEAT("x", 1));
INSERT INTO t2 VALUES (1, REPEAT("x", 1));
if (`SELECT $case = "B"`)
{
--write_file $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
wait-binlog_truncate_multi_engine.test
EOF
SET GLOBAL debug_dbug="d,enable_log_write_upto_crash";
}
BEGIN;
INSERT INTO t2 VALUES (2, REPEAT("x", 4100));
INSERT INTO t1 VALUES (2, REPEAT("x", 4100));
if (`SELECT $debug_sync_action != ""`)
{
--eval SET DEBUG_SYNC= $debug_sync_action
}
send COMMIT;
--connection default
if (`SELECT $case = "B"`)
{
--source include/wait_until_disconnected.inc
--source include/start_mysqld.inc
}
if (`SELECT $case != "B"`)
{
SET DEBUG_SYNC= "now WAIT_FOR con1_ready";
--echo List of binary logs after rotation
--source include/show_binary_logs.inc
--echo # restart the server with $restart_parameters
--echo # the server is restarted
--source include/restart_mysqld.inc
}
--connection default
--echo #
--echo # *** Summary: $test_outcome:
--echo #
SELECT COUNT(*) FROM t1;
SELECT COUNT(*) FROM t2;
SELECT @@GLOBAL.gtid_binlog_state;
SELECT @@GLOBAL.gtid_binlog_pos;
--echo List of binary logs at the end of the tests
--source include/show_binary_logs.inc
--echo # ***
# cleanup
DELETE FROM t1;
DELETE FROM t2;
--disconnect con1
--echo #
# ==== Purpose ====
#
# Test verifies truncation of multiple binary logs with multiple transactional
# storage engines
#
# ==== References ====
#
# MDEV-21117: recovery for --rpl-semi-sync-slave-enabled server
--source include/have_rocksdb.inc
--source include/have_innodb.inc
--source include/have_debug.inc
--source include/have_debug_sync.inc
--source include/have_binlog_format_row.inc
--let $old_max_binlog_size= `select @@global.max_binlog_size`
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
--let $MYSQLD_DATADIR= `SELECT @@datadir`
CREATE TABLE t1 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb;
CREATE TABLE t2 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=rocksdb;
--let $case = "A"
--let $description = "neither engine committed => rollback & binlog truncate"
# Hold off engine commits after write to binlog and its rotation.
# The transaction is killed along with the server after that.
--let $shutdown_timeout=0
--let $debug_sync_action = "commit_after_release_LOCK_log SIGNAL con1_ready WAIT_FOR signal_no_signal"
--let $restart_parameters = --rpl-semi-sync-slave-enabled=1
--let $test_outcome= 1 row should be present in both tables; binlog is truncated; number of binlogs at reconnect - 3
--source binlog_truncate_multi_engine.inc
--echo Proof of the truncated binlog file is readable (two transactions must be seen):
--exec $MYSQL_BINLOG --short-form --skip-annotate-row-events $MYSQLD_DATADIR/master-bin.000002
--let $case = "B"
--let $description = "one engine has committed its transaction branch"
# Hold off after one engine has committed.
--let $shutdown_timeout=0
--let $debug_sync_action = ""
# Both debug_sync and debug-dbug are required to make sure Engines remember the commit state
# debug_sync alone will not help.
--let $restart_parameters = --rpl-semi-sync-slave-enabled=1
--let $test_outcome= 2 rows should be present in both tables; no binlog truncation; one extra binlog file compare with A; number of binlogs at reconnect - 4
--source binlog_truncate_multi_engine.inc
--let $case = "C"
--let $description= "both engines have committed its transaction branch"
--let $debug_sync_action = "commit_after_run_commit_ordered SIGNAL con1_ready WAIT_FOR signal_no_signal"
# Hold off after both engines have committed. The server is shut down.
--let $shutdown_timeout=
--let $restart_parameters = --rpl-semi-sync-slave-enabled=1
--let $test_outcome= 2 rows should be present in both tables; no binlog truncation; the same # of binlog files as in B; number of binlogs at reconnect - 4
--source binlog_truncate_multi_engine.inc
DROP TABLE t1, t2;
--echo # End of the tests
# ==== Purpose ====
#
# Test verifies truncation of multiple binary logs.
#
# ==== References ====
# MDEV-21117: recovery for --rpl-semi-sync-slave-enabled server
--source include/have_innodb.inc
--source include/have_debug_sync.inc
--source include/have_binlog_format_row.inc
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
SET @@global.max_binlog_size= 4096;
RESET MASTER;
FLUSH LOGS;
CREATE TABLE ti (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb;
CREATE TABLE tm (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=MyISAM;
connect(master1,localhost,root,,);
--echo "List of binary logs before rotation"
--source include/show_binary_logs.inc
# Some load to either non- and transactional egines
# that should not affect the following recovery:
INSERT INTO ti VALUES(1,"I am gonna survive");
INSERT INTO tm VALUES(1,"me too!");
# hold on near engine commit
SET DEBUG_SYNC= "commit_after_release_LOCK_after_binlog_sync SIGNAL master1_ready WAIT_FOR con1_go";
--send INSERT INTO ti VALUES (2, REPEAT("x", 4100))
connect(master2,localhost,root,,);
# The 2nd trx for recovery, it does not rotate binlog
SET DEBUG_SYNC= "now WAIT_FOR master1_ready";
SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master2_ready WAIT_FOR master2_go";
--send INSERT INTO ti VALUES (3, "not gonna survive")
--connection default
SET DEBUG_SYNC= "now WAIT_FOR master2_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
SELECT @@global.gtid_binlog_state;
--connection default
--source include/kill_mysqld.inc
--disconnect master1
--disconnect master2
#
# Server restart
#
--let $restart_parameters= --rpl-semi-sync-slave-enabled=1
--source include/start_mysqld.inc
# Check error log for a successful truncate message.
let $log_error_ = $MYSQLTEST_VARDIR/log/mysqld.1.err;
--let SEARCH_FILE=$log_error_
--let SEARCH_PATTERN=truncated binlog file:.*master.*000002
--source include/search_pattern_in_file.inc
--echo "One record should be present in table"
SELECT * FROM ti;
--echo # The truncated gtid binlog state
SELECT @@global.gtid_binlog_state;
SELECT @@global.gtid_binlog_pos;
--echo # Cleanup
DROP TABLE ti;
--echo # End of the tests
# ==== Purpose ====
# The test verifies attempt to recover by the semisync slave server whose
# binlog is unsafe for truncation.
#
# ==== Implementation ====
# 2 binlog files are created with the 1st one destined to be the binlog
# checkpoint file for recovery.
# The final group of events is replication unsafe (myisam INSERT).
# Therefore the semisync slave recovery may not.
#
# Steps:
# 0 - Set max_binlog_size= 4096, to help an insert into a
# transaction table 'ti' get binlog rotated while the
# transaction won't be committed, being stopped at
# a prior to commit debug_sync point
# 1 - insert into a non-transactional 'tm' table completes with
# binary logging as well
# 2 - kill and attempt to restart the server as semisync slave that
# must produce an expected unsafe-to-recover error
# 3 - complete the test with a normal restart that successfully finds and
# commits the transaction in doubt.
#
# ==== References ====
#
# MDEV-21117: recovery for --rpl-semi-sync-slave-enabled server
#
--source include/have_innodb.inc
--source include/have_debug_sync.inc
--source include/have_binlog_format_row.inc
SET @@global.max_binlog_size= 4096;
call mtr.add_suppression("Table '.*tm' is marked as crashed and should be repaired");
call mtr.add_suppression("Got an error from unknown thread");
call mtr.add_suppression("Checking table: '.*tm'");
call mtr.add_suppression("Recovering table: '.*tm'");
call mtr.add_suppression("Cannot truncate the binary log to file");
call mtr.add_suppression("Crash recovery failed");
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
call mtr.add_suppression("Found 1 prepared transactions");
call mtr.add_suppression("mysqld: Table.*tm.*is marked as crashed");
call mtr.add_suppression("Checking table.*tm");
RESET MASTER;
FLUSH LOGS;
CREATE TABLE ti (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb;
CREATE TABLE tm (f INT) ENGINE=MYISAM;
--let $row_count = 5
--let $i = `select $row_count-2`
--disable_query_log
while ($i)
{
--eval INSERT INTO ti VALUES ($i, REPEAT("x", 1))
--dec $i
}
--enable_query_log
INSERT INTO tm VALUES(1);
connect(master1,localhost,root,,);
connect(master2,localhost,root,,);
connect(master3,localhost,root,,);
--connection master1
# The 1st trx binlogs, rotate binlog and hold on before committing at engine
SET DEBUG_SYNC= "commit_after_release_LOCK_after_binlog_sync SIGNAL master1_ready WAIT_FOR master1_go";
--send_eval INSERT INTO ti VALUES ($row_count - 1, REPEAT("x", 4100))
--connection master2
# The 2nd trx for recovery, it does not rotate binlog
SET DEBUG_SYNC= "commit_before_get_LOCK_commit_ordered SIGNAL master2_ready WAIT_FOR master2_go";
--send_eval INSERT INTO ti VALUES ($row_count, REPEAT("x", 1))
--connection master3
SET DEBUG_SYNC= "now WAIT_FOR master2_ready";
SET DEBUG_SYNC= "commit_before_get_LOCK_after_binlog_sync SIGNAL master3_ready";
--send INSERT INTO tm VALUES (2)
--connection default
SET DEBUG_SYNC= "now WAIT_FOR master3_ready";
--echo # The gtid binlog state prior the crash must be restored at the end of the test;
SELECT @@global.gtid_binlog_state;
--source include/kill_mysqld.inc
#
# Server restarts
#
--echo # Failed restart as the semisync slave
--error 1
--exec $MYSQLD_LAST_CMD --rpl-semi-sync-slave-enabled=1 >> $MYSQLTEST_VARDIR/log/mysqld.1.err 2>&1
--echo # Normal restart
--source include/start_mysqld.inc
# Check error log for correct messages.
let $log_error_ = $MYSQLTEST_VARDIR/log/mysqld.1.err;
--let SEARCH_FILE=$log_error_
--let SEARCH_PATTERN=Cannot truncate the binary log to file
--source include/search_pattern_in_file.inc
--echo # Proof that the in-doubt transactions are recovered by the 2nd normal server restart
--eval SELECT COUNT(*) = $row_count as 'True' FROM ti
# myisam table may require repair (which is not tested here)
--disable_warnings
SELECT COUNT(*) <= 1 FROM tm;
--enable_warnings
--echo # The gtid binlog state prior the crash is restored now
SELECT @@GLOBAL.gtid_binlog_state;
SELECT @@GLOBAL.gtid_binlog_pos;
--echo # Cleanup
DROP TABLE ti, tm;
--echo End of test
if (`SELECT COUNT(*) = 0 FROM INFORMATION_SCHEMA.PLUGINS WHERE PLUGIN_NAME = 'rocksdb'`)
{
--skip Requires rocksdb
}
\ No newline at end of file
include/master-slave.inc
[connection master]
connection server_2;
include/stop_slave.inc
connection server_1;
RESET MASTER;
SET @@global.max_binlog_size= 4096;
connection server_2;
RESET MASTER;
SET @@global.max_binlog_size= 4096;
set @@global.rpl_semi_sync_slave_enabled = 1;
set @@global.gtid_slave_pos = "";
CHANGE MASTER TO master_use_gtid= slave_pos;
include/start_slave.inc
connection server_1;
ALTER TABLE mysql.gtid_slave_pos ENGINE=InnoDB;
set @@global.rpl_semi_sync_master_enabled = 1;
set @@global.rpl_semi_sync_master_wait_point=AFTER_SYNC;
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
call mtr.add_suppression("1 client is using or hasn.t closed the table properly");
call mtr.add_suppression("Table './mtr/test_suppressions' is marked as crashed and should be repaired");
CREATE TABLE t1 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb;
INSERT INTO t1 VALUES (1, 'dummy1');
connect conn_client,127.0.0.1,root,,test,$SERVER_MYPORT_1,;
SET DEBUG_SYNC= "commit_after_release_LOCK_after_binlog_sync SIGNAL con1_ready WAIT_FOR con1_go";
INSERT INTO t1 VALUES (2, REPEAT("x", 4100));
connection server_1;
SET DEBUG_SYNC= "now WAIT_FOR con1_ready";
# Kill the server
connection server_2;
include/stop_slave.inc
SELECT @@GLOBAL.gtid_current_pos;
@@GLOBAL.gtid_current_pos
0-1-8
# restart: --rpl-semi-sync-slave-enabled=1
connection server_1;
FOUND 1 /truncated binlog file:.*master.*000001/ in mysqld.1.err
disconnect conn_client;
connection server_2;
set global rpl_semi_sync_master_enabled = 1;
set global rpl_semi_sync_master_wait_point=AFTER_SYNC;
connection server_1;
CHANGE MASTER TO master_host='127.0.0.1', master_port=$new_master_port, master_user='root', master_use_gtid=SLAVE_POS;
set global rpl_semi_sync_slave_enabled = 1;
set @@global.gtid_slave_pos=@@global.gtid_binlog_pos;
include/start_slave.inc
connection server_2;
INSERT INTO t1 VALUES (3, 'dummy3');
# The gtid state on current master must be equal to ...
SHOW VARIABLES LIKE 'gtid_binlog_pos';
Variable_name Value
gtid_binlog_pos 0-2-9
connection server_1;
SELECT COUNT(*) = 3 as 'true' FROM t1;
true
1
# ... the gtid states on the slave:
SHOW VARIABLES LIKE 'gtid_slave_pos';
Variable_name Value
gtid_slave_pos 0-2-9
SHOW VARIABLES LIKE 'gtid_binlog_pos';
Variable_name Value
gtid_binlog_pos 0-2-9
connection server_2;
connect conn_client,127.0.0.1,root,,test,$SERVER_MYPORT_2,;
SET DEBUG_SYNC= "commit_after_release_LOCK_after_binlog_sync SIGNAL con1_ready WAIT_FOR con1_go";
INSERT INTO t1 VALUES (4, REPEAT("x", 4100));
connect conn_client_2,127.0.0.1,root,,test,$SERVER_MYPORT_2,;
SET DEBUG_SYNC= "now WAIT_FOR con1_ready";
SET DEBUG_SYNC= "commit_after_release_LOCK_log SIGNAL con1_ready WAIT_FOR con2_go";
INSERT INTO t1 VALUES (5, REPEAT("x", 4100));
connection server_2;
SET DEBUG_SYNC= "now WAIT_FOR con1_ready";
# Kill the server
connection server_1;
include/stop_slave.inc
SELECT @@GLOBAL.gtid_current_pos;
@@GLOBAL.gtid_current_pos
0-2-11
# restart: --rpl-semi-sync-slave-enabled=1
connection server_2;
NOT FOUND /truncated binlog file:.*slave.*000001/ in mysqld.2.err
disconnect conn_client;
connection server_1;
set global rpl_semi_sync_master_enabled = 1;
set global rpl_semi_sync_master_wait_point=AFTER_SYNC;
connection server_2;
CHANGE MASTER TO master_host='127.0.0.1', master_port=$new_master_port, master_user='root', master_use_gtid=SLAVE_POS;
set global rpl_semi_sync_slave_enabled = 1;
set @@global.gtid_slave_pos=@@global.gtid_binlog_pos;
include/start_slave.inc
connection server_1;
INSERT INTO t1 VALUES (6, 'Done');
# The gtid state on current master must be equal to ...
SHOW VARIABLES LIKE 'gtid_binlog_pos';
Variable_name Value
gtid_binlog_pos 0-1-12
connection server_2;
SELECT COUNT(*) = 6 as 'true' FROM t1;
true
1
# ... the gtid states on the slave:
SHOW VARIABLES LIKE 'gtid_slave_pos';
Variable_name Value
gtid_slave_pos 0-1-12
SHOW VARIABLES LIKE 'gtid_binlog_pos';
Variable_name Value
gtid_binlog_pos 0-1-12
include/diff_tables.inc [server_1:t1, server_2:t1]
# Cleanup
connection server_1;
DROP TABLE t1;
connection server_2;
include/stop_slave.inc
connection server_1;
set @@global.rpl_semi_sync_master_enabled = 0;
set @@global.rpl_semi_sync_slave_enabled = 0;
set @@global.rpl_semi_sync_master_wait_point=default;
RESET SLAVE;
RESET MASTER;
connection server_2;
set @@global.rpl_semi_sync_master_enabled = 0;
set @@global.rpl_semi_sync_slave_enabled = 0;
set @@global.rpl_semi_sync_master_wait_point=default;
CHANGE MASTER TO master_host='127.0.0.1', master_port=$SERVER_MYPORT_1, master_user='root', master_use_gtid=no;
include/start_slave.inc
connection default;
include/rpl_end.inc
if ($failover_to_slave)
{
--let $server_to_crash=1
--let $server_to_promote=2
--let $new_master_port=$SERVER_MYPORT_2
--let $client_port=$SERVER_MYPORT_1
--connect (conn_client,127.0.0.1,root,,test,$SERVER_MYPORT_1,)
}
if (!$failover_to_slave)
{
--let $server_to_crash=2
--let $server_to_promote=1
--let $new_master_port=$SERVER_MYPORT_1
--let $client_port=$SERVER_MYPORT_2
--connect (conn_client,127.0.0.1,root,,test,$SERVER_MYPORT_2,)
}
# Hold insert after write to binlog and before "run_commit_ordered" in engine
SET DEBUG_SYNC= "commit_after_release_LOCK_after_binlog_sync SIGNAL con1_ready WAIT_FOR con1_go";
--send_eval $query_to_crash
# complicate recovery with an extra binlog file
if (!$failover_to_slave)
{
--connect (conn_client_2,127.0.0.1,root,,test,$SERVER_MYPORT_2,)
# use the same signal with $query_to_crash
SET DEBUG_SYNC= "now WAIT_FOR con1_ready";
SET DEBUG_SYNC= "commit_after_release_LOCK_log SIGNAL con1_ready WAIT_FOR con2_go";
--send_eval $query2_to_crash
}
--connection server_$server_to_crash
SET DEBUG_SYNC= "now WAIT_FOR con1_ready";
--source include/kill_mysqld.inc
--connection server_$server_to_promote
--error 2003
--source include/stop_slave.inc
SELECT @@GLOBAL.gtid_current_pos;
--let $restart_parameters=--rpl-semi-sync-slave-enabled=1
--let $allow_rpl_inited=1
--source include/start_mysqld.inc
--connection server_$server_to_crash
--enable_reconnect
--source include/wait_until_connected_again.inc
# Check error log for correct messages.
let $log_error_ = $MYSQLTEST_VARDIR/log/mysqld.$server_to_crash.err;
--let SEARCH_FILE=$log_error_
--let SEARCH_PATTERN=$log_search_pattern
--source include/search_pattern_in_file.inc
--disconnect conn_client
#
# FAIL OVER now to new master
#
--connection server_$server_to_promote
set global rpl_semi_sync_master_enabled = 1;
set global rpl_semi_sync_master_wait_point=AFTER_SYNC;
--connection server_$server_to_crash
--let $master_port=$SERVER_MYPORT_2
if (`select $server_to_crash = 2`)
{
--let $master_port=$SERVER_MYPORT_1
}
evalp CHANGE MASTER TO master_host='127.0.0.1', master_port=$new_master_port, master_user='root', master_use_gtid=SLAVE_POS;
set global rpl_semi_sync_slave_enabled = 1;
set @@global.gtid_slave_pos=@@global.gtid_binlog_pos;
--source include/start_slave.inc
!include suite/rpl/rpl_1slave_base.cnf
!include include/default_client.cnf
[mysqld.1]
log-slave-updates
gtid-strict-mode=1
[mysqld.2]
log-slave-updates
gtid-strict-mode=1
# ==== Purpose ====
#
# Test verifies replication failover scenario.
#
# ==== Implementation ====
#
# Steps:
# 0 - Having two servers 1 and 2 enable semi-sync replication with
# with the master wait 'after_sync'.
# 1 - Insert a row. While inserting second row simulate
# a server crash at once the transaction is written to binlog, flushed
# and synced but the binlog position is not updated.
# 2 - Post crash-recovery on the old master execute there CHANGE MASTER
# TO command to connect to server id 2.
# 3 - The old master new slave server 1 must connect to the new
# master server 2.
# 4 - repeat the above to crash the new master and restore in role the old one
#
# ==== References ====
#
# MDEV-21117: recovery for --rpl-semi-sync-slave-enabled server
--source include/have_innodb.inc
--source include/have_debug_sync.inc
--source include/have_binlog_format_row.inc
--source include/master-slave.inc
# Initial slave
--connection server_2
--source include/stop_slave.inc
# Initial master
--connection server_1
RESET MASTER;
SET @@global.max_binlog_size= 4096;
--connection server_2
RESET MASTER;
SET @@global.max_binlog_size= 4096;
set @@global.rpl_semi_sync_slave_enabled = 1;
set @@global.gtid_slave_pos = "";
CHANGE MASTER TO master_use_gtid= slave_pos;
--source include/start_slave.inc
--connection server_1
ALTER TABLE mysql.gtid_slave_pos ENGINE=InnoDB;
set @@global.rpl_semi_sync_master_enabled = 1;
set @@global.rpl_semi_sync_master_wait_point=AFTER_SYNC;
call mtr.add_suppression("Can.t init tc log");
call mtr.add_suppression("Aborting");
call mtr.add_suppression("1 client is using or hasn.t closed the table properly");
call mtr.add_suppression("Table './mtr/test_suppressions' is marked as crashed and should be repaired");
CREATE TABLE t1 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb;
INSERT INTO t1 VALUES (1, 'dummy1');
#
# CRASH the original master, and FAILOVER to the new
#
# value 1 for server id 1 -> 2 failover
--let $failover_to_slave=1
--let $query_to_crash= INSERT INTO t1 VALUES (2, REPEAT("x", 4100))
--let $log_search_pattern=truncated binlog file:.*master.*000001
--source rpl_semi_sync_crash.inc
--connection server_2
--let $rows_so_far=3
--eval INSERT INTO t1 VALUES ($rows_so_far, 'dummy3')
--save_master_pos
--echo # The gtid state on current master must be equal to ...
SHOW VARIABLES LIKE 'gtid_binlog_pos';
--connection server_1
--sync_with_master
--eval SELECT COUNT(*) = $rows_so_far as 'true' FROM t1
--echo # ... the gtid states on the slave:
SHOW VARIABLES LIKE 'gtid_slave_pos';
SHOW VARIABLES LIKE 'gtid_binlog_pos';
--connection server_2
#
# CRASH the new master and FAILOVER back to the original
#
# value 0 for the reverse server id 2 -> 1 failover
--let $failover_to_slave=0
--let $query_to_crash = INSERT INTO t1 VALUES (4, REPEAT("x", 4100))
--let $query2_to_crash= INSERT INTO t1 VALUES (5, REPEAT("x", 4100))
--let $log_search_pattern=truncated binlog file:.*slave.*000001
--source rpl_semi_sync_crash.inc
--connection server_1
--let $rows_so_far=6
--eval INSERT INTO t1 VALUES ($rows_so_far, 'Done')
--save_master_pos
--echo # The gtid state on current master must be equal to ...
SHOW VARIABLES LIKE 'gtid_binlog_pos';
--connection server_2
--sync_with_master
--eval SELECT COUNT(*) = $rows_so_far as 'true' FROM t1
--echo # ... the gtid states on the slave:
SHOW VARIABLES LIKE 'gtid_slave_pos';
SHOW VARIABLES LIKE 'gtid_binlog_pos';
--let $diff_tables=server_1:t1, server_2:t1
--source include/diff_tables.inc
#
--echo # Cleanup
#
--connection server_1
DROP TABLE t1;
--save_master_pos
--connection server_2
--sync_with_master
--source include/stop_slave.inc
--connection server_1
set @@global.rpl_semi_sync_master_enabled = 0;
set @@global.rpl_semi_sync_slave_enabled = 0;
set @@global.rpl_semi_sync_master_wait_point=default;
RESET SLAVE;
RESET MASTER;
--connection server_2
set @@global.rpl_semi_sync_master_enabled = 0;
set @@global.rpl_semi_sync_slave_enabled = 0;
set @@global.rpl_semi_sync_master_wait_point=default;
evalp CHANGE MASTER TO master_host='127.0.0.1', master_port=$SERVER_MYPORT_1, master_user='root', master_use_gtid=no;
--source include/start_slave.inc
connection default;
--enable_reconnect
--source include/wait_until_connected_again.inc
--source include/rpl_end.inc
This diff is collapsed.
......@@ -44,6 +44,7 @@
#include <mysql/psi/mysql_table.h>
#include "sql_sequence.h"
#include "mem_root_array.h"
#include <utility> // pair
class Alter_info;
class Virtual_column_info;
......@@ -931,6 +932,32 @@ struct xid_t {
};
typedef struct xid_t XID;
/*
Enumerates a sequence in the order of
their creation that is in the top-down order of the index file.
Ranges from zero through MAX_binlog_id.
Not confuse the value with the binlog file numerical suffix,
neither with the binlog file line in the binlog index file.
*/
typedef uint Binlog_file_id;
const Binlog_file_id MAX_binlog_id= UINT_MAX;
/*
Compound binlog-id and byte offset of transaction's first event
in a sequence (e.g the recovery sequence) of binlog files.
Binlog_offset(0,0) is the minimum value to mean
the first byte of the first binlog file.
*/
typedef std::pair<Binlog_file_id, my_off_t> Binlog_offset;
/* binlog-based recovery transaction descriptor */
struct xid_recovery_member
{
my_xid xid;
uint in_engine_prepare; // number of engines that have xid prepared
bool decided_to_commit;
Binlog_offset binlog_coord; // semisync recovery binlog offset
};
/* for recover() handlerton call */
#define MIN_XID_LIST_SIZE 128
#define MAX_XID_LIST_SIZE (1024*128)
......@@ -5320,7 +5347,8 @@ int ha_commit_one_phase(THD *thd, bool all);
int ha_commit_trans(THD *thd, bool all);
int ha_rollback_trans(THD *thd, bool all);
int ha_prepare(THD *thd);
int ha_recover(HASH *commit_list);
int ha_recover(HASH *commit_list, MEM_ROOT *mem_root= NULL);
uint ha_recover_complete(HASH *commit_list, Binlog_offset *coord= NULL);
/* transactions: these functions never call handlerton functions directly */
int ha_enable_transaction(THD *thd, bool on);
......@@ -5448,4 +5476,8 @@ int del_global_index_stat(THD *thd, TABLE* table, KEY* key_info);
int del_global_table_stat(THD *thd, const LEX_CSTRING *db, const LEX_CSTRING *table);
uint ha_count_rw_all(THD *thd, Ha_trx_info **ptr_ha_info);
bool non_existing_table_error(int error);
uint ha_count_rw_2pc(THD *thd, bool all);
uint ha_check_and_coalesce_trx_read_only(THD *thd, Ha_trx_info *ha_list,
bool all);
#endif /* HANDLER_INCLUDED */
This diff is collapsed.
......@@ -477,6 +477,7 @@ class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG
/* Flag used to optimise around wait_for_prior_commit. */
bool queued_by_other;
ulong binlog_id;
bool ro_1pc; // passes the binlog_cache_mngr::ro_1pc value to Gtid ctor
};
/*
......@@ -810,7 +811,8 @@ class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG
my_bool *with_annotate= 0); // binary log write
bool write_transaction_to_binlog(THD *thd, binlog_cache_mngr *cache_mngr,
Log_event *end_ev, bool all,
bool using_stmt_cache, bool using_trx_cache);
bool using_stmt_cache, bool using_trx_cache,
bool is_ro_1pc);
bool write_incident_already_locked(THD *thd);
bool write_incident(THD *thd);
......@@ -860,6 +862,9 @@ class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG
int purge_first_log(Relay_log_info* rli, bool included);
int set_purge_index_file_name(const char *base_file_name);
int open_purge_index_file(bool destroy);
bool truncate_and_remove_binlogs(const char *truncate_file,
my_off_t truncate_pos,
rpl_gtid *gtid);
bool is_inited_purge_index_file();
int close_purge_index_file();
int clean_purge_index_file();
......@@ -896,7 +901,8 @@ class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG
void set_status_variables(THD *thd);
bool is_xidlist_idle();
bool write_gtid_event(THD *thd, bool standalone, bool is_transactional,
uint64 commit_id);
uint64 commit_id,
bool has_xid= false, bool ro_1pc= false);
int read_state_from_file();
int write_state_to_file();
int get_most_recent_gtid_list(rpl_gtid **list, uint32 *size);
......@@ -1237,4 +1243,8 @@ class Gtid_list_log_event;
const char *
get_gtid_list_event(IO_CACHE *cache, Gtid_list_log_event **out_gtid_list);
int binlog_commit(THD *thd, bool all, bool is_ro_1pc);
int binlog_commit_by_xid(handlerton *hton, XID *xid);
int binlog_rollback_by_xid(handlerton *hton, XID *xid);
#endif /* LOG_H */
......@@ -53,6 +53,7 @@
#include "sql_digest.h"
#include "zlib.h"
#include "myisampack.h"
#include <algorithm>
#define my_b_write_string(A, B) my_b_write((A), (uchar*)(B), (uint) (sizeof(B) - 1))
......@@ -2560,10 +2561,12 @@ Binlog_checkpoint_log_event::Binlog_checkpoint_log_event(
Gtid_log_event::Gtid_log_event(const uchar *buf, uint event_len,
const Format_description_log_event
*description_event)
: Log_event(buf, description_event), seq_no(0), commit_id(0)
: Log_event(buf, description_event), seq_no(0), commit_id(0),
flags_extra(0), extra_engines(0)
{
uint8 header_size= description_event->common_header_len;
uint8 post_header_len= description_event->post_header_len[GTID_EVENT-1];
const uchar *buf_0= buf;
if (event_len < (uint) header_size + (uint) post_header_len ||
post_header_len < GTID_HEADER_LEN)
return;
......@@ -2597,6 +2600,32 @@ Gtid_log_event::Gtid_log_event(const uchar *buf, uint event_len,
memcpy(xid.data, buf, data_length);
buf+= data_length;
}
/* the extra flags check and actions */
if (static_cast<uint>(buf - buf_0) < event_len)
{
flags_extra= *buf++;
/*
extra engines flags presence is identifed by non-zero byte value
at this point
*/
if (flags_extra & FL_EXTRA_MULTI_ENGINE)
{
DBUG_ASSERT(static_cast<uint>(buf - buf_0) < event_len);
extra_engines= *buf++;
DBUG_ASSERT(extra_engines > 0);
}
}
/*
the strict '<' part of the assert corresponds to extra zero-padded
trailing bytes,
*/
DBUG_ASSERT(static_cast<uint>(buf - buf_0) <= event_len);
/* and the last of them is tested. */
DBUG_ASSERT(static_cast<uint>(buf - buf_0) == event_len ||
buf_0[event_len - 1] == 0);
}
......
......@@ -489,6 +489,16 @@ class String;
*/
#define LOG_EVENT_IGNORABLE_F 0x80
/**
@def LOG_EVENT_ACCEPT_OWN_F
Flag sets by the semisync slave for accepting
the same server_id ("own") events which the slave must not have
in its state. Typically such events were never committed by
their originator (this server) and discared at its semisync-slave recovery.
*/
#define LOG_EVENT_ACCEPT_OWN_F 0x4000
/**
@def LOG_EVENT_SKIP_REPLICATION_F
......@@ -3602,6 +3612,13 @@ class Gtid_log_event: public Log_event
event_mysql_xid_t xid;
#endif
uchar flags2;
uint flags_extra; // more flags area placed after the regular flags2's one
/*
Number of engine participants in transaction minus 1.
When zero the event does not contain that information.
*/
uint8 extra_engines;
/* Flags2. */
/* FL_STANDALONE is set when there is no terminating COMMIT event. */
......@@ -3633,9 +3650,19 @@ class Gtid_log_event: public Log_event
/* FL_"COMMITTED or ROLLED-BACK"_XA is set for XA transaction. */
static const uchar FL_COMPLETED_XA= 128;
/* Flags_extra. */
/*
FL_EXTRA_MULTI_ENGINE is set for event group comprising a transaction
involving multiple storage engines. No flag and extra data are added
to the event when the transaction involves only one engine.
*/
static const uchar FL_EXTRA_MULTI_ENGINE= 1;
#ifdef MYSQL_SERVER
Gtid_log_event(THD *thd_arg, uint64 seq_no, uint32 domain_id, bool standalone,
uint16 flags, bool is_transactional, uint64 commit_id);
uint16 flags, bool is_transactional, uint64 commit_id,
bool has_xid= false, bool is_ro_1pc= false);
#ifdef HAVE_REPLICATION
void pack_info(Protocol *protocol);
virtual int do_apply_event(rpl_group_info *rgi);
......
......@@ -644,7 +644,7 @@ Log_event::do_shall_skip(rpl_group_info *rgi)
rli->replicate_same_server_id,
rli->slave_skip_counter));
if ((server_id == global_system_variables.server_id &&
!rli->replicate_same_server_id) ||
!(rli->replicate_same_server_id || (flags & LOG_EVENT_ACCEPT_OWN_F))) ||
(rli->slave_skip_counter == 1 && rli->is_in_group()) ||
(flags & LOG_EVENT_SKIP_REPLICATION_F &&
opt_replicate_events_marked_for_skip != RPL_SKIP_REPLICATE))
......@@ -3261,10 +3261,13 @@ bool Binlog_checkpoint_log_event::write()
Gtid_log_event::Gtid_log_event(THD *thd_arg, uint64 seq_no_arg,
uint32 domain_id_arg, bool standalone,
uint16 flags_arg, bool is_transactional,
uint64 commit_id_arg)
uint64 commit_id_arg, bool has_xid,
bool ro_1pc)
: Log_event(thd_arg, flags_arg, is_transactional),
seq_no(seq_no_arg), commit_id(commit_id_arg), domain_id(domain_id_arg),
flags2((standalone ? FL_STANDALONE : 0) | (commit_id_arg ? FL_GROUP_COMMIT_ID : 0))
flags2((standalone ? FL_STANDALONE : 0) |
(commit_id_arg ? FL_GROUP_COMMIT_ID : 0)),
flags_extra(0), extra_engines(0)
{
cache_type= Log_event::EVENT_NO_CACHE;
bool is_tmp_table= thd_arg->lex->stmt_accessed_temp_table();
......@@ -3287,15 +3290,40 @@ Gtid_log_event::Gtid_log_event(THD *thd_arg, uint64 seq_no_arg,
flags2|= (thd_arg->rgi_slave->gtid_ev_flags2 & (FL_DDL|FL_WAITED));
XID_STATE &xid_state= thd->transaction->xid_state;
if (is_transactional && xid_state.is_explicit_XA() &&
(thd->lex->sql_command == SQLCOM_XA_PREPARE ||
xid_state.get_state_code() == XA_PREPARED))
if (is_transactional)
{
DBUG_ASSERT(thd->lex->xa_opt != XA_ONE_PHASE);
if (xid_state.is_explicit_XA() &&
(thd->lex->sql_command == SQLCOM_XA_PREPARE ||
xid_state.get_state_code() == XA_PREPARED))
{
DBUG_ASSERT(thd->lex->xa_opt != XA_ONE_PHASE);
flags2|= thd->lex->sql_command == SQLCOM_XA_PREPARE ?
FL_PREPARED_XA : FL_COMPLETED_XA;
xid.set(xid_state.get_xid());
}
/* count non-zero extra recoverable engines; total = extra + 1 */
if (has_xid)
{
DBUG_ASSERT(ha_count_rw_2pc(thd_arg,
thd_arg->in_multi_stmt_transaction_mode()));
extra_engines=
ha_count_rw_2pc(thd_arg, thd_arg->in_multi_stmt_transaction_mode()) - 1;
}
else if (ro_1pc)
{
extra_engines= UCHAR_MAX;
}
else if (thd->lex->sql_command == SQLCOM_XA_PREPARE)
{
DBUG_ASSERT(thd_arg->in_multi_stmt_transaction_mode());
flags2|= thd->lex->sql_command == SQLCOM_XA_PREPARE ?
FL_PREPARED_XA : FL_COMPLETED_XA;
xid.set(xid_state.get_xid());
uint8 count= ha_count_rw_2pc(thd_arg, true);
extra_engines= count > 1 ? 0 : UCHAR_MAX;
}
if (extra_engines > 0)
flags_extra|= FL_EXTRA_MULTI_ENGINE;
}
}
......@@ -3339,19 +3367,19 @@ Gtid_log_event::peek(const uchar *event_start, size_t event_len,
bool
Gtid_log_event::write()
{
uchar buf[GTID_HEADER_LEN+2+sizeof(XID)];
size_t write_len;
uchar buf[GTID_HEADER_LEN+2+sizeof(XID) + /* flags_extra: */ 1+4];
size_t write_len= 13;
int8store(buf, seq_no);
int4store(buf+8, domain_id);
buf[12]= flags2;
if (flags2 & FL_GROUP_COMMIT_ID)
{
int8store(buf+13, commit_id);
DBUG_ASSERT(write_len + 8 == GTID_HEADER_LEN + 2);
int8store(buf+write_len, commit_id);
write_len= GTID_HEADER_LEN + 2;
}
else
write_len= 13;
if (flags2 & (FL_PREPARED_XA | FL_COMPLETED_XA))
{
......@@ -3363,6 +3391,16 @@ Gtid_log_event::write()
memcpy(buf+write_len, xid.data, data_length);
write_len+= data_length;
}
if (flags_extra > 0)
{
buf[write_len]= flags_extra;
write_len++;
}
if (flags_extra & FL_EXTRA_MULTI_ENGINE)
{
buf[write_len]= extra_engines;
write_len++;
}
if (write_len < GTID_HEADER_LEN)
{
......
......@@ -6173,6 +6173,15 @@ static int queue_event(Master_info* mi, const uchar *buf, ulong event_len)
uchar new_buf_arr[4096];
bool is_malloc = false;
bool is_rows_event= false;
/*
The flag has replicate_same_server_id semantics and is raised to accept
a same-server-id event on the semisync slave, for both the gtid and legacy
connection modes.
Such events can appear as result of this server recovery so the event
was created there and replicated elsewhere right before the crash. At recovery
it could be evicted from the server's binlog.
*/
bool do_accept_own_server_id= false;
/*
FD_q must have been prepared for the first R_a event
inside get_master_version_and_clock()
......@@ -6234,6 +6243,7 @@ static int queue_event(Master_info* mi, const uchar *buf, ulong event_len)
unlock_data_lock= FALSE;
goto err;
}
DBUG_ASSERT(((uchar) buf[FLAGS_OFFSET] & LOG_EVENT_ACCEPT_OWN_F) == 0);
if (mi->rli.relay_log.description_event_for_queue->binlog_version<4 &&
buf[EVENT_TYPE_OFFSET] != FORMAT_DESCRIPTION_EVENT /* a way to escape */)
......@@ -6933,7 +6943,8 @@ static int queue_event(Master_info* mi, const uchar *buf, ulong event_len)
}
else
if ((s_id == global_system_variables.server_id &&
!mi->rli.replicate_same_server_id) ||
!(mi->rli.replicate_same_server_id ||
(do_accept_own_server_id= rpl_semi_sync_slave_enabled))) ||
event_that_should_be_ignored(buf) ||
/*
the following conjunction deals with IGNORE_SERVER_IDS, if set
......@@ -6993,6 +7004,19 @@ static int queue_event(Master_info* mi, const uchar *buf, ulong event_len)
}
else
{
if (do_accept_own_server_id)
{
int2store(const_cast<uchar*>(buf + FLAGS_OFFSET),
uint2korr(buf + FLAGS_OFFSET) | LOG_EVENT_ACCEPT_OWN_F);
if (checksum_alg != BINLOG_CHECKSUM_ALG_OFF)
{
ha_checksum crc= 0;
crc= my_checksum(crc, (const uchar *) buf,
event_len - BINLOG_CHECKSUM_LEN);
int4store(&buf[event_len - BINLOG_CHECKSUM_LEN], crc);
}
}
if (likely(!rli->relay_log.write_event_buffer((uchar*)buf, event_len)))
{
mi->master_log_pos+= inc_pos;
......
......@@ -831,6 +831,7 @@ void log_write_up_to(lsn_t lsn, bool flush_to_disk, bool rotate_key,
flush_lock.release(flush_lsn);
log_flush_notify(flush_lsn);
DBUG_EXECUTE_IF("crash_after_log_write_upto", DBUG_SUICIDE(););
}
/** write to the log file up to the last log entry.
......
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