BUG#36507020: relay_log_space_limit GTID and large txns may lead to no channel progress

Problem
-------

When running GTID-based replication with the 'relay_log_space_limit'
enabled, restarting the auto positioning protocol may cause a
deadlock (infinite loop) in the replication.

Analysis
--------

When receiver is waiting for available relay log space,
it may happen that the connected dump thread times out while
sending data due to reaching the 'net_write_timeout'.
After receiver wakes up, it writes a part of a trasaction
into the relay log, notices that connection is
down and reconnects to the source. Under a tight limit of
the 'relay_log_space_limit', when only one large transaction
fits into the relay log, recevier and coordinator enter
a sequential mode of execution:
- receiver waits for available storage
- applier either releases the storage or, when reaching the
  state to waiting for a new event, tells receiver
  to schedule one more.
If part of the next transaction entered the relay log
after a large transaction, and applying this unfinished
transaction takes more time than 'net_write_timeout',
the receiver (waiting for available relay log space),
applier (which cannot purge whilst being inside of
transaction boundary) and dump thread (having restrictions on
'net_write_timeout'), enter an infinite loop of:
- receiver writes a part of transaction to the relay log
- receiver waits for available storage or notification to
  schedule one more event
- applier starts applying an unfinished transaction
- dump thread reaches the 'net_write_timeout'
- applier finishes applying a part of a transaction and
  reaches the state of waiting for new events, notifies
  the reader to queue one more
- receiver wakes up, auto positioning protocol restarts at
  beginning of the transaction
- receiver writes a part of transaction to the relay log, but
  afterwards hits the limit of 'relay_log_space_limit'
- ...

Before this patch, the 'relay_log_space_limit' was
not respected not only for transactions which
size exceed the 'relay_log_space_limit', but also
when replica could not purge previous logs.

Solution
--------

As a solution to the bug fix, we introduce
the following changes:

Receiver will respect the 'relay_log_space_limit' set
by the user, unless a transaction received by the
receiver cannot fit into the purged relay log.
Before queueing the received transaction,
receiver checks whether scheduling a full transaction is
possible. If not, the receiver:
- sets the flag indicating that recevier is waiting
- rotates the relay log
- waits until notified that relay log purge was executed
  and applier has purged all available relay logs
Afterwards, receiver may queue a transaction, without
checking the limit again.

Before moving to the next file, the coordinator will check
if receiver is waiting for available relay log space.
If yes, the coordinator will forcibly purge applied logs
including the current relay log file. To safely
purge the current relay log file the coordinator must
- synchronize all of its workers before moving to
  the next file
- forcibly update group positions, which is necessary
  to allow current purging of the relay log
- update the variable read by the receiver which
  contains relay log filename to which applier
  was moved
Those operations are allowed because we know that
receiver waits at a transaction boundary and
rotates the relay log before waiting.

Therefore, in this patch, we remove the existing
logic coordinating the coordinator and the
recevier which ignore the relay log space limit
for one event at a time, until we are able to
purge the relay log and reclaim space for the
next event. We respect the available relay log
space, unless this is no longer possible because
a large transaction was received and even though
all relay logs was removed, it still cannot fit
into available limit.

Note about behavior change
--------------------------

Before this patch, the 'relay_log_space_limit' was
not respected not only for transactions which
size exceed the 'relay_log_space_limit', but also
when replica could not purge previous logs.

After this patch, the relay log can grow only up to
max(relay_log_space_limit, max_transaction_size + size required to
write relay log header, FDE, RLE, PGLE and 1 GTID for an unfinished
transaction in case dump thread disconnects while replica is waiting
for available space).

Note about change compared to previous push
-------------------------------------------

This patch addresses two problems in the previous, reverted push:

 1. The previous patch made the applier segfault when the receiver
    waits for relay log space, in case replica_parallel_workers=0.
    This made e.g. rpl.rpl_stm_relay_ign_space fail when executed with
    --replica-parallel-workers=0.

    The problem was that, when the applier reached EOF while the
    receiver was waiting for relay log space, the applier would call
    m_rli->current_mts_mode->wait_for_workers_to_finish.  But when
    replica_parallel_workers==0, current_mts_mode==nullptr.

    Fixed by calling
    m_rli->current_mts_mode->wait_for_workers_to_finish only when
    replica_parallel_workers>0.

 2. The previous patch would time out in a number of test cases having
    partial transactions, in 8.0 but not in 8.4 and trunk.

    The problem was that the new member
    Relay_log_info::is_receiver_waiting_for_rl_space, of type
    std::atomic<bool>, was not explicitly initialized.  In 8.0, a
    default-constructed std::atomic<bool> leaves the value
    uninitialized, so therefore the initial value could, by chance,
    evaluate to true, which broke the logic of this variable.  This
    did not occur in 8.4 and trunk, because they use C++20, where
    default-constructed std::atomic objects are initialized to the
    default value of the underlying type.

    Fixed by explicitly initialzing the member to false.

Change-Id: I6bcaa312e1159d9b16bb19cf292272e82440dc49

Author: Sven Sandberg

libbinlogevents/include/binlog_event.h

@@ -365,6 +365,20 @@ enum Log_event_type {
   ENUM_END_EVENT /* end marker */
 };
 
+/// @brief Event type helpers, enclosed in the structure
+struct Log_event_type_helper {
+  /// @brief Helps to identify known GTID event - returns true
+  /// for GTID_LOG_EVENT and GTID_TAGGED_LOG_EVENT
+  inline static bool is_assigned_gtid_event(const Log_event_type &type) {
+    return type == GTID_LOG_EVENT;
+  }
+  /// @brief Helps to identify any GTID event - returns true
+  /// for GTID_LOG_EVENT, GTID_TAGGED_LOG_EVENT and ANONYMOUS_GTID_LOG_EVENT
+  inline static bool is_any_gtid_event(const Log_event_type &type) {
+    return is_assigned_gtid_event(type) || type == ANONYMOUS_GTID_LOG_EVENT;
+  }
+};
+
 /**
   Struct to pass basic information about a event: type, query, is it ignorable
 */

libbinlogevents/include/control_events.h

@@ -1172,6 +1172,9 @@ class Gtid_event : public Binary_log_event {
     transaction_length = transaction_length_arg;
   }
 
+  /// @return The value of the `transaction_length` field.
+  unsigned long long get_trx_length() const { return transaction_length; }
+
   /** The version of the server where the transaction was originally executed */
   uint32_t original_server_version;
   /** The version of the immediate server */

mysql-test/include/assert_grep.inc

@@ -9,7 +9,7 @@
 # --let $assert_text= TEXT
 # --let $assert_file= FILE
 # --let $assert_select= REGEX
-# [--let $assert_match= REGEX | --let $assert_count= NUMBER]
+# [--let $assert_match= REGEX | --let $assert_count= NUMBER | --let $assert_count_condition= CONDITION]
 # [--let $assert_only_after= REGEX]
 # --source include/assert_grep.inc
 #
@@ -35,6 +35,14 @@
 #     $assert_match, assert that there were exactly $assert_count
 #     matching lines.
 #
+#   $assert_count_condition
+#     Instead of asserting that the selected lines match
+#     $assert_match, assert that $assert_count_condition is met for
+#     the number of matching lines. The 'assert_count_condition'
+#     must be a valid Perl expression, which consists of an operator and
+#     right side expression - an integer.
+#     For example, 'assert_count_condition' may be <= 1.
+#
 #   $assert_only_after
 #     Reset all the lines matched and the counter when finding this pattern.
 #     It is useful for searching things in the mysqld.err log file just
@@ -58,18 +66,27 @@ if ($assert_match == '')
 {
   if ($assert_count == '')
   {
-    --die !!!ERROR IN TEST: you must set either $assert_match or $assert_count
-  }
-}
-if ($assert_match != '')
-{
-  if ($assert_count != '')
-  {
-    --echo assert_text='$assert_text' assert_count='$assert_count'
-    --die !!!ERROR IN TEST: you must set only one of $assert_match or $assert_count
+    if ($assert_count_condition == '')
+    {
+      --die !!!ERROR IN TEST: you must set either $assert_match or $assert_count or $assert_count_condition
+    }
   }
 }
 
+--let $_ag_assert_count = 0
+if ($assert_match != '') {
+  --inc $_ag_assert_count
+}
+if ($assert_count != '') {
+  --inc $_ag_assert_count
+}
+if ($assert_count_condition != '') {
+  --inc $_ag_assert_count
+}
+if ($_ag_assert_count != 1) {
+  --echo assert_text='$assert_text' assert_match='$assert_match' assert_count='$assert_count' assert_count_condition='$assert_count_condition'
+  --die !!!ERROR IN TEST: you must set exactly one of $assert_match, $assert_count or $assert_count_condition
+}
 
 --let $include_filename= assert_grep.inc [$assert_text]
 --source include/begin_include_file.inc
@@ -80,6 +97,7 @@ if ($assert_match != '')
 --let _AG_ASSERT_SELECT= $assert_select
 --let _AG_ASSERT_MATCH= $assert_match
 --let _AG_ASSERT_COUNT= $assert_count
+--let _AG_ASSERT_COUNT_CONDITION= $assert_count_condition
 --let _AG_OUT= `SELECT CONCAT('$MYSQLTEST_VARDIR/tmp/_ag_', UUID())`
 --let _AG_ASSERT_ONLY_AFTER= $assert_only_after
 
@@ -91,12 +109,16 @@ if ($assert_match != '')
   my $assert_select= $ENV{'_AG_ASSERT_SELECT'};
   my $assert_match= $ENV{'_AG_ASSERT_MATCH'};
   my $assert_count= $ENV{'_AG_ASSERT_COUNT'};
+  my $assert_count_condition= $ENV{'_AG_ASSERT_COUNT_CONDITION'};
   my $assert_only_after= $ENV{'_AG_ASSERT_ONLY_AFTER'};
   my $out= $ENV{'_AG_OUT'};
 
   if (!defined($assert_count)) {
     $assert_count = '';
   }
+  if (!defined($assert_count_condition)) {
+    $assert_count_condition = '';
+  }
 
   my $result= '';
   my $count= 0;
@@ -109,7 +131,7 @@ if ($assert_match != '')
       $count = 0;
     }
     if ($line =~ /$assert_select/) {
-      if ($assert_count ne '') {
+      if ($assert_count ne '' || $assert_count_condition ne '') {
         $count++;
       }
       else {
@@ -122,7 +144,12 @@ if ($assert_match != '')
   if ($assert_count ne '' && ($count != $assert_count)) {
     print OUT ($count) or die("Error $? writing $out: $!");
   }
-  elsif ($assert_count eq '' && $result !~ /$assert_match/) {
+  elsif ($assert_count_condition ne '' &&
+         eval "$count $assert_count_condition" eq '') {
+    print OUT ($count) or die("Error $? writing $out: $!");
+  }
+  elsif ($assert_count eq '' && $assert_count_condition eq '' &&
+         $result !~ /$assert_match/) {
     print OUT ($result) or die("Error $? writing $out: $!");
   }
   else {
@@ -142,6 +169,7 @@ if ($_ag_outcome != 'assert_grep.inc ok')
   --echo assert_select: '$assert_select'
   --echo assert_match: '$assert_match'
   --echo assert_count: '$assert_count'
+  --echo assert_count_condition: '$assert_count_condition'
   --echo assert_only_after: '$assert_only_after'
   if ($assert_match != '')
   {
@@ -151,6 +179,10 @@ if ($_ag_outcome != 'assert_grep.inc ok')
   {
     --echo number of matching lines: $_ag_outcome
   }
+  if ($assert_count_condition != '')
+  {
+    --echo number of matching lines: $_ag_outcome
+  }
   --die assert_grep.inc failed.
 }
 

mysql-test/include/have_nodebug.inc

@@ -1,5 +1,5 @@
 let $have_debug = `SELECT (VERSION() LIKE '%debug%')`;
 if ($have_debug)
 {
-  --skip Test requires 'have_nodebug'
+  --skip Test requires binaries to be compiled in release mode
 }

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

@@ -0,0 +1,56 @@
+include/master-slave.inc
+Warnings:
+Note	####	Sending passwords in plain text without SSL/TLS is extremely insecure.
+Note	####	Storing MySQL user name or password information in the connection metadata repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START REPLICA; see the 'START REPLICA Syntax' in the MySQL Manual for more information.
+[connection master]
+
+# 1. Start the receiver
+
+[connection slave]
+include/start_slave_io.inc
+
+# 2. Create a table
+# 3. Generate 2 small transactions, rotate relay log after each
+#    transaction
+
+[connection master]
+CREATE TABLE t (a LONGBLOB) ENGINE = InnoDB;
+INSERT INTO t VALUES (REPEAT('a', 1000));
+include/sync_slave_io_with_master.inc
+FLUSH RELAY LOGS;
+[connection master]
+INSERT INTO t VALUES (REPEAT('a', 1000));
+include/sync_slave_io_with_master.inc
+FLUSH RELAY LOGS;
+
+# 4. Generate a transaction that exceeds the relay log space limit, which
+#    will block the receiver
+
+[connection master]
+INSERT INTO t VALUES (REPEAT('a', 10000));
+
+# 5. Run replication applier
+
+[connection slave]
+include/start_slave_sql.inc
+
+# 6. Synchronize source and replica servers
+
+[connection master]
+include/sync_slave_sql_with_master.inc
+
+# 7. Execute a transaction that cannot fit into the relay log space
+#    limit. After purging relay log, the limit is ignored.
+
+[connection master]
+INSERT INTO t VALUES (REPEAT('a', 15000));
+
+# 8. Synchronize source and replica servers
+
+include/sync_slave_sql_with_master.inc
+
+# Clean up
+
+[connection master]
+DROP TABLE t;
+include/rpl_end.inc

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

@@ -0,0 +1,49 @@
+include/master-slave.inc
+Warnings:
+Note	####	Sending passwords in plain text without SSL/TLS is extremely insecure.
+Note	####	Storing MySQL user name or password information in the connection metadata repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START REPLICA; see the 'START REPLICA Syntax' in the MySQL Manual for more information.
+[connection master]
+
+# 1. Create a table
+# 2. Generate several large transactions, containing large events
+
+CREATE TABLE t (a LONGBLOB) ENGINE = InnoDB;
+CREATE PROCEDURE gen_transactions(trx_count INT, ev_count INT, insert_byte_count INT)
+BEGIN
+SET @x = 0;
+REPEAT
+START TRANSACTION;
+SET @ev_cnt = 0;
+REPEAT
+INSERT INTO t VALUES (REPEAT('a', insert_byte_count));
+SET @ev_cnt = @ev_cnt + 1;
+UNTIL @ev_cnt >= ev_count
+END REPEAT;
+COMMIT;
+SET @x = @x + 1;
+UNTIL @x >= trx_count
+END REPEAT;
+END %
+CALL gen_transactions(5, 3, 104857600);
+
+# 3. Run replication
+
+[connection slave]
+include/start_slave.inc
+
+# 4. Synchronize source and replica servers
+
+[connection master]
+include/sync_slave_sql_with_master.inc
+
+# 5. Check Pass condition 1: the number of connects to the source
+#    is less than or equal to the number of transactions
+
+include/assert_grep.inc [Check Pass condition 1]
+
+# Clean up
+
+[connection master]
+DROP TABLE t;
+DROP PROCEDURE gen_transactions;
+include/rpl_end.inc

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

@@ -0,0 +1 @@
+--relay-log-space-limit=11000