mariadb/mysql-test/suite/rpl/r/rpl_heartbeat_at_rotate.result
Brandon Nesterenko a394fc0270 MDEV-29981: Replica stops with "Found invalid event in binary log"
Replication can stop in error if a Heartbeat log event is sent to a
replica during rotation. There are two bugs at play:

  1. Prior to MDEV-30128 (added in 11.0), there is a bug when checking
     legacy events. When the replica rotates its relay logs, it
     initializes its Format_description_log_event with binlog version 3
     (this is hard-coded). So immediately after rotation (and until a
     new Format_descriptor with binlog_format 4 is sent from the
     master), the IO thread is expecting binlog_format 3 (i.e. it will
     call queue_old_event() for incoming events). This invalidates any
     events that are sent with an event type higher than 14. In theory,
     we wouldn't expect any events to be sent in-between a rotate and
     the next format descriptor log event, but if a long enough period
     of time passes between then, the primary will generate and send a
     Heartbeat event (of type 27). In such case, the slave will see the
     heartbeat event of type 27, see it is higher than 14, and result
     in an error mentioning 'Found invalid event in binary log', with
     the expected log coordinates of the new log (which is
     optimistically populated from the Rotate log event, not the new
     event).

  2. In all versions of MariaDB (11.0+), there is a bug when checking
     the state of a Heartbeat log event, in that it doesn't consider a
     rotated binary log. The check is meant to ensure that the
     heartbeat provided by the master (i.e. the state of the master) is
     greater than or equal to the state of the slave. In other words,
     it checks that the slave isn't ahead of the master. However, if
     the filename provided by the master heartbeat event is different
     than the filename saved for the slave's state, the check always
     fails. This is broken, because when the master rotates its logs,
     the new binary log file will have a different filename (i.e. an
     incremented index counter suffix). For example, if the master
     rotates its binary logs from master-bin.000002 to
     master-bin.000003, master-bin.000003 is ahead of
     master-bin.000002, but the slave will see a difference between the
     filenames and fail the check.

To fix the first problem, this patch disallows passing a heartbeat
event into queue_old_event (which is the source of the error, as it
tries to parse a heartbeat log event). This function (queue_old_event)
was removed with MDEV-30128, so bypassing it for heartbeat events is
not consequential (and it is already also done for
Format_description_events, which are not supported in old binlog file
versions). Note that backporting all of MDEV-30128 was also considered,
but this is less risky for GA.

To fix the second problem, we simply ignore heartbeat events on the
slave if the filenames don't match. This is because during rotation,
it can appear that the slave is ahead of the master, which breaks the
validity of the check (i.e. the check is to ensure the master is
ahead of the slave).

Additionally note that this patch restores a heartbeat check that was
incorrectly removed in 780db8e252

Reviewed-by: Andrei Elkin <andrei.elkin@mariadb.com>
Signed-off-by: Brandon Nesterenko <brandon.nesterenko@mariadb.com>
2025-08-22 15:04:02 -06:00

38 lines
1.1 KiB
Text

# Binlog format independent
include/master-slave.inc
[connection master]
#
# Initialize test data
connection slave;
include/stop_slave.inc
change master to master_heartbeat_period=2;
include/start_slave.inc
# Rotating master logs and pausing after Rotate_event is written..
connection master;
set @old_dbug= @@global.debug_dbug;
set @@global.debug_dbug= "+d,stop_after_rotate_written";
flush binary logs;
# Waiting for Rotate event to write/sync to disk
connection server_1;
set debug_sync="now wait_for rotate_written";
# Sleep 3s so the master sends a heartbeat event to the slave
connection server_1;
set debug_sync="now signal finish_rotate";
connection master;
set @@global.debug_dbug= @old_dbug;
#
# Ensure replication continues without error..
connection master;
create table t1 (a int);
insert into t1 values (1);
connection slave;
include/diff_tables.inc [master:test.t1,slave:test.t1]
#
# 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_heartbeat_at_rotate.test