WL#10956 Binlog Access API - Step3 Relaylog Applier Reader

This patch replaced the last Log_event::read_log_event() call to
Relaylog_file_reader which was introduced in Step2 patch. So
Log_event::read_log_event() was finally removed from the code.

It also did some refacotring
- It created Rpl_applier_reader class which is responsible for reading
  events from relaylog files.
- The code of next_event was moved into Rpl_applier_reader class and
  separated into a few functions.
- The applier reader is only need when applier is online. It is used
  as a local variable of handle_slave_sql().
- change_master and purge_relay_logs don't need to reopen or reinitialize
  the applier read anymore. So rli::init_relay_log_pos is reorganized as
  group_relay_log_is_valid() to verify group_relay_log_name existing.
- rli::event_relay_log_pos and rli::event_relay_log_name are only used
  when applying events. So they just need to be intilaized in Rpl_applier_reader
  class.
- Moved the code period checking out mts_checkpoint_routine. It was
  encapsulated into a new function called rli::is_time_for_mts_checkpoint

Author: Libing Song

client/mysqlbinlog.cc

@@ -1964,8 +1964,7 @@ static Exit_status dump_multiple_logs(int argc, char **argv) {
   When reading a remote binlog, this function is used to grab the
   Format_description_log_event in the beginning of the stream.
 
-  This is not as smart as check_header() (used for local log); it will
-  not work for a binlog which mixes format. TODO: fix this.
+  It will not work for a binlog which mixes format. TODO: fix this.
 
   @retval ERROR_STOP An error occurred - the program should terminate.
   @retval OK_CONTINUE No error, the program should continue.
@@ -2399,11 +2398,13 @@ class Stdin_binlog_istream : public Basic_seekable_istream,
     return false;
   }
 
+  /* purecov: begin inspected */
   /** Stdin has no length. It should never be called. */
   my_off_t length() override {
     DBUG_ASSERT(0);
     return 0;
   };
