maria-developers team mailing list archive

[sujatha <sujatha.sivakumar@xxxxxxxxxxx>]

revision-id: 27b046d2e95add5ba87e231279d2a7774db5b0c7 (mariadb-10.2.31-317-g27b046d2e95)
parent(s): a1e52e7f32cee7c204078db4c4beb88250d7e1f6
author: Sujatha
committer: Sujatha
timestamp: 2020-07-21 11:16:40 +0530
message:

MDEV-14203: rpl.rpl_extra_col_master_myisam, rpl.rpl_slave_load_tmpdir_not_exist failed in buildbot with a warning

Problem:
=======
rpl.rpl_slave_load_tmpdir_not_exist 'stmt' w3 [ fail ]  Found warnings/errors
in server log file!

Test ended at 2017-09-27 20:34:55
[Warning] Master is configured to log replication events with checksum, but
will not send such events to slaves that cannot process them
^ Found warnings in /mnt/buildbot/build/mariadb-10.2.10/mysql-test/var/3/log/mysqld.1.err
ok
Analysis:
========
When slave tries to connect to master 'get_master_version_and_clock' function
is invoked to perform elaborated slave-master handshake. During this process
slave server queries master server, to know if it is checksum aware and at the
same time master is notified about its CRC-awareness. The master's side
instant value of @@global.binlog_checksum is stored in the dump thread's
uservar area as well as cached locally to become known in consensus by master
and slave.

Post hand-shake slave requests master for binlog dump. It sends
'COM_BINLOG_DUMP'. This command is sent to master by 'cli_advanced_command'
call. If there is some temporary network failure during this request_dump
call, 'end_server' is invoked to close the current connection between master
and slave. Upon connection close the dump thread on the master gets terminated
and it clears the 'uservar' data it got through master-slave handshake.

The 'COM_BINLOG_DUMP' command is sent once again without master-slave
handshake. Since the checksum data is not available with new dump thread a
warning gets reported.

Fix:
===
Upon network write error donot attempt reconnect, proceed to master-slave
handshake. This ensures that master is aware of slave's capability to use
checksums.

---
 .../rpl/r/rpl_dump_request_retry_warning.result    | 22 ++++++++
 .../rpl/t/rpl_dump_request_retry_warning.test      | 60 ++++++++++++++++++++++
 sql-common/client.c                                |  2 +
 sql/net_serv.cc                                    | 13 +++++
 sql/slave.cc                                       |  3 +-
 5 files changed, 99 insertions(+), 1 deletion(-)

