Re: bk commit into 5.1 tree (aelkin:1.2659) BUG#32971

[He Zhenxing]

Hi Andrei

On 2008-01-16 Wed 19:15 +0200，Andrei Elkin wrote：
> Below is the list of changes that have just been committed into a local
> 5.1 repository of elkin. When elkin does a push these changes will
> be propagated to the main repository and, within 24 hours after the
> push, to the public repository.
> For information on how to access the public repository
> see http://dev.mysql.com/doc/mysql/en/installing-source-tree.html
> 
> ChangeSet@stripped, 2008-01-16 19:15:39+02:00, aelkin@stripped +10 -0
>   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 two 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@stripped, 2008-01-16 19:15:32+02:00, aelkin@stripped +3 -1
>     A new handler level error code that is supposed to be mapped to a set of more
>     specific ER_ user level errors.
> 
>   mysql-test/extra/rpl_tests/rpl_row_tabledefs.test@stripped, 2008-01-16 19:15:32+02:00,
> aelkin@stripped +3 -3
>     Adding yet another extra field to see more than one error in show
>     slave status' report.
> 
>   mysql-test/suite/rpl/r/rpl_row_tabledefs_2myisam.result@stripped, 2008-01-16
> 19:15:32+02:00, aelkin@stripped +10 -10
>     results changed (the error message etc)
> 
>   mysql-test/suite/rpl/r/rpl_row_tabledefs_3innodb.result@stripped, 2008-01-16
> 19:15:33+02:00, aelkin@stripped +10 -10
>     results changed
> 
>   sql/log_event.cc@stripped, 2008-01-16 19:15:33+02:00, aelkin@stripped +39 -12
>     Refining slave_rows_error_report to iterate on the list of gathered errors;
>     Simplifying signature of prepare_record as the function does not call
>     rli->report to leave that duty to the event's top level code.
> 
>   sql/log_event.h@stripped, 2008-01-16 19:15:33+02:00, aelkin@stripped +2 -0
>     adding a corrupt event error pushing. The error will be seen with
>     show slave status.
> 
>   sql/log_event_old.cc@stripped, 2008-01-16 19:15:33+02:00, aelkin@stripped +2
> -2
>     similar to log_event.cc changes
> 
>   sql/rpl_record.cc@stripped, 2008-01-16 19:15:34+02:00, aelkin@stripped +5 -12
>     prepare_record only pushes an error to the list
> 
>   sql/rpl_record.h@stripped, 2008-01-16 19:15:34+02:00, aelkin@stripped +1 -2
>     signature changed
> 
>   sql/share/errmsg.txt@stripped, 2008-01-16 19:15:34+02:00, aelkin@stripped +2
> -0
>     The user level error code that corresponds to HA_ERR_CORRUPT_EVENT.
>     The error will be reported in show slave status if such a failure happens.
> 
> diff -Nrup a/include/my_base.h b/include/my_base.h
> --- a/include/my_base.h	2007-10-20 19:19:50 +03:00
> +++ b/include/my_base.h	2008-01-16 19:15:32 +02:00
> @@ -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)
>  
> diff -Nrup a/mysql-test/extra/rpl_tests/rpl_row_tabledefs.test
> b/mysql-test/extra/rpl_tests/rpl_row_tabledefs.test
> --- a/mysql-test/extra/rpl_tests/rpl_row_tabledefs.test	2007-12-12 12:14:49 +02:00
> +++ b/mysql-test/extra/rpl_tests/rpl_row_tabledefs.test	2008-01-16 19:15:32 +02:00
> @@ -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;
>  # ... 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);
> +INSERT INTO t1_nodef VALUES (2,4,6,8);
>  
>  --echo **** On Master ****
>  connection master;
> diff -Nrup a/mysql-test/suite/rpl/r/rpl_row_tabledefs_2myisam.result
> b/mysql-test/suite/rpl/r/rpl_row_tabledefs_2myisam.result
> --- a/mysql-test/suite/rpl/r/rpl_row_tabledefs_2myisam.result	2007-12-12 12:19:30
> +02:00
> +++ b/mysql-test/suite/rpl/r/rpl_row_tabledefs_2myisam.result	2008-01-16 19:15:32
> +02:00
> @@ -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;
>  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; 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; 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);
> +INSERT INTO t1_nodef VALUES (2,4,6,8);
>  **** 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
> +1	4	3	4
> +2	4	6	8
>  **** 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
> +1	4	3	4
>  **** 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;
> diff -Nrup a/mysql-test/suite/rpl/r/rpl_row_tabledefs_3innodb.result
> b/mysql-test/suite/rpl/r/rpl_row_tabledefs_3innodb.result
> --- a/mysql-test/suite/rpl/r/rpl_row_tabledefs_3innodb.result	2007-12-12 12:19:30
> +02:00
> +++ b/mysql-test/suite/rpl/r/rpl_row_tabledefs_3innodb.result	2008-01-16 19:15:33
> +02:00
> @@ -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;
>  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; 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; 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);
> +INSERT INTO t1_nodef VALUES (2,4,6,8);
>  **** 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
> +1	4	3	4
> +2	4	6	8
>  **** 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
> +1	4	3	4
>  **** 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;
> diff -Nrup a/sql/log_event.cc b/sql/log_event.cc
> --- a/sql/log_event.cc	2007-12-17 15:21:19 +02:00
> +++ b/sql/log_event.cc	2008-01-16 19:15:33 +02:00
> @@ -99,27 +99,50 @@ 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,
>                                             TABLE *table, const char * type,
>                                             const char *log_name, ulong pos)
>  {
> -  const char *handler_error=  HA_ERR(ha_error);
> +  const char *handler_error= HA_ERR(ha_error);
> +  char buff[MAX_SLAVE_ERRMSG], *slider;
> +  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 + sizeof(buff) - 1;
> +       slider= buff + len, err= it++)

