Bug #32971 No user level error message from slave sql thread when ER_NO_DEFAULT_FOR_FIELD

The error message due to lack of the default value for an extra field
was not as informative as it should be.

Fixed with improving the scheme of gathering, propagating and reporting
errors in applying rows events. 
The scheme is in the following.
Any kind of error of processing of a row event incidents are to be 
registered with my_error().
In the end Rows_log_event::do_apply_event() invokes rli->report() with the 
message to display consisting of all the errors.
This mimics `show warnings' displaying.
A simple test checks three errors in processing an event.
Two hunks - a user level error and pushing it into the list - 
have been devoted to already fixed Bug@31702.

Some open issues relating to this artifact listed on BUG@21842 page and
on WL@3679.
Todo: to synchronize the statement in the tests comments on Update and Delete
events may not stop when an extra field does not have a default with wl@3228 spec.

include/my_base.h

@@ -411,7 +411,9 @@ enum ha_base_keytype {
                                             statement */
 #define HA_ERR_CORRUPT_EVENT      171    /* The event was corrupt, leading to
                                             illegal data being read */
-#define HA_ERR_LAST              171     /*Copy last error nr.*/
+#define HA_ERR_ROWS_EVENT_APPLY   172    /* The event could not be processed
+                                            no other hanlder error happened */
+#define HA_ERR_LAST              172     /*Copy last error nr.*/
 /* Add error numbers before HA_ERR_LAST and change it accordingly. */
 #define HA_ERR_ERRORS            (HA_ERR_LAST - HA_ERR_FIRST + 1)
 

mysql-test/extra/rpl_tests/rpl_row_tabledefs.test

@@ -46,7 +46,7 @@ ALTER TABLE t1_bit
 ALTER TABLE t1_char ADD x CHAR(20) DEFAULT 'Just a test';
 # ... and add one non-nullable INT column last in table 't1_text'
 #     with no default,
-ALTER TABLE t1_nodef ADD x INT NOT NULL;
+ALTER TABLE t1_nodef ADD x INT NOT NULL, ADD y INT NOT NULL, ADD z INT NOT NULL;
 # ... and remove the last column in t2
 ALTER TABLE t2 DROP b;
 # ... change the type of the single column in table 't4'
@@ -222,8 +222,8 @@ sync_slave_with_master;
 
 --echo **** On Slave ****
 connection slave;
-INSERT INTO t1_nodef VALUES (1,2,3);
-INSERT INTO t1_nodef VALUES (2,4,6);
+INSERT INTO t1_nodef VALUES (1,2,3,4,5);
+INSERT INTO t1_nodef VALUES (2,4,6,8,10);
 
 --echo **** On Master ****
 connection master;

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

@@ -26,7 +26,7 @@ ADD x BIT(3) DEFAULT b'011',
 ADD y BIT(5) DEFAULT b'10101',
 ADD z BIT(2) DEFAULT b'10';
 ALTER TABLE t1_char ADD x CHAR(20) DEFAULT 'Just a test';
-ALTER TABLE t1_nodef ADD x INT NOT NULL;
+ALTER TABLE t1_nodef ADD x INT NOT NULL, ADD y INT NOT NULL, ADD z INT NOT NULL;
 ALTER TABLE t2 DROP b;
 ALTER TABLE t4 MODIFY a FLOAT;
 ALTER TABLE t5 MODIFY b FLOAT;
@@ -125,7 +125,7 @@ Replicate_Ignore_Table
 Replicate_Wild_Do_Table	
 Replicate_Wild_Ignore_Table	
 Last_Errno	1364
-Last_Error	Could not execute Write_rows event on table test.t1_nodef; handler error <unknown>; the event's master log master-bin.000001, end_log_pos 2674
+Last_Error	Could not execute Write_rows event on table test.t1_nodef; Field 'x' doesn't have a default value, Error_code: 1364; Field 'y' doesn't have a default value, Error_code: 1364; Field 'z' doesn't have a default value, Error_code: 1364; handler error HA_ERR_ROWS_EVENT_APPLY; the event's master log master-bin.000001, end_log_pos 2674
 Skip_Counter	0
 Exec_Master_Log_Pos	#
 Relay_Log_Space	#
@@ -143,7 +143,7 @@ Master_SSL_Verify_Server_Cert	No
 Last_IO_Errno	0
 Last_IO_Error	
 Last_SQL_Errno	1364
-Last_SQL_Error	Could not execute Write_rows event on table test.t1_nodef; handler error <unknown>; the event's master log master-bin.000001, end_log_pos 2674
+Last_SQL_Error	Could not execute Write_rows event on table test.t1_nodef; Field 'x' doesn't have a default value, Error_code: 1364; Field 'y' doesn't have a default value, Error_code: 1364; Field 'z' doesn't have a default value, Error_code: 1364; handler error HA_ERR_ROWS_EVENT_APPLY; the event's master log master-bin.000001, end_log_pos 2674
 SET GLOBAL SQL_SLAVE_SKIP_COUNTER=2;
 START SLAVE;
 INSERT INTO t9 VALUES (2);
@@ -393,8 +393,8 @@ INSERT INTO t1_nodef VALUES (1,2);
 INSERT INTO t1_nodef VALUES (2,4);
 SET SQL_LOG_BIN=1;
 **** On Slave ****
-INSERT INTO t1_nodef VALUES (1,2,3);
-INSERT INTO t1_nodef VALUES (2,4,6);
+INSERT INTO t1_nodef VALUES (1,2,3,4,5);
+INSERT INTO t1_nodef VALUES (2,4,6,8,10);
 **** On Master ****
 UPDATE t1_nodef SET b=2*b WHERE a=1;
 SELECT * FROM t1_nodef ORDER BY a;
@@ -403,9 +403,9 @@ a	b
 2	4
 **** On Slave ****
 SELECT * FROM t1_nodef ORDER BY a;
-a	b	x
-1	4	3
-2	4	6
+a	b	x	y	z
+1	4	3	4	5
+2	4	6	8	10
 **** On Master ****
 DELETE FROM t1_nodef WHERE a=2;
 SELECT * FROM t1_nodef ORDER BY a;
@@ -413,8 +413,8 @@ a	b
 1	4
 **** On Slave ****
 SELECT * FROM t1_nodef ORDER BY a;
-a	b	x
-1	4	3
+a	b	x	y	z
+1	4	3	4	5
 **** Cleanup ****
 DROP TABLE IF EXISTS t1_int,t1_bit,t1_char,t1_nodef;
 DROP TABLE IF EXISTS t2,t3,t4,t5,t6,t7,t8,t9;

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

@@ -26,7 +26,7 @@ ADD x BIT(3) DEFAULT b'011',
 ADD y BIT(5) DEFAULT b'10101',
 ADD z BIT(2) DEFAULT b'10';
 ALTER TABLE t1_char ADD x CHAR(20) DEFAULT 'Just a test';
-ALTER TABLE t1_nodef ADD x INT NOT NULL;
+ALTER TABLE t1_nodef ADD x INT NOT NULL, ADD y INT NOT NULL, ADD z INT NOT NULL;
 ALTER TABLE t2 DROP b;
 ALTER TABLE t4 MODIFY a FLOAT;
 ALTER TABLE t5 MODIFY b FLOAT;
@@ -125,7 +125,7 @@ Replicate_Ignore_Table
 Replicate_Wild_Do_Table	
 Replicate_Wild_Ignore_Table	
 Last_Errno	1364
-Last_Error	Could not execute Write_rows event on table test.t1_nodef; handler error <unknown>; the event's master log master-bin.000001, end_log_pos 2944
+Last_Error	Could not execute Write_rows event on table test.t1_nodef; Field 'x' doesn't have a default value, Error_code: 1364; Field 'y' doesn't have a default value, Error_code: 1364; Field 'z' doesn't have a default value, Error_code: 1364; handler error HA_ERR_ROWS_EVENT_APPLY; the event's master log master-bin.000001, end_log_pos 3692
 Skip_Counter	0
 Exec_Master_Log_Pos	#
 Relay_Log_Space	#
@@ -143,7 +143,7 @@ Master_SSL_Verify_Server_Cert	No
 Last_IO_Errno	0
 Last_IO_Error	
 Last_SQL_Errno	1364
-Last_SQL_Error	Could not execute Write_rows event on table test.t1_nodef; handler error <unknown>; the event's master log master-bin.000001, end_log_pos 2944
+Last_SQL_Error	Could not execute Write_rows event on table test.t1_nodef; Field 'x' doesn't have a default value, Error_code: 1364; Field 'y' doesn't have a default value, Error_code: 1364; Field 'z' doesn't have a default value, Error_code: 1364; handler error HA_ERR_ROWS_EVENT_APPLY; the event's master log master-bin.000001, end_log_pos 3692
 SET GLOBAL SQL_SLAVE_SKIP_COUNTER=2;
 START SLAVE;
 INSERT INTO t9 VALUES (2);
@@ -393,8 +393,8 @@ INSERT INTO t1_nodef VALUES (1,2);
 INSERT INTO t1_nodef VALUES (2,4);
 SET SQL_LOG_BIN=1;
 **** On Slave ****
-INSERT INTO t1_nodef VALUES (1,2,3);
-INSERT INTO t1_nodef VALUES (2,4,6);
+INSERT INTO t1_nodef VALUES (1,2,3,4,5);
+INSERT INTO t1_nodef VALUES (2,4,6,8,10);
 **** On Master ****
 UPDATE t1_nodef SET b=2*b WHERE a=1;
 SELECT * FROM t1_nodef ORDER BY a;
@@ -403,9 +403,9 @@ a	b
 2	4
 **** On Slave ****
 SELECT * FROM t1_nodef ORDER BY a;
-a	b	x
-1	4	3
-2	4	6
+a	b	x	y	z
+1	4	3	4	5
+2	4	6	8	10
 **** On Master ****
 DELETE FROM t1_nodef WHERE a=2;
 SELECT * FROM t1_nodef ORDER BY a;
@@ -413,8 +413,8 @@ a	b
 1	4
 **** On Slave ****
 SELECT * FROM t1_nodef ORDER BY a;
-a	b	x
-1	4	3
+a	b	x	y	z
+1	4	3	4	5
 **** Cleanup ****
 DROP TABLE IF EXISTS t1_int,t1_bit,t1_char,t1_nodef;
 DROP TABLE IF EXISTS t2,t3,t4,t5,t6,t7,t8,t9;

sql/log_event.cc

@@ -99,12 +99,23 @@ static const char *HA_ERR(int i)
   case HA_ERR_RECORD_IS_THE_SAME: return "HA_ERR_RECORD_IS_THE_SAME";
   case HA_ERR_LOGGING_IMPOSSIBLE: return "HA_ERR_LOGGING_IMPOSSIBLE";
   case HA_ERR_CORRUPT_EVENT: return "HA_ERR_CORRUPT_EVENT";
+  case HA_ERR_ROWS_EVENT_APPLY : return "HA_ERR_ROWS_EVENT_APPLY";
   }
   return 0;
 }
 
 /**
-   macro to call from different branches of Rows_log_event::do_apply_event
+   Error reporting facility for Rows_log_event::do_apply_event
+
+   @param level     error, warning or info
+   @param ha_error  HA_ERR_ code
+   @param rli       pointer to the active Relay_log_info instance
+   @param thd       pointer to the slave thread's thd
+   @param table     pointer to the event's table object
+   @param type      the type of the event
+   @param log_name  the master binlog file name
+   @param pos       the master binlog file pos (the next after the event)
+
 */
 static void inline slave_rows_error_report(enum loglevel level, int ha_error,
                                            Relay_log_info const *rli, THD *thd,
@@ -112,14 +123,27 @@ static void inline slave_rows_error_report(enum loglevel level, int ha_error,
                                            const char *log_name, ulong pos)
 {
   const char *handler_error= HA_ERR(ha_error);
+  char buff[MAX_SLAVE_ERRMSG], *slider;
+  const char *buff_end= buff + sizeof(buff);
+  uint len;
+  List_iterator_fast<MYSQL_ERROR> it(thd->warn_list);
+  MYSQL_ERROR *err;
+  buff[0]= 0;
+
+  for (err= it++, slider= buff; err && slider < buff_end - 1;
+       slider += len, err= it++)
+  {
+    len= my_snprintf(slider, buff_end - slider,
+                     " %s, Error_code: %d;", err->msg, err->code);
+  }
+  
   rli->report(level, thd->net.last_errno,
               "Could not execute %s event on table %s.%s;"
-              "%s%s handler error %s; "
+              "%s handler error %s; "
               "the event's master log %s, end_log_pos %lu",
               type, table->s->db.str,
               table->s->table_name.str,
-              thd->net.last_error[0] != 0 ? thd->net.last_error : "",
-              thd->net.last_error[0] != 0 ? ";" : "",
+              buff,
               handler_error == NULL? "<unknown>" : handler_error,
               log_name, pos);
 }
@@ -7548,7 +7572,7 @@ Rows_log_event::write_row(const Relay_log_info *const rli,
 
   /* fill table->record[0] with default values */
 
-  if ((error= prepare_record(rli, table, m_width,
+  if ((error= prepare_record(table, m_width,
                              TRUE /* check if columns have def. values */)))
     DBUG_RETURN(error);
   
@@ -7863,12 +7887,16 @@ int Rows_log_event::find_row(const Relay_log_info *rli)
   DBUG_ASSERT(m_table && m_table->in_use != NULL);
 
   TABLE *table= m_table;
-  int error;
+  int error= 0;
 
-  /* unpack row - missing fields get default values */
+  /*
+    rpl_row_tabledefs.test specifies that
+    if the extra field on the slave does not have a default value
+    and this is okay with Delete or Update events.
+    Todo: fix wl3228 hld that requires defauls for all types of events
+  */
   
-  // TODO: shall we check and report errors here?
-  prepare_record(NULL,table,m_width,FALSE /* don't check errors */); 
+  prepare_record(table, m_width, FALSE);
   error= unpack_current_row(rli);
 
 #ifndef DBUG_OFF

sql/log_event.h

@@ -3127,6 +3127,8 @@ protected:
     ASSERT_OR_RETURN_ERROR(m_curr_row < m_rows_end, HA_ERR_CORRUPT_EVENT);
     int const result= ::unpack_row(rli, m_table, m_width, m_curr_row, &m_cols,
                                    &m_curr_row_end, &m_master_reclength);
+    if (m_curr_row_end > m_rows_end)
+      my_error(ER_SLAVE_CORRUPT_EVENT, MYF(0));
     ASSERT_OR_RETURN_ERROR(m_curr_row_end <= m_rows_end, HA_ERR_CORRUPT_EVENT);
     return result;
   }

sql/log_event_old.cc

@@ -2077,7 +2077,7 @@ Old_rows_log_event::write_row(const Relay_log_info *const rli,
 
   /* fill table->record[0] with default values */
 
-  if ((error= prepare_record(rli, table, m_width,
+  if ((error= prepare_record(table, m_width,
                              TRUE /* check if columns have def. values */)))
     DBUG_RETURN(error);
   
@@ -2288,7 +2288,7 @@ int Old_rows_log_event::find_row(const Relay_log_info *rli)
   /* unpack row - missing fields get default values */
 
   // TODO: shall we check and report errors here?
-  prepare_record(NULL,table,m_width,FALSE /* don't check errors */); 
+  prepare_record(table, m_width, FALSE /* don't check errors */); 
   error= unpack_current_row(rli); 
 
 #ifndef DBUG_OFF

sql/rpl_record.cc

@@ -307,17 +307,15 @@ unpack_row(Relay_log_info const *rli,
   If @c check is true, fields are explicitly initialized only if they have
   default value or can be NULL. Otherwise error is reported.
  
-  @param log    Used to report errors.
   @param table  Table whose record[0] buffer is prepared. 
   @param skip   Number of columns for which default value initialization 
                 should be skipped.
   @param check  Indicates if errors should be checked when setting default
                 values.
                 
-  @returns 0 on success. 
+  @returns 0 on success or a handler level error code
  */ 
-int prepare_record(const Slave_reporting_capability *const log, 
-                   TABLE *const table, 
+int prepare_record(TABLE *const table, 
                    const uint skip, const bool check)
 {
   DBUG_ENTER("prepare_record");
@@ -337,13 +335,8 @@ int prepare_record(const Slave_reporting_capability *const log,
 
     if (check && ((f->flags & mask) == mask))
     {
-      DBUG_ASSERT(log);
-      log->report(ERROR_LEVEL, ER_NO_DEFAULT_FOR_FIELD,
-                  "Field `%s` of table `%s`.`%s` "
-                  "has no default value and cannot be NULL",
-                  f->field_name, table->s->db.str,
-                  table->s->table_name.str);
-      error = ER_NO_DEFAULT_FOR_FIELD;
+      my_error(ER_NO_DEFAULT_FOR_FIELD, MYF(0), f->field_name);
+      error = HA_ERR_ROWS_EVENT_APPLY;
     }
     else
       f->set_default();

sql/rpl_record.h

@@ -30,8 +30,7 @@ int unpack_row(Relay_log_info const *rli,
                uchar const **const row_end, ulong *const master_reclength);
 
 // Fill table's record[0] with default values.
-int prepare_record(const Slave_reporting_capability *const, TABLE *const, 
-                   const uint =0, const bool =FALSE);
+int prepare_record(TABLE *const, const uint =0, const bool =FALSE);
 #endif
 
 #endif

sql/share/errmsg.txt

@@ -6119,3 +6119,5 @@ ER_SLAVE_AMBIGOUS_EXEC_MODE
 
 ER_NO_FORMAT_DESCRIPTION_EVENT_BEFORE_BINLOG_STATEMENT
   eng "The BINLOG statement of type `%s` was not preceded by a format description BINLOG statement."
+ER_SLAVE_CORRUPT_EVENT
+  eng "Corrupted replication event was detected"