Skip to content

Commit

Permalink
MDEV-35939: rpl.rpl_parallel_sbm: "Slave_last_event_time is not equal…
Browse files Browse the repository at this point in the history
… to Master_last_event_time"

The test rpl.rpl_parallel_sbm would fail because
Slave_last_event_time would not match Master_last_event_time after
syncing with the master (i.e. via sync_with_master_gtid.inc). This
happens because the timing statistics are updated after updating
gtid_slave_pos. That is, gtid_slave_pos is updated with the
transaction commit, whereas the timing statistics are updated when
the relay log position is updated (i.e. after the commit). This is
by design. For the test, this means there is a small amount of time
after sync_with_master_gtid.inc where the SHOW SLAVE STATUS output
lags behind the data state of the slave. This would cause the test
to fail if comparing Slave_last_event_time to Master_last_event_time
during this period, because Slave_last_event_time would not yet
reflect the latest committed transaction.

The fix is to add a wait_condition before the comparison to wait for
the SHOW SLAVE STATUS statistics to be updated. The actual check is
to wait for Seconds_Behind_Master == 0, because the slave should be
idle at this point, which forces the value to be 0.

The test failure can be reproduced with the following patch:

diff --git a/sql/rpl_gtid.cc b/sql/rpl_gtid.cc
index db5c26b6237..b346a32b573 100644
--- a/sql/rpl_gtid.cc
+++ b/sql/rpl_gtid.cc
@@ -300,6 +300,7 @@ rpl_slave_state::update(uint32 domain_id, uint32 server_id, uint64 sub_id,
   mysql_mutex_lock(&LOCK_slave_state);
   res= update_nolock(domain_id, server_id, sub_id, seq_no, hton, rgi);
   mysql_mutex_unlock(&LOCK_slave_state);
+  sleep(1);
   return res;
 }
  • Loading branch information
bnestere committed Jan 26, 2025
1 parent 195dcfe commit 01fafd4
Show file tree
Hide file tree
Showing 2 changed files with 10 additions and 0 deletions.
1 change: 1 addition & 0 deletions mysql-test/suite/rpl/r/rpl_parallel_sbm.result
Original file line number Diff line number Diff line change
Expand Up @@ -68,6 +68,7 @@ connection server_2;
UNLOCK TABLES;
include/sync_with_master_gtid.inc
# MDEV-33856: New definition for Seconds_Behind_Master
# Waiting for slave timing statistics to update ..
# Ensuring Slave_last_event_time is now up-to-date once event is executed
# ..done
#
Expand Down
9 changes: 9 additions & 0 deletions mysql-test/suite/rpl/t/rpl_parallel_sbm.test
Original file line number Diff line number Diff line change
Expand Up @@ -154,6 +154,15 @@ UNLOCK TABLES;
--source include/sync_with_master_gtid.inc

--echo # MDEV-33856: New definition for Seconds_Behind_Master

# The update of slave timing statistics (Seconds_Behind_Master,
# Slave_last_event_time, etc) lags slightly behind the update of
# gtid_slave_pos (we just called sync_with_master_gtid), so wait for SBM==0 to
# indicate the statistics have been updated
--echo # Waiting for slave timing statistics to update ..
--let $wait_condition= SELECT count(*) FROM information_schema.slave_status WHERE Seconds_Behind_Master=0
--source include/wait_condition.inc

--echo # Ensuring Slave_last_event_time is now up-to-date once event is executed
--let $slave_time_trx1_commit= query_get_value(SHOW ALL SLAVES STATUS, Slave_last_event_time, 1)
--let $slave_time_trx1_commit_unix= `SELECT truncate(unix_timestamp("$slave_time_trx1_commit"),0)`
Expand Down

0 comments on commit 01fafd4

Please sign in to comment.