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.

13 files changed, 160 insertions, 71 deletions

diff --git a/mysql-test/include/show_rpl_debug_info.inc b/mysql-test/include/show_rpl_debug_info.inc
new file mode 100644
index 00000000000..252d63f1bf4
--- /dev/null
+++ b/mysql-test/include/show_rpl_debug_info.inc
@@ -0,0 +1,87 @@
+# ==== Purpose ====
+#
+# Print status information for replication, typically used to debug
+# test failures.
+#
+# First, the following is printed on slave:
+#
+#   SHOW SLAVE STATUS
+#   SHOW PROCESSLIST
+#   SHOW BINLOG EVENTS IN <binlog_name>
+#
+# Where <binlog_name> is the currently active binlog.
+#
+# Then, the following is printed on master:
+#
+#   SHOW MASTER STATUS
+#   SHOW PROCESSLIST
+#   SHOW BINLOG EVENTS IN <sql_binlog_name>
+#   SHOW BINLOG EVENTS IN <io_binlog_name>
+#
+# Where <sql_binlog_name> is the binlog name that the slave sql thread
+# is currently reading from and <io_binlog_name> is the binlog that
+# the slave IO thread is currently reading from.
+#
+# ==== Usage ====
+#
+# [let $master_connection= <connection>;]
+# source include/show_rpl_debug_info.inc;
+#
+# If $master_connection is set, debug info will be retrieved from the
+# connection named $master_connection.  Otherwise, it will be
+# retrieved from the 'master' connection if the current connection is
+# 'slave'.
+
+let $_con= $CURRENT_CONNECTION;
+--echo
+--echo [on $_con]
+--echo
+--echo **** SHOW SLAVE STATUS on $_con ****
+query_vertical SHOW SLAVE STATUS;
+--echo
+--echo **** SHOW PROCESSLIST on $_con ****
+SHOW PROCESSLIST;
+--echo
+--echo **** SHOW BINLOG EVENTS on $_con ****
+let $binlog_name= query_get_value("SHOW MASTER STATUS", File, 1);
+eval SHOW BINLOG EVENTS IN '$binlog_name';
+
+let $_master_con= $master_connection;
+if (`SELECT '$_master_con' = ''`)
+{
+  if (`SELECT '$_con' = 'slave'`)
+  {
+    let $_master_con= master;
+  }
+  if (`SELECT '$_master_con' = ''`)
+  {
+    --echo Unable to determine master connection. No debug info printed for master.
+    --echo Please fix the test case by setting $master_connection before sourcing
+    --echo show_rpl_debug_info.inc.
+  }
+}
+
+if (`SELECT '$_master_con' != ''`)
+{
+
+  let $master_binlog_name_io= query_get_value("SHOW SLAVE STATUS", Master_Log_File, 1);
+  let $master_binlog_name_sql= query_get_value("SHOW SLAVE STATUS", Relay_Master_Log_File, 1);
+  --echo
+  --echo [on $_master_con]
+  connection $_master_con;
+  --echo
+  --echo **** SHOW MASTER STATUS on $_master_con ****
+  query_vertical SHOW MASTER STATUS;
+  --echo
+  --echo **** SHOW PROCESSLIST on $_master_con ****
+  SHOW PROCESSLIST;
+  --echo
+  --echo **** SHOW BINLOG EVENTS on $_master_con ****
+  eval SHOW BINLOG EVENTS IN '$master_binlog_name_sql';
+  if (`SELECT '$master_binlog_name_io' != '$master_binlog_name_sql'`)
+  {
+    eval SHOW BINLOG EVENTS IN '$master_binlog_name_io';
+  }
+
+  connection $_con;
+}
diff --git a/mysql-test/include/start_slave.inc b/mysql-test/include/start_slave.inc
index 0a78c5d8026..78a02736de8 100644
--- a/mysql-test/include/start_slave.inc
+++ b/mysql-test/include/start_slave.inc
@@ -11,7 +11,7 @@
 # source include/wait_for_slave_to_start.inc;
 #
 # Parameters to this macro are $slave_timeout and
-# $slave_keep_connection. See wait_for_slave_param.inc for
+# $master_connection. See wait_for_slave_param.inc for
 # descriptions.
 
 --disable_query_log
diff --git a/mysql-test/include/stop_slave.inc b/mysql-test/include/stop_slave.inc
index e9c56034fb3..7161e6fe739 100644
--- a/mysql-test/include/stop_slave.inc
+++ b/mysql-test/include/stop_slave.inc
@@ -11,7 +11,7 @@
 # source include/wait_for_slave_to_start.inc;
 #
 # Parameters to this macro are $slave_timeout and
