#At file:///home/sven/bzr/b40482-incident_log_event_assertion/5.1-bugteam/ based on revid:sergey.glukhov@stripped
2756 Sven Sandberg 2008-12-29
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.
added:
mysql-test/include/cleanup_fake_relay_log.inc
mysql-test/include/setup_fake_relay_log.inc
mysql-test/std_data/bug40482-bin.000001
mysql-test/suite/rpl/r/rpl_binlog_corruption.result
mysql-test/suite/rpl/t/rpl_binlog_corruption-master.opt
mysql-test/suite/rpl/t/rpl_binlog_corruption.test
modified:
sql/log_event.cc
sql/log_event.h
sql/rpl_constants.h
per-file messages:
mysql-test/include/cleanup_fake_relay_log.inc
Added auxiliary file to restore things that setup_fake_relay_log.inc did.
mysql-test/include/setup_fake_relay_log.inc
Added auxiliary file to setup replication from an existing relay log.
mysql-test/std_data/bug40482-bin.000001
Binlog file for rpl.rpl_binlog_corruption
mysql-test/suite/rpl/t/rpl_binlog_corruption.test
New test file.
sql/log_event.cc
Check that the incident number is correct at the time the event is constructed.
Do not assert it at the time it is printed.
sql/log_event.h
Incident_log_event::is_valid() should verify that the incident number is valid.
sql/rpl_constants.h
Incident numbers should be hard-coded, since they may appear in files.
=== added file 'mysql-test/include/cleanup_fake_relay_log.inc'
--- a/mysql-test/include/cleanup_fake_relay_log.inc 1970-01-01 00:00:00 +0000
+++ b/mysql-test/include/cleanup_fake_relay_log.inc 2008-12-29 16:04:10 +0000
@@ -0,0 +1,16 @@
+# ==== 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
=== added file 'mysql-test/include/setup_fake_relay_log.inc'
--- a/mysql-test/include/setup_fake_relay_log.inc 1970-01-01 00:00:00 +0000
+++ b/mysql-test/include/setup_fake_relay_log.inc 2008-12-29 16:04:10 +0000
@@ -0,0 +1,78 @@
+# ==== 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
=== added file 'mysql-test/std_data/bug40482-bin.000001'
Binary files a/mysql-test/std_data/bug40482-bin.000001 1970-01-01 00:00:00 +0000 and b/mysql-test/std_data/bug40482-bin.000001 2008-12-29 16:04:10 +0000 differ
=== added file 'mysql-test/suite/rpl/r/rpl_binlog_corruption.result'
--- a/mysql-test/suite/rpl/r/rpl_binlog_corruption.result 1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/rpl/r/rpl_binlog_corruption.result 2008-12-29 16:04:10 +0000
@@ -0,0 +1,8 @@
+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
=== added file 'mysql-test/suite/rpl/t/rpl_binlog_corruption-master.opt'
--- a/mysql-test/suite/rpl/t/rpl_binlog_corruption-master.opt 1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/rpl/t/rpl_binlog_corruption-master.opt 2008-12-29 16:04:10 +0000
@@ -0,0 +1 @@
+--replicate-same-server-id --relay-log=slave-relay-bin
=== added file 'mysql-test/suite/rpl/t/rpl_binlog_corruption.test'
--- a/mysql-test/suite/rpl/t/rpl_binlog_corruption.test 1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/rpl/t/rpl_binlog_corruption.test 2008-12-29 16:04:10 +0000
@@ -0,0 +1,42 @@
+# ==== 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;
=== modified file 'sql/log_event.cc'
--- a/sql/log_event.cc 2008-12-16 12:12:22 +0000
+++ b/sql/log_event.cc 2008-12-29 16:04:10 +0000
@@ -9057,7 +9057,17 @@ Incident_log_event::Incident_log_event(c
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];
}
=== modified file 'sql/log_event.h'
--- a/sql/log_event.h 2008-08-27 18:52:44 +0000
+++ b/sql/log_event.h 2008-12-29 16:04:10 +0000
@@ -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;
}
=== modified file 'sql/rpl_constants.h'
--- a/sql/rpl_constants.h 2007-03-29 18:31:09 +0000
+++ b/sql/rpl_constants.h 2008-12-29 16:04:10 +0000
@@ -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
| Thread |
|---|
| • bzr commit into mysql-5.1-bugteam branch (sven:2756) Bug#40482 | Sven Sandberg | 29 Dec |
