Skip to content

Commit

Permalink
MDEV-7145: Delayed replication, intermediate commit.
Browse files Browse the repository at this point in the history
Initial merge of delayed replication from MySQL git.

The code from the initial push into MySQL is merged, and the
associated test case passes. A number of tasks are still pending:

1. Check full test suite run for any regressions or .result file updates.

2. Extend the feature to also work for parallel replication.

3. There are some todo-comments about future refactoring left from
MySQL, these should be located and merged on top.

4. There are some later related MySQL commits, these should be checked
and merged. These include:
    e134b9362ba0b750d6ac1b444780019622d14aa5
    b38f0f7857c073edfcc0a64675b7f7ede04be00f
    fd2b210383358fe7697f201e19ac9779879ba72a
    afc397376ec50e96b2918ee64e48baf4dda0d37d

5. The testcase from MySQL relies heavily on sleep and timing for
testing, and seems likely to sporadically fail on heavily loaded test
servers in buildbot or distro build farms.

Signed-off-by: Kristian Nielsen <knielsen@knielsen-hq.org>
  • Loading branch information
knielsen committed Oct 14, 2016
1 parent 50f19ca commit 19abe79
Show file tree
Hide file tree
Showing 19 changed files with 1,150 additions and 211 deletions.
39 changes: 39 additions & 0 deletions mysql-test/extra/rpl_tests/delayed_slave_wait_on_query.inc
Original file line number Diff line number Diff line change
@@ -0,0 +1,39 @@
# ==== Purpose ====
#
# Auxiliary file used by rpl_delayed_slave.test. This assumes that an
# 'INSERT INTO t1...' query has been executed on the master. It does
# this:
#
# - After half the delay, check the status. It should be delaying and
# the query should not have executed.
#
# - After one and a half delay, check the status. It should not be
# delaying and the query should be executed.
#
# ==== Usage ====
#
# --source extra/rpl_tests/delayed_slave_wait_on_query.inc

connection master;
--echo [on slave]
--let $slave_timeout= $time1

--source include/sync_slave_io_with_master.inc
--echo # sleep 1*T
--sleep $time1

--echo # Expect query not executed and status is 'Waiting until MASTER_DELAY...'
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
--source include/show_delayed_slave_state.inc

--echo # sleep 1*T
--sleep $time1

--echo # sync with master (with timeout 1*T)
--source include/sync_with_master.inc

--echo # Expect query executed and status is 'Has read all relay log...'
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
--source include/show_delayed_slave_state.inc