-# $slave_keep_connection. See wait_for_slave_param.inc for
+# $master_connection. See wait_for_slave_param.inc for
 # descriptions.
 
 --disable_query_log
diff --git a/mysql-test/include/sync_slave_io_with_master.inc b/mysql-test/include/sync_slave_io_with_master.inc
index 882724bc986..f7dd563039c 100644
--- a/mysql-test/include/sync_slave_io_with_master.inc
+++ b/mysql-test/include/sync_slave_io_with_master.inc
@@ -15,7 +15,7 @@
 # Must be called on the master. Will change connection to the slave.
 #
 # Parameters to this macro are $slave_timeout and
-# $slave_keep_connection. See wait_for_slave_param.inc for
+# $master_connection. See wait_for_slave_param.inc for
 # descriptions.
 
 let $_master_file= query_get_value("SHOW MASTER STATUS", File, 1);
diff --git a/mysql-test/include/wait_for_slave_io_to_start.inc b/mysql-test/include/wait_for_slave_io_to_start.inc
index 3ada2a0e927..abdc8339290 100644
--- a/mysql-test/include/wait_for_slave_io_to_start.inc
+++ b/mysql-test/include/wait_for_slave_io_to_start.inc
@@ -9,7 +9,7 @@
 # source include/wait_for_slave_io_to_start.inc;
 #
 # Parameters to this macro are $slave_timeout and
-# $slave_keep_connection. See wait_for_slave_param.inc for
+# $master_connection. See wait_for_slave_param.inc for
 # descriptions.
 
 let $slave_param= Slave_IO_Running;
diff --git a/mysql-test/include/wait_for_slave_io_to_stop.inc b/mysql-test/include/wait_for_slave_io_to_stop.inc
index 16a03d94511..f61b0db1ed7 100644
--- a/mysql-test/include/wait_for_slave_io_to_stop.inc
+++ b/mysql-test/include/wait_for_slave_io_to_stop.inc
@@ -8,7 +8,7 @@
 # source include/wait_for_slave_io_to_stop.inc;
 #
 # Parameters to this macro are $slave_timeout and
-# $slave_keep_connection. See wait_for_slave_param.inc for
+# $master_connection. See wait_for_slave_param.inc for
 # descriptions.
 
 # if server has not used CHANGE MASTER to initiate slave, SHOW SLAVE
diff --git a/mysql-test/include/wait_for_slave_param.inc b/mysql-test/include/wait_for_slave_param.inc
index 6d61f2f8caa..82e57922913 100644
--- a/mysql-test/include/wait_for_slave_param.inc
+++ b/mysql-test/include/wait_for_slave_param.inc
@@ -7,7 +7,7 @@
 #
 # let $slave_param= Slave_SQL_Running;
 # let $slave_param_value= No;
-# --source include/slave_wait_param.inc
+# source include/slave_wait_param.inc;
 #
 # Parameters:
 #
@@ -27,14 +27,14 @@
 #   The default timeout is 5 minutes. You can change the timeout by
 #   setting $slave_timeout. The unit is tenths of seconds.
 #
-# $slave_keep_connection
+# $master_connection
 #   If the timeout is reached, debug info is given by calling SHOW
-#   SLAVE STATUS, SHOW PROCESSLIST, and SHOW BINLOG EVENTS.  By
-#   default (assuming the current connection is slave), a 'connection
-#   master' is then issued, and the same information is printed again
-#   on the master host.  You can avoid switching to master (and thus
-#   suppress debug info on master too) by setting
-#   $slave_keep_connection to 1.
+#   SLAVE STATUS, SHOW PROCESSLIST, and SHOW BINLOG EVENTS.  Then, a
+#   'connection master' is then issued, and more debug info is given
+#   by calling SHOW MASTER STATUS, SHOW PROCESSLIST, and SHOW BINLOG
+#   EVENTS.  If $master_connection is set, the latter three commands
+#   will be issued on $master_connection instead of on the host named
+#   'master'.  See also show_rpl_debug_info.inc
 #
 # $slave_error_message
 #   If set, this is printed when a timeout occurs. This is primarily
@@ -57,38 +57,26 @@ if (`SELECT '$_slave_param_comparison' = ''`)
 }
 
 let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1);
