From 9005108234ca97ce9e86935fd79ea0b3fb97ec43 Mon Sep 17 00:00:00 2001 From: Andrei Elkin Date: Fri, 26 Jan 2018 23:26:39 +0200 Subject: [PATCH] MDEV-14721 Big transaction events get lost on semisync master when replicate_events_marked_for_skip=FILTER_ON_MASTER [Note this is a cherry-pick from 10.2 branch.] When events of a big transaction are binlogged offsetting over 2GB from the beginning of the log the semisync master's dump thread lost such events. The events were skipped by the Dump thread that found their skipping status erroneously. The current fixes make sure the skipping status is computed correctly. The test verifies them simulating the 2GB offset. --- .../rpl/r/rpl_semi_sync_skip_repl.result | 23 +++++++ .../suite/rpl/t/rpl_semi_sync_skip_repl.test | 62 +++++++++++++++++++ sql/log_event.cc | 2 + sql/sql_repl.cc | 7 +-- 4 files changed, 89 insertions(+), 5 deletions(-) create mode 100644 mysql-test/suite/rpl/r/rpl_semi_sync_skip_repl.result create mode 100644 mysql-test/suite/rpl/t/rpl_semi_sync_skip_repl.test diff --git a/mysql-test/suite/rpl/r/rpl_semi_sync_skip_repl.result b/mysql-test/suite/rpl/r/rpl_semi_sync_skip_repl.result new file mode 100644 index 00000000000..4762ac8dd07 --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_semi_sync_skip_repl.result @@ -0,0 +1,23 @@ +include/master-slave.inc +[connection master] +call mtr.add_suppression("Timeout waiting for reply of binlog"); +SET @@GLOBAL.rpl_semi_sync_master_enabled = 1; +SET @@GLOBAL.rpl_semi_sync_master_timeout=100; +include/stop_slave.inc +SET @@GLOBAL.replicate_events_marked_for_skip=FILTER_ON_MASTER; +SET @@GLOBAL. rpl_semi_sync_slave_enabled = 1; +include/start_slave.inc +CREATE TABLE t1 (a INT) ENGINE=innodb; +SET @@GLOBAL.debug_dbug= "d,dbug_master_binlog_over_2GB"; +SET @@SESSION.skip_replication=1; +INSERT INTO t1 SET a=1; +SET @@SESSION.skip_replication=0; +INSERT INTO t1 SET a=0; +SET @@GLOBAL.debug_dbug=""; +SET @@GLOBAL. rpl_semi_sync_master_timeout = 10000; +SET @@GLOBAL. rpl_semi_sync_master_enabled = 0; +DROP TABLE t1; +include/stop_slave.inc +SET @@GLOBAL. rpl_semi_sync_slave_enabled = 0; +SET @@GLOBAL.replicate_events_marked_for_skip = REPLICATE; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_semi_sync_skip_repl.test b/mysql-test/suite/rpl/t/rpl_semi_sync_skip_repl.test new file mode 100644 index 00000000000..2f6da18067c --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_semi_sync_skip_repl.test @@ -0,0 +1,62 @@ +# MDEV-14721 Big transaction events get lost on semisync master when +# replicate_events_marked_for_skip=FILTER_ON_MASTER +# +# When events of a big transaction are binlogged offsetting over 2GB from +# the beginning of the log the semisync master's dump thread +# lost such events. +# The test verifies the fixes' correctness simulating the 2GB offset. + +source include/have_semisync.inc; +source include/not_embedded.inc; +source include/have_innodb.inc; +source include/have_debug.inc; +source include/master-slave.inc; + +--connection master +# Suppress warnings that might be generated during the test +call mtr.add_suppression("Timeout waiting for reply of binlog"); + +--let $sav_enabled_master=`SELECT @@GLOBAL.rpl_semi_sync_master_enabled ` +--let $sav_timeout_master=`SELECT @@GLOBAL.rpl_semi_sync_master_timeout ` +SET @@GLOBAL.rpl_semi_sync_master_enabled = 1; +SET @@GLOBAL.rpl_semi_sync_master_timeout=100; + +--connection slave +source include/stop_slave.inc; +--let $sav_skip_marked_slave=`SELECT @@GLOBAL.replicate_events_marked_for_skip ` +SET @@GLOBAL.replicate_events_marked_for_skip=FILTER_ON_MASTER; +--let $sav_enabled_slave=`SELECT @@GLOBAL.rpl_semi_sync_slave_enabled ` +SET @@GLOBAL. rpl_semi_sync_slave_enabled = 1; + +source include/start_slave.inc; + +--connection master +CREATE TABLE t1 (a INT) ENGINE=innodb; + +# Make the following events as if they offset over 2GB from the beginning of binlog +SET @@GLOBAL.debug_dbug= "d,dbug_master_binlog_over_2GB"; +SET @@SESSION.skip_replication=1; +INSERT INTO t1 SET a=1; +SET @@SESSION.skip_replication=0; +INSERT INTO t1 SET a=0; + +--sync_slave_with_master + +# +# Clean up +# +--connection master +SET @@GLOBAL.debug_dbug=""; +--eval SET @@GLOBAL. rpl_semi_sync_master_timeout = $sav_timeout_master +--eval SET @@GLOBAL. rpl_semi_sync_master_enabled = $sav_enabled_master + +--connection master +DROP TABLE t1; + +--sync_slave_with_master +source include/stop_slave.inc; +--eval SET @@GLOBAL. rpl_semi_sync_slave_enabled = $sav_enabled_slave +--eval SET @@GLOBAL.replicate_events_marked_for_skip = $sav_skip_marked_slave + +--let $rpl_only_running_threads= 1 +--source include/rpl_end.inc diff --git a/sql/log_event.cc b/sql/log_event.cc index 81bc683625f..aadd0938093 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -1311,6 +1311,8 @@ bool Log_event::write_header(ulong event_data_length) */ log_pos= writer->pos() + data_written; + + DBUG_EXECUTE_IF("dbug_master_binlog_over_2GB", log_pos += (1ULL <<31);); } now= get_time(); // Query start time diff --git a/sql/sql_repl.cc b/sql/sql_repl.cc index b5cca334891..569c3d2c4ef 100644 --- a/sql/sql_repl.cc +++ b/sql/sql_repl.cc @@ -1904,11 +1904,8 @@ send_event_to_slave(binlog_send_info *info, Log_event_type event_type, */ if (info->thd->variables.option_bits & OPTION_SKIP_REPLICATION) { - /* - The first byte of the packet is a '\0' to distinguish it from an error - packet. So the actual event starts at offset +1. - */ - uint16 event_flags= uint2korr(&((*packet)[FLAGS_OFFSET+1])); + uint16 event_flags= uint2korr(&((*packet)[FLAGS_OFFSET + ev_offset])); + if (event_flags & LOG_EVENT_SKIP_REPLICATION_F) return NULL; }