+  /* purecov: end */
 
  private:
   /**

mysql-test/suite/binlog/r/binlog_reader_coverage.result

@@ -0,0 +1,20 @@
+call mtr.add_suppression("Binary logging not possible");
+call mtr.add_suppression("Attempting backtrace");
+RESET MASTER;
+CREATE TABLE t1(c1 INT);
+SET debug = "+d,simulate_init_io_cache_failure";
+SHOW BINLOG EVENTS;
+ERROR HY000: Error when executing command SHOW BINLOG EVENTS: Could not open log file
+SET debug = "-d,simulate_init_io_cache_failure";
+SET debug = "+d,simulate_allocate_failure";
+SHOW BINLOG EVENTS;
+ERROR HY000: Error when executing command SHOW BINLOG EVENTS: memory allocation failed reading log event
+SET debug = "-d,simulate_allocate_failure";
+SET debug = "+d,simulate_seek_failure";
+SHOW BINLOG EVENTS FROM 337;
+ERROR HY000: Error when executing command SHOW BINLOG EVENTS: I/O error reading log event
+SET debug = "-d,simulate_seek_failure";
+SET debug = "+d,simulate_ostream_write_failure";
+INSERT INTO t1 VALUES(1);
+ERROR HY000: Binary logging not possible. Message: An error occurred during flush stage of the commit. 'binlog_error_action' is set to 'ABORT_SERVER'. Hence aborting the server.
+DROP TABLE t1;

mysql-test/suite/binlog/t/binlog_reader_coverage.test

@@ -0,0 +1,48 @@
+# Coverage Tests for WL#10956
+--source include/not_valgrind.inc
+--source include/have_debug.inc
+--source include/have_binlog_format_row.inc
+call mtr.add_suppression("Binary logging not possible");
+call mtr.add_suppression("Attempting backtrace");
+RESET MASTER;
+
+CREATE TABLE t1(c1 INT);
+--let $start_pos = query_get_value(SHOW MASTER STATUS, Position, 1)
+
+SET debug = "+d,simulate_init_io_cache_failure";
+--error ER_ERROR_WHEN_EXECUTING_COMMAND
+SHOW BINLOG EVENTS;
+SET debug = "-d,simulate_init_io_cache_failure";
+
+SET debug = "+d,simulate_allocate_failure";
+--error ER_ERROR_WHEN_EXECUTING_COMMAND
+SHOW BINLOG EVENTS;
+SET debug = "-d,simulate_allocate_failure";
+
+SET debug = "+d,simulate_seek_failure";
+--error ER_ERROR_WHEN_EXECUTING_COMMAND
+eval SHOW BINLOG EVENTS FROM $start_pos;
+SET debug = "-d,simulate_seek_failure";
+
+--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
+SET debug = "+d,simulate_ostream_write_failure";
+--error ER_BINLOG_LOGGING_IMPOSSIBLE
+INSERT INTO t1 VALUES(1);
+
+--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
+--enable_reconnect
+--source include/wait_until_connected_again.inc
+
+--error 1
+--exec $MYSQL_BINLOG file_not_exist >/dev/null
+
+--error 1,12
+--exec $MYSQL_BINLOG -#d,simulate_init_io_cache_failure - > /dev/null 2>&1
+
+--error 1,12
+--exec $MYSQL_BINLOG -#d,simulate_init_io_cache_failure binlog.000001 > /dev/null  2>&1
+
+--error 1,12
+--exec $MYSQL_BINLOG --start-position=100000000 binlog.000001 > /dev/null 2>&1
+DROP TABLE t1;
+

mysql-test/suite/ndb_rpl/r/ndb_rpl_checksum.result

@@ -77,7 +77,7 @@ include/start_slave.inc
 set @@global.master_verify_checksum = 1;
 set @@session.debug='d,simulate_checksum_test_failure';
 show binlog events;
-ERROR HY000: Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error
+ERROR HY000: Error when executing command SHOW BINLOG EVENTS: event read from binlog did not pass crc check
 set @@session.debug='';
 set @@global.master_verify_checksum = default;
 include/stop_slave.inc
@@ -92,7 +92,7 @@ set @@global.slave_sql_verify_checksum = 1;
 set @@global.debug='d,simulate_checksum_test_failure';
 start slave sql_thread;
 include/wait_for_slave_sql_error.inc [errno=13117]
-Last_SQL_Error = 'Error initializing relay log position: I/O error reading event at position 4'
+Last_SQL_Error = 'Error initializing relay log position: event read from binlog did not pass crc check'
 include/stop_slave.inc
 set @@global.debug='';
 include/start_slave.inc

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

@@ -7,6 +7,7 @@ Note	####	Storing MySQL user name or password information in the master info rep
 CALL mtr.add_suppression('Slave failed to initialize master info structure from the repository');
 CALL mtr.add_suppression('This operation cannot be performed with a running slave');
 CALL mtr.add_suppression('Could not find target log file mentioned in relay log info in the index file');
+CALL mtr.add_suppression('Could not find relay log file');
 CALL mtr.add_suppression('A slave with the same server_uuid/server_id as this slave has connected to the master');
 SET @saved_event_scheduler= @@GLOBAL.event_scheduler;
 SET @saved_relay_log_purge= @@GLOBAL.relay_log_purge;

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

@@ -22,6 +22,8 @@ call mtr.add_suppression("Could not find target log file mentioned in relay log
 call mtr.add_suppression("Failed to initialize the relay-log-info structure");
 call mtr.add_suppression("Failed to initialize the master info structure");
 call mtr.add_suppression("Failed to create or recover replication info repositories");
+call mtr.add_suppression("listed in the index, but failed to stat");
+call mtr.add_suppression("Error counting relay log space");
 include/rpl_stop_server.inc [server_number=2]
 # Removing  file(s)
 include/rpl_start_server.inc [server_number=2]

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

@@ -26,6 +26,13 @@
 CALL mtr.add_suppression('Slave failed to initialize master info structure from the repository');
 CALL mtr.add_suppression('This operation cannot be performed with a running slave');
 CALL mtr.add_suppression('Could not find target log file mentioned in relay log info in the index file');
+# For case:
+# STOP SLAVE SQL_THREAD; // IO_THREAD is running
+# CHANGE MASTER TO relay_log_name = 'non-existing relay log name',...;
+# While CHANGE MASTER throwns an error, group_relay_log_name is changed to the
+# non-existing file name.
+# START SLAVE SQL_THREAD; // It will log below error.
+CALL mtr.add_suppression('Could not find relay log file');
 CALL mtr.add_suppression('A slave with the same server_uuid/server_id as this slave has connected to the master');
 
 # Save current event scheduler status

mysql-test/suite/rpl/t/rpl_multi_source_slave_files.cnf

@@ -12,7 +12,6 @@ relay-log-purge=0
 relay-log-recovery=1
 sync_relay_log=10
 max-relay-log-size=1073741824
-relay-log-space-limit=1073741824
 relay-log=relaylog-msr
 relay-log-index=relaylog-msr.index
 sync-master-info=10

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

@@ -41,6 +41,8 @@ call mtr.add_suppression("Could not find target log file mentioned in relay log
 call mtr.add_suppression("Failed to initialize the relay-log-info structure");
 call mtr.add_suppression("Failed to initialize the master info structure");
 call mtr.add_suppression("Failed to create or recover replication info repositories");
+call mtr.add_suppression("listed in the index, but failed to stat");
+call mtr.add_suppression("Error counting relay log space");
 
 # Stop slave
 --let $rpl_server_number= 2

mysql-test/suite/rpl_nogtid/r/rpl_checksum.result

@@ -92,7 +92,7 @@ set @@global.slave_sql_verify_checksum = 1;
 set @@global.debug='d,simulate_checksum_test_failure';
 start slave sql_thread;
 include/wait_for_slave_sql_error.inc [errno=13117]
-Last_SQL_Error = 'Error initializing relay log position: I/O error reading event at position 4'
+Last_SQL_Error = 'Event crc check failed! Most likely there is event corruption.'
 include/stop_slave.inc
 set @@global.debug='';
 include/start_slave.inc

mysys/mf_iocache.cc

@@ -179,6 +179,8 @@ int init_io_cache_ext(IO_CACHE *info, File file, size_t cachesize,
   DBUG_PRINT("enter", ("cache: %p  type: %d  pos: %ld", info, (int)type,
                        (ulong)seek_offset));
 
+  DBUG_EXECUTE_IF("simulate_init_io_cache_failure", DBUG_RETURN(1););
+
   info->file = file;
   info->file_key = file_key;
   info->type = TYPE_NOT_SET; /* Don't set it until mutex are created */

share/errmsg-utf8.txt

@@ -10999,10 +10999,10 @@ ER_BINLOG_FILE_BEING_READ_NOT_PURGED
 ER_BINLOG_IO_ERROR_READING_HEADER
   eng "I/O error reading the header from the binary log, errno=%d, io cache code=%d"
 
-ER_BINLOG_CANT_OPEN_LOG
+OBSOLETE_ER_BINLOG_CANT_OPEN_LOG
   eng "Failed to open log (file '%s', errno %d)"
 
-ER_BINLOG_CANT_CREATE_CACHE_FOR_LOG
+OBSOLETE_ER_BINLOG_CANT_CREATE_CACHE_FOR_LOG
   eng "Failed to create a cache on log (file '%s')"
 
 ER_BINLOG_FILE_EXTENSION_NUMBER_EXHAUSTED
@@ -11068,7 +11068,7 @@ ER_BINLOG_CANT_SET_TMP_INDEX_NAME
 ER_BINLOG_FAILED_TO_OPEN_TEMPORARY_INDEX_FILE
   eng "MYSQL_BIN_LOG::open_crash_safe_index_file failed to open temporary index file."
 
-ER_BINLOG_ERROR_GETTING_NEXT_LOG_FROM_INDEX
+OBSOLETE_ER_BINLOG_ERROR_GETTING_NEXT_LOG_FROM_INDEX
   eng "next log error: %d  offset: %s  log: %s included: %d"
 
 ER_BINLOG_CANT_OPEN_TMP_INDEX
@@ -18182,6 +18182,9 @@ ER_CANT_SET_ERROR_SUPPRESSION_LIST_FROM_COMMAND_LINE
 ER_INVALID_VALUE_OF_BIND_ADDRESSES
   eng "Invalid value for command line option bind-addresses: '%s'"
 
+ER_RELAY_LOG_SPACE_LIMIT_DISABLED
+  eng "Ignoring the @@global.relay_log_space_limit option because @@global.relay_log_purge is disabled."
+
 #
 # End of 8.0 Server error messages.
 # (Please read comments from the header of this section before adding error

sql/CMakeLists.txt

@@ -722,7 +722,7 @@ SET (SLAVE_SOURCE rpl_slave.cc rpl_reporting.cc rpl_mi.cc rpl_rli.cc
                   rpl_rli_pdb.cc rpl_info_dummy.cc rpl_mts_submode.cc
                   rpl_slave_commit_order_manager.cc rpl_msr.cc
                   rpl_trx_boundary_parser.cc rpl_channel_service_interface.cc
-                  rpl_slave_until_options.cc)
+                  rpl_slave_until_options.cc rpl_applier_reader.cc)
 ADD_CONVENIENCE_LIBRARY(slave ${SLAVE_SOURCE})
 ADD_DEPENDENCIES(slave GenError)
 

sql/basic_istream.cc

@@ -18,9 +18,7 @@
 #include <my_sys.h>
 #include <mysql/psi/mysql_file.h>
 
-IO_CACHE_istream::IO_CACHE_istream() {
-  memset(&m_io_cache, 0, sizeof(m_io_cache));
-}
+IO_CACHE_istream::IO_CACHE_istream() {}
 
 IO_CACHE_istream::~IO_CACHE_istream() { close(); }
 
@@ -63,11 +61,12 @@ ssize_t IO_CACHE_istream::read(unsigned char *buffer, size_t length) {
 }
 
 bool IO_CACHE_istream::seek(my_off_t offset) {
+  DBUG_EXECUTE_IF("simulate_seek_failure", return true;);
   my_b_seek(&m_io_cache, offset);
   return false;
 }
 
-Stdin_istream::Stdin_istream() { memset(&m_io_cache, 0, sizeof(m_io_cache)); }
+Stdin_istream::Stdin_istream() {}
 
 Stdin_istream::~Stdin_istream() { close(); }
 

sql/basic_ostream.cc

@@ -20,9 +20,7 @@
 #include "mysqld_error.h"
 #include "sql/log.h"
 
-IO_CACHE_ostream::IO_CACHE_ostream() {
-  memset(&m_io_cache, 0, sizeof(m_io_cache));
-}
+IO_CACHE_ostream::IO_CACHE_ostream() {}
 IO_CACHE_ostream::~IO_CACHE_ostream() { close(); }
 
 bool IO_CACHE_ostream::open(
@@ -52,18 +50,14 @@ bool IO_CACHE_ostream::close() {
   return false;
 }
 
-my_off_t IO_CACHE_ostream::tell() {
-  DBUG_ASSERT(my_b_inited(&m_io_cache));
-  return my_b_tell(&m_io_cache);
-}
-
 bool IO_CACHE_ostream::seek(my_off_t offset) {
   DBUG_ASSERT(my_b_inited(&m_io_cache));
   return reinit_io_cache(&m_io_cache, WRITE_CACHE, offset, false, true);
 }
 
 bool IO_CACHE_ostream::write(const unsigned char *buffer, my_off_t length) {
   DBUG_ASSERT(my_b_inited(&m_io_cache));
+  DBUG_EXECUTE_IF("simulate_ostream_write_failure", return true;);
   return my_b_safe_write(&m_io_cache, buffer, length);
 }
 

sql/basic_ostream.h

@@ -99,11 +99,6 @@ class IO_CACHE_ostream : public Truncatable_ostream {
   */
   bool close();
 
-  /**
-     Returns the write position of the file.
-  */
-  my_off_t tell();
-
   bool write(const unsigned char *buffer, my_off_t length) override;
   bool seek(my_off_t offset) override;
   bool truncate(my_off_t offset) override;