-while (`SELECT NOT('$_show_slave_status_value' $_slave_param_comparison '$slave_param_value')`)
+while (`SELECT NOT('$_show_slave_status_value' $_slave_param_comparison '$slave_param_value') AND $_slave_timeout_counter > 0`)
 {
-  if (!$_slave_timeout_counter)
+  dec $_slave_timeout_counter;
+  if ($_slave_timeout_counter)
   {
-    --echo **** ERROR: failed while waiting for slave parameter $slave_param $_slave_param_comparison $slave_param_value ****
-    if (`SELECT '$slave_error_message' != ''`)
-    {
-      --echo Message: $slave_error_message
-    }
-    --echo Note: the following output may have changed since the failure was detected
-    --echo **** Showing SLAVE STATUS, PROCESSLIST, and BINLOG EVENTS on slave ****
-    query_vertical SHOW SLAVE STATUS;
-    SHOW PROCESSLIST;
-    let $binlog_name= query_get_value("SHOW MASTER STATUS", File, 1);
-    eval SHOW BINLOG EVENTS IN '$binlog_name';
-    if (!$slave_keep_connection) {
-      let $master_binlog_name_io= query_get_value("SHOW SLAVE STATUS", Master_Log_File, 1);
-      let $master_binlog_name_sql= query_get_value("SHOW SLAVE STATUS", Relay_Master_Log_File, 1);
-      --echo **** Showing MASTER STATUS, PROCESSLIST, and BINLOG EVENTS on master ****
-      --echo [on master]
-      connection master;
-      query_vertical SHOW MASTER STATUS;
-      SHOW PROCESSLIST;
-      eval SHOW BINLOG EVENTS IN '$master_binlog_name_sql';
-      if (`SELECT '$master_binlog_name_io' != '$master_binlog_name_sql'`)
-      {
-        eval SHOW BINLOG EVENTS IN '$master_binlog_name_io';
-      }
-    }
-    exit;
+    sleep 0.1;
+    let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1);
   }
-  dec $_slave_timeout_counter;
-  sleep 0.1;
-  let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1);
+}
+
+# This has to be outside the loop until BUG#41913 has been fixed
+if (!$_slave_timeout_counter)
+{
+  --echo **** ERROR: timeout after $slave_timeout seconds while waiting for slave parameter $slave_param $_slave_param_comparison $slave_param_value ****
+  if (`SELECT '$slave_error_message' != ''`)
+  {
+    --echo Message: $slave_error_message
+  }
+  --echo Current connection is '$CURRENT_CONNECTION'
+  echo Note: the following output may have changed since the failure was detected;
+  source include/show_rpl_debug_info.inc;
+  exit;
 }
diff --git a/mysql-test/include/wait_for_slave_sql_error.inc b/mysql-test/include/wait_for_slave_sql_error.inc
index 2d392f0e761..ad1d7a9e639 100644
--- a/mysql-test/include/wait_for_slave_sql_error.inc
+++ b/mysql-test/include/wait_for_slave_sql_error.inc
@@ -1,7 +1,8 @@
 # ==== Purpose ====
 #
 # Waits until the SQL thread of the current connection has got an
-# error, or until a timeout is reached.
+# error, or until a timeout is reached. Also waits until the SQL
+# thread has completely stopped.
 #
 # ==== Usage ====
 #
@@ -10,28 +11,29 @@
 # Parameters:
 #
 # $slave_sql_errno
-#   Number of expected SQL error. If it skipped then any error
-#   will pass.
+#   The expected SQL error number.  This is required.
+#   (After BUG#41956 has been fixed, this will be required to be a
+#   symbolic name instead of a number.)
 # 
-# $slave_timeout and
-#   See wait_for_slave_param.inc for descriptions.
+# $slave_timeout
+#   See wait_for_slave_param.inc for description.
 # 
-# $slave_keep_connection. 
-#   See wait_for_slave_param.inc for descriptions.
+# $master_connection
+#   See wait_for_slave_param.inc for description.
 