--source include/check_slave_is_running.inc
3 changes: 3 additions & 0 deletions mysql-test/include/check-testcase.test
Original file line number Diff line number Diff line change
Expand Up @@ -67,6 +67,9 @@ if ($tmp)
--echo Replicate_Do_Domain_Ids
--echo Replicate_Ignore_Domain_Ids
--echo Parallel_Mode conservative
--echo SQL_Delay 0
--echo SQL_Remaining_Delay NULL
--echo Slave_SQL_Running_State
}
if (!$tmp) {
# Note: after WL#5177, fields 13-18 shall not be filtered-out.
Expand Down
28 changes: 28 additions & 0 deletions mysql-test/include/show_delayed_slave_state.inc
Original file line number Diff line number Diff line change
@@ -0,0 +1,28 @@
# ==== Purpose ====
#
# Display the delay state of the SQL thread.
#
# ==== Usage ====
#
# --let $verbose_delayed_slave_state= [0|1]
# --source extra/rpl_tests/show_delayed_slave_state.inc
#
# By default, the output is normalized so that it does not depend on
# exact timing or exact binlog positions. If
# $verbose_delayed_slave_state is set, then it outputs exact times and
# binlog positions. This can be useful for debugging.

--let $_delayed_slave_status= query_get_value(SHOW SLAVE STATUS, Slave_SQL_Running_State, 1)

--let $_delayed_slave_remaining_delay= query_get_value(SHOW SLAVE STATUS, SQL_Remaining_Delay, 1)
--let $_delayed_slave_qualitative_delay= `SELECT CASE WHEN "$_delayed_slave_remaining_delay" = "NULL" THEN "NULL" WHEN "$_delayed_slave_remaining_delay" = "0" THEN "0" ELSE "greater than zero" END`

--let $_delayed_slave_io_pos= query_get_value(SHOW SLAVE STATUS, Read_Master_Log_Pos, 1)
--let $_delayed_slave_sql_pos= query_get_value(SHOW SLAVE STATUS, Exec_Master_Log_Pos, 1)
--let $_delayed_slave_qualitative_log_pos= `SELECT IF($_delayed_slave_io_pos > $_delayed_slave_sql_pos, "behind", "in sync with")`

--echo Slave_SQL_Running_State='$_delayed_slave_status'; SQL_Remaining_Delay is $_delayed_slave_qualitative_delay; SQL thread is $_delayed_slave_qualitative_log_pos IO thread

if ($verbose_delayed_slave_state) {
--echo SQL_Remaining_Delay='$_delayed_slave_remaining_delay'; Read_master_log_pos='$_delayed_slave_io_pos'; Exec_Master_Log_Pos='$_delayed_slave_sql_pos'
}
26 changes: 26 additions & 0 deletions mysql-test/include/sync_with_master.inc
Original file line number Diff line number Diff line change
@@ -0,0 +1,26 @@
# ==== Purpose ====
#
# This file does the same as the built-in command sync_with_master,
# but can be configured to use a custom timeout. This has the benefit
# that it accepts the same $slave_timeout and $master_connection
# parameters as wait_for_slave_param.inc
#
#
# ==== Usage ====
#
# --connection master
# --source include/save_master_pos.inc
# --connection slave
# --source include/sync_with_master.inc
#
# Parameters to this macro are $slave_timeout and
# $master_connection. See wait_for_slave_param.inc for
# descriptions.

--let $slave_param= Relay_Master_Log_File
--let $slave_param_value= $_master_file
--source include/wait_for_slave_param.inc

--let $slave_param= Exec_Master_Log_Pos
--let $slave_param_value= $_master_pos
--source include/wait_for_slave_param.inc
172 changes: 172 additions & 0 deletions mysql-test/suite/rpl/r/rpl_delayed_slave.result
Original file line number Diff line number Diff line change
@@ -0,0 +1,172 @@
include/master-slave.inc
[connection master]
call mtr.add_suppression("Unsafe statement written to the binary log using statement format");
call mtr.add_suppression("Unsafe statement written to the binary log using statement format");
[on master]
CREATE TABLE t1 (a VARCHAR(100), b INT AUTO_INCREMENT PRIMARY KEY);
==== Normal setup ====
[on slave]
include/stop_slave.inc
# CHANGE MASTER TO MASTER_DELAY = 2*T
# Checking that delay is what we set it to
# Expect status to be ''
SELECT STATE FROM INFORMATION_SCHEMA.PROCESSLIST ORDER BY ID DESC LIMIT 1;
STATE

include/start_slave.inc
[on master]
INSERT INTO t1(a) VALUES ('normal setup');
[on slave]
include/sync_slave_io_with_master.inc
# sleep 1*T
# Expect query not executed and status is 'Waiting until MASTER_DELAY...'
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
a b
Slave_SQL_Running_State='Waiting until MASTER_DELAY seconds after master executed event'; SQL_Remaining_Delay is greater than zero; SQL thread is behind IO thread
# sleep 1*T
# sync with master (with timeout 1*T)
include/wait_for_slave_param.inc [Relay_Master_Log_File]
include/wait_for_slave_param.inc [Exec_Master_Log_Pos]
# Expect query executed and status is 'Has read all relay log...'
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
a b
normal setup 1
Slave_SQL_Running_State='Slave has read all relay log; waiting for the slave I/O thread to update it'; SQL_Remaining_Delay is NULL; SQL thread is in sync with IO thread
include/check_slave_is_running.inc
==== Slave lags "naturally" after master ====
[on master]
# CREATE FUNCTION delay_on_slave(time_units INT) RETURNS INT BEGIN IF @@GLOBAL.server_id = 2 THEN RETURN SLEEP(time_units * T); ELSE RETURN 0; END IF; END
INSERT INTO t1(a) SELECT delay_on_slave(3);
Warnings:
Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement is unsafe because it uses a system variable that may have a different value on the slave.
Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement is unsafe because it uses a system function that may return a different value on the slave.
INSERT INTO t1(a) VALUES ('slave is already lagging: this statement should execute immediately');
INSERT INTO t1(a) SELECT delay_on_slave(2);
Warnings:
Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement is unsafe because it uses a system variable that may have a different value on the slave.
Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement is unsafe because it uses a system function that may return a different value on the slave.
[on slave]
include/sync_slave_io_with_master.inc
# sleep 1*T
# Expect no query executed and status is 'Waiting until MASTER_DELAY...'
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
a b
normal setup 1
Slave_SQL_Running_State='Waiting until MASTER_DELAY seconds after master executed event'; SQL_Remaining_Delay is greater than zero; SQL thread is behind IO thread
# wait for first query to execute
# sleep 1*T
# Expect second query executed and status is executing third query (i.e., 'User sleep')
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
a b
slave is already lagging: this statement should execute immediately 3
Slave_SQL_Running_State='User sleep'; SQL_Remaining_Delay is NULL; SQL thread is behind IO thread
# sleep 2*T
# Expect query executed and status is 'Has read all relay log...'
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
a b
0 4
Slave_SQL_Running_State='Slave has read all relay log; waiting for the slave I/O thread to update it'; SQL_Remaining_Delay is NULL; SQL thread is in sync with IO thread
==== Seconds_Behind_Master ====
# Bring slave to sync.
include/stop_slave.inc
CHANGE MASTER TO MASTER_DELAY = 0;
include/start_slave.inc
INSERT INTO t1(a) VALUES ('Syncing slave');
include/stop_slave.inc
# CHANGE MASTER TO MASTER_DELAY = 2*T
include/start_slave.inc
INSERT INTO t1(a) VALUES (delay_on_slave(1));
Warnings:
Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement is unsafe because it uses a system variable that may have a different value on the slave.
Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement is unsafe because it uses a system function that may return a different value on the slave.
# sleep 1*T
# sleep 1*T
==== STOP SLAVE and START SLAVE ====
include/stop_slave.inc
# CHANGE MASTER TO MASTER_DELAY = 3*T
include/start_slave.inc
# Checking that delay is what we set it to
[on master]
INSERT INTO t1(a) VALUES ('stop slave and start slave');
[on slave]
# sleep 1*T
SET @before_stop_slave= UNIX_TIMESTAMP();
include/stop_slave.inc
# STOP SLAVE finished in time.
# Expect query not executed and status is ''
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
a b
0 6
Slave_SQL_Running_State=''; SQL_Remaining_Delay is NULL; SQL thread is behind IO thread
include/start_slave.inc
# START SLAVE finished in time.
[on slave]
include/sync_slave_io_with_master.inc
# sleep 1*T
# Expect query not executed and status is 'Waiting until MASTER_DELAY...'
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
a b
0 6
Slave_SQL_Running_State='Waiting until MASTER_DELAY seconds after master executed event'; SQL_Remaining_Delay is greater than zero; SQL thread is behind IO thread
# sleep 1*T
# sync with master (with timeout 1*T)
include/wait_for_slave_param.inc [Relay_Master_Log_File]
include/wait_for_slave_param.inc [Exec_Master_Log_Pos]
# Expect query executed and status is 'Has read all relay log...'
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
a b
stop slave and start slave 7
Slave_SQL_Running_State='Slave has read all relay log; waiting for the slave I/O thread to update it'; SQL_Remaining_Delay is NULL; SQL thread is in sync with IO thread
include/check_slave_is_running.inc
==== Change back to no delay ====
[on slave]
include/stop_slave.inc
CHANGE MASTER TO MASTER_DELAY = 0;
# Expect delay is 0.
SQL_Delay='0'
include/start_slave.inc
[on master]
INSERT INTO t1(a) VALUES ('change back to no delay');
[on slave]
include/sync_slave_io_with_master.inc
# sleep 1*T
# Expect query executed and status is 'Has read all relay log...'
SELECT * FROM t1 ORDER BY b DESC LIMIT 1;
a b
change back to no delay 8
Slave_SQL_Running_State='Slave has read all relay log; waiting for the slave I/O thread to update it'; SQL_Remaining_Delay is NULL; SQL thread is in sync with IO thread
==== Reset delay with RESET SLAVE ====
include/stop_slave.inc
CHANGE MASTER TO MASTER_DELAY = 71;
include/start_slave.inc
# Expect delay is 71
SQL_Delay='71'
include/stop_slave.inc
RESET SLAVE;
[on master]
RESET MASTER;
[on slave]
include/start_slave.inc
# Expect delay is 0
SQL_Delay='0'
==== Set a bad value for the delay ====
include/stop_slave.inc
# Expect error for setting negative delay
CHANGE MASTER TO MASTER_DELAY = -1;
ERROR 42000: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near '-1' at line 1
# Expect that it's ok to set delay of 2^31-1
CHANGE MASTER TO MASTER_DELAY = 2147483647;
# Expect error for setting delay between 2^31 and 2^32-1
CHANGE MASTER TO MASTER_DELAY = 2147483648;
ERROR HY000: The requested value 2147483648 for the master delay exceeds the maximum 2147483647
# Expect error for setting delay to nonsense
CHANGE MASTER TO MASTER_DELAY = blah;
ERROR 42000: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'blah' at line 1
CHANGE MASTER TO MASTER_DELAY = 0;
include/start_slave.inc
==== Clean up ====
[on master]
DROP TABLE t1;
DROP FUNCTION delay_on_slave;
[on slave]
include/rpl_end.inc
Loading

0 comments on commit 19abe79

Please sign in to comment.