Add MDEV-25999 & MDEV-36840 to MDEV-16091’s test

1. Stricten MDEV-16091’s `rpl.rpl_seconds_behind_master_spike`
   to prove that its fix covered MDEV-25999 as well
2. Add a Parallel Replication variant via a new `.combinations` file;
   its current failure confirm MDEV-36840.

Because Parallel Replication queues Format Description Events as
position update metaevents, this variant uses a separate set of API-
compatible breakpoints to pause both the main and worker threads.
To support them, this commit replaces the MDEV-33327 patch c75905c
with a live-activation solution. In contrast, previous iterations queued
the activation pre-test and relied on other factors to enable the break.

Reviewed-by: Brandon Nesterenko <brandon.nesterenko@mariadb.com>

Author: ParadoxV5

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

@@ -4,17 +4,18 @@ connection slave;
 include/stop_slave.inc
 CHANGE MASTER TO MASTER_USE_GTID=NO;
 include/start_slave.inc
-include/stop_slave.inc
-SET @save_dbug= @@GLOBAL.debug_dbug;
-SET @@global.debug_dbug="+d,pause_sql_thread_on_relay_fde_after_trans";
-SET @@global.debug_dbug="+d,negate_clock_diff_with_master";
-include/start_slave.inc
 # Future events must be logged at least 2 seconds after
 # the slave starts
 connection master;
 # Write events to ensure slave will be consistent with master
 create table t1 (a int);
 insert into t1 values (1);
+connection slave;
+# Enable breakpoints
+SET @save_dbug= @@GLOBAL.debug_dbug;
+SET @@GLOBAL.debug_dbug=
+'+d,pause_sql_thread_on_fde,negate_clock_diff_with_master';
+connection master;
 # Flush logs on master forces slave to generate a Format description
 # event in its relay log
 flush logs;
@@ -26,8 +27,8 @@ count(*)=1
 1
 # The relay log FDE has been processed - here we check to ensure it was
 # not considered in Seconds_Behind_Master calculation
-connection slave1;
-# Safely resume slave SQL thread
+Seconds_Behind_Master = '0'
+# Safely resume slave SQL (worker) thread
 # Prove SQL thread is in state "debug sync point: now"
 SET @@global.debug_dbug="-d,pause_sql_thread_on_fde";
 SET DEBUG_SYNC='now SIGNAL sql_thread_continue';

mysql-test/suite/rpl/t/rpl_seconds_behind_master_spike.combinations

@@ -0,0 +1,5 @@
+[serial]
+--slave-parallel-threads=0
+
+[parallel]
+--slave-parallel-threads=1

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

@@ -18,6 +18,8 @@
 #
 # References:
 #   MDEV-16091: Seconds_Behind_Master spikes to millions of seconds
+#   MDEV-25999: Unrealistic "Seconds behind master" value
+#   MDEV-36840: Seconds_Behind_Master Spike at Log Rotation on Parallel Replica
 #
 --source include/have_debug.inc
 --source include/have_debug_sync.inc
@@ -31,12 +33,6 @@
 CHANGE MASTER TO MASTER_USE_GTID=NO;
 --source include/start_slave.inc
 
---source include/stop_slave.inc
-SET @save_dbug= @@GLOBAL.debug_dbug;
-SET @@global.debug_dbug="+d,pause_sql_thread_on_relay_fde_after_trans";
-SET @@global.debug_dbug="+d,negate_clock_diff_with_master";
---source include/start_slave.inc
-
 --let $sleep_time=2
 --echo # Future events must be logged at least $sleep_time seconds after
 --echo # the slave starts
@@ -46,33 +42,38 @@ SET @@global.debug_dbug="+d,negate_clock_diff_with_master";
 --echo # Write events to ensure slave will be consistent with master
 create table t1 (a int);
 insert into t1 values (1);
---let $t_master_events_logged= `SELECT UNIX_TIMESTAMP()`
+--sync_slave_with_master
+let $wait_condition= SELECT STATE LIKE '%waiting for more updates'
+  FROM information_schema.PROCESSLIST WHERE COMMAND = 'Slave_SQL';
+--source include/wait_condition.inc
+
+--echo # Enable breakpoints
+SET @save_dbug= @@GLOBAL.debug_dbug;
+SET @@GLOBAL.debug_dbug=
+  '+d,pause_sql_thread_on_fde,negate_clock_diff_with_master';
 
+--connection master
 --echo # Flush logs on master forces slave to generate a Format description
 --echo # event in its relay log
 flush logs;
 
 --connection slave
 --echo # On the next FDE, the slave should have the master CREATE/INSERT events
+--sleep $sleep_time
 SET DEBUG_SYNC='now WAIT_FOR paused_on_fde';
 select count(*)=1 from t1;
 
 --echo # The relay log FDE has been processed - here we check to ensure it was
 --echo # not considered in Seconds_Behind_Master calculation
---connection slave1
-let $sbm= query_get_value(SHOW SLAVE STATUS, Seconds_Behind_Master, 1);
---let $t_now= `SELECT UNIX_TIMESTAMP()`
-
-# Ensure Seconds_Behind_Master does not point beyond when we have proven the
-# events we have proven to have executed. The extra second is needed as a
-# buffer because the recorded times are not exact with when the events were
-# recorded on the master.
-if(`select $sbm > $t_now - $t_master_events_logged + 1`)
-{
-    die "A relay log event was incorrectly used to set Seconds_Behind_Master";
-}
-
---echo # Safely resume slave SQL thread
+# `Seconds_Behind_Master` must remains 0.
+# * MDEV-16091: `Seconds_Behind_Master` should not point at the FDE's timestamp,
+#   which is the time of `start_slave.inc`.
+# * MDEV-25999 & MDEV-36840: For a new event stream, `Seconds_Behind_Master`
+#   should not point at anything at all, because FDEs are not user content.
+--let $status_items= Seconds_Behind_Master
+--source include/show_slave_status.inc
+
+--echo # Safely resume slave SQL (worker) thread
 
 --let $dbug_wait_state="debug sync point: now"
 --echo # Prove SQL thread is in state $dbug_wait_state

sql/rpl_parallel.cc

@@ -104,6 +104,17 @@ handle_queued_pos_update(THD *thd, rpl_parallel_thread::queued_event *qev)
       (e->force_abort && !rli->stop_for_until))
     return;
 
+  #ifdef ENABLED_DEBUG_SYNC
+    DBUG_EXECUTE_IF("pause_sql_thread_on_fde",
+      DBUG_ASSERT(!debug_sync_set_action(thd, STRING_WITH_LEN(
+        "now SIGNAL paused_on_fde WAIT_FOR sql_thread_continue"
+      )));
+      DBUG_ASSERT(!debug_sync_set_action(thd, STRING_WITH_LEN(
+        "now SIGNAL main_sql_thread_continue"
+      )));
+    );
+  #endif
+
   mysql_mutex_lock(&rli->data_lock);
   cmp= compare_log_name(rli->group_relay_log_name, qev->event_relay_log_name);
   if (cmp < 0)

sql/slave.cc

@@ -4481,6 +4481,12 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli,
         rli->event_relay_log_pos= rli->future_event_relay_log_pos;
       if (res >= 0)
       {
+        DBUG_EXECUTE_IF("pause_sql_thread_on_fde",
+          if (typ == FORMAT_DESCRIPTION_EVENT)
+            DBUG_ASSERT(!debug_sync_set_action(thd, STRING_WITH_LEN(
+              "now WAIT_FOR main_sql_thread_continue"
+            )));
+        );
 #ifdef WITH_WSREP
 	wsrep_after_statement(thd);
 #endif /* WITH_WSREP */
@@ -4511,15 +4517,6 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli,
     {
       Gtid_log_event *gev= static_cast<Gtid_log_event *>(ev);
 
-#ifdef ENABLED_DEBUG_SYNC
-    DBUG_EXECUTE_IF(
-        "pause_sql_thread_on_relay_fde_after_trans",
-        {
-          DBUG_SET("-d,pause_sql_thread_on_relay_fde_after_trans");
-          DBUG_SET("+d,pause_sql_thread_on_next_relay_fde");
-        });
-#endif
-
       /*
         For GTID, allocate a new sub_id for the given domain_id.
         The sub_id must be allocated in increasing order of binlog order.
@@ -4671,16 +4668,13 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli,
     wsrep_after_statement(thd);
 #endif /* WITH_WSREP */
 #ifdef ENABLED_DEBUG_SYNC
-    DBUG_EXECUTE_IF(
-        "pause_sql_thread_on_next_relay_fde",
-        if (ev && typ == FORMAT_DESCRIPTION_EVENT &&
-            ((Format_description_log_event *) ev)->is_relay_log_event()) {
-          DBUG_ASSERT(!debug_sync_set_action(
-              thd,
-              STRING_WITH_LEN(
-                  "now SIGNAL paused_on_fde WAIT_FOR sql_thread_continue")));
-          DBUG_SET("-d,pause_sql_thread_on_next_relay_fde");
-        });
+    // Note: Parallel Replication does not hit this point.
+    DBUG_EXECUTE_IF("pause_sql_thread_on_fde",
+      if (typ == FORMAT_DESCRIPTION_EVENT)
+        DBUG_ASSERT(!debug_sync_set_action(thd, STRING_WITH_LEN(
+          "now SIGNAL paused_on_fde WAIT_FOR sql_thread_continue"
+        )));
+    );
 #endif
 
     DBUG_RETURN(exec_res);