MDEV-33672: Gtid_log_event Construction from File Should Ensure Event Length When Using Extra Flags

A GTID event can have variable length, with contributing factors
such as the variable length from the flags2 and optional extra flags
fields. These fields are bitmaps, where each set bit indicates an
additional value that should be appended to the event, e.g.
multi-engine transactions append a number to indicate the number of
additional engines a transaction uses. However, if a flags bit is
set, and no additional fields are appended to the event, MDEV-33672
reports that the server can still try to read from memory as if it
did exist. Note, however, in debug builds, this condition is
asserted for FL_EXTRA_MULTI_ENGINE.

This patch fixes this to check that the length of the event is
aligned with the expectation set by the flags for FL_PREPARED_XA,
FL_COMPLETED_XA, and FL_EXTRA_MULTI_ENGINE.

Reviewed By
============
Kristian Nielsen <knielsen@knielsen-hq.org>

mysql-test/suite/rpl/r/rpl_gtid_header_valid.result

+include/master-slave.inc
+[connection master]
+#
+# Initialize test data
+connection master;
+create table t1 (a int) engine=innodb;
+include/save_master_gtid.inc
+set @@SESSION.debug_dbug= "+d,binlog_force_commit_id";
+connection slave;
+set SQL_LOG_BIN= 0;
+call mtr.add_suppression('Found invalid event in binary log');
+call mtr.add_suppression('Slave SQL.*Relay log read failure: Could not parse relay log event entry.* 1594');
+set SQL_LOG_BIN= 1;
+include/sync_with_master_gtid.inc
+include/stop_slave.inc
+include/start_slave.inc
+#
+# Test FL_PREPARED_XA
+connection master;
+set @@SESSION.debug_dbug= "+d,negate_xid_from_gtid";
+set @commit_id= 100;
+XA START 'x1';
+insert into t1 values (1);
+XA END 'x1';
+XA PREPARE 'x1';
+set @@SESSION.debug_dbug= "-d,negate_xid_from_gtid";
+XA COMMIT 'x1';
+include/save_master_gtid.inc
+# Waiting for slave to find invalid event..
+connection slave;
+include/wait_for_slave_sql_error.inc [errno=1594]
+STOP SLAVE IO_THREAD;
+# Reset master binlogs (as there is an invalid event) and slave state
+connection master;
+RESET MASTER;
+connection slave;
+RESET MASTER;
+RESET SLAVE;
+set @@global.gtid_slave_pos="";
+include/start_slave.inc
+#
+# Test FL_COMPLETED_XA
+connection master;
+set @commit_id= 101;
+XA START 'x1';
+insert into t1 values (2);
+XA END 'x1';
+XA PREPARE 'x1';
+set @@SESSION.debug_dbug= "+d,negate_xid_from_gtid";
+XA COMMIT 'x1';
+set @@SESSION.debug_dbug= "-d,negate_xid_from_gtid";
+include/save_master_gtid.inc
+# Waiting for slave to find invalid event..
+connection slave;
+include/wait_for_slave_sql_error.inc [errno=1594]
+STOP SLAVE IO_THREAD;
+# Cleanup hanging XA PREPARE on slave
+set statement SQL_LOG_BIN=0 for XA COMMIT 'x1';
+# Reset master binlogs (as there is an invalid event) and slave state
+connection master;
+RESET MASTER;
+connection slave;
+RESET MASTER;
+RESET SLAVE;
+set @@global.gtid_slave_pos="";
+include/start_slave.inc
+#
+# Test Missing xid.data (but has format id and length description parts)
+connection master;
+set @commit_id= 101;
+XA START 'x1';
+insert into t1 values (1);
+XA END 'x1';
+XA PREPARE 'x1';
+set @@SESSION.debug_dbug= "+d,negate_xid_data_from_gtid";
+XA COMMIT 'x1';
+set @@SESSION.debug_dbug= "-d,negate_xid_data_from_gtid";
+include/save_master_gtid.inc
+# Waiting for slave to find invalid event..
+connection slave;
+include/wait_for_slave_sql_error.inc [errno=1594]
+STOP SLAVE IO_THREAD;
+# Cleanup hanging XA PREPARE on slave
+set statement SQL_LOG_BIN=0 for XA COMMIT 'x1';
+# Reset master binlogs (as there is an invalid event) and slave state
+connection master;
+RESET MASTER;
+connection slave;
+RESET MASTER;
+RESET SLAVE;
+set @@global.gtid_slave_pos="";
+include/start_slave.inc
+#
+# Test FL_EXTRA_MULTI_ENGINE
+connection master;
+set @old_dbug= @@SESSION.debug_dbug;
+set @@SESSION.debug_dbug= "+d,inject_fl_extra_multi_engine_into_gtid";
+set @commit_id= 102;
+insert into t1 values (3);
+include/save_master_gtid.inc
+set @@SESSION.debug_dbug=@old_dbug;
+connection slave;
+# Waiting for slave to find invalid event..
+include/wait_for_slave_sql_error.inc [errno=1594]
+STOP SLAVE IO_THREAD;
+# Reset master binlogs (as there is an invalid event) and slave state
+connection master;
+RESET MASTER;
+connection slave;
+RESET SLAVE;
+RESET MASTER;
+set @@global.gtid_slave_pos="";
+include/start_slave.inc
+#
+# Cleanup
+connection master;
+drop table t1;
+include/save_master_gtid.inc
+connection slave;
+include/sync_with_master_gtid.inc
+include/rpl_end.inc
+# End of rpl_gtid_header_valid.test

