1 files changed, 428 insertions, 0 deletions
diff --git a/mysql-test/suite/rpl/t/rpl_delayed_slave.test b/mysql-test/suite/rpl/t/rpl_delayed_slave.test
new file mode 100644
index 00000000..d00e796b
--- /dev/null
+++ b/mysql-test/suite/rpl/t/rpl_delayed_slave.test
@@ -0,0 +1,428 @@
+# ==== Purpose ====
+#
+# Test the time-delayed replication feature, i.e.,
+# CHANGE MASTER TO MASTER_DELAY=X:
+#
+#  - Verify that slave has executed the events after but not before the
+#    delay timeout.
+#
+#  - Verify that delay is correct when slave is already lagging
+#    due to slow queries.
+#
+#  - Verify that Seconds_Behind_Master is greater than or equal to the
+#    delay if the slave still has unprocessed events in the relay log
+#    and more time than the delay has elapsed since the last event was
+#    executed on the master.
+#
+#  - Verify that STOP SLAVE works instantly even during a delay, and
+#    that it does not cause the waited-for event to be executed too
+#    early on slave.
+#
+#  - Verify that changing back to no delay works.
+#
+#  - Verify that RESET SLAVE sets the delay to 0.
+#
+#  - Verify that setting a bad value for the delay gives an error.
+#
+# ==== Implementation ====
+#
+# We run the slave with 10 seconds lag.
+#
+# In general, to test that a query has not been executed by the slave
+# before this time, we wait until the slave IO thread has received the
+# event, and then 5 seconds more, and check that the table has not
+# been updated.  To test that a query has been executed after this
+# time, we wait 10 seconds more.
+#
+# To simulate that the slave lags due to slow queries, we invoke a
+# stored function that executes SLEEP if @@gloval.server_id==2. This
+# requires that we run with binlog_format=STATEMENT.
+#
+# ==== Related Bugs and Worklogs ====
+#
+# WL#344: Time-delayed replication
+# BUG#28760: Simulating a replication lag
+# [duplicate] BUG#22072: configurable delayed replication
+# [duplicate] BUG#21639: Add Replication Delay parameter
+# BUG#56442: Slave executes delayed statements when STOP SLAVE is issued
+#
+# ==== Issues with this Test Case ====
+#
+# The test is inherently timing-sensitive (i.e., contains races) and
+# is likely to fail sporadically on a loaded host.
+#
+# The test takes a long time; it sleeps for around 20*10 seconds.
+
+--source include/big_test.inc
+--source include/not_valgrind.inc
+--source include/master-slave.inc
+# Needed so that sleeps get executed in the slave SQL thread.
+--source include/have_binlog_format_statement.inc
+
+
+call mtr.add_suppression("Unsafe statement written to the binary log using statement format");
+--connection slave
+call mtr.add_suppression("Unsafe statement written to the binary log using statement format");
+--source include/stop_slave.inc
+CHANGE MASTER TO MASTER_USE_GTID=NO;
+--source include/start_slave.inc
+--connection master
+
+
+# We assume that any simple operation takes zero time, with an error
+# margin of $time1 seconds. Hence, if we run with a delay of $time2
+# seconds, we expect that:
+#  - If we execute a query on master and wait $time1 seconds, then the
+#    query has been copied to slave but not yet executed.
+#  - If we execute a query on master and wait $time3 seconds, then the
+#    query has been executed.
+--let $time1= 10
+if (`SELECT '$max_query_execution_time' > 0`) {
+  --let $time1= $max_query_execution_time
+}
+--let $time2= `SELECT 2 * $time1`
+--let $time3= `SELECT 3 * $time1`
+
+
+--echo [on master]
+CREATE TABLE t1 (a VARCHAR(100), b INT);
+INSERT INTO t1 VALUES ("zero", 0);
+
+
+--echo ==== Normal setup ====
+
+--echo [on slave]
+--sync_slave_with_master
+
+--source include/stop_slave.inc
+
+--echo # CHANGE MASTER TO MASTER_DELAY = 2*T
+--disable_query_log
+eval CHANGE MASTER TO MASTER_DELAY = $time2;
+--enable_query_log
+
+--source include/start_slave.inc
+
+--let $assert_text= SHOW SLAVE STATUS should return the same delay that we set with CHANGE MASTER
+--let $assert_cond= [SHOW SLAVE STATUS, SQL_Delay, 1] = $time2
+--source include/rpl_assert.inc
+
+--echo [on master]
+--connection master
+INSERT INTO t1 VALUES ('normal setup', 1);
+
+--let $query_number= 1
+--source include/delayed_slave_wait_on_query.inc
+
+
+--echo ==== Slave lags "naturally" after master ====
+
+--echo [on master]
+--connection master
+
+--disable_query_log
+--echo # 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
+--eval CREATE FUNCTION delay_on_slave(time_units INT) RETURNS INT BEGIN IF @@GLOBAL.server_id = 2 THEN RETURN SLEEP(time_units * $time1); ELSE RETURN 0; END IF; END
+--enable_query_log
+
+INSERT INTO t1 SELECT delay_on_slave(3), 2;
+
+--save_master_pos
+INSERT INTO t1 VALUES ('slave is already lagging: this statement should execute immediately', 3);
+INSERT INTO t1 SELECT delay_on_slave(2), 4;
+
+--echo [on slave]
+--source include/sync_slave_io_with_master.inc
+--echo # sleep 1*T
+--sleep $time1
+
+--let $assert_text= No query executed
+--let $assert_cond= MAX(b) = 1 FROM t1
+--source include/rpl_assert.inc
+
+--let $assert_text= Status should be 'Waiting until MASTER_DELAY...'
+--let $assert_cond= "[SHOW SLAVE STATUS, Slave_SQL_Running_State, 1]" LIKE "Waiting until MASTER_DELAY%"
+--source include/rpl_assert.inc
+
+--echo # wait for first query to execute
+--sync_with_master
+
+--echo # sleep 1*T
+--sleep $time1
+
+--let $assert_text= Second query executed
+--let $assert_cond= MAX(b) = 3 FROM t1
+--source include/rpl_assert.inc
+
+let $parallel= `SELECT @@GLOBAL.slave_parallel_threads`;
+if (!$parallel)
+{
+  let $assert_text= Status should be executing third query (i.e., 'User sleep');
+  let $assert_cond= "[SHOW SLAVE STATUS, Slave_SQL_Running_State, 1]" = "User sleep";
+  source include/rpl_assert.inc;
+}
+
+--echo # sleep 2*T
+--sleep $time2
+
+--let $assert_text= Third query executed
+--let $assert_cond= MAX(b) = 4 FROM t1
+--source include/rpl_assert.inc
+
+--let $assert_text= Status should be 'Has read all relay log...'
+--let $assert_cond= "[SHOW SLAVE STATUS, Slave_SQL_Running_State, 1]" LIKE "Slave has read all relay log%"
+--source include/rpl_assert.inc
+
+
+--echo ==== Seconds_Behind_Master ====
+
+--echo # Bring slave to sync.
+--source include/stop_slave.inc
+CHANGE MASTER TO MASTER_DELAY = 0;
+--source include/start_slave.inc
+
+--connection master
+INSERT INTO t1 VALUES ('Syncing slave', 5);
+--sync_slave_with_master
+
+--source include/stop_slave.inc
+--echo # CHANGE MASTER TO MASTER_DELAY = 2*T
+--disable_query_log
+eval CHANGE MASTER TO MASTER_DELAY = $time2;
+--enable_query_log
+--source include/start_slave.inc
+
+--connection master
+INSERT INTO t1 VALUES (delay_on_slave(1), 6);
+--save_master_pos
+--connection slave
+
+--echo # sleep 1*T
+--sleep $time1
+
+--let $assert_cond= [SHOW SLAVE STATUS, Seconds_Behind_Master, 1] >= 0 AND <1> < $time2
+--let $assert_text= Seconds_Behind_Master should be between 0 and the 2*T
+--source include/rpl_assert.inc
+
+--echo # sleep 1*T
+--sleep $time1
+
+--let $assert_cond= [SHOW SLAVE STATUS, Seconds_Behind_Master, 1] >= $time2
+--let $assert_text= Seconds_Behind_Master should be at least 2*T
+--source include/rpl_assert.inc
+
+--sync_with_master
+
+
+--echo ==== STOP SLAVE / START SLAVE + DML ====
+
+# Set up a longer delay.
+--source include/stop_slave.inc
+
+--echo # CHANGE MASTER TO MASTER_DELAY = 3*T
+--disable_query_log
+eval CHANGE MASTER TO MASTER_DELAY = $time3;
+--enable_query_log
+
+--source include/start_slave.inc
+
+--echo [on master]
+--connection master
+INSERT INTO t1 VALUES ('stop slave and start slave: DML', 7);
+
+--echo [on slave]
+--connection slave
+--echo # sleep 1*T
+--sleep $time1
+--let $timestamp_before_stop= `SELECT UNIX_TIMESTAMP()`
+--let $relay_log_pos_before_stop= query_get_value(SHOW SLAVE STATUS, Relay_Log_Pos, 1)
+--source include/stop_slave.inc
+
+--let $assert_text= STOP SLAVE should finish quickly, not wait for the ongoing sleep to finish
+--let $assert_cond= UNIX_TIMESTAMP() - $timestamp_before_stop < $time1
+--source include/rpl_assert.inc
+
+--let $assert_text= SQL thread position should not increase after STOP SLAVE
+--let $assert_cond= [SHOW SLAVE STATUS, Relay_Log_Pos, 1] = $relay_log_pos_before_stop
+--source include/rpl_assert.inc
+
+--let $assert_text= Query should not be executed after STOP SLAVE
+--let $assert_cond= MAX(b) = 6 FROM t1
+--source include/rpl_assert.inc
+
+--let $assert_text= Status should be '' after STOP SLAVE
+--let $assert_cond= "[SHOW SLAVE STATUS, Slave_SQL_Running_State, 1]" = ""
+--source include/rpl_assert.inc
+
+--source include/start_slave.inc
+
+--let $assert_text= START SLAVE should finish quickly
+--let $assert_cond= UNIX_TIMESTAMP() - $timestamp_before_stop < $time1
+--source include/rpl_assert.inc
+
+--let $query_number= 7
+--source include/delayed_slave_wait_on_query.inc
+
+
+--echo ==== STOP SLAVE / START SLAVE + DDL ====
+
+--echo This verifies BUG#56442
+
+--echo [on master]
+--connection master
+CREATE TABLE t_check_dml_not_executed_prematurely (a INT);
+--source include/save_master_pos.inc
+
+--echo [on slave]
+--connection slave
+--echo # sleep 1*T
+--sleep $time1
+
+--let $timestamp_before_stop= `SELECT UNIX_TIMESTAMP()`
+--let $relay_log_pos_before_stop= query_get_value(SHOW SLAVE STATUS, Relay_Log_Pos, 1)
+--source include/stop_slave.inc
+
+--let $assert_text= STOP SLAVE should finish quickly, not wait for the ongoing sleep to finish
+--let $assert_cond= UNIX_TIMESTAMP() - $timestamp_before_stop < $time1
+--source include/rpl_assert.inc
+
+--let $assert_text= SQL thread position should not increase after STOP SLAVE
+--let $assert_cond= [SHOW SLAVE STATUS, Relay_Log_Pos, 1] = $relay_log_pos_before_stop
+--source include/rpl_assert.inc
+
+--let $assert_text= Query should not be executed after STOP SLAVE
+--let $assert_cond= COUNT(*) = 0 FROM INFORMATION_SCHEMA.TABLES WHERE TABLE_NAME = "t_check_dml_not_executed_prematurely"
+--source include/rpl_assert.inc
+
+--let $assert_text= Status should be '' after STOP SLAVE
+--let $assert_cond= "[SHOW SLAVE STATUS, Slave_SQL_Running_State, 1]" = ""
+--source include/rpl_assert.inc
+
+--source include/start_slave.inc
+
+--let $assert_text= START SLAVE should finish quickly
+--let $assert_cond= UNIX_TIMESTAMP() - $timestamp_before_stop < $time1
+--source include/rpl_assert.inc
+
+--echo # sleep 1*T
+--sleep $time1
+
+--let $assert_text= DDL Query should not be executed after START SLAVE
+--let $assert_cond= COUNT(*) = 0 FROM INFORMATION_SCHEMA.TABLES WHERE TABLE_NAME = "t_check_dml_not_executed_prematurely"
+--source include/rpl_assert.inc
+
+--let $assert_text= Status should be 'Waiting until MASTER_DELAY...'
+--let $assert_cond= "[SHOW SLAVE STATUS, Slave_SQL_Running_State, 1]" LIKE "Waiting until MASTER_DELAY%"
+--source include/rpl_assert.inc
+
+--echo # sleep 1*T
+--sleep $time1
+
+--echo # sync with master (with timeout 1*T)
+--source include/sync_with_master.inc
+
+--let $assert_text= DDL Query should be executed
+--let $assert_cond= COUNT(*) = 1 FROM INFORMATION_SCHEMA.TABLES WHERE TABLE_NAME = "t_check_dml_not_executed_prematurely"
+--source include/rpl_assert.inc
+
+--let $assert_text= Status should be 'Has read all relay log...'
+--let $assert_cond= "[SHOW SLAVE STATUS, Slave_SQL_Running_State, 1]" LIKE "Slave has read all relay log%"
+--source include/rpl_assert.inc
+
+--source include/check_slave_is_running.inc
+
+
+--echo ==== Change back to no delay ====
+
+--echo [on slave]
+--connection slave
+--source include/stop_slave.inc
+CHANGE MASTER TO MASTER_DELAY = 0;
+
+--let $assert_text= Delay should be 0 when we set it to 0
+--let $assert_cond= [SHOW SLAVE STATUS, SQL_Delay, 1] = 0
+--source include/rpl_assert.inc
+
+--source include/start_slave.inc
+
+--echo [on master]
+--connection master
+INSERT INTO t1 VALUES ('change back to no delay', 8);
+
+--echo [on slave]
+--source include/sync_slave_io_with_master.inc
+--echo # sleep 1*T
+--sleep $time1
+
+--let $assert_text= Query should be executed
+--let $assert_cond= MAX(b) = 8 FROM t1
+--source include/rpl_assert.inc
+
+--let $assert_text= Status should be 'Slave has read all relay log...'
+--let $assert_cond= "[SHOW SLAVE STATUS, Slave_SQL_Running_State, 1]" Like "Slave has read all relay log%"
+--source include/rpl_assert.inc
+
+
+--echo ==== Reset delay with RESET SLAVE ====
+
+--source include/stop_slave.inc
+CHANGE MASTER TO MASTER_DELAY = 71;
+--source include/start_slave.inc
+
+--let $assert_text= Delay should be 71 when we set it to 71
+--let $assert_cond= [SHOW SLAVE STATUS, SQL_Delay, 1] = 71
+--source include/rpl_assert.inc
+
+--source include/stop_slave.inc
+--let $master_use_gtid_option= No
+--source include/reset_slave.inc
+--echo [on master]
+--connection master
+RESET MASTER;
+--echo [on slave]
+--connection slave
+--source include/start_slave.inc
+
+--let $assert_text= Delay should be 0 after RESET SLAVE
+--let $assert_cond= [SHOW SLAVE STATUS, SQL_Delay, 1] = 0
+--source include/rpl_assert.inc
+
+
+--echo ==== Set an invalid value for the delay ====
+
+--source include/stop_slave.inc
+
+--echo # Expect error for setting negative delay
+--error ER_PARSE_ERROR
+CHANGE MASTER TO MASTER_DELAY = -1;
+
+--echo # Expect that it's ok to set delay of 2^31-1
+CHANGE MASTER TO MASTER_DELAY = 2147483647;
+--echo # Expect error for setting delay between 2^31 and 2^32-1
+--error ER_MASTER_DELAY_VALUE_OUT_OF_RANGE
+CHANGE MASTER TO MASTER_DELAY = 2147483648;
+
+--echo # Expect error for setting delay to nonsense
+--error ER_PARSE_ERROR
+CHANGE MASTER TO MASTER_DELAY = blah;
+
+# todo: CHANGE MASTER TO MASTER_DELAY = 999999999999999999999999999
+# should give error
+
+CHANGE MASTER TO MASTER_DELAY = 0;
+--source include/start_slave.inc
+
+
+--echo ==== Clean up ====
+
+--echo [on master]
+--connection master
+DROP TABLE t1, t_check_dml_not_executed_prematurely;
+DROP FUNCTION delay_on_slave;
+
+--echo [on slave]
+--sync_slave_with_master
+SELECT @@GLOBAL.slave_parallel_mode;
+SELECT @@GLOBAL.slave_parallel_threads;
+
+--source include/rpl_end.inc