BUG#37718: rpl.rpl_stm_mystery22 fails sporadically on pushbuild

Problem 1: The test waits for an error in the slave sql thread,
then resolves the error and issues 'start slave'. However, there
is a gap between when the error is reported and the slave sql
thread stops. If this gap was long, the slave would still be
running when 'start slave' happened, so 'start slave' would fail
and cause a test failure.
Fix 1: Made wait_for_slave_sql_error wait for the slave to stop
instead of wait for error in the IO thread. After stopping, the
error code is verified. If the error code is wrong, debug info
is printed. To print debug info, the debug printing code in
wait_for_slave_param.inc was moved out to a new file,
show_rpl_debug_info.inc.
Problem 2: rpl_stm_mystery22 is a horrible name, the comments in
the file didn't explain anything useful, the test was generally
hard to follow, and the test was essentially duplicated between
rpl_stm_mystery22 and rpl_row_mystery22.
Fix 2: The test is about conflicts in the slave SQL thread,
hence I renamed the tests to rpl_{stm,row}_conflicts. Refactored
the test so that the work is done in
extra/rpl_tests/rpl_conflicts.inc, and
rpl.rpl_{row,stm}_conflicts merely sets some variables and then
sourced extra/rpl_tests/rpl_conflicts.inc.
The tests have been rewritten and comments added.
Problem 3: When calling wait_for_slave_sql_error.inc, you always
want to verify that the sql thread stops because of the expected
error and not because of some other error. Currently,
wait_for_slave_sql_error.inc allows the caller to omit the error
code, in which case all error codes are accepted.
Fix 3: Made wait_for_slave_sql_error.inc fail if no error code
is given. Updated rpl_filter_tables_not_exist accordingly.
Problem 4: rpl_filter_tables_not_exist had a typo, the dollar
sign was missing in a 'let' statement.
Fix 4: Added dollar sign.
Problem 5: When replicating from other servers than the one named
'master', the wait_for_slave_* macros were unable to print debug
info on the master.
Fix 5: Replace parameter $slave_keep_connection by
$master_connection.


mysql-test/extra/rpl_tests/rpl_conflicts.test:
  rpl_stm_mystery22 and rpl_row_mystery22 have now been refactored and renamed:
  The two test cases rpl.rpl_stm_conflicts.test and rpl.rpl_row_conflicts.test
  just set some parameters, and then source include/rpl_tests/rpl_conflicts.test.
  Also, cleaned up the test case a bit, and fixed BUG#37718.
mysql-test/include/show_rpl_debug_info.inc:
  Factored out the debug printing code from wait_for_slave_param.inc to
  a new file, show_rpl_debug_info.inc.
  Also removed the $slave_keep_connection parameter, and replaced it by
  $master_connection. This allows printing debug info on the master, no
  matter what the name of the master connection is.
mysql-test/include/start_slave.inc:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/include/stop_slave.inc:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/include/sync_slave_io_with_master.inc:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/include/wait_for_slave_io_to_start.inc:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/include/wait_for_slave_io_to_stop.inc:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/include/wait_for_slave_param.inc:
  Factored out the debug printing code from wait_for_slave_param.inc to
  a new file, show_rpl_debug_info.inc.
  Also removed the $slave_keep_connection parameter, and replaced it by
  $master_connection. This allows printing debug info on the master, no
  matter what the name of the master connection is.
  Had to move the printing of debug info out of the while loop because
  of BUG number 41913.