I think the upper line should be:
  slider+= len, err= it++)

And I think by using:
  char *buff_end = buff + sizeof(buff);
and then using buff_end instead of the expression will make the code
more succinct and maybe a little bit faster.

> +  {
> +    len= my_snprintf(slider, buff - slider + sizeof(buff),
> +                     " %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 +7571,7 @@ Rows_log_event::write_row(const Relay_lo
>  
>    /* 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,13 +7886,17 @@ int Rows_log_event::find_row(const Relay
>    DBUG_ASSERT(m_table && m_table->in_use != NULL);
>  
>    TABLE *table= m_table;
> -  int error;
> -
> -  /* unpack row - missing fields get default values */
> +  int error= 0;
>  
> -  // TODO: shall we check and report errors here?
> -  prepare_record(NULL,table,m_width,FALSE /* don't check errors */); 
> -  error= unpack_current_row(rli); 
> +  /*
> +    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
> +  */
> +  
> +  prepare_record(table, m_width, FALSE);
> +  error= unpack_current_row(rli);
>  
>  #ifndef DBUG_OFF
>    DBUG_PRINT("info",("looking for the following record"));
> diff -Nrup a/sql/log_event.h b/sql/log_event.h
> --- a/sql/log_event.h	2007-12-14 20:01:59 +02:00
> +++ b/sql/log_event.h	2008-01-16 19:15:33 +02:00
> @@ -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;
>    }
> diff -Nrup a/sql/log_event_old.cc b/sql/log_event_old.cc
> --- a/sql/log_event_old.cc	2007-12-05 21:00:06 +02:00
> +++ b/sql/log_event_old.cc	2008-01-16 19:15:33 +02:00
> @@ -2077,7 +2077,7 @@ Old_rows_log_event::write_row(const Rela
>  
>    /* 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 R
>    /* 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
> diff -Nrup a/sql/rpl_record.cc b/sql/rpl_record.cc
> --- a/sql/rpl_record.cc	2007-10-17 10:29:06 +03:00
> +++ b/sql/rpl_record.cc	2008-01-16 19:15:34 +02:00
> @@ -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,18 +335,13 @@ int prepare_record(const Slave_reporting
>  
>      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();
>    }
> -
> +  

only white space difference, should be removed

>    DBUG_RETURN(error);
>  }
>  
> diff -Nrup a/sql/rpl_record.h b/sql/rpl_record.h
> --- a/sql/rpl_record.h	2007-09-10 14:15:59 +03:00
> +++ b/sql/rpl_record.h	2008-01-16 19:15:34 +02:00
> @@ -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
> diff -Nrup a/sql/share/errmsg.txt b/sql/share/errmsg.txt
> --- a/sql/share/errmsg.txt	2007-12-14 20:01:59 +02:00
> +++ b/sql/share/errmsg.txt	2008-01-16 19:15:34 +02:00
> @@ -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 "Currupted replication event was detected"