MDEV-5799: Error messages written upon LOST EVENTS incident are corrupted

This is MySQL Bug#59123. The message string stored in an INCIDENT event was
not zero-terminated. This caused any following checksum bytes (if enabled on
the master) to be output to the error log as trailing garbage when the message
was printed to the error log.

Backport the patch from MySQL 5.6:

  revno: 2876.228.200
  revision-id: zhenxing.he@sun.com-20110111051323-w2xnzvcjn46x6h6u
  committer: He Zhenxing <zhenxing.he@sun.com>
  timestamp: Tue 2011-01-11 13:13:23 +0800
  message:
    BUG#59123 rpl_stm_binlog_max_cache_size fails sporadically with found warnings

Also add a test case.

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

@@ -128,7 +128,33 @@ insert into t3 value (1, @@global.binlog_checksum);
 drop table t1, t2, t3;
 set @@global.binlog_checksum = @master_save_binlog_checksum;
 set @@global.master_verify_checksum = @save_master_verify_checksum;
+*** Bug#59123 / MDEV-5799: INCIDENT_EVENT checksum written to error log as garbage characters ***
+CREATE TABLE t4 (a INT PRIMARY KEY);
+INSERT INTO t4 VALUES (1);
+SET sql_log_bin=0;
+CALL mtr.add_suppression("\\[ERROR\\] Can't generate a unique log-filename");
+SET sql_log_bin=1;
+SET @old_dbug= @@GLOBAL.debug_dbug;
+SET debug_dbug= '+d,binlog_inject_new_name_error';
+FLUSH LOGS;
+ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
+
+SET debug_dbug= @old_dbug;
+INSERT INTO t4 VALUES (2);
+include/wait_for_slave_sql_error.inc [errno=1590]
+Last_SQL_Error = 'The incident LOST_EVENTS occured on the master. Message: error writing to the binary log'
+SELECT * FROM t4 ORDER BY a;
+a
+1
+STOP SLAVE IO_THREAD;
+SET sql_slave_skip_counter= 1;
+include/start_slave.inc
+SELECT * FROM t4 ORDER BY a;
+a
+1
+2
 set @@global.binlog_checksum = @slave_save_binlog_checksum;
 set @@global.slave_sql_verify_checksum = @save_slave_sql_verify_checksum;
 End of tests
+DROP TABLE t4;
 include/rpl_end.inc

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

@@ -260,9 +260,66 @@ AAAAAAAAAAAAAAAAAAAx+apMEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
 
 #connection slave;
 sync_slave_with_master;
+
+
+--echo *** Bug#59123 / MDEV-5799: INCIDENT_EVENT checksum written to error log as garbage characters ***
+
+--connection master
+
+--source include/wait_for_binlog_checkpoint.inc
+CREATE TABLE t4 (a INT PRIMARY KEY);
+INSERT INTO t4 VALUES (1);
+
+SET sql_log_bin=0;
+CALL mtr.add_suppression("\\[ERROR\\] Can't generate a unique log-filename");
+SET sql_log_bin=1;
+SET @old_dbug= @@GLOBAL.debug_dbug;
+SET debug_dbug= '+d,binlog_inject_new_name_error';
+--error ER_NO_UNIQUE_LOGFILE
+FLUSH LOGS;
+SET debug_dbug= @old_dbug;
+
+INSERT INTO t4 VALUES (2);
+
+--connection slave
+--let $slave_sql_errno= 1590
+--source include/wait_for_slave_sql_error.inc
+
+# Search the error log for the error message.
+# The bug was that 4 garbage bytes were output in the middle of the error
+# message; by searching for a pattern that spans that location, we can
+# catch the error.
+let $log_error_= `SELECT @@GLOBAL.log_error`;
+if(!$log_error_)
+{
+    # MySQL Server on windows is started with --console and thus
+    # does not know the location of its .err log, use default location
+    let $log_error_ = $MYSQLTEST_VARDIR/log/mysqld.2.err;
+}
+--let SEARCH_FILE= $log_error_
+--let SEARCH_PATTERN= Slave SQL: The incident LOST_EVENTS occured on the master\. Message: error writing to the binary log, Internal MariaDB error code: 1590
+--source include/search_pattern_in_file.inc
+
+SELECT * FROM t4 ORDER BY a;
+STOP SLAVE IO_THREAD;
+SET sql_slave_skip_counter= 1;
+--source include/start_slave.inc
+
+--connection master
+--save_master_pos
+
+--connection slave
+--sync_with_master
+SELECT * FROM t4 ORDER BY a;
+
+
+--connection slave
 set @@global.binlog_checksum = @slave_save_binlog_checksum;
 set @@global.slave_sql_verify_checksum = @save_slave_sql_verify_checksum;
 
 --echo End of tests
 
+--connection master
+DROP TABLE t4;
+
 --source include/rpl_end.inc

sql/log.cc

@@ -2646,7 +2646,8 @@ int MYSQL_LOG::generate_new_name(char *new_name, const char *log_name)
   {
     if (!fn_ext(log_name)[0])
     {
-      if (find_uniq_filename(new_name))
+      if (DBUG_EVALUATE_IF("binlog_inject_new_name_error", TRUE, FALSE) ||
+          find_uniq_filename(new_name))
       {
         my_printf_error(ER_NO_UNIQUE_LOGFILE, ER(ER_NO_UNIQUE_LOGFILE),
                         MYF(ME_FATALERROR), log_name);

sql/log_event.cc

@@ -12452,6 +12452,8 @@ 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_message.str= NULL;
+  m_message.length= 0;
   int incident_number= uint2korr(buf + common_header_len);
   if (incident_number >= INCIDENT_COUNT ||
       incident_number <= INCIDENT_NONE)
@@ -12468,7 +12470,13 @@ Incident_log_event::Incident_log_event(const char *buf, uint event_len,
   uint8 len= 0;                   // Assignment to keep compiler happy
   const char *str= NULL;          // Assignment to keep compiler happy
   read_str(&ptr, str_end, &str, &len);
-  m_message.str= const_cast<char*>(str);
+  if (!(m_message.str= (char*) my_malloc(len+1, MYF(MY_WME))))
+  {
+    /* Mark this event invalid */
+    m_incident= INCIDENT_NONE;
+    DBUG_VOID_RETURN;
+  }
+  strmake(m_message.str, str, len);
   m_message.length= len;
   DBUG_PRINT("info", ("m_incident: %d", m_incident));
   DBUG_VOID_RETURN;
@@ -12477,6 +12485,8 @@ Incident_log_event::Incident_log_event(const char *buf, uint event_len,
 
 Incident_log_event::~Incident_log_event()
 {
+  if (m_message.str)
+    my_free(m_message.str);
 }
 
 

sql/log_event.h

@@ -4686,7 +4686,16 @@ public:
   {
     DBUG_ENTER("Incident_log_event::Incident_log_event");
     DBUG_PRINT("enter", ("m_incident: %d", m_incident));
-    m_message= msg;
+    m_message.str= NULL;
+    m_message.length= 0;
+    if (!(m_message.str= (char*) my_malloc(msg.length+1, MYF(MY_WME))))
+    {
+      /* Mark this event invalid */
+      m_incident= INCIDENT_NONE;
+      DBUG_VOID_RETURN;
+    }
+    strmake(m_message.str, msg.str, msg.length);
+    m_message.length= msg.length;
     set_direct_logging();
     /* Replicate the incident irregardless of @@skip_replication. */
     flags&= ~LOG_EVENT_SKIP_REPLICATION_F;