mysql-test/include/wait_for_slave_sql_error.inc:
  Made it wait until the slave sql thread has stopped. This
  takes very short time and avoids race condition bugs in
  test cases (e.g., fixes BUG#37718).
  Replaced $slave_keep_connection by $master_connection.
mysql-test/include/wait_for_slave_sql_error_and_skip.inc:
  Since wait_for_slave_sql_error now waits for the slave sql
  thread to stop too, wait_for_slave_sql_error_and_skip does not
  have to wait for the slave sql thread to stop.
  Also, since wait_for_slave_sql_error now requires the parameter
  $slave_sql_errno to be set, wait_for_slave_sql_error_and_skip
  requires that as well: updated the usage instructions.
mysql-test/include/wait_for_slave_sql_to_start.inc:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/include/wait_for_slave_sql_to_stop.inc:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/include/wait_for_slave_to_start.inc:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/include/wait_for_slave_to_stop.inc:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/suite/rpl/r/rpl_row_conflicts.result:
  update result file
mysql-test/suite/rpl/r/rpl_stm_conflicts.result:
  update result file
mysql-test/suite/rpl/t/rpl_dual_pos_advance.test:
  Replaced $slave_keep_connection by $master_connection.
mysql-test/suite/rpl/t/rpl_filter_tables_not_exist.test:
  Set $slave_sql_errno, since it is now required.
  Add dollar sign to $show_sql_error (without dollar sign,
  mtr makes it an environment variable).
mysql-test/suite/rpl/t/rpl_row_conflicts.test:
  rpl_stm_mystery22 and rpl_row_mystery22 have now been refactored and renamed:
  The two test cases rpl.rpl_stm_conflicts.test and rpl.rpl_row_conflicts.test
  just set some parameters, and then source include/rpl_tests/rpl_conflicts.test.
  Also, cleaned up the test case a bit, and fixed BUG#37718.
mysql-test/suite/rpl/t/rpl_row_mystery22.test:
  rpl_stm_mystery22 and rpl_row_mystery22 have now been refactored and renamed:
  The two test cases rpl.rpl_stm_conflicts.test and rpl.rpl_row_conflicts.test
  just set some parameters, and then source include/rpl_tests/rpl_conflicts.test.
  Also, cleaned up the test case a bit, and fixed BUG#37718.
mysql-test/suite/rpl/t/rpl_stm_conflicts.test:
  rpl_stm_mystery22 and rpl_row_mystery22 have now been refactored and renamed:
  The two test cases rpl.rpl_stm_conflicts.test and rpl.rpl_row_conflicts.test
  just set some parameters, and then source include/rpl_tests/rpl_conflicts.test.
  Also, cleaned up the test case a bit, and fixed BUG#37718.

10 files changed, 212 insertions, 186 deletions

diff --git a/mysql-test/suite/rpl/r/rpl_row_conflicts.result b/mysql-test/suite/rpl/r/rpl_row_conflicts.result
new file mode 100644
index 00000000000..0f15bfc7156
--- /dev/null
+++ b/mysql-test/suite/rpl/r/rpl_row_conflicts.result
@@ -0,0 +1,109 @@
+stop slave;
+drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
+reset master;
+reset slave;
+drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
+start slave;
+call mtr.add_suppression("Slave: Can\'t find record in \'t1\' Error_code: .*");
+[on slave]
+SET @old_slave_exec_mode= @@global.slave_exec_mode;
+######## Run with slave_exec_mode=STRICT ########
+SET @@global.slave_exec_mode = 'STRICT';
+==== Initialize ====
+[on master]
+CREATE TABLE t1(a INT PRIMARY KEY);
+[on slave]
+==== Test: SQL thread sees 'INSERT' of existing key ====
+---- Prepare slave so that it will get duplicate key error ----
+INSERT INTO t1 VALUES (1);
+---- Insert rows on master ----
+[on master]
+INSERT INTO t1 VALUES (1);
+SELECT * FROM t1;
+a
+1
+[on slave]
+---- Wait until slave stops with an error ----
+Last_SQL_Error = Could not execute Write_rows event on table test.t1; Duplicate entry '1' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log master-bin.000001, end_log_pos 346 (expected "duplicate key" error)
+SELECT * FROM t1;
+a
+1
+---- Resolve the conflict on the slave and restart SQL thread ----
+DELETE FROM t1 WHERE a = 1;
+START SLAVE SQL_THREAD;
+---- Sync slave and verify that there is no error ----
+Last_SQL_Error = '' (expected no error)
+SELECT * FROM t1;
+a
+1
+==== Test: SQL thread sees 'DELETE' of non-existing row ====
+---- On master, insert two rows, the second with binlogging off ----
+[on master]
+DELETE FROM t1;
+INSERT INTO t1 VALUES (1);
+[on slave]
+DELETE FROM t1 WHERE a = 1;
+---- On master, remove the row that does not exist on slave ----
+[on master]
+DELETE FROM t1 WHERE a = 1;
+SELECT * FROM t1;
+a
+[on slave]
+---- Wait until slave stops with an error ----
+Last_SQL_Error = Could not execute Delete_rows event on table test.t1; Can't find record in 't1', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 982 (expected "can't find record" error)
+SELECT * FROM t1;
+a
+---- Resolve the conflict on the slave and restart SQL thread ----
+INSERT INTO t1 VALUES (1);
+START SLAVE SQL_THREAD;
+---- Sync slave and verify that there is no error ----
+Last_SQL_Error =  (expected no error)
+SELECT * FROM t1;
+a
+==== Clean up ====
+[on master]
+DROP TABLE t1;
+[on slave]
+######## Run with slave_exec_mode=IDEMPOTENT ########
+set @@global.slave_exec_mode= 'IDEMPOTENT';
+==== Initialize ====
+[on master]
+CREATE TABLE t1(a INT PRIMARY KEY);
+[on slave]
+==== Test: SQL thread sees 'INSERT' of existing key ====
+---- Prepare slave so that it will get duplicate key error ----
+INSERT INTO t1 VALUES (1);
+---- Insert rows on master ----
+[on master]
+INSERT INTO t1 VALUES (1);
+SELECT * FROM t1;
+a
+1
+[on slave]
+---- Sync slave and verify that there is no error ----
+Last_SQL_Error = '' (expected no error)
+SELECT * FROM t1;
+a
+1
+==== Test: SQL thread sees 'DELETE' of non-existing row ====
+---- On master, insert two rows, the second with binlogging off ----
+[on master]
+DELETE FROM t1;
+INSERT INTO t1 VALUES (1);
+[on slave]
+DELETE FROM t1 WHERE a = 1;
+---- On master, remove the row that does not exist on slave ----
+[on master]
+DELETE FROM t1 WHERE a = 1;
+SELECT * FROM t1;
+a
+[on slave]
+---- Sync slave and verify that there is no error ----
+Last_SQL_Error =  (expected no error)
+SELECT * FROM t1;
+a
+==== Clean up ====
+[on master]
+DROP TABLE t1;
+[on slave]
+SET @@global.slave_exec_mode= @old_slave_exec_mode;
diff --git a/mysql-test/suite/rpl/r/rpl_row_mystery22.result b/mysql-test/suite/rpl/r/rpl_row_mystery22.result
deleted file mode 100644
index 5e42a89d741..00000000000
--- a/mysql-test/suite/rpl/r/rpl_row_mystery22.result
+++ /dev/null
@@ -1,32 +0,0 @@
-stop slave;
-drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
-reset master;
-reset slave;
-drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
-start slave;
-create table t1(n int auto_increment primary key, s char(10));
-set @@global.slave_exec_mode= 'IDEMPOTENT';
-insert into t1 values (2,'old');
-insert into t1 values(NULL,'new');
-insert into t1 values(NULL,'new');
-select * from t1 order by n;
-n	s
-1	new
-2	new
-delete from t1 where n = 2;
-start slave;
-stop slave;
-create table t2(n int);
-drop table t2;
-insert into t1 values(NULL,'new');
-set sql_log_bin=0;
-insert into t1 values(NULL,'new');
-set sql_log_bin=1;
-delete from t1 where n=4;
-start slave;
-select * from t1 order by n;
-n	s
-1	new
-3	new
-drop table t1;
-set @@global.slave_exec_mode= default;
diff --git a/mysql-test/suite/rpl/r/rpl_stm_conflicts.result b/mysql-test/suite/rpl/r/rpl_stm_conflicts.result
new file mode 100644
index 00000000000..b0df9516b7c
--- /dev/null
+++ b/mysql-test/suite/rpl/r/rpl_stm_conflicts.result
@@ -0,0 +1,54 @@
+stop slave;
+drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
+reset master;
+reset slave;
+drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
+start slave;
+==== Initialize ====
+[on master]
+CREATE TABLE t1(a INT PRIMARY KEY);
+[on slave]
+==== Test: SQL thread sees 'INSERT' of existing key ====
+---- Prepare slave so that it will get duplicate key error ----
+INSERT INTO t1 VALUES (1);
+---- Insert rows on master ----
+[on master]
+INSERT INTO t1 VALUES (1);
+SELECT * FROM t1;
+a
+1
+[on slave]
+---- Wait until slave stops with an error ----
+Last_SQL_Error = Error 'Duplicate entry '1' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t1 VALUES (1)' (expected "duplicate key" error)
+SELECT * FROM t1;
+a
+1
+---- Resolve the conflict on the slave and restart SQL thread ----
+DELETE FROM t1 WHERE a = 1;
+START SLAVE SQL_THREAD;
+---- Sync slave and verify that there is no error ----
+Last_SQL_Error = '' (expected no error)
+SELECT * FROM t1;
+a
+1
+==== Test: SQL thread sees 'DELETE' of non-existing row ====
+---- On master, insert two rows, the second with binlogging off ----
+[on master]
+DELETE FROM t1;
+INSERT INTO t1 VALUES (1);
+[on slave]
+DELETE FROM t1 WHERE a = 1;
+---- On master, remove the row that does not exist on slave ----
+[on master]
+DELETE FROM t1 WHERE a = 1;
+SELECT * FROM t1;
+a
+[on slave]
+---- Sync slave and verify that there is no error ----
+Last_SQL_Error =  (expected no error)
+SELECT * FROM t1;
+a
+==== Clean up ====
+[on master]
+DROP TABLE t1;
+[on slave]
diff --git a/mysql-test/suite/rpl/r/rpl_stm_mystery22.result b/mysql-test/suite/rpl/r/rpl_stm_mystery22.result
deleted file mode 100644
index ea34b308ec2..00000000000
--- a/mysql-test/suite/rpl/r/rpl_stm_mystery22.result
+++ /dev/null
@@ -1,31 +0,0 @@
-stop slave;
-drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
-reset master;
-reset slave;
-drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
-start slave;
-create table t1(n int auto_increment primary key, s char(10));
-insert into t1 values (2,'old');
-insert into t1 values(NULL,'new');
-insert into t1 values(NULL,'new');
-select * from t1 order by n;
-n	s
-1	new
-2	old
-delete from t1 where n = 2;
-start slave;
-stop slave;
-create table t2(n int);
-drop table t2;
-insert into t1 values(NULL,'new');
-set sql_log_bin=0;
-insert into t1 values(NULL,'new');
-set sql_log_bin=1;
-delete from t1 where n=4;
-start slave;
-select * from t1 order by n;
-n	s
-1	new
-2	new
-3	new
-drop table t1;
diff --git a/mysql-test/suite/rpl/t/rpl_dual_pos_advance.test b/mysql-test/suite/rpl/t/rpl_dual_pos_advance.test
index 11dd46727dc..9efb3d16d2b 100644
--- a/mysql-test/suite/rpl/t/rpl_dual_pos_advance.test
+++ b/mysql-test/suite/rpl/t/rpl_dual_pos_advance.test
@@ -12,7 +12,8 @@ source include/have_innodb.inc;
 
 # set up "dual head"
 
-let $slave_keep_connection= 1;
+# Needed for debug info in wait_for_slave_sql_to_stop.
+let $master_connection= slave;
 connection slave;
 reset master;
 
diff --git a/mysql-test/suite/rpl/t/rpl_filter_tables_not_exist.test b/mysql-test/suite/rpl/t/rpl_filter_tables_not_exist.test
index 274599857be..bf71ffbfd1e 100644
--- a/mysql-test/suite/rpl/t/rpl_filter_tables_not_exist.test
+++ b/mysql-test/suite/rpl/t/rpl_filter_tables_not_exist.test
@@ -124,9 +124,11 @@ UPDATE t7 LEFT JOIN (t8, t4, t1) ON (t7.id=t8.id and t7.id=t4.id and t7.id=t1.id
 sync_slave_with_master;
 connection master;
 
-# Parameter for include/wait_for_slave_sql_error_and_skip.inc, ask it
-# to show SQL error message
-let show_sql_error=1;
+# Parameters for include/wait_for_slave_sql_error_and_skip.inc:
+# Ask it to show SQL error message.
+let $show_sql_error= 1;
+# The expected error will always be 1146 (ER_NO_SUCH_TABLE).
+let $slave_sql_errno= 1146;
 
 #
 # Only do tables are referenced for update, these statements should
diff --git a/mysql-test/suite/rpl/t/rpl_row_conflicts.test b/mysql-test/suite/rpl/t/rpl_row_conflicts.test
new file mode 100644
index 00000000000..59757e2e802
--- /dev/null
+++ b/mysql-test/suite/rpl/t/rpl_row_conflicts.test
@@ -0,0 +1,31 @@
+# See the top of mysql-test/extra/rpl_tests/rpl_conflicts.test for
+# explanation of what this test does.
+#
+# This test file is for row-logging mode. It runs the test twice, with
+# slave_exec_mode=STRICT and slave_exec_mode=IDEMPOTENT, respectively.
+
+source include/have_binlog_format_row.inc;
+source include/master-slave.inc;
+
+connection slave;
+call mtr.add_suppression("Slave: Can\'t find record in \'t1\' Error_code: .*");
+
+--echo [on slave]
+connection slave;
+SET @old_slave_exec_mode= @@global.slave_exec_mode;
+
+
+--echo ######## Run with slave_exec_mode=STRICT ########
+
+SET @@global.slave_exec_mode = 'STRICT';
+source extra/rpl_tests/rpl_conflicts.test;
+
+
+--echo ######## Run with slave_exec_mode=IDEMPOTENT ########
+
+set @@global.slave_exec_mode= 'IDEMPOTENT';
+source extra/rpl_tests/rpl_conflicts.test;
+
+
+SET @@global.slave_exec_mode= @old_slave_exec_mode;
+source include/master-slave-end.inc;
diff --git a/mysql-test/suite/rpl/t/rpl_row_mystery22.test b/mysql-test/suite/rpl/t/rpl_row_mystery22.test
deleted file mode 100644
index a3ba8648b22..00000000000
--- a/mysql-test/suite/rpl/t/rpl_row_mystery22.test
+++ /dev/null
@@ -1,52 +0,0 @@
-# Originally taken from rpl_mystery22.test,
-# but this row-based-replication test has a totally different spirit:
-# slave will not stop because of dup key,
-# instead we test if it does overwrite the dup key
-# as expected.
--- source include/have_binlog_format_row.inc
--- source include/master-slave.inc
-
-# first, cause a duplicate key problem on the slave
-create table t1(n int auto_increment primary key, s char(10));
-sync_slave_with_master;
-
-# bug#31552/31609 idempotency is not default any longer
-# so that the declared in heading comments aim of the test
-# should be backed up with explicit setting of the slave mode
-set @@global.slave_exec_mode= 'IDEMPOTENT';
-
-insert into t1 values (2,'old');
-connection master;
-insert into t1 values(NULL,'new');
-insert into t1 values(NULL,'new');
-save_master_pos;
-connection slave;
-sync_with_master;
-select * from t1 order by n;
-delete from t1 where n = 2;
---disable_warnings
-start slave;
---enable_warnings
-sync_with_master;
-stop slave;
-connection master;
-create table t2(n int);
-drop table t2;
-insert into t1 values(NULL,'new');
-# what happens when we delete a row which does not exist on slave?
-set sql_log_bin=0;
-insert into t1 values(NULL,'new');
-set sql_log_bin=1;
-delete from t1 where n=4;
-save_master_pos;
-connection slave;
---disable_warnings
-start slave;
---enable_warnings
-sync_with_master;
-select * from t1 order by n;
-#clean up
-connection master;
-drop table t1;
-sync_slave_with_master;
-set @@global.slave_exec_mode= default;
diff --git a/mysql-test/suite/rpl/t/rpl_stm_conflicts.test b/mysql-test/suite/rpl/t/rpl_stm_conflicts.test
new file mode 100644
index 00000000000..07b7a0bf8f7
--- /dev/null
+++ b/mysql-test/suite/rpl/t/rpl_stm_conflicts.test
@@ -0,0 +1,11 @@
+# See the top of mysql-test/extra/rpl_tests/rpl_conflicts.test for an
+# explanation of what this test does.
+#
+# This test file is for statement-logging mode.
+
+source include/have_binlog_format_mixed_or_statement.inc;
+source include/master-slave.inc;
+
+source extra/rpl_tests/rpl_conflicts.test;
+
+source include/master-slave-end.inc;
diff --git a/mysql-test/suite/rpl/t/rpl_stm_mystery22.test b/mysql-test/suite/rpl/t/rpl_stm_mystery22.test
deleted file mode 100644
index 171bd9d5531..00000000000
--- a/mysql-test/suite/rpl/t/rpl_stm_mystery22.test
+++ /dev/null
@@ -1,67 +0,0 @@
-################################
-# Change Author: JBM
-# Change Date: 2006-01-12
-# Change: Added back have stm binlog
-# and added requirments comments
-################################
-# test case to make slave thread get ahead by 22 bytes
-################################
-#REQUIREMENT: If there is a faked slave duplicate key insert 
-#error and the slave is restarted, the replication should 
-#proceed in a correct way.
-################################
-#REQUIREMENT: If there is a faked slave non-existing record 
-#delete error and the slave is restarted, then the replication 
-#should proceed in a correct way.
-#################################
-
--- source include/have_binlog_format_mixed_or_statement.inc
--- source include/master-slave.inc
-
-# first, cause a duplicate key problem on the slave
-create table t1(n int auto_increment primary key, s char(10));
-sync_slave_with_master;
-insert into t1 values (2,'old');
-connection master;
-insert into t1 values(NULL,'new');
-insert into t1 values(NULL,'new');
-save_master_pos;
-connection slave;
-# wait until the slave tries to run the query, fails and aborts slave thread
-let $slave_sql_errno= 1062;
-source include/wait_for_slave_sql_error.inc;
-select * from t1 order by n;
-delete from t1 where n = 2;
---disable_warnings
-start slave;
---enable_warnings
-sync_with_master;
-#now the buggy slave would be confused on the offset but it can replicate
-#in order to make it break, we need to stop/start the slave one more time
-stop slave;
-connection master;
-# to be able to really confuse the slave, we need some non-auto-increment
-# events in the log
-create table t2(n int);
-drop table t2;
-insert into t1 values(NULL,'new');
-# what happens when we delete a row which does not exist on slave?
-set sql_log_bin=0;
-insert into t1 values(NULL,'new');
-set sql_log_bin=1;
-delete from t1 where n=4;
-save_master_pos;
-connection slave;
---disable_warnings
-start slave;
---enable_warnings
-#now the truth comes out - if the slave is buggy, it will never sync because
-#the slave thread is not able to read events
-sync_with_master;
-select * from t1 order by n;
-#clean up
-connection master;
-drop table t1;
-sync_slave_with_master;
-
-# End of 4.1 tests