From 6ed9fc6b7a64bafe85186eb37db8593b8ef2acbc Mon Sep 17 00:00:00 2001 From: unknown Date: Thu, 12 Apr 2007 08:58:04 +0200 Subject: [PATCH] BUG#25688 (RBR: circular replication may cause STMT_END_F flags to be skipped): By moving statement end actions from Rows_log_event::do_apply_event() to Rows_log_event::do_update_pos() they will always be executed, even if Rows_log_event::do_apply_event() is skipped because the event originated at the same server. This because Rows_log_event::do_update_pos() is always executed (unless Rows_log_event::do_apply_event() failed with an error, in which case the slave stops with an error anyway). Adding test case. Fixing logic to detect if inside a group. If a rotate event occured when an initial prefix of events for a statement, but for which the table did contain a key, last_event_start_time is set to zero, causing rotate to end the group but without unlocking any tables. This left a lock hanging around, which subsequently triggered an assertion when a second attempt was made to lock the same sequence of tables. In order to solve the above problem, a new flag was added to the relay log info structure that is used to indicate that the replication thread is currently executing a statement. Using this flag, the replication thread is in a group if it is either in a statement or inside a trans- action. The patch also eliminates some gratuitous header file inclusions that were not needed (and caused compile errors) and replaced them with forward definitions. sql/item_func.cc: Including definition of MASTER_INFO. sql/log.cc: Including definition of RELAY_LOG_INFO since it is used in the file. sql/log_event.cc: Moving statement end actions from Rows_log_event::do_apply_event() to Rows_log_event::do_update_pos(). Factoring out code to update group positions and event positions into relay log info structure. --- Adding debugging printouts. Fixing logic to detect if inside a group. sql/log_event.h: Adding Rows_log_event::do_update_pos(). sql/mysqld.cc: Including definition of MASTER_INFO. sql/repl_failsafe.cc: Including definition of MASTER_INFO. sql/rpl_mi.h: Including definition of RELAY_LOG_INFO since it is used in the file. sql/rpl_rli.cc: Adding member function stmt_done() to do after-statement updates of the relay log info structure. sql/rpl_rli.h: Adding member function stmt_done() to do after-statement updates of the relay log info structure. sql/set_var.cc: Including definition of MASTER_INFO. sql/slave.cc: Adding debuging printouts. sql/slave.h: Removing inclusion definitions of MASTER_INFO and RELAY_LOG_INFO and replacing them with forward declarations since the classes are not used in the file. The gratuitous inclusion lead to compile errors in the two classes above in files that used neither. sql/sql_binlog.cc: Including definition of RELAY_LOG_INFO since it is used in the file. sql/sql_class.cc: Including definition of RELAY_LOG_INFO since it is used in the file. sql/sql_class.h: Removing inclusion definitions of RELAY_LOG_INFO and replacing it with forward declaration since the class is not used in the file. The gratuitous inclusion lead to compile errors in the class above in files didn't use the class. sql/sql_insert.cc: Including definition of MASTER_INFO. sql/sql_repl.cc: Including definition of MASTER_INFO. mysql-test/r/rpl_ndb_circular_simplex.result: New BitKeeper file ``mysql-test/r/rpl_ndb_circular_simplex.result'' mysql-test/t/rpl_ndb_circular_simplex.test: New BitKeeper file ``mysql-test/t/rpl_ndb_circular_simplex.test'' --- mysql-test/r/rpl_ndb_circular_simplex.result | 61 +++++ mysql-test/t/rpl_ndb_circular_simplex.test | 77 ++++++ sql/item_func.cc | 1 + sql/log.cc | 1 + sql/log_event.cc | 254 ++++++++++--------- sql/log_event.h | 2 + sql/mysqld.cc | 1 + sql/repl_failsafe.cc | 1 + sql/rpl_mi.h | 3 + sql/rpl_rli.cc | 50 +++- sql/rpl_rli.h | 71 ++++++ sql/set_var.cc | 1 + sql/slave.cc | 40 +-- sql/slave.h | 9 +- sql/sql_binlog.cc | 1 + sql/sql_class.cc | 1 + sql/sql_class.h | 4 +- sql/sql_insert.cc | 1 + sql/sql_repl.cc | 1 + 19 files changed, 435 insertions(+), 145 deletions(-) create mode 100644 mysql-test/r/rpl_ndb_circular_simplex.result create mode 100644 mysql-test/t/rpl_ndb_circular_simplex.test diff --git a/mysql-test/r/rpl_ndb_circular_simplex.result b/mysql-test/r/rpl_ndb_circular_simplex.result new file mode 100644 index 00000000000..2b9c4820f73 --- /dev/null +++ b/mysql-test/r/rpl_ndb_circular_simplex.result @@ -0,0 +1,61 @@ +stop slave; +drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; +reset master; +reset slave; +drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; +start slave; +CREATE TABLE t1 (a int key, b int) ENGINE=NDB; +SHOW TABLES; +Tables_in_test +t1 +RESET MASTER; +INSERT INTO t1 VALUES (1,2); +INSERT INTO t1 VALUES (2,3); +STOP SLAVE; +CHANGE MASTER TO MASTER_HOST="127.0.0.1",MASTER_PORT=SLAVE_PORT,MASTER_USER="root"; +RESET MASTER; +START SLAVE; +SHOW SLAVE STATUS; +Slave_IO_State # +Master_Host 127.0.0.1 +Master_User root +Master_Port 9308 +Connect_Retry 60 +Master_Log_File slave-bin.000001 +Read_Master_Log_Pos 468 +Relay_Log_File # +Relay_Log_Pos # +Relay_Master_Log_File slave-bin.000001 +Slave_IO_Running Yes +Slave_SQL_Running Yes +Replicate_Do_DB +Replicate_Ignore_DB +Replicate_Do_Table +Replicate_Ignore_Table +Replicate_Wild_Do_Table +Replicate_Wild_Ignore_Table +Last_Errno 0 +Last_Error +Skip_Counter 0 +Exec_Master_Log_Pos 468 +Relay_Log_Space # +Until_Condition None +Until_Log_File +Until_Log_Pos 0 +Master_SSL_Allowed No +Master_SSL_CA_File +Master_SSL_CA_Path +Master_SSL_Cert +Master_SSL_Cipher +Master_SSL_Key +Seconds_Behind_Master # +SELECT * FROM t1 ORDER BY a; +a b +1 2 +2 3 +STOP SLAVE; +START SLAVE; +SELECT * FROM t1 ORDER BY a; +a b +1 2 +2 3 diff --git a/mysql-test/t/rpl_ndb_circular_simplex.test b/mysql-test/t/rpl_ndb_circular_simplex.test new file mode 100644 index 00000000000..08c5dd7ae1e --- /dev/null +++ b/mysql-test/t/rpl_ndb_circular_simplex.test @@ -0,0 +1,77 @@ +--source include/have_ndb.inc +--source include/have_binlog_format_row.inc +--source include/master-slave.inc + +connection master; +CREATE TABLE t1 (a int key, b int) ENGINE=NDB; +sync_slave_with_master; +SHOW TABLES; + +# Lose the events from the slave binary log: there is no +# need to re-create the table on the master. +connection slave; +RESET MASTER; + +# Insert some values on the slave and master +connection master; +INSERT INTO t1 VALUES (1,2); +# Switch to slave once event is applied and insert a row +sync_slave_with_master; +connection slave; +INSERT INTO t1 VALUES (2,3); + +# ... it is now very probable that we have a mixed event in the binary +# log. If we don't, the test should still pass, but will not test the +# mixed event situation. + +# The statement is disabled since it cannot reliably show the same +# info all the time. Use it for debug purposes. + +#SHOW BINLOG EVENTS; + +# Replicate back to the master to test this mixed event on the master +STOP SLAVE; + +connection master; +--replace_result $SLAVE_MYPORT SLAVE_PORT +eval CHANGE MASTER TO MASTER_HOST="127.0.0.1",MASTER_PORT=$SLAVE_MYPORT,MASTER_USER="root"; + +RESET MASTER; +START SLAVE; + +connection slave; +save_master_pos; +connection master; +sync_with_master; + +# The statement is disabled since it cannot reliably show the same +# info all the time. Use it for debug purposes. + +#SHOW BINLOG EVENTS; + +# Check that there is no error in replication +--replace_result $MASTER_MYPORT MASTER_PORT +--replace_column 1 # 8 # 9 # 23 # 33 # +query_vertical SHOW SLAVE STATUS; + +# Check that we have the data on the master +SELECT * FROM t1 ORDER BY a; + +# We should now have another mixed event, likely with "slave" server +# id last, and with the STMT_END_F flag set. + +# The statement is disabled since it cannot reliably show the same +# info all the time. Use it for debug purposes. + +#SHOW BINLOG EVENTS; + +# now lets see that this data is applied correctly on the slave +STOP SLAVE; +save_master_pos; + +connection slave; +START SLAVE; + +# check that we have the data on the slave +sync_with_master; +SELECT * FROM t1 ORDER BY a; diff --git a/sql/item_func.cc b/sql/item_func.cc index b7a708686a8..d0fbffde169 100644 --- a/sql/item_func.cc +++ b/sql/item_func.cc @@ -22,6 +22,7 @@ #include "mysql_priv.h" #include "slave.h" // for wait_for_master_pos +#include "rpl_mi.h" #include #include #include diff --git a/sql/log.cc b/sql/log.cc index fe3a4f7df5e..12e70827666 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -20,6 +20,7 @@ #include "mysql_priv.h" #include "sql_repl.h" #include "rpl_filter.h" +#include "rpl_rli.h" #include #include diff --git a/sql/log_event.cc b/sql/log_event.cc index e3c94b5e1c9..6e028695fd5 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -22,6 +22,8 @@ #include "mysql_priv.h" #include "slave.h" +#include "rpl_rli.h" +#include "rpl_mi.h" #include "rpl_filter.h" #include "rpl_utility.h" #include @@ -31,6 +33,8 @@ #define log_cs &my_charset_latin1 +#define FLAGSTR(V,F) ((V)&(F)?#F" ":"") + /* Cache that will automatically be written to a dedicated file on destruction. @@ -547,49 +551,7 @@ int Log_event::do_update_pos(RELAY_LOG_INFO *rli) Matz: I don't think we will need this check with this refactoring. */ if (rli) - { - /* - If in a transaction, and if the slave supports transactions, just - inc_event_relay_log_pos(). We only have to check for OPTION_BEGIN - (not OPTION_NOT_AUTOCOMMIT) as transactions are logged with - BEGIN/COMMIT, not with SET AUTOCOMMIT= . - - CAUTION: opt_using_transactions means - innodb || bdb ; suppose the master supports InnoDB and BDB, - but the slave supports only BDB, problems - will arise: - - suppose an InnoDB table is created on the master, - - then it will be MyISAM on the slave - - but as opt_using_transactions is true, the slave will believe he - is transactional with the MyISAM table. And problems will come - when one does START SLAVE; STOP SLAVE; START SLAVE; (the slave - will resume at BEGIN whereas there has not been any rollback). - This is the problem of using opt_using_transactions instead of a - finer "does the slave support - _the_transactional_handler_used_on_the_master_". - - More generally, we'll have problems when a query mixes a - transactional handler and MyISAM and STOP SLAVE is issued in the - middle of the "transaction". START SLAVE will resume at BEGIN - while the MyISAM table has already been updated. - */ - if ((thd->options & OPTION_BEGIN) && opt_using_transactions) - rli->inc_event_relay_log_pos(); - else - { - rli->inc_group_relay_log_pos(log_pos); - flush_relay_log_info(rli); - /* - Note that Rotate_log_event::do_apply_event() does not call - this function, so there is no chance that a fake rotate event - resets last_master_timestamp. Note that we update without - mutex (probably ok - except in some very rare cases, only - consequence is that value may take some time to display in - Seconds_Behind_Master - not critical). - */ - rli->last_master_timestamp= when; - } - } + rli->stmt_done(log_pos, when); return 0; // Cannot fail currently } @@ -1024,6 +986,10 @@ Log_event* Log_event::read_log_event(const char* buf, uint event_len, break; } + DBUG_PRINT("read_event", ("%s(type_code: %d; event_len: %d)", + ev ? ev->get_type_str() : "", + buf[EVENT_TYPE_OFFSET], + event_len)); /* is_valid() are small event-specific sanity tests which are important; for example there are some my_malloc() in constructors @@ -3578,17 +3544,6 @@ bool Rotate_log_event::write(IO_CACHE* file) } #endif -/** - Helper function to detect if the event is inside a group. - */ -#if defined(HAVE_REPLICATION) && !defined(MYSQL_CLIENT) -static bool is_in_group(THD *const thd, RELAY_LOG_INFO *const rli) -{ - return (thd->options & OPTION_BEGIN) != 0 || - (rli->last_event_start_time > 0); -} -#endif - /* Rotate_log_event::do_apply_event() @@ -3639,7 +3594,7 @@ int Rotate_log_event::do_update_pos(RELAY_LOG_INFO *rli) relay log, which shall not change the group positions. */ if ((server_id != ::server_id || rli->replicate_same_server_id) && - !is_in_group(thd, rli)) + !rli->is_in_group()) { DBUG_PRINT("info", ("old group_master_log_name: '%s' " "old group_master_log_pos: %lu", @@ -3803,6 +3758,12 @@ void Intvar_log_event::print(FILE* file, PRINT_EVENT_INFO* print_event_info) #if defined(HAVE_REPLICATION)&& !defined(MYSQL_CLIENT) int Intvar_log_event::do_apply_event(RELAY_LOG_INFO const *rli) { + /* + We are now in a statement until the associated query log event has + been processed. + */ + const_cast(rli)->set_flag(RELAY_LOG_INFO::IN_STMT); + switch (type) { case LAST_INSERT_ID_EVENT: thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt= 1; @@ -3903,6 +3864,12 @@ void Rand_log_event::print(FILE* file, PRINT_EVENT_INFO* print_event_info) #if defined(HAVE_REPLICATION) && !defined(MYSQL_CLIENT) int Rand_log_event::do_apply_event(RELAY_LOG_INFO const *rli) { + /* + We are now in a statement until the associated query log event has + been processed. + */ + const_cast(rli)->set_flag(RELAY_LOG_INFO::IN_STMT); + thd->rand.seed1= (ulong) seed1; thd->rand.seed2= (ulong) seed2; return 0; @@ -4297,6 +4264,12 @@ int User_var_log_event::do_apply_event(RELAY_LOG_INFO const *rli) double real_val; longlong int_val; + /* + We are now in a statement until the associated query log event has + been processed. + */ + const_cast(rli)->set_flag(RELAY_LOG_INFO::IN_STMT); + if (is_null) { it= new Item_null(); @@ -6171,6 +6144,17 @@ int Rows_log_event::do_apply_event(RELAY_LOG_INFO const *rli) /* A small test to verify that objects have consistent types */ DBUG_ASSERT(sizeof(thd->options) == sizeof(OPTION_RELAXED_UNIQUE_CHECKS)); + /* + Now we are in a statement and will stay in a statement until we + see a STMT_END_F. + + We set this flag here, before actually applying any rows, in + case the SQL thread is stopped and we need to detect that we're + inside a statement and halting abruptly might cause problems + when restarting. + */ + const_cast(rli)->set_flag(RELAY_LOG_INFO::IN_STMT); + error= do_before_row_operations(table); while (error == 0 && row_start < (const char*) m_rows_end) { @@ -6243,69 +6227,13 @@ int Rows_log_event::do_apply_event(RELAY_LOG_INFO const *rli) DBUG_RETURN(error); } - if (get_flags(STMT_END_F)) - { - /* - This is the end of a statement or transaction, so close (and - unlock) the tables we opened when processing the - Table_map_log_event starting the statement. - - OBSERVER. This will clear *all* mappings, not only those that - are open for the table. There is not good handle for on-close - actions for tables. - - NOTE. Even if we have no table ('table' == 0) we still need to be - here, so that we increase the group relay log position. If we didn't, we - could have a group relay log position which lags behind "forever" - (assume the last master's transaction is ignored by the slave because of - replicate-ignore rules). - */ - thd->binlog_flush_pending_rows_event(true); - /* - If this event is not in a transaction, the call below will, if some - transactional storage engines are involved, commit the statement into - them and flush the pending event to binlog. - If this event is in a transaction, the call will do nothing, but a - Xid_log_event will come next which will, if some transactional engines - are involved, commit the transaction and flush the pending event to the - binlog. - */ - error= ha_autocommit_or_rollback(thd, 0); - /* - Now what if this is not a transactional engine? we still need to - flush the pending event to the binlog; we did it with - thd->binlog_flush_pending_rows_event(). Note that we imitate - what is done for real queries: a call to - ha_autocommit_or_rollback() (sometimes only if involves a - transactional engine), and a call to be sure to have the pending - event flushed. - */ - - thd->reset_current_stmt_binlog_row_based(); - const_cast(rli)->cleanup_context(thd, 0); - - if (error == 0) - { - /* - Clear any errors pushed in thd->net.last_err* if for example "no key - found" (as this is allowed). This is a safety measure; apparently - those errors (e.g. when executing a Delete_rows_log_event of a - non-existing row, like in rpl_row_mystery22.test, - thd->net.last_error = "Can't find record in 't1'" and last_errno=1032) - do not become visible. We still prefer to wipe them out. - */ - thd->clear_error(); - } - else - slave_print_msg(ERROR_LEVEL, rli, error, - "Error in %s event: commit of row events failed, " - "table `%s`.`%s`", - get_type_str(), table->s->db.str, - table->s->table_name.str); - DBUG_RETURN(error); - } - - if (table && (table->s->primary_key == MAX_KEY) && !cache_stmt) + /* + This code would ideally be placed in do_update_pos() instead, but + since we have no access to table there, we do the setting of + last_event_start_time here instead. + */ + if (table && (table->s->primary_key == MAX_KEY) && + !cache_stmt && get_flags(STMT_END_F) == RLE_NO_FLAGS) { /* ------------ Temporary fix until WL#2975 is implemented --------- @@ -6326,12 +6254,92 @@ int Rows_log_event::do_apply_event(RELAY_LOG_INFO const *rli) const_cast(rli)->last_event_start_time= time(0); } - DBUG_ASSERT(error == 0); - thd->clear_error(); - DBUG_RETURN(0); } +int +Rows_log_event::do_update_pos(RELAY_LOG_INFO *rli) +{ + DBUG_ENTER("Rows_log_event::do_update_pos"); + int error= 0; + + DBUG_PRINT("info", ("flags: %s", + get_flags(STMT_END_F) ? "STMT_END_F " : "")); + + if (get_flags(STMT_END_F)) + { + /* + This is the end of a statement or transaction, so close (and + unlock) the tables we opened when processing the + Table_map_log_event starting the statement. + + OBSERVER. This will clear *all* mappings, not only those that + are open for the table. There is not good handle for on-close + actions for tables. + + NOTE. Even if we have no table ('table' == 0) we still need to be + here, so that we increase the group relay log position. If we didn't, we + could have a group relay log position which lags behind "forever" + (assume the last master's transaction is ignored by the slave because of + replicate-ignore rules). + */ + thd->binlog_flush_pending_rows_event(true); + + /* + If this event is not in a transaction, the call below will, if some + transactional storage engines are involved, commit the statement into + them and flush the pending event to binlog. + If this event is in a transaction, the call will do nothing, but a + Xid_log_event will come next which will, if some transactional engines + are involved, commit the transaction and flush the pending event to the + binlog. + */ + error= ha_autocommit_or_rollback(thd, 0); + + /* + Now what if this is not a transactional engine? we still need to + flush the pending event to the binlog; we did it with + thd->binlog_flush_pending_rows_event(). Note that we imitate + what is done for real queries: a call to + ha_autocommit_or_rollback() (sometimes only if involves a + transactional engine), and a call to be sure to have the pending + event flushed. + */ + + thd->reset_current_stmt_binlog_row_based(); + rli->cleanup_context(thd, 0); + if (error == 0) + { + /* + Indicate that a statement is finished. + Step the group log position if we are not in a transaction, + otherwise increase the event log position. + */ + rli->stmt_done(log_pos, when); + + /* + Clear any errors pushed in thd->net.last_err* if for example "no key + found" (as this is allowed). This is a safety measure; apparently + those errors (e.g. when executing a Delete_rows_log_event of a + non-existing row, like in rpl_row_mystery22.test, + thd->net.last_error = "Can't find record in 't1'" and last_errno=1032) + do not become visible. We still prefer to wipe them out. + */ + thd->clear_error(); + } + else + slave_print_msg(ERROR_LEVEL, rli, error, + "Error in %s event: commit of row events failed", + get_type_str()); + } + else + { + rli->inc_event_relay_log_pos(); + } + + DBUG_RETURN(error); +} + #endif /* !defined(MYSQL_CLIENT) && defined(HAVE_REPLICATION) */ #ifndef MYSQL_CLIENT @@ -6413,7 +6421,9 @@ void Rows_log_event::print_helper(FILE *file, { bool const last_stmt_event= get_flags(STMT_END_F); print_header(head, print_event_info, !last_stmt_event); - my_b_printf(head, "\t%s: table id %lu\n", name, m_table_id); + my_b_printf(head, "\t%s: table id %lu%s\n", + name, m_table_id, + last_stmt_event ? " flags: STMT_END_F" : ""); print_base64(body, print_event_info, !last_stmt_event); } diff --git a/sql/log_event.h b/sql/log_event.h index 51543291621..575b70bb68e 100644 --- a/sql/log_event.h +++ b/sql/log_event.h @@ -841,6 +841,7 @@ public: } protected: + /** Primitive to apply an event to the database. @@ -2242,6 +2243,7 @@ private: #if !defined(MYSQL_CLIENT) && defined(HAVE_REPLICATION) virtual int do_apply_event(RELAY_LOG_INFO const *rli); + virtual int do_update_pos(RELAY_LOG_INFO *rli); /* Primitive to prepare for a sequence of row executions. diff --git a/sql/mysqld.cc b/sql/mysqld.cc index 7c7d9dc923f..4b9f75d8947 100644 --- a/sql/mysqld.cc +++ b/sql/mysqld.cc @@ -17,6 +17,7 @@ #include #include #include "slave.h" +#include "rpl_mi.h" #include "sql_repl.h" #include "rpl_filter.h" #include "repl_failsafe.h" diff --git a/sql/repl_failsafe.cc b/sql/repl_failsafe.cc index 934a6821514..f8994ed5506 100644 --- a/sql/repl_failsafe.cc +++ b/sql/repl_failsafe.cc @@ -19,6 +19,7 @@ #include "repl_failsafe.h" #include "sql_repl.h" #include "slave.h" +#include "rpl_mi.h" #include "rpl_filter.h" #include "log_event.h" #include diff --git a/sql/rpl_mi.h b/sql/rpl_mi.h index ae77e64d93a..cc074bf88a4 100644 --- a/sql/rpl_mi.h +++ b/sql/rpl_mi.h @@ -18,6 +18,9 @@ #ifdef HAVE_REPLICATION +#include "rpl_rli.h" + + /***************************************************************************** Replication IO Thread diff --git a/sql/rpl_rli.cc b/sql/rpl_rli.cc index b0db355154e..72e307d828b 100644 --- a/sql/rpl_rli.cc +++ b/sql/rpl_rli.cc @@ -15,6 +15,7 @@ #include "mysql_priv.h" +#include "rpl_mi.h" #include "rpl_rli.h" #include // For MY_STAT #include "sql_repl.h" // For check_binlog_magic @@ -37,7 +38,7 @@ st_relay_log_info::st_relay_log_info() inited(0), abort_slave(0), slave_running(0), until_condition(UNTIL_NONE), until_log_pos(0), retried_trans(0), tables_to_lock(0), tables_to_lock_count(0), - last_event_start_time(0) + last_event_start_time(0), m_flags(0) { DBUG_ENTER("st_relay_log_info::st_relay_log_info"); @@ -1086,6 +1087,52 @@ bool st_relay_log_info::cached_charset_compare(char *charset) const } +void st_relay_log_info::stmt_done(my_off_t const event_master_log_pos, + time_t event_creation_time) +{ + clear_flag(IN_STMT); + + /* + If in a transaction, and if the slave supports transactions, just + inc_event_relay_log_pos(). We only have to check for OPTION_BEGIN + (not OPTION_NOT_AUTOCOMMIT) as transactions are logged with + BEGIN/COMMIT, not with SET AUTOCOMMIT= . + + CAUTION: opt_using_transactions means innodb || bdb ; suppose the + master supports InnoDB and BDB, but the slave supports only BDB, + problems will arise: - suppose an InnoDB table is created on the + master, - then it will be MyISAM on the slave - but as + opt_using_transactions is true, the slave will believe he is + transactional with the MyISAM table. And problems will come when + one does START SLAVE; STOP SLAVE; START SLAVE; (the slave will + resume at BEGIN whereas there has not been any rollback). This is + the problem of using opt_using_transactions instead of a finer + "does the slave support _transactional handler used on the + master_". + + More generally, we'll have problems when a query mixes a + transactional handler and MyISAM and STOP SLAVE is issued in the + middle of the "transaction". START SLAVE will resume at BEGIN + while the MyISAM table has already been updated. + */ + if ((sql_thd->options & OPTION_BEGIN) && opt_using_transactions) + inc_event_relay_log_pos(); + else + { + inc_group_relay_log_pos(event_master_log_pos); + flush_relay_log_info(this); + /* + Note that Rotate_log_event::do_apply_event() does not call this + function, so there is no chance that a fake rotate event resets + last_master_timestamp. Note that we update without mutex + (probably ok - except in some very rare cases, only consequence + is that value may take some time to display in + Seconds_Behind_Master - not critical). + */ + last_master_timestamp= event_creation_time; + } +} + #if !defined(MYSQL_CLIENT) && defined(HAVE_REPLICATION) void st_relay_log_info::cleanup_context(THD *thd, bool error) { @@ -1112,6 +1159,7 @@ void st_relay_log_info::cleanup_context(THD *thd, bool error) m_table_map.clear_tables(); close_thread_tables(thd); clear_tables_to_lock(); + clear_flag(IN_STMT); last_event_start_time= 0; DBUG_VOID_RETURN; } diff --git a/sql/rpl_rli.h b/sql/rpl_rli.h index 3f06e108f6d..234d24a9569 100644 --- a/sql/rpl_rli.h +++ b/sql/rpl_rli.h @@ -51,6 +51,17 @@ struct RPL_TABLE_LIST; typedef struct st_relay_log_info { + /** + Flags for the state of the replication. + */ + enum enum_state_flag { + /** The replication thread is inside a statement */ + IN_STMT, + + /** Flag counter. Should always be last */ + STATE_FLAGS_COUNT + }; + /* If flag set, then rli does not store its state in any info file. This is the case only when we execute BINLOG SQL commands inside @@ -314,6 +325,66 @@ typedef struct st_relay_log_info transaction). */ time_t last_event_start_time; + + /** + Helper function to do after statement completion. + + This function is called from an event to complete the group by + either stepping the group position, if the "statement" is not + inside a transaction; or increase the event position, if the + "statement" is inside a transaction. + + @param event_log_pos + Master log position of the event. The position is recorded in the + relay log info and used to produce information for SHOW + SLAVE STATUS. + + @param event_creation_time + Timestamp for the creation of the event on the master side. The + time stamp is recorded in the relay log info and used to compute + the Seconds_behind_master field. + */ + void stmt_done(my_off_t event_log_pos, + time_t event_creation_time); + + + /** + Set the value of a replication state flag. + + @param flag Flag to set + */ + void set_flag(enum_state_flag flag) + { + m_flags |= (1UL << flag); + } + + /** + Clear the value of a replication state flag. + + @param flag Flag to clear + */ + void clear_flag(enum_state_flag flag) + { + m_flags &= ~(1UL << flag); + } + + /** + Is the replication inside a group? + + Replication is inside a group if either: + - The OPTION_BEGIN flag is set, meaning we're inside a transaction + - The RLI_IN_STMT flag is set, meaning we're inside a statement + + @retval true Replication thread is currently inside a group + @retval false Replication thread is currently not inside a group + */ + bool is_in_group() const { + return (sql_thd->options & OPTION_BEGIN) || + (m_flags & (1UL << IN_STMT)); + } + +private: + uint32 m_flags; } RELAY_LOG_INFO; diff --git a/sql/set_var.cc b/sql/set_var.cc index f7376a502fc..fd015202929 100644 --- a/sql/set_var.cc +++ b/sql/set_var.cc @@ -51,6 +51,7 @@ #include "mysql_priv.h" #include #include "slave.h" +#include "rpl_mi.h" #include #include #include diff --git a/sql/slave.cc b/sql/slave.cc index bc6cef95fc6..cd939bd092f 100644 --- a/sql/slave.cc +++ b/sql/slave.cc @@ -17,8 +17,9 @@ #include #include -#include "rpl_rli.h" #include "slave.h" +#include "rpl_mi.h" +#include "rpl_rli.h" #include "sql_repl.h" #include "rpl_filter.h" #include "repl_failsafe.h" @@ -1731,11 +1732,12 @@ static int exec_relay_log_event(THD* thd, RELAY_LOG_INFO* rli) /* */ - DBUG_PRINT("info",("type_code=%d (%s), server_id=%d", - type_code, ev->get_type_str(), ev->server_id)); - DBUG_PRINT("info", ("thd->options={ %s%s}", + DBUG_PRINT("exec_event",("%s(type_code: %d; server_id: %d)", + ev->get_type_str(), type_code, ev->server_id)); + DBUG_PRINT("info", ("thd->options: %s%s; rli->last_event_start_time: %lu", FLAGSTR(thd->options, OPTION_NOT_AUTOCOMMIT), - FLAGSTR(thd->options, OPTION_BEGIN))); + FLAGSTR(thd->options, OPTION_BEGIN), + rli->last_event_start_time)); @@ -1777,21 +1779,21 @@ static int exec_relay_log_event(THD* thd, RELAY_LOG_INFO* rli) if (reason == Log_event::EVENT_SKIP_NOT) exec_res= ev->apply_event(rli); #ifndef DBUG_OFF - else - { - /* - This only prints information to the debug trace. + /* + This only prints information to the debug trace. - TODO: Print an informational message to the error log? - */ - static const char *const explain[] = { - "event was not skipped", // EVENT_SKIP_NOT, - "event originated from this server", // EVENT_SKIP_IGNORE, - "event skip counter was non-zero" // EVENT_SKIP_COUNT - }; - DBUG_PRINT("info", ("%s was skipped because %s", - ev->get_type_str(), explain[reason])); - } + TODO: Print an informational message to the error log? + */ + static const char *const explain[] = { + // EVENT_SKIP_NOT, + "not skipped", + // EVENT_SKIP_IGNORE, + "skipped because event originated from this server", + // EVENT_SKIP_COUNT + "skipped because event skip counter was non-zero" + }; + DBUG_PRINT("skip_event", ("%s event was %s", + ev->get_type_str(), explain[reason])); #endif DBUG_PRINT("info", ("apply_event error = %d", exec_res)); diff --git a/sql/slave.h b/sql/slave.h index 107b74c09dd..cb880c8125d 100644 --- a/sql/slave.h +++ b/sql/slave.h @@ -22,13 +22,18 @@ #include "my_list.h" #include "rpl_filter.h" #include "rpl_tblmap.h" -#include "rpl_rli.h" -#include "rpl_mi.h" #define SLAVE_NET_TIMEOUT 3600 #define MAX_SLAVE_ERROR 2000 + +// Forward declarations +struct st_relay_log_info; +typedef st_relay_log_info RELAY_LOG_INFO; + +class MASTER_INFO; + /***************************************************************************** MySQL Replication diff --git a/sql/sql_binlog.cc b/sql/sql_binlog.cc index 6f7bbda96de..d3fdd95707c 100644 --- a/sql/sql_binlog.cc +++ b/sql/sql_binlog.cc @@ -14,6 +14,7 @@ Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA */ #include "mysql_priv.h" +#include "rpl_rli.h" #include "base64.h" /* diff --git a/sql/sql_class.cc b/sql/sql_class.cc index d4d8084b301..71f52974ec6 100644 --- a/sql/sql_class.cc +++ b/sql/sql_class.cc @@ -26,6 +26,7 @@ #endif #include "mysql_priv.h" +#include "rpl_rli.h" #include #include "log_event.h" #include diff --git a/sql/sql_class.h b/sql/sql_class.h index 66914bdf908..dc420976572 100644 --- a/sql/sql_class.h +++ b/sql/sql_class.h @@ -21,9 +21,11 @@ #endif #include "log.h" -#include "rpl_rli.h" #include "rpl_tblmap.h" +struct st_relay_log_info; +typedef st_relay_log_info RELAY_LOG_INFO; + class Query_log_event; class Load_log_event; class Slave_log_event; diff --git a/sql/sql_insert.cc b/sql/sql_insert.cc index c0e0203ed86..f0917556e30 100644 --- a/sql/sql_insert.cc +++ b/sql/sql_insert.cc @@ -60,6 +60,7 @@ #include "sql_select.h" #include "sql_show.h" #include "slave.h" +#include "rpl_mi.h" #ifndef EMBEDDED_LIBRARY static TABLE *delayed_get_table(THD *thd,TABLE_LIST *table_list); diff --git a/sql/sql_repl.cc b/sql/sql_repl.cc index debc9a7b572..5cc81fc2405 100644 --- a/sql/sql_repl.cc +++ b/sql/sql_repl.cc @@ -16,6 +16,7 @@ #include "mysql_priv.h" #ifdef HAVE_REPLICATION +#include "rpl_mi.h" #include "sql_repl.h" #include "log_event.h" #include "rpl_filter.h"