Replication Undefined Behavior on Malformed Rotate Log Event

An event whose two statements of its own length disagree is accepted by the
receiver and written into the relay log as it arrived. Three consequences
follow.

• The SQL thread reads the relay log using the header lengths, so it starts its
  next read inside the previous event and fails there. Replication stops with a
  relay log read failure, and the file and position it reports for the failure
  are not where the problem is.
• The bytes the SQL thread lands on are source-supplied, because they are part
  of the Rotate event's binlog file name, so a source can place a complete event
  with a valid checksum at that offset and have the replica apply an event that
  never appeared in the source's own binlog. Note that a source can already send
  whatever events it likes, so this is not an escalation of what it can make a
  replica execute. What it defeats is comparing the replica's applied stream
  against the source's binlog afterwards.
• It is the precondition that makes MDEV-40492 reachable with a size the source
  chooses, because the fake Rotate handling there memcpys using the packet length
  while rewriting the header length. Fixing the bound in MDEV-40492 stops that
  overflow; adding this check removes the disagreement that made it useful.

event_len in queue_event() is the packet length: read_event()
returns len - 1 from cli_safe_read_reallen()
(sql/slave.cc:3817). The event header separately declares its own length
at EVENT_LEN_OFFSET. Nothing reconciles the two. The only sites touching
EVENT_LEN_OFFSET in sql/slave.cc are the fake-Rotate rewrites at
:6716 and :6739, and two DBUG_ASSERTs at :6721 and :6741,
which are debug only and which nothing maintains.

Rotate_log_event's reader states the requirement and relies on it
(sql/log_event.cc:2587):

  // The caller will ensure that event_len is what we have at EVENT_LEN_OFFSET

The caller does not ensure it.

The check applies to the event types queue_event() builds without the
general deserialization path. In MariaDB that set is ROTATE_EVENT,
HEARTBEAT_LOG_EVENT and GTID_EVENT. It is not upstream's set of six: MariaDB
has no TRANSACTION_PAYLOAD_EVENT or ANONYMOUS_GTID_LOG_EVENT, and its
GTID_LIST_EVENT and FORMAT_DESCRIPTION_EVENT go through
Log_event::read_log_event().

The shape to add is a rejection of
event_len < LOG_EVENT_MINIMAL_HEADER_LEN || event_len != uint4korr(buf + EVENT_LEN_OFFSET)
for those types, which also turns the two existing DBUG_ASSERTs into
invariants something maintains.

All maintained branches are affected.

To reproduce:

The injection declares a shorter length in the header while leaving the packet
intact, in send_event_to_slave(), which every real event passes through.
Note that fix_checksum() cannot be used here, because it derives the length
it covers from EVENT_LEN_OFFSET, which is the field being falsified. The
receiver checks the checksum against the packet length, so recomputing over the
packet is what lets the event through.

Patch file:

--- a/sql/sql_repl.cc

+++ b/sql/sql_repl.cc

@@ send_event_to_slave(), before my_net_write()

+  DBUG_EXECUTE_IF("binlog_sender_short_event_len",

+  {

+    if (event_type == ROTATE_EVENT)

+    {

+      char *ev= (char*) packet->ptr() + ev_offset;

+      ulong plen= (ulong) (packet->length() - ev_offset);

+      int4store(ev + EVENT_LEN_OFFSET, plen - 8);

+      if (current_checksum_alg != BINLOG_CHECKSUM_ALG_OFF &&

+          current_checksum_alg != BINLOG_CHECKSUM_ALG_UNDEF)

+        int4store(ev + plen - BINLOG_CHECKSUM_LEN,

+                  my_checksum(0, (uchar*) ev, plen - BINLOG_CHECKSUM_LEN));

+    }

+  });

Test file:

--source include/have_debug.inc

--source include/have_binlog_format_row.inc

--source include/master-slave.inc

--connection master

create table t1 (a int);

insert into t1 values (1);

--source include/save_master_gtid.inc

--connection slave

--source include/sync_with_master_gtid.inc

--connection master

set @@global.debug_dbug= "+d,binlog_sender_short_event_len";

# The SQL thread stays stopped, so the relay log the receiver damages is never

# read. Reading it is the second consequence above and not what this asserts.

--connection slave

--source include/stop_slave_sql.inc

--source include/stop_slave_io.inc

START SLAVE IO_THREAD;

--source include/wait_for_slave_io_to_start.inc

--connection master

FLUSH LOGS;

# The receiver adopts the new binlog name from an event whose two length

# statements disagree, and reports no error for it.

--connection slave

--let $slave_param= Master_log_file

--let $slave_param_value= master-bin.000002

--source include/wait_for_slave_param.inc

--let $io_errno= query_get_value(SHOW SLAVE STATUS, Last_IO_Errno, 1)

--let $assert_text= The IO thread reported no error for the length mismatch

--let $assert_cond= "$io_errno" = "0"

--source include/assert.inc

The test asserts what the receiver does today, which is accept the event. Once
the check exists the IO thread rejects it with 1595 and the assertions have to
be inverted. RESET SLAVE drops the damaged relay log during cleanup, and
gtid_slave_pos survives that, so replication resumes from what the SQL
thread had applied before the injection.