mysql-test/suite/rpl/t/rpl_gtid_header_valid.test

+#
+#   This test ensures that, when a GTID event is constructed by reading its
+# content from a binlog file, the reader (e.g. replica, in this test) cannot
+# read beyond the length of the GTID event. That is, we ensure that the
+# structure indicated by its flags and extra_flags are consistent with the
+# actual content of the event.
+#
+#   To spoof a broken GTID log event, we use the DEBUG_DBUG mechanism to inject
+# the master to write invalid GTID events for each flag. The transaction is
+# given a commit id to ensure the event is not shorter than GTID_HEADER_LEN,
+# which would result in zero padding up to GTID_HEADER_LEN.
+#
+#
+# References:
+#   MDEV-33672: Gtid_log_event Construction from File Should Ensure Event
+#               Length When Using Extra Flags
+#
+
+--source include/have_debug.inc
+
+# GTID event extra_flags are format independent
+--source include/have_binlog_format_row.inc
+--source include/have_innodb.inc
+--source include/master-slave.inc
+
+--echo #
+--echo # Initialize test data
+--connection master
+create table t1 (a int) engine=innodb;
+--source include/save_master_gtid.inc
+set @@SESSION.debug_dbug= "+d,binlog_force_commit_id";
+
+--connection slave
+set SQL_LOG_BIN= 0;
+call mtr.add_suppression('Found invalid event in binary log');
+call mtr.add_suppression('Slave SQL.*Relay log read failure: Could not parse relay log event entry.* 1594');
+set SQL_LOG_BIN= 1;
+--source include/sync_with_master_gtid.inc
+--source include/stop_slave.inc
+--source include/start_slave.inc
+--let $cid_ctr= 100
+
+
+--echo #
+--echo # Test FL_PREPARED_XA
+--connection master
+set @@SESSION.debug_dbug= "+d,negate_xid_from_gtid";
+--eval set @commit_id= $cid_ctr
+
+XA START 'x1';
+insert into t1 values (1);
+XA END 'x1';
+XA PREPARE 'x1';
+set @@SESSION.debug_dbug= "-d,negate_xid_from_gtid";
+XA COMMIT 'x1';
+--source include/save_master_gtid.inc
+
+--echo # Waiting for slave to find invalid event..
+--connection slave
+let $slave_sql_errno= 1594; # ER_SLAVE_RELAY_LOG_READ_FAILURE
+source include/wait_for_slave_sql_error.inc;
+STOP SLAVE IO_THREAD;
+
+--echo # Reset master binlogs (as there is an invalid event) and slave state
+--connection master
+RESET MASTER;
+--connection slave
+RESET MASTER;
+RESET SLAVE;
+set @@global.gtid_slave_pos="";
+--source include/start_slave.inc
+
+
+--echo #
+--echo # Test FL_COMPLETED_XA
+--connection master
+--inc $cid_ctr
+--eval set @commit_id= $cid_ctr
+XA START 'x1';
+--let $next_val = `SELECT max(a)+1 FROM t1`
+--eval insert into t1 values ($next_val)
+XA END 'x1';
+XA PREPARE 'x1';
+set @@SESSION.debug_dbug= "+d,negate_xid_from_gtid";
+XA COMMIT 'x1';
+set @@SESSION.debug_dbug= "-d,negate_xid_from_gtid";
+--source include/save_master_gtid.inc
+
+--echo # Waiting for slave to find invalid event..
+--connection slave
+let $slave_sql_errno= 1594; # ER_SLAVE_RELAY_LOG_READ_FAILURE
+source include/wait_for_slave_sql_error.inc;
+STOP SLAVE IO_THREAD;
+
+--echo # Cleanup hanging XA PREPARE on slave
+set statement SQL_LOG_BIN=0 for XA COMMIT 'x1';
+
+--echo # Reset master binlogs (as there is an invalid event) and slave state
+--connection master
+RESET MASTER;
+--connection slave
+RESET MASTER;
+RESET SLAVE;
+set @@global.gtid_slave_pos="";
+--source include/start_slave.inc
+
+
+--echo #
+--echo # Test Missing xid.data (but has format id and length description parts)
+
+--connection master
+--eval set @commit_id= $cid_ctr
+
+XA START 'x1';
+insert into t1 values (1);
+XA END 'x1';
+XA PREPARE 'x1';
+set @@SESSION.debug_dbug= "+d,negate_xid_data_from_gtid";
+XA COMMIT 'x1';
+set @@SESSION.debug_dbug= "-d,negate_xid_data_from_gtid";
+--source include/save_master_gtid.inc
+
+--echo # Waiting for slave to find invalid event..
+--connection slave
+let $slave_sql_errno= 1594; # ER_SLAVE_RELAY_LOG_READ_FAILURE
+source include/wait_for_slave_sql_error.inc;
+STOP SLAVE IO_THREAD;
+
+--echo # Cleanup hanging XA PREPARE on slave
+set statement SQL_LOG_BIN=0 for XA COMMIT 'x1';
+
+--echo # Reset master binlogs (as there is an invalid event) and slave state
+--connection master
+RESET MASTER;
+--connection slave
+RESET MASTER;
+RESET SLAVE;
+set @@global.gtid_slave_pos="";
+--source include/start_slave.inc
+
+
+--echo #
+--echo # Test FL_EXTRA_MULTI_ENGINE
+--connection master
+set @old_dbug= @@SESSION.debug_dbug;
+set @@SESSION.debug_dbug= "+d,inject_fl_extra_multi_engine_into_gtid";
+--inc $cid_ctr
+--eval set @commit_id= $cid_ctr
+--let $next_val = `SELECT max(a)+1 FROM t1`
+--eval insert into t1 values ($next_val)
+--source include/save_master_gtid.inc
+set @@SESSION.debug_dbug=@old_dbug;
+
+--connection slave
+--echo # Waiting for slave to find invalid event..
+let $slave_sql_errno= 1594; # ER_SLAVE_RELAY_LOG_READ_FAILURE
+source include/wait_for_slave_sql_error.inc;
+STOP SLAVE IO_THREAD;
+
+--echo # Reset master binlogs (as there is an invalid event) and slave state
+--connection master
+RESET MASTER;
+
+--connection slave
+RESET SLAVE;
+RESET MASTER;
+set @@global.gtid_slave_pos="";
+--source include/start_slave.inc
+
+--echo #
+--echo # Cleanup
+
+--connection master
+drop table t1;
+--source include/save_master_gtid.inc
+
+--connection slave
+--source include/sync_with_master_gtid.inc
+
+--source include/rpl_end.inc
+--echo # End of rpl_gtid_header_valid.test