-let $old_slave_param_comparison= $slave_param_comparison;
-
-let $slave_param= Last_SQL_Errno;
-let $slave_param_comparison= !=;
-let $slave_param_value= 0;
-
-if ($slave_sql_errno) {
-  let $slave_param_comparison= =;
-  let $slave_param_value= $slave_sql_errno;
+if (`SELECT '$slave_sql_errno' = ''`) {
+  --echo !!!ERROR IN TEST: you must set \$slave_sql_errno before sourcing wait_fro_slave_sql_error.inc
+  exit;
 }
 
-let $slave_error_message= Failed while waiting for slave to produce an error in its sql thread;
+let $slave_param= Slave_SQL_Running;
+let $slave_param_value= No;
+let $slave_error_message= Failed while waiting for slave to stop the SQL thread (expecting error in the SQL thread);
 source include/wait_for_slave_param.inc;
-let $slave_error_message= ;
 
-let $slave_param_comparison= $old_slave_param_comparison;
+let $_error= query_get_value(SHOW SLAVE STATUS, Last_SQL_Errno, 1);
+if (`SELECT '$_error' != '$slave_sql_errno'`) {
+  --echo Slave stopped with wrong error code: $_error (expected $slave_sql_errno)
+  source include/show_rpl_debug_info.inc;
+  exit;
+}
diff --git a/mysql-test/include/wait_for_slave_sql_error_and_skip.inc b/mysql-test/include/wait_for_slave_sql_error_and_skip.inc
index 9b5641bfa34..247de3a41a1 100644
--- a/mysql-test/include/wait_for_slave_sql_error_and_skip.inc
+++ b/mysql-test/include/wait_for_slave_sql_error_and_skip.inc
@@ -5,8 +5,23 @@
 #
 # ==== Usage ====
 #
-# let show_sql_error=0|1;
+# let $slave_sql_error= <ERRNO>;
 # source include/wait_for_slave_sql_error_and_skip.inc;
+#
+# Parameters:
+#
+# $slave_sql_errno
+#   The error number to wait for. This is required. (See
+#   wait_for_slave_sql_error.inc)
+#
+# $show_sql_error
+#   If set, will print the error to the query log.
+#
+# $slave_timeout
+#   See wait_for_slave_param.inc for description.
+# 
+# $master_connection
+#   See wait_for_slave_param.inc for description.
 
 echo --source include/wait_for_slave_sql_error_and_skip.inc;
 connection slave;
@@ -17,9 +32,6 @@ if ($show_sql_error)
   echo Last_SQL_Error = $error;
 }
 
-# wait for SQL thread to stop after the error
-source include/wait_for_slave_sql_to_stop.inc;
-
 # skip the erroneous statement
 set global sql_slave_skip_counter=1;
 source include/start_slave.inc;
diff --git a/mysql-test/include/wait_for_slave_sql_to_start.inc b/mysql-test/include/wait_for_slave_sql_to_start.inc
index 45f32f97553..48744f5dd13 100644
--- a/mysql-test/include/wait_for_slave_sql_to_start.inc
+++ b/mysql-test/include/wait_for_slave_sql_to_start.inc
@@ -8,7 +8,7 @@
 # source include/wait_for_slave_sql_to_start.inc;
 #
 # Parameters to this macro are $slave_timeout and
-# $slave_keep_connection. See wait_for_slave_param.inc for
+# $master_connection. See wait_for_slave_param.inc for
 # descriptions.
 
 let $slave_param= Slave_SQL_Running;
diff --git a/mysql-test/include/wait_for_slave_sql_to_stop.inc b/mysql-test/include/wait_for_slave_sql_to_stop.inc
index 565203a9f59..6992613b646 100644
--- a/mysql-test/include/wait_for_slave_sql_to_stop.inc
+++ b/mysql-test/include/wait_for_slave_sql_to_stop.inc
@@ -8,7 +8,7 @@
 # source include/wait_for_slave_sql_to_stop.inc;
 #
 # Parameters to this macro are $slave_timeout and
-# $slave_keep_connection. See wait_for_slave_param.inc for
+# $master_connection. See wait_for_slave_param.inc for
 # descriptions.
 
 # if server has not used CHANGE MASTER to initiate slave, SHOW SLAVE
diff --git a/mysql-test/include/wait_for_slave_to_start.inc b/mysql-test/include/wait_for_slave_to_start.inc
index 3e23ceac4cc..567950cc6d7 100644
--- a/mysql-test/include/wait_for_slave_to_start.inc
+++ b/mysql-test/include/wait_for_slave_to_start.inc
@@ -8,7 +8,7 @@
 # source include/wait_for_slave_to_start.inc;
 #
 # Parameters to this macro are $slave_timeout and
-# $slave_keep_connection. See wait_for_slave_param.inc for
+# $master_connection. See wait_for_slave_param.inc for
 # descriptions.
 
 let $slave_error_message= Failed while waiting for slave to start;
diff --git a/mysql-test/include/wait_for_slave_to_stop.inc b/mysql-test/include/wait_for_slave_to_stop.inc
index 86604a15b95..56d0e7b0c91 100644
--- a/mysql-test/include/wait_for_slave_to_stop.inc
+++ b/mysql-test/include/wait_for_slave_to_stop.inc
@@ -8,7 +8,7 @@
 # source include/wait_for_slave_to_stop.inc;
 #
 # Parameters to this macro are $slave_timeout and
-# $slave_keep_connection. See wait_for_slave_param.inc for
+# $master_connection. See wait_for_slave_param.inc for
 # descriptions.
 
 # if server has not used CHANGE MASTER to initiate slave, SHOW SLAVE