From: Date: January 28 2008 9:11am Subject: Re: bk commit into 5.1 tree (aelkin:1.2659) BUG#32971 List-Archive: http://lists.mysql.com/commits/41290 Message-Id: <1201507885.6369.18.camel@hezx> MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit 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 ; 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 ; 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 ; 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 ; 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 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? "" : 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"