sql/log_event.cc

@@ -2629,6 +2629,11 @@ Gtid_log_event::Gtid_log_event(const uchar *buf, uint event_len,
   }
   if (flags2 & (FL_PREPARED_XA | FL_COMPLETED_XA))
   {
+    if (event_len < static_cast<uint>(buf - buf_0) + 6)
+    {
+      seq_no= 0;
+      return;
+    }
     xid.formatID= uint4korr(buf);
     buf+= 4;
 
@@ -2637,6 +2642,11 @@ Gtid_log_event::Gtid_log_event(const uchar *buf, uint event_len,
     buf+= 2;
 
     long data_length= xid.bqual_length + xid.gtrid_length;
+    if (event_len < static_cast<uint>(buf - buf_0) + data_length)
+    {
+      seq_no= 0;
+      return;
+    }
     memcpy(xid.data, buf, data_length);
     buf+= data_length;
   }
@@ -2651,8 +2661,11 @@ Gtid_log_event::Gtid_log_event(const uchar *buf, uint event_len,
     */
     if (flags_extra & FL_EXTRA_MULTI_ENGINE)
     {
-      DBUG_ASSERT(static_cast<uint>(buf - buf_0) < event_len);
-
+      if (event_len < static_cast<uint>(buf - buf_0) + 1)
+      {
+        seq_no= 0;
+        return;
+      }
       extra_engines= *buf++;
 
       DBUG_ASSERT(extra_engines > 0);

sql/log_event.h

@@ -3666,7 +3666,16 @@ class Gtid_log_event: public Log_event
   {
     return GTID_HEADER_LEN + ((flags2 & FL_GROUP_COMMIT_ID) ? 2 : 0);
   }
-  bool is_valid() const { return seq_no != 0; }
+
+  bool is_valid() const
+  {
+    /*
+      seq_no is set to 0 if the structure of a serialized GTID event does not
+      align with that as indicated by flags and extra_flags.
+    */
+    return seq_no != 0;
+  }
+
 #ifdef MYSQL_SERVER
   bool write();
   static int make_compatible_event(String *packet, bool *need_dummy_event,

sql/log_event_server.cc

@@ -3411,21 +3411,41 @@ Gtid_log_event::write()
     write_len= GTID_HEADER_LEN + 2;
   }
 
-  if (flags2 & (FL_PREPARED_XA | FL_COMPLETED_XA))
+  if (flags2 & (FL_PREPARED_XA | FL_COMPLETED_XA)
+#ifndef DBUG_OFF
+      && DBUG_EVALUATE_IF("negate_xid_from_gtid", 0, 1)
+#endif
+  )
   {
     int4store(&buf[write_len],   xid.formatID);
     buf[write_len +4]=   (uchar) xid.gtrid_length;
     buf[write_len +4+1]= (uchar) xid.bqual_length;
     write_len+= 6;
     long data_length= xid.bqual_length + xid.gtrid_length;
+
+#ifndef DBUG_OFF
+    if (DBUG_EVALUATE_IF("negate_xid_data_from_gtid", 0, 1))
+    {
+#endif
     memcpy(buf+write_len, xid.data, data_length);
     write_len+= data_length;
+#ifndef DBUG_OFF
+    }
+#endif
   }
+
+  DBUG_EXECUTE_IF("inject_fl_extra_multi_engine_into_gtid", {
+    flags_extra|= FL_EXTRA_MULTI_ENGINE;
+  });
   if (flags_extra > 0)
   {
     buf[write_len]= flags_extra;
     write_len++;
   }
+  DBUG_EXECUTE_IF("inject_fl_extra_multi_engine_into_gtid", {
+    flags_extra&= ~FL_EXTRA_MULTI_ENGINE;
+  });
+
   if (flags_extra & FL_EXTRA_MULTI_ENGINE)
   {
     buf[write_len]= extra_engines;