summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorAndrei <andrei.elkin@mariadb.com>2022-08-30 00:26:20 +0300
committerAndrei <andrei.elkin@mariadb.com>2022-09-07 20:35:43 +0300
commit5563202089e78855ad9295a3526a70e766d8a42d (patch)
tree6915bcd142b3b73ab59e4f07251fd627da09fb64
parent80cf7a4c43209a91ac6514ac3ea0dd0b592e17f0 (diff)
downloadmariadb-git-5563202089e78855ad9295a3526a70e766d8a42d.tar.gz
MDEV-29322 ASAN heap-use-after-free in Query_log_event::do_apply_event
The ASAN report was made in the parallel slave execution of a query event and implicitly involved (so also parallelly run) Format-Description event. The Query actually had unexpected impossible dependency on a preceding "old" FD whose instance got destructed, to cause the ASAN error. The case is fixed with storing the FD's value into Query-log-event at its instantiating on slave. The stored value is from the very FD of the Query's original binlog so remains to be correct at the query event applying. The branch C. of a new rpl_parallel_29322.test also demonstrates (may need few --repeat though) the bug in its simple form of the same server version binlog.
-rw-r--r--mysql-test/suite/rpl/include/rpl_parallel_29322.inc111
-rw-r--r--mysql-test/suite/rpl/r/rpl_parallel_29322.result238
-rw-r--r--mysql-test/suite/rpl/t/rpl_parallel_29322.test64
-rw-r--r--sql/log_event.cc2
-rw-r--r--sql/log_event.h2
-rw-r--r--sql/log_event_server.cc7
6 files changed, 416 insertions, 8 deletions
diff --git a/mysql-test/suite/rpl/include/rpl_parallel_29322.inc b/mysql-test/suite/rpl/include/rpl_parallel_29322.inc
new file mode 100644
index 00000000000..54eb13d7f09
--- /dev/null
+++ b/mysql-test/suite/rpl/include/rpl_parallel_29322.inc
@@ -0,0 +1,111 @@
+# A "body" for rpl.rpl_parallel_29322 that runs having as input
+# the master and slave @@global.explicit_defaults_for_timestamp.
+#
+# The Key notes
+# -------------
+# On master: a sequence of binlog files is composed with
+# different server versions.
+# On slave: to first try enqueuing all master events.
+# Due to binlog files are from different version
+# servers when the new (of binlog 2) FD shows up the enqueuing
+# will hiccup as workers have to
+# process all events already scheduled (see wait_condition below).
+# This part proves of the different server version the binlogs
+# indeed are.
+# After the worker is unblocked the exection proceeds.
+#
+# In the end compare table definitions and print table data
+# to prove correctness.
+
+--connection slave
+--source include/stop_slave.inc
+reset slave;
+
+--connection master
+--let $datadir= `SELECT @@datadir`
+
+reset master; # Master starts a new serious of binlog files
+
+create table t2 (a timestamp, b int);
+show create table t2;
+--save_master_pos
+
+--connection slave
+--source include/start_slave.inc
+--sync_with_master
+--source include/stop_slave.inc
+
+# load for two $same_version_binlogs branches
+--connection master
+if (!$same_version_binlogs)
+{
+ insert into t2 values (null, 1);
+ flush binary logs;
+ flush binary logs;
+ insert into t2 values (null, 2);
+}
+if ($same_version_binlogs)
+{
+--disable_query_log
+ --let $count=8
+ while ($count)
+ {
+ --let $queries=4
+ while ($queries)
+ {
+ insert into t2 values (null, 1);
+ --dec $queries
+ }
+ flush binary logs;
+ flush binary logs;
+ --dec $count
+ }
+--enable_query_log
+}
+--save_master_pos
+
+if (!$same_version_binlogs)
+{
+ --move_file $datadir/master-bin.000002 $datadir/master-bin.000002.sav
+ --copy_file $MYSQL_TEST_DIR/std_data/mdev29078-mysql-bin.000001 $datadir/master-bin.000002
+ --exec $MYSQL_BINLOG --short-form $datadir/master-bin.000002
+
+ # To demonstrate different version binlogs, hold back worker
+ # until the SQL thread state shows waiting.
+ --connection slave1
+ lock table t2 write;
+}
+
+--connection slave
+--source include/start_slave.inc
+
+if (!$same_version_binlogs)
+{
+ --let $slave_waits_for=Waiting for worker threads to be idle
+ --let $wait_condition= SELECT COUNT(*) > 0 FROM information_schema.processlist WHERE state = "$slave_waits_for"
+ --source include/wait_condition.inc
+
+ --connection slave1
+ unlock tables;
+
+ --connection slave
+ --sync_with_master
+ show create table t1;
+ set statement time_zone='+2:00' for select * from t1;
+ drop table t1;
+
+ --connection master
+ --remove_file $datadir/master-bin.000002
+ --move_file $datadir/master-bin.000002.sav $datadir/master-bin.000002
+}
+
+--connection slave
+--sync_with_master
+show create table t2;
+--let $diff_tables=master:t2,slave:t2
+--source include/diff_tables.inc
+
+--connection master
+drop table t2;
+
+--sync_slave_with_master
diff --git a/mysql-test/suite/rpl/r/rpl_parallel_29322.result b/mysql-test/suite/rpl/r/rpl_parallel_29322.result
new file mode 100644
index 00000000000..43cac55aec8
--- /dev/null
+++ b/mysql-test/suite/rpl/r/rpl_parallel_29322.result
@@ -0,0 +1,238 @@
+#
+# MDEV-29322 ASAN use-after-free options_written_to_bin_log
+#
+include/master-slave.inc
+[connection master]
+# A. set the master and slave explicit_defaults_for_timestamp values crisscross to (1,0)
+connection master;
+set @sav.explicit_defaults_for_timestamp = @@session.explicit_defaults_for_timestamp;
+set @@session.explicit_defaults_for_timestamp = 1;
+connection slave;
+set @sav.explicit_defaults_for_timestamp = @@global.explicit_defaults_for_timestamp;
+set global explicit_defaults_for_timestamp = 0;
+set @sav.slave_parallel_workers = @@global.slave_parallel_workers;
+include/stop_slave.inc
+set @@global.slave_parallel_workers = 1;
+include/start_slave.inc
+connection slave;
+include/stop_slave.inc
+reset slave;
+connection master;
+reset master;
+create table t2 (a timestamp, b int);
+show create table t2;
+Table Create Table
+t2 CREATE TABLE `t2` (
+ `a` timestamp NULL DEFAULT NULL,
+ `b` int(11) DEFAULT NULL
+) ENGINE=MyISAM DEFAULT CHARSET=latin1
+connection slave;
+include/start_slave.inc
+include/stop_slave.inc
+connection master;
+insert into t2 values (null, 1);
+flush binary logs;
+flush binary logs;
+insert into t2 values (null, 2);
+/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
+/*!40019 SET @@session.max_insert_delayed_threads=0*/;
+/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
+DELIMITER /*!*/;
+ROLLBACK/*!*/;
+use `test`/*!*/;
+SET TIMESTAMP=1658586280/*!*/;
+SET @@session.pseudo_thread_id=999999999/*!*/;
+SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1, @@session.check_constraint_checks=1/*!*/;
+SET @@session.sql_mode=1411383296/*!*/;
+SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
+/*!\C utf8 *//*!*/;
+SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
+SET @@session.lc_time_names=0/*!*/;
+SET @@session.collation_database=DEFAULT/*!*/;
+create table t1 (f1 timestamp, f2 timestamp)
+/*!*/;
+START TRANSACTION
+/*!*/;
+SET TIMESTAMP=1658586288/*!*/;
+insert t1 values (NULL, NULL)
+/*!*/;
+SET TIMESTAMP=1658586288/*!*/;
+COMMIT
+/*!*/;
+START TRANSACTION
+/*!*/;
+SET TIMESTAMP=1658586335/*!*/;
+insert t1 () values ()
+/*!*/;
+SET TIMESTAMP=1658586335/*!*/;
+COMMIT
+/*!*/;
+DELIMITER ;
+# End of log file
+ROLLBACK /* added by mysqlbinlog */;
+/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
+/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
+connection slave1;
+lock table t2 write;
+connection slave;
+include/start_slave.inc
+connection slave1;
+unlock tables;
+connection slave;
+show create table t1;
+Table Create Table
+t1 CREATE TABLE `t1` (
+ `f1` timestamp NULL DEFAULT NULL,
+ `f2` timestamp NULL DEFAULT NULL
+) ENGINE=MyISAM DEFAULT CHARSET=latin1
+set statement time_zone='+2:00' for select * from t1;
+f1 f2
+NULL NULL
+NULL NULL
+drop table t1;
+connection master;
+connection slave;
+show create table t2;
+Table Create Table
+t2 CREATE TABLE `t2` (
+ `a` timestamp NULL DEFAULT NULL,
+ `b` int(11) DEFAULT NULL
+) ENGINE=MyISAM DEFAULT CHARSET=latin1
+include/diff_tables.inc [master:t2,slave:t2]
+connection master;
+drop table t2;
+connection slave;
+# B. alternate the master and slave vars' values to (0,1)
+connection master;
+set @@session.explicit_defaults_for_timestamp = 0;
+connection slave;
+set @@global.explicit_defaults_for_timestamp = 1;
+connection slave;
+include/stop_slave.inc
+reset slave;
+connection master;
+reset master;
+create table t2 (a timestamp, b int);
+show create table t2;
+Table Create Table
+t2 CREATE TABLE `t2` (
+ `a` timestamp NOT NULL DEFAULT current_timestamp() ON UPDATE current_timestamp(),
+ `b` int(11) DEFAULT NULL
+) ENGINE=MyISAM DEFAULT CHARSET=latin1
+connection slave;
+include/start_slave.inc
+include/stop_slave.inc
+connection master;
+insert into t2 values (null, 1);
+flush binary logs;
+flush binary logs;
+insert into t2 values (null, 2);
+/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
+/*!40019 SET @@session.max_insert_delayed_threads=0*/;
+/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
+DELIMITER /*!*/;
+ROLLBACK/*!*/;
+use `test`/*!*/;
+SET TIMESTAMP=1658586280/*!*/;
+SET @@session.pseudo_thread_id=999999999/*!*/;
+SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1, @@session.check_constraint_checks=1/*!*/;
+SET @@session.sql_mode=1411383296/*!*/;
+SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
+/*!\C utf8 *//*!*/;
+SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
+SET @@session.lc_time_names=0/*!*/;
+SET @@session.collation_database=DEFAULT/*!*/;
+create table t1 (f1 timestamp, f2 timestamp)
+/*!*/;
+START TRANSACTION
+/*!*/;
+SET TIMESTAMP=1658586288/*!*/;
+insert t1 values (NULL, NULL)
+/*!*/;
+SET TIMESTAMP=1658586288/*!*/;
+COMMIT
+/*!*/;
+START TRANSACTION
+/*!*/;
+SET TIMESTAMP=1658586335/*!*/;
+insert t1 () values ()
+/*!*/;
+SET TIMESTAMP=1658586335/*!*/;
+COMMIT
+/*!*/;
+DELIMITER ;
+# End of log file
+ROLLBACK /* added by mysqlbinlog */;
+/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
+/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
+connection slave1;
+lock table t2 write;
+connection slave;
+include/start_slave.inc
+connection slave1;
+unlock tables;
+connection slave;
+show create table t1;
+Table Create Table
+t1 CREATE TABLE `t1` (
+ `f1` timestamp NOT NULL DEFAULT current_timestamp() ON UPDATE current_timestamp(),
+ `f2` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00'
+) ENGINE=MyISAM DEFAULT CHARSET=latin1
+set statement time_zone='+2:00' for select * from t1;
+f1 f2
+2022-07-23 16:24:48 2022-07-23 16:24:48
+2022-07-23 16:25:35 0000-00-00 00:00:00
+drop table t1;
+connection master;
+connection slave;
+show create table t2;
+Table Create Table
+t2 CREATE TABLE `t2` (
+ `a` timestamp NOT NULL DEFAULT current_timestamp() ON UPDATE current_timestamp(),
+ `b` int(11) DEFAULT NULL
+) ENGINE=MyISAM DEFAULT CHARSET=latin1
+include/diff_tables.inc [master:t2,slave:t2]
+connection master;
+drop table t2;
+connection slave;
+# C. the bug case on the same version binlogs also to demo on the patch's base
+include/stop_slave.inc
+set @@global.slave_parallel_workers = 4;
+include/start_slave.inc
+connection slave;
+include/stop_slave.inc
+reset slave;
+connection master;
+reset master;
+create table t2 (a timestamp, b int);
+show create table t2;
+Table Create Table
+t2 CREATE TABLE `t2` (
+ `a` timestamp NOT NULL DEFAULT current_timestamp() ON UPDATE current_timestamp(),
+ `b` int(11) DEFAULT NULL
+) ENGINE=MyISAM DEFAULT CHARSET=latin1
+connection slave;
+include/start_slave.inc
+include/stop_slave.inc
+connection master;
+connection slave;
+include/start_slave.inc
+connection slave;
+show create table t2;
+Table Create Table
+t2 CREATE TABLE `t2` (
+ `a` timestamp NOT NULL DEFAULT current_timestamp() ON UPDATE current_timestamp(),
+ `b` int(11) DEFAULT NULL
+) ENGINE=MyISAM DEFAULT CHARSET=latin1
+include/diff_tables.inc [master:t2,slave:t2]
+connection master;
+drop table t2;
+connection slave;
+connection master;
+set @@session.explicit_defaults_for_timestamp = @sav.explicit_defaults_for_timestamp;
+connection slave;
+set @@global.explicit_defaults_for_timestamp = @sav.explicit_defaults_for_timestamp;
+include/stop_slave.inc
+set @@global.slave_parallel_workers = @sav.slave_parallel_workers;
+include/start_slave.inc
+include/rpl_end.inc
diff --git a/mysql-test/suite/rpl/t/rpl_parallel_29322.test b/mysql-test/suite/rpl/t/rpl_parallel_29322.test
new file mode 100644
index 00000000000..675960592f8
--- /dev/null
+++ b/mysql-test/suite/rpl/t/rpl_parallel_29322.test
@@ -0,0 +1,64 @@
+--echo #
+--echo # MDEV-29322 ASAN use-after-free options_written_to_bin_log
+--echo #
+
+# The tests verify that at query execution slave parallel workers successfully
+# find a correct options_written_to_bin_log value associated with the query.
+# There are three test branches, A and B take care of different server version
+# binlogs. The homogeneous binlog case of C. branch is also for how-to-reproduce
+# the bug, may need few --repeat :s though.
+
+--source include/have_binlog_format_mixed.inc
+--source include/master-slave.inc
+
+--echo # A. set the master and slave explicit_defaults_for_timestamp values crisscross to (1,0)
+--let $same_version_binlogs=0
+
+--connection master
+# Configure master and slave with different values of the following variable:
+set @sav.explicit_defaults_for_timestamp = @@session.explicit_defaults_for_timestamp;
+set @@session.explicit_defaults_for_timestamp = 1;
+--connection slave
+# slave must produce the master version of the table definition and its data
+set @sav.explicit_defaults_for_timestamp = @@global.explicit_defaults_for_timestamp;
+set global explicit_defaults_for_timestamp = 0;
+# the global var gets changed in the included file
+set @sav.slave_parallel_workers = @@global.slave_parallel_workers;
+--source include/stop_slave.inc
+set @@global.slave_parallel_workers = 1;
+--source include/start_slave.inc
+
+--source suite/rpl/include/rpl_parallel_29322.inc
+
+--echo # B. alternate the master and slave vars' values to (0,1)
+
+--connection master
+# Configure master and slave with different values of the following variable:
+set @@session.explicit_defaults_for_timestamp = 0;
+--connection slave
+# slave must produce the master version of the table definition and its data
+set @@global.explicit_defaults_for_timestamp = 1;
+
+--source suite/rpl/include/rpl_parallel_29322.inc
+
+
+--echo # C. the bug case on the same version binlogs also to demo on the patch's base
+--let $same_version_binlogs=1
+# with more workers the bug shows more likeky on the patch's base slave.
+--source include/stop_slave.inc
+set @@global.slave_parallel_workers = 4;
+--source include/start_slave.inc
+
+--source suite/rpl/include/rpl_parallel_29322.inc
+
+# cleanup
+--connection master
+set @@session.explicit_defaults_for_timestamp = @sav.explicit_defaults_for_timestamp;
+--connection slave
+set @@global.explicit_defaults_for_timestamp = @sav.explicit_defaults_for_timestamp;
+--source include/stop_slave.inc
+set @@global.slave_parallel_workers = @sav.slave_parallel_workers;
+--source include/start_slave.inc
+
+
+--source include/rpl_end.inc
diff --git a/sql/log_event.cc b/sql/log_event.cc
index 4c4514bb4e2..20cf4d45073 100644
--- a/sql/log_event.cc
+++ b/sql/log_event.cc
@@ -1528,7 +1528,7 @@ Query_log_event::Query_log_event(const char* buf, uint event_len,
switch (*pos++) {
case Q_FLAGS2_CODE:
CHECK_SPACE(pos, end, 4);
- flags2_inited= 1;
+ flags2_inited= description_event->options_written_to_bin_log;
flags2= uint4korr(pos);
DBUG_PRINT("info",("In Query_log_event, read flags2: %lu", (ulong) flags2));
pos+= 4;
diff --git a/sql/log_event.h b/sql/log_event.h
index 4c2ee3e484e..096d8587848 100644
--- a/sql/log_event.h
+++ b/sql/log_event.h
@@ -2088,7 +2088,7 @@ public:
flags2==0 (5.0 master, we know this has a meaning of flags all down which
must influence the query).
*/
- bool flags2_inited;
+ uint32 flags2_inited;
bool sql_mode_inited;
bool charset_inited;
diff --git a/sql/log_event_server.cc b/sql/log_event_server.cc
index 7a8561051ba..56d1c978ac4 100644
--- a/sql/log_event_server.cc
+++ b/sql/log_event_server.cc
@@ -1713,12 +1713,7 @@ int Query_log_event::do_apply_event(rpl_group_info *rgi,
thd->slave_expected_error= expected_error;
if (flags2_inited)
{
- /*
- all bits of thd->variables.option_bits which are 1 in
- OPTIONS_WRITTEN_TO_BIN_LOG must take their value from
- flags2.
- */
- ulonglong mask= rli->relay_log.description_event_for_exec->options_written_to_bin_log;
+ ulonglong mask= flags2_inited;
thd->variables.option_bits= (flags2 & mask) |
(thd->variables.option_bits & ~mask);
}