BUG#40482: server/mysqlbinlog crashes when reading invalid Incident_log_event

Problem: When an Incident_log_event contains a bad incident number on disk,
the server crashes with an assertion.
Fix: Don't validate input with assertions. Use errors.

mysql-test/include/cleanup_fake_relay_log.inc

+# ==== Purpose ====
+#
+# Clean up files create by setup_fake_relay_log.inc.
+#
+# ==== Usage ====
+#
+# See setup_fake_relay_log.inc
+
+--echo Cleaning up after setup_fake_relay_log.inc
+
+# Remove files.
+remove_file $_fake_relay_log;
+remove_file $_fake_relay_index;
+--disable_query_log
+eval SET @@global.relay_log_purge= $_fake_relay_log_purge;
+--enable_query_log

mysql-test/include/setup_fake_relay_log.inc

+# ==== Purpose ====
+#
+# Setup replication from an existing relay log in the current
+# connection.
+#
+# ==== Usage ====
+#
+# Make sure the slave is not running and issue:
+#
+#   let $fake_relay_log= /path/to/fake-relay-log-file.000001
+#   source include/setup_fake_relay_log.inc;
+#   START SLAVE SQL_THREAD; # setup_fake_relay_log doesn't start slave
+#   ...
+#   source include/cleanup_fake_relay_log.inc
+#
+# You must run the server with --relay-log=FILE. You probably want to
+# run with --replicate-same-server-id too.
+#
+# ==== Implementation ====
+#
+# First makes a sanity check, ensuring that the slave threads are not
+# running.  Then copies the $fake_relay_log to RELAY_BIN-fake.000001,
+# where RELAY_BIN is the basename of the relay log, and updates
+# RELAY_BIN.index. Finally issues CHANGE MASTER so that it uses the
+# given files.
+#
+# ==== Side effects ====
+#
+# Creates a binlog file and a binlog index file, and sets
+# @@global.relay_log_purge=1. All this is restored when you call
+# cleanup_fake_relay_log.inc.
+#
+# Enables the query log.
+
+
+--disable_query_log
+
+# Print message.
+let $_fake_relay_log_printable= `SELECT REPLACE('$fake_relay_log', '$MYSQL_TEST_DIR', 'MYSQL_TEST_DIR')`;
+--echo Setting up fake replication from $_fake_relay_log_printable
+
+# Sanity check.
+let $_sql_running= query_get_value(SHOW SLAVE STATUS, Slave_SQL_Running, 1);
+let $_io_running= query_get_value(SHOW SLAVE STATUS, Slave_IO_Running, 1);
+if (`SELECT "$_sql_running" = "Yes" OR "$_io_running" = "Yes"`) {
+  --echo Error: Slave was running when test case sourced
+  --echo include/setup_fake_replication.inc
+  --echo Slave_IO_Running = $_io_running; Slave_SQL_Running = $_sql_running
+  --echo Printing some debug info:
+  SHOW SLAVE STATUS;
+  SHOW MASTER STATUS;
+  SHOW BINLOG EVENTS;
+  SHOW PROCESSLIST;
+}
+
+# Read server variables.
+let $MYSQLD_DATADIR= `SELECT @@datadir`;
+let $_fake_filename= query_get_value(SHOW VARIABLES LIKE 'relay_log', Value, 1);
+if (`SELECT '$_fake_filename' = ''`) {
+  --echo Badly written test case: relay_log variable is empty. Please use the
+  --echo server option --relay-log=FILE.
+}
+let $_fake_relay_log= $MYSQLD_DATADIR/$_fake_filename-fake.000001;
+let $_fake_relay_index= $MYSQLD_DATADIR/$_fake_filename.index;
+# Need to restore relay_log_purge in cleanup_fake_relay_log.inc, since
+# CHANGE MASTER modifies it (see the manual for CHANGE MASTER).
+let $_fake_relay_log_purge= `SELECT @@global.relay_log_purge`;
+
+# Create relay log file.
+copy_file $fake_relay_log $_fake_relay_log;
+
+# Create relay log index.
+eval SELECT '$_fake_relay_log' INTO OUTFILE '$_fake_relay_index';
+
+# Setup replication from existing relay log.
+eval CHANGE MASTER TO MASTER_HOST='dummy.localdomain', RELAY_LOG_FILE='$_fake_relay_log', RELAY_LOG_POS=4;
+
+--enable_query_log

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

+call mtr.add_suppression('Found invalid event in binary log');
+==== Initialize ====
+Setting up fake replication from MYSQL_TEST_DIR/std_data/bug40482-bin.000001
+==== Test ====
+START SLAVE SQL_THREAD;
+Last_SQL_Error = Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.
+==== Clean up ====
+Cleaning up after setup_fake_relay_log.inc

mysql-test/suite/rpl/t/rpl_binlog_corruption-master.opt

+--replicate-same-server-id --relay-log=slave-relay-bin

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

+# ==== Purpose ====
+#
+# Verify that the slave stops gracefully when reading a relay log with
+# corrupted data.
+#
+# ==== Implementation ====
+#
+# Setup "fake replication" where the slave only starts the SQL thread,
+# not the IO thread, and reads from an existing relay log that has
+# been prepared so that it contains the error.  This requires some
+# extra server options: see the -master.opt file.
+#
+# ==== Related bugs ====
+#
+# BUG#31793: log event corruption causes crash
+# BUG#40482: server/mysqlbinlog crashes when reading invalid Incident_log_event
+
+source include/have_log_bin.inc;
+# BUG#40482 only manifested itself in debug-compiled binaries.
+source include/have_debug.inc;
+
+call mtr.add_suppression('Found invalid event in binary log');
+
+
+#
+# BUG#40482: server/mysqlbinlog crashes when reading invalid Incident_log_event
+#
+# The relay log contains an Incident_log_event with a non-existing
+# incident number.
+
+--echo ==== Initialize ====
+let $fake_relay_log= $MYSQL_TEST_DIR/std_data/bug40482-bin.000001;
+source include/setup_fake_relay_log.inc;
+
+--echo ==== Test ====
+START SLAVE SQL_THREAD;
+source include/wait_for_slave_sql_error.inc;
+let $error= query_get_value(SHOW SLAVE STATUS, Last_SQL_Error, 1);
+--echo Last_SQL_Error = $error
+
+--echo ==== Clean up ====
+source include/cleanup_fake_relay_log.inc;

sql/log_event.cc

@@ -9057,7 +9057,17 @@ Incident_log_event::Incident_log_event(const char *buf, uint event_len,
   DBUG_PRINT("info",("event_len: %u; common_header_len: %d; post_header_len: %d",
                      event_len, common_header_len, post_header_len));
 
-  m_incident= static_cast<Incident>(uint2korr(buf + common_header_len));
+  int incident_number= uint2korr(buf + common_header_len);
+  if (incident_number >= INCIDENT_COUNT ||
+      incident_number <= INCIDENT_NONE)
+  {
+    // If the incident is not recognized, this binlog event is
+    // invalid.  If we set incident_number to INCIDENT_NONE, the
+    // invalidity will be detected by is_valid().
+    incident_number= INCIDENT_NONE;
+    DBUG_VOID_RETURN;
+  }
+  m_incident= static_cast<Incident>(incident_number);
   char const *ptr= buf + common_header_len + post_header_len;
   char const *const str_end= buf + event_len;
   uint8 len= 0;                   // Assignment to keep compiler happy
@@ -9085,9 +9095,6 @@ Incident_log_event::description() const
 
   DBUG_PRINT("info", ("m_incident: %d", m_incident));
 
-  DBUG_ASSERT(0 <= m_incident);
-  DBUG_ASSERT((size_t) m_incident <= sizeof(description)/sizeof(*description));
-
   return description[m_incident];
 }
 

sql/log_event.h

@@ -3870,7 +3870,10 @@ public:
 
   virtual Log_event_type get_type_code() { return INCIDENT_EVENT; }
 
-  virtual bool is_valid() const { return 1; }
+  virtual bool is_valid() const
+  {
+    return m_incident > INCIDENT_NONE && m_incident < INCIDENT_COUNT;
+  }
   virtual int get_data_size() {
     return INCIDENT_HEADER_LEN + 1 + m_message.length;
   }

sql/rpl_constants.h

@@ -6,10 +6,10 @@
  */
 enum Incident {
   /** No incident */
-  INCIDENT_NONE,
+  INCIDENT_NONE = 0,
 
   /** There are possibly lost events in the replication stream */
-  INCIDENT_LOST_EVENTS,
+  INCIDENT_LOST_EVENTS = 1,
 
   /** Shall be last event of the enumeration */
   INCIDENT_COUNT