diff --git a/mysql-test/suite/rpl/r/rpl_dump_request_retry_warning.result b/mysql-test/suite/rpl/r/rpl_dump_request_retry_warning.result
new file mode 100644
index 00000000000..3a80d5b5f31
--- /dev/null
+++ b/mysql-test/suite/rpl/r/rpl_dump_request_retry_warning.result
@@ -0,0 +1,22 @@
+include/master-slave.inc
+[connection master]
+CREATE TABLE t1(a int);
+INSERT INTO t1 VALUES(1);
+connection slave;
+SET @saved_dbug = @@GLOBAL.debug_dbug;
+SET @@global.debug_dbug= 'd,simulate_error_on_packet_write';
+START SLAVE;
+SET DEBUG_SYNC= 'now WAIT_FOR parked';
+SET @@GLOBAL.debug_dbug = @saved_dbug;
+SET DEBUG_SYNC= 'now SIGNAL continue';
+SET DEBUG_SYNC= 'RESET';
+include/wait_for_slave_io_to_start.inc
+include/wait_for_slave_sql_to_start.inc
+connection master;
+include/sync_slave_sql_with_master.inc
+SELECT * FROM t1;
+a
+1
+connection master;
+DROP TABLE t1;
+include/rpl_end.inc
diff --git a/mysql-test/suite/rpl/t/rpl_dump_request_retry_warning.test b/mysql-test/suite/rpl/t/rpl_dump_request_retry_warning.test
new file mode 100644
index 00000000000..d9fb8258765
--- /dev/null
+++ b/mysql-test/suite/rpl/t/rpl_dump_request_retry_warning.test
@@ -0,0 +1,60 @@
+# ==== Purpose ====
+#
+# Test verifies that, due to a temporary network error, if request dump
+# command specific packet write operation fails then the write error gets
+# handled appropriately. Further retry will be initiated with appropriate
+# slave registration on master. This will ensure that master has all the
+# details of slave and no warnings are reported on the master side.
+#
+# ==== Implementation ====
+#
+# Steps:
+#    0 - Skip the slave start.
+#    1 - Enable debug simulation which will simulate packet write error during
+#        dump request command execution.
+#    2 - Start the slave. Observe that slave is able to reconnect post
+#        temporary network write error.
+#
+# ==== References ====
+#
+# MDEV-14203: rpl.rpl_extra_col_master_myisam,
+#             rpl.rpl_slave_load_tmpdir_not_exist failed in buildbot with a
+#             warning
+#
+# MDEV-13258: rpl.rpl_skip_replication, rpl.rpl_set_statement_default_master
+#             failed in buildbot
+# 
+
+--source include/have_debug.inc
+--source include/have_debug_sync.inc
+--let $rpl_skip_start_slave=1
+--source include/master-slave.inc
+
+# Do an insert on master
+CREATE TABLE t1(a int);
+INSERT INTO t1 VALUES(1);
+
+# Add a debug point and start the slave so that dump request fails.
+connection slave;
+SET @saved_dbug = @@GLOBAL.debug_dbug;
+SET @@global.debug_dbug= 'd,simulate_error_on_packet_write';
+
+START SLAVE;
+SET DEBUG_SYNC= 'now WAIT_FOR parked';
+SET @@GLOBAL.debug_dbug = @saved_dbug;
+SET DEBUG_SYNC= 'now SIGNAL continue';
+SET DEBUG_SYNC= 'RESET';
+
+--source include/wait_for_slave_io_to_start.inc
+--source include/wait_for_slave_sql_to_start.inc
+
+# Sync the slave and verify that slave has caught up with the master.
+connection master;
+--source include/sync_slave_sql_with_master.inc
+SELECT * FROM t1;
+
+# Cleanup
+connection master;
+DROP TABLE t1;
+
+--source include/rpl_end.inc
diff --git a/sql-common/client.c b/sql-common/client.c
index 227759f4163..b66eee2a508 100644
--- a/sql-common/client.c
+++ b/sql-common/client.c
@@ -721,6 +721,8 @@ cli_advanced_command(MYSQL *mysql, enum enum_server_command command,
       set_mysql_error(mysql, CR_NET_PACKET_TOO_LARGE, unknown_sqlstate);
       goto end;
     }
+    if (net->last_errno == ER_NET_ERROR_ON_WRITE && command == COM_BINLOG_DUMP)
+      goto end;
     end_server(mysql);
     if (mysql_reconnect(mysql) || stmt_skip)
       goto end;
diff --git a/sql/net_serv.cc b/sql/net_serv.cc
index f39eaaadf46..e625b307343 100644
--- a/sql/net_serv.cc
+++ b/sql/net_serv.cc
@@ -45,6 +45,7 @@
 #include <violite.h>
 #include <signal.h>
 #include "probes_mysql.h"
+#include <debug_sync.h>
 
 #ifdef EMBEDDED_LIBRARY
 #undef MYSQL_SERVER
@@ -486,6 +487,18 @@ net_write_command(NET *net,uchar command,
   DBUG_ENTER("net_write_command");
   DBUG_PRINT("enter",("length: %lu", (ulong) len));
 
+  DBUG_EXECUTE_IF("simulate_error_on_packet_write",
+                  {
+                    if (command == COM_BINLOG_DUMP)
+                    {
+                      net->last_errno = ER_NET_ERROR_ON_WRITE;
+                      socket_errno = 2;
+                      DBUG_ASSERT(!debug_sync_set_action(
+                      (THD *)net->thd,
+                      STRING_WITH_LEN("now SIGNAL parked WAIT_FOR continue")));
+                      DBUG_RETURN(true);
+                    }
+                  };);
   MYSQL_NET_WRITE_START(length);
 
   buff[4]=command;				/* For first packet */
diff --git a/sql/slave.cc b/sql/slave.cc
index 1bf83aa9652..87eacfcfd0a 100644
--- a/sql/slave.cc
+++ b/sql/slave.cc
@@ -3297,7 +3297,8 @@ static int request_dump(THD *thd, MYSQL* mysql, Master_info* mi,
       in the future, we should do a better error analysis, but for
       now we just fill up the error log :-)
     */
-    if (mysql_errno(mysql) == ER_NET_READ_INTERRUPTED)
+    if (mysql_errno(mysql) == ER_NET_READ_INTERRUPTED ||
+        mysql_errno(mysql) == ER_NET_ERROR_ON_WRITE)
       *suppress_warnings= TRUE;                 // Suppress reconnect warning
     else
       sql_print_error("Error on COM_BINLOG_DUMP: %d  %s, will retry in %d secs",