# # Ensure that Seconds_Behind_Master works correctly on the parallel replica. # --source include/have_log_bin.inc --source include/have_debug.inc --source include/have_debug_sync.inc --source include/master-slave.inc --echo # --echo # MDEV-29639: Seconds_Behind_Master is incorrect for Delayed, Parallel Replicas --echo # # This test ensures that after a delayed parallel slave has idled, i.e. # executed everything in its relay log, the next event group that the SQL # thread reads from the relay log will immediately be used in the # Seconds_Behind_Master. In particular, it ensures that the calculation for # Seconds_Behind_Master is based on the timestamp of the new transaction, # rather than the last committed transaction. # # Note that the test doesn't actually use the value of MASTER_DELAY, but # rather uses debug_sync to coordinate the end of the delay. This is to ensure # that on slow machines, a delay doesn't pass before the test gets a chance to # validate results. Additionally, it lets us continue testing after validation # so we don't have to wait out a full delay unnecessarily. The debug_sync point # is enabled via sql_delay_by_debug_sync, which will delay transactions based # only on GTID events, so only one synchronization is needed per transaction. # --connection slave --source include/stop_slave.inc --let $save_dbug= `SELECT @@GLOBAL.debug_dbug` --let $save_parallel_mode= `SELECT @@GLOBAL.slave_parallel_mode` set @@GLOBAL.slave_parallel_mode= CONSERVATIVE; set @@GLOBAL.debug_dbug= "d,negate_clock_diff_with_master,sql_delay_by_debug_sync"; --let $master_delay= 1 --eval change master to master_delay=$master_delay, master_use_gtid=Slave_Pos --source include/start_slave.inc --connection master --let insert_ctr= 0 create table t1 (a int); create table t2 (a int); --source include/save_master_gtid.inc --connection slave --let $slave_sync_method= gtid --let $num_event_groups= 2 --source include/sync_with_master_sql_delay_debug_sync.inc --echo # --echo # Pt 1) Ensure SBM is updated immediately upon arrival of the next event --connection master --echo # Sleep 2 to allow a buffer between events for SBM check sleep 2; --let $ts_trx_before_ins= `SELECT UNIX_TIMESTAMP()` --eval insert into t1 values ($insert_ctr) --inc $insert_ctr --source include/save_master_gtid.inc --connection slave --echo # Waiting for transaction to arrive on slave and begin SQL Delay.. set debug_sync= "now WAIT_FOR at_sql_delay"; --echo # Validating SBM is updated on event arrival.. --let $sbm_trx1_arrive= query_get_value(SHOW SLAVE STATUS, Seconds_Behind_Master, 1) --let $seconds_since_idling= `SELECT UNIX_TIMESTAMP() - $ts_trx_before_ins` if (`SELECT $sbm_trx1_arrive > ($seconds_since_idling + 1)`) { --echo # SBM was $sbm_trx1_arrive yet shouldn't have been larger than $seconds_since_idling + 1 (for possible negative clock_diff_with_master) --die Seconds_Behind_Master should reset after idling } --echo # ..done --echo # MDEV-33856: New definition for Seconds_Behind_Master --echo # Validating Master_last_event_time is updated on event arrival.. --let $mle_time_trx1_arrive= query_get_value(SHOW ALL SLAVES STATUS, Master_last_event_time, 1) --let $mle_time_trx1_arrive_unix= `SELECT truncate(unix_timestamp("$mle_time_trx1_arrive"), 0)` if (`SELECT $mle_time_trx1_arrive_unix < ($ts_trx_before_ins - 1)`) { --echo # Master_last_event_time: $mle_time_trx1_arrive_unix ($mle_time_trx1_arrive) --die Master_last_event_time was not updated for delayed replica at event arrival time } --echo # ..done --echo # Validating Slave_last_event_time is still from the last transaction.. # Note we infer Slave_last_event_time via Master_Slave_time_diff --let $time_diff_trx1_arrive= query_get_value(SHOW ALL SLAVES STATUS, Master_Slave_time_diff, 1) if ($time_diff_trx1_arrive < 2) { --let $slave_time_trx1_arrive= query_get_value(SHOW ALL SLAVES STATUS, Slave_last_event_time, 1) --let $slave_time_trx1_arrive_unix= `SELECT truncate(unix_timestamp("$slave_time_trx1_arrive"), 0)` --echo # Slave_last_event_time: $slave_time_trx1_arrive_unix ($slave_time_trx1_arrive) --echo # Master_Slave_time_diff: $time_diff_trx1_arrive --die Slave_last_event_time is too recent, should not be less than 2 seconds, ie. from sleeping } --echo # ..done --echo # MDEV-32265. At time of STOP SLAVE, if the SQL Thread is currently --echo # delaying a transaction; then when the reciprocal START SLAVE occurs, --echo # if the event is still to be delayed, SBM should resume accordingly --connection server_2 --echo # Ensure the kill from STOP SLAVE will be received before continuing the --echo # SQL thread set debug_sync="after_thd_awake_kill SIGNAL slave_notified_of_kill"; --send STOP SLAVE --connection slave set debug_sync= "now WAIT_FOR slave_notified_of_kill"; set debug_sync= "now SIGNAL continue_sql_thread"; --connection server_2 --reap --source include/wait_for_slave_to_stop.inc set debug_sync="RESET"; --echo # Lock t1 on slave to ensure the event can't finish (and thereby update --echo # Seconds_Behind_Master) so slow running servers don't accidentally --echo # catch up to the master before checking SBM. --connection server_2 LOCK TABLES t1 WRITE; --source include/start_slave.inc --connection slave --echo # SQL delay has no impact for the rest of the test case, so ignore it --let $slave_sync_method= none --source include/sync_with_master_sql_delay_debug_sync.inc --echo # Waiting for replica to get blocked by the table lock --let $wait_condition= SELECT count(*) FROM information_schema.processlist WHERE state LIKE 'Waiting for table metadata lock'; --source include/wait_condition.inc --echo # Sleeping 1s to increment SBM sleep 1; --echo # Ensuring Seconds_Behind_Master increases after sleeping.. --let $sbm_trx1_after_1s_sleep= query_get_value(SHOW SLAVE STATUS, Seconds_Behind_Master, 1) if (`SELECT $sbm_trx1_after_1s_sleep <= $sbm_trx1_arrive`) { --echo # ..failed --die Seconds_Behind_Master did not increase after sleeping, but should have } --echo # ..done --connection server_2 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)` if ($slave_time_trx1_commit_unix != $mle_time_trx1_arrive_unix) { --echo # Slave_last_event_time: $slave_time_trx1_commit_unix ($slave_time_trx1_commit) --echo # Master_last_event_time: $mle_time_trx1_arrive_unix ($mle_time_trx1_arrive) --die Slave_last_event_time is not equal to Master_last_event_time despite being up-to-date } --let $time_diff_trx1_commit= query_get_value(SHOW ALL SLAVES STATUS, Master_Slave_time_diff, 1) if ($time_diff_trx1_commit != 0) { --echo # Master_Slave_time_diff: $time_diff_trx1_commit --die Master_Slave_time_diff should be 0, as slave is up-to-date } --echo # ..done --echo # --echo # Pt 2) If the worker threads have not entered an idle state, ensure --echo # following events do not update SBM --connection slave LOCK TABLES t1 WRITE; --connection master --echo # Sleep 2 to allow a buffer between events for SBM check sleep 2; --let $ts_trxpt2_before_ins= `SELECT UNIX_TIMESTAMP()` --eval insert into t1 values ($insert_ctr) --inc $insert_ctr --echo # Sleep 3 to create gap between events sleep 3; --eval insert into t1 values ($insert_ctr) --inc $insert_ctr --let $ts_trx_after_ins= `SELECT UNIX_TIMESTAMP()` --source include/save_master_pos.inc --connection slave --echo # Wait for first transaction to complete SQL delay and begin execution.. --let $slave_sync_method= none --source include/sync_with_master_sql_delay_debug_sync.inc --let $wait_condition= SELECT count(*) FROM information_schema.processlist WHERE state LIKE 'Waiting for table metadata lock%' AND command LIKE 'Slave_Worker'; --source include/wait_condition.inc --echo # Wait for second transaction to complete SQL delay.. --source include/sync_with_master_sql_delay_debug_sync.inc --echo # Validate SBM calculation doesn't use the second transaction because worker threads shouldn't have gone idle.. --let $sbm_after_trx_no_idle= query_get_value(SHOW SLAVE STATUS, Seconds_Behind_Master, 1) --let $timestamp_trxpt2_arrive= `SELECT UNIX_TIMESTAMP()` if (`SELECT $sbm_after_trx_no_idle < $timestamp_trxpt2_arrive - $ts_trx_after_ins - 1`) { --let $cmpv= `SELECT $timestamp_trxpt2_arrive - $ts_trx_after_ins` --echo # SBM $sbm_after_trx_no_idle was more recent than time since last transaction ($cmpv seconds) --die Seconds_Behind_Master should not have used second transaction timestamp } --let $seconds_since_idling= `SELECT ($timestamp_trxpt2_arrive - $ts_trxpt2_before_ins)` --echo # ..and that SBM wasn't calculated using prior committed transactions if (`SELECT $sbm_after_trx_no_idle > ($seconds_since_idling + 1)`) { --echo # SBM was $sbm_after_trx_no_idle yet shouldn't have been larger than $seconds_since_idling + 1 (for possible negative clock_diff_with_master) --die Seconds_Behind_Master calculation should not have used prior committed transaction } --echo # ..done --connection slave UNLOCK TABLES; --source include/sync_with_master.inc --echo # Cleanup --source include/stop_slave.inc set debug_sync= "RESET"; set @@GLOBAL.debug_dbug= "-d,sql_delay_by_debug_sync"; --eval CHANGE MASTER TO master_delay=0 --source include/start_slave.inc --echo # --echo # MDEV-30619: Parallel Slave SQL Thread Can Update Seconds_Behind_Master with Active Workers --echo # # This test ensures that a parallel slave will not update # Seconds_Behind_Master after the SQL Thread has idled if the worker threads # are still executing events. To test this, two events are executed on the # primary with $sleep seconds in-between them. Once the second event begins # execution on the replica, Seconds_Behind_Master is queried to ensure it # reflects the value of the first transaction, rather than the second. --connection slave --echo # Ensure the replica is fully idle before starting transactions --let $wait_condition= SELECT count(*) FROM information_schema.processlist WHERE state LIKE 'Slave has read all relay log%'; --source include/wait_condition.inc --let $wait_condition= SELECT count(*)=2 FROM information_schema.processlist WHERE state LIKE 'Waiting for work from SQL thread'; --source include/wait_condition.inc --echo # Lock t1 on slave so the first received transaction does not complete/commit LOCK TABLES t1 WRITE; --connection master --let $ts_t1_before_master_ins= `SELECT UNIX_TIMESTAMP()` --eval insert into t1 values ($insert_ctr) --inc $insert_ctr --source include/save_master_gtid.inc --connection slave --echo # Waiting for first transaction to begin.. --let $wait_condition= SELECT count(*) FROM information_schema.processlist WHERE state LIKE 'Waiting for table metadata lock'; --source include/wait_condition.inc --let $sbm_1= query_get_value(SHOW SLAVE STATUS, Seconds_Behind_Master, 1) --connection master --let $sleep = 2 --echo # Sleep $sleep sec to create a gap between events sleep $sleep; INSERT INTO t2 VALUES (1); --source include/save_master_gtid.inc --connection slave --echo # Waiting for second transaction to begin.. --let $wait_condition= SELECT count(*) FROM information_schema.processlist WHERE state LIKE 'Waiting for prior transaction to start commit%'; --source include/wait_condition.inc --let $sbm_2= query_get_value(SHOW SLAVE STATUS, Seconds_Behind_Master, 1) if (`SELECT $sbm_1 + $sleep > $sbm_2`) { --echo # Seconds_Behind_Masters: $sbm_1 $sbm_2_0 --die Two successive Seconds_Behind_Master timestamps must be separated by the sleep parameter value or greater } --connection slave UNLOCK TABLES; --source include/sync_with_master_gtid.inc --echo # --echo # Cleanup --connection master DROP TABLE t1, t2; --source include/save_master_gtid.inc --connection slave --source include/sync_with_master_gtid.inc --source include/stop_slave.inc --eval set @@GLOBAL.debug_dbug= "$save_dbug" --evalp set @@GLOBAL.slave_parallel_mode= "$save_parallel_mode" --source include/start_slave.inc --source include/rpl_end.inc --echo # End of rpl_parallel_sbm.test