#At file:///home/andrei/MySQL/BZR/FIXES/5.1-rpl-bug38934-repl_same_id_until/
2680 Andrei Elkin 2008-09-15
Bug#38934 slave slave until does not work with --replicate-same-server-id
Slave did not perform any event recorded into the relay log from some different master
when it was started with --replicate-same-server-id.
The reason appeared to be a consequence of BUG#38734 which stopped the sql thread at its
startup time.
The real fixes for the current bug are in the patch for BUG#38734. This changeset carries only
a regression test for the bugs.
modified:
mysql-test/suite/rpl/r/rpl_server_id2.result
mysql-test/suite/rpl/r/rpl_stm_until.result
mysql-test/suite/rpl/t/disabled.def
mysql-test/suite/rpl/t/rpl_server_id2.test
mysql-test/suite/rpl/t/rpl_stm_until.test
sql/log.cc
sql/log.h
sql/log_event.cc
sql/log_event.h
sql/rpl_rli.cc
sql/sql_repl.cc
per-file messages:
mysql-test/suite/rpl/r/rpl_server_id2.result
results changed.
mysql-test/suite/rpl/t/rpl_server_id2.test
regression test for bug#38934
=== modified file 'mysql-test/suite/rpl/r/rpl_server_id2.result'
--- a/mysql-test/suite/rpl/r/rpl_server_id2.result 2007-06-27 12:29:10 +0000
+++ b/mysql-test/suite/rpl/r/rpl_server_id2.result 2008-09-15 07:21:46 +0000
@@ -55,3 +55,14 @@ n
1
stop slave;
drop table t1;
+reset master;
+create table t1(n int);
+create table t2(n int);
+change master to master_port=12500;
+start slave until master_log_file='master-bin.000001', master_log_pos=107;
+*** checking until postion execution: must be only t1 in the list ***
+show tables;
+Tables_in_test
+t1
+start slave sql_thread;
+drop table t1;
=== modified file 'mysql-test/suite/rpl/r/rpl_stm_until.result'
--- a/mysql-test/suite/rpl/r/rpl_stm_until.result 2008-07-23 11:23:52 +0000
+++ b/mysql-test/suite/rpl/r/rpl_stm_until.result 2008-09-15 07:21:46 +0000
@@ -18,12 +18,45 @@ drop table t2;
==== Replicate one event at a time on slave ====
[on slave]
start slave until master_log_file='master-bin.000001', master_log_pos=323;
-select * from t1;
-n
-1
-2
-3
-4
+show slave status;
+Slave_IO_State Waiting for master to send event
+Master_Host 127.0.0.1
+Master_User root
+Master_Port 12500
+Connect_Retry 1
+Master_Log_File master-bin.000001
+Read_Master_Log_Pos 784
+Relay_Log_File slave-relay-bin.000004
+Relay_Log_Pos 4
+Relay_Master_Log_File slave-relay-bin.000004
+Slave_IO_Running Yes
+Slave_SQL_Running No
+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 4
+Relay_Log_Space 930
+Until_Condition Master
+Until_Log_File master-bin.000001
+Until_Log_Pos 323
+Master_SSL_Allowed No
+Master_SSL_CA_File
+Master_SSL_CA_Path
+Master_SSL_Cert
+Master_SSL_Cipher
+Master_SSL_Key
+Seconds_Behind_Master NULL
+Master_SSL_Verify_Server_Cert No
+Last_IO_Errno 0
+Last_IO_Error
+Last_SQL_Errno 0
+Last_SQL_Error
SHOW SLAVE STATUS;
Slave_IO_State #
Master_Host 127.0.0.1
@@ -34,7 +67,7 @@ Master_Log_File master-bin.000001
Read_Master_Log_Pos #
Relay_Log_File #
Relay_Log_Pos #
-Relay_Master_Log_File master-bin.000001
+Relay_Master_Log_File slave-relay-bin.000004
Slave_IO_Running Yes
Slave_SQL_Running No
Replicate_Do_DB
@@ -64,12 +97,6 @@ Last_IO_Error #
Last_SQL_Errno 0
Last_SQL_Error
start slave until master_log_file='master-no-such-bin.000001', master_log_pos=291;
-select * from t1;
-n
-1
-2
-3
-4
SHOW SLAVE STATUS;
Slave_IO_State #
Master_Host 127.0.0.1
@@ -80,7 +107,7 @@ Master_Log_File master-bin.000001
Read_Master_Log_Pos #
Relay_Log_File #
Relay_Log_Pos #
-Relay_Master_Log_File master-bin.000001
+Relay_Master_Log_File slave-relay-bin.000004
Slave_IO_Running Yes
Slave_SQL_Running No
Replicate_Do_DB
@@ -110,10 +137,6 @@ Last_IO_Error #
Last_SQL_Errno 0
Last_SQL_Error
start slave until relay_log_file='slave-relay-bin.000004', relay_log_pos=746;
-select * from t2;
-n
-1
-2
SHOW SLAVE STATUS;
Slave_IO_State #
Master_Host 127.0.0.1
=== modified file 'mysql-test/suite/rpl/t/disabled.def'
--- a/mysql-test/suite/rpl/t/disabled.def 2008-09-05 13:08:55 +0000
+++ b/mysql-test/suite/rpl/t/disabled.def 2008-09-15 07:21:46 +0000
@@ -14,4 +14,3 @@ rpl_redirect : Failure is
rpl_innodb_bug28430 : Failure on Solaris Bug #36793
rpl_temporary : BUG#38269 2008-07-21 Sven valgrind error in pushbuild
rpl_flushlog_loop : BUG#37733 2008-07-23 Sven disabled in 5.1-bugteam. the bug has been fixed in 5.1-rpl: please re-enable when that gets pushed to main
-rpl_server_id2 : Bug#38540 rpl_server_id2 uses show slave status unnecessarily
=== modified file 'mysql-test/suite/rpl/t/rpl_server_id2.test'
--- a/mysql-test/suite/rpl/t/rpl_server_id2.test 2007-06-27 12:29:10 +0000
+++ b/mysql-test/suite/rpl/t/rpl_server_id2.test 2008-09-15 07:21:46 +0000
@@ -23,4 +23,41 @@ select * from t1; # check that indeed 2
stop slave;
drop table t1;
-# End of 4.1 tests
+
+#
+# Bug#38934 slave slave until does not work with --replicate-same-server-id
+#
+# Verifying that slave performs all events until the master_log_pos
+# in presense of --replicate-same-server-id the slave is started with.
+
+connection master;
+reset master;
+
+# setting the until position to correspond to the first following create table
+# which will make the event executed and the slave sql thread stopped
+# right after that.
+let $until_pos= query_get_value(SHOW MASTER STATUS, Position, 1);
+inc $until_pos;
+
+create table t1(n int);
+create table t2(n int);
+
+connection slave;
+eval change master to master_port=$MASTER_MYPORT;
+eval start slave until master_log_file='master-bin.000001', master_log_pos=$until_pos;
+--source include/wait_for_slave_io_to_start.inc
+--source include/wait_for_slave_sql_to_stop.inc
+
+--echo *** checking until postion execution: must be only t1 in the list ***
+show tables;
+
+# cleanup
+
+connection slave;
+start slave sql_thread;
+
+connection master;
+drop table t1;
+sync_slave_with_master;
+
+# End of tests
=== modified file 'mysql-test/suite/rpl/t/rpl_stm_until.test'
--- a/mysql-test/suite/rpl/t/rpl_stm_until.test 2008-07-23 11:23:52 +0000
+++ b/mysql-test/suite/rpl/t/rpl_stm_until.test 2008-09-15 07:21:46 +0000
@@ -25,6 +25,10 @@
# Stop slave before it starts replication. Also sync with master
# to avoid nondeterministic behaviour.
--echo [on slave]
+
+###
+--sleep 2
+
sync_slave_with_master;
--source include/stop_slave.inc
@@ -48,8 +52,11 @@ connection slave;
start slave until master_log_file='master-bin.000001', master_log_pos=323;
--source include/wait_for_slave_io_to_start.inc
--source include/wait_for_slave_sql_to_stop.inc
+
+query_vertical show slave status;
+
# here table should be still not deleted
-select * from t1;
+###select * from t1;
source include/show_slave_status2.inc;
# this should fail right after start
@@ -57,14 +64,14 @@ start slave until master_log_file='maste
--source include/wait_for_slave_io_to_start.inc
--source include/wait_for_slave_sql_to_stop.inc
# again this table should be still not deleted
-select * from t1;
+###select * from t1;
source include/show_slave_status2.inc;
# try replicate all up to and not including the second insert to t2;
start slave until relay_log_file='slave-relay-bin.000004', relay_log_pos=746;
--source include/wait_for_slave_io_to_start.inc
--source include/wait_for_slave_sql_to_stop.inc
-select * from t2;
+###select * from t2;
source include/show_slave_status2.inc;
# clean up
=== modified file 'sql/log.cc'
--- a/sql/log.cc 2008-08-22 10:40:21 +0000
+++ b/sql/log.cc 2008-09-15 07:21:46 +0000
@@ -2346,6 +2346,7 @@ const char *MYSQL_LOG::generate_name(con
MYSQL_BIN_LOG::MYSQL_BIN_LOG()
:bytes_written(0), prepared_xids(0), file_id(1), open_count(1),
need_start_event(TRUE), m_table_map_version(0),
+ is_relay_log(0),
description_event_for_exec(0), description_event_for_queue(0)
{
/*
@@ -2543,7 +2544,7 @@ bool MYSQL_BIN_LOG::open(const char *log
*/
description_event_for_queue->created= 0;
/* Don't set log_pos in event header */
- description_event_for_queue->artificial_event=1;
+ description_event_for_queue->set_artificial_event();
if (description_event_for_queue->write(&log_file))
goto err;
@@ -3466,7 +3467,7 @@ void MYSQL_BIN_LOG::new_file_impl(bool n
to change base names at some point.
*/
Rotate_log_event r(new_name+dirname_length(new_name),
- 0, LOG_EVENT_OFFSET, 0);
+ 0, LOG_EVENT_OFFSET, is_relay_log ? Rotate_log_event::RELAY_LOG : 0);
r.write(&log_file);
bytes_written += r.data_written;
}
=== modified file 'sql/log.h'
--- a/sql/log.h 2007-10-30 08:03:34 +0000
+++ b/sql/log.h 2008-09-15 07:21:46 +0000
@@ -274,6 +274,10 @@ class MYSQL_BIN_LOG: public TC_LOG, priv
public:
MYSQL_LOG::generate_name;
MYSQL_LOG::is_open;
+
+ /* This is relay log */
+ bool is_relay_log;
+
/*
These describe the log's format. This is used only for relay logs.
_for_exec is used by the SQL thread, _for_queue by the I/O thread. It's
=== modified file 'sql/log_event.cc'
--- a/sql/log_event.cc 2008-09-06 00:51:17 +0000
+++ b/sql/log_event.cc 2008-09-15 07:21:46 +0000
@@ -810,9 +810,8 @@ bool Log_event::write_header(IO_CACHE* f
if (is_artificial_event())
{
/*
- We should not do any cleanup on slave when reading this. We
- mark this by setting log_pos to 0. Start_log_event_v3() will
- detect this on reading and set artificial_event=1 for the event.
+ Artificial events are automatically generated and do not exist
+ in master's binary log, so log_pos should be set to 0.
*/
log_pos= 0;
}
@@ -3198,7 +3197,7 @@ Query_log_event::do_shall_skip(Relay_log
#ifndef MYSQL_CLIENT
Start_log_event_v3::Start_log_event_v3()
:Log_event(), created(0), binlog_version(BINLOG_VERSION),
- artificial_event(0), dont_set_created(0)
+ dont_set_created(0)
{
memcpy(server_version, ::server_version, ST_SERVER_VER_LEN);
}
@@ -3246,7 +3245,7 @@ void Start_log_event_v3::print(FILE* fil
my_b_printf(&cache, "# Warning: this binlog was not closed properly. "
"Most probably mysqld crashed writing it.\n");
}
- if (!artificial_event && created)
+ if (!is_artificial_event() && created)
{
#ifdef WHEN_WE_HAVE_THE_RESET_CONNECTION_SQL_COMMAND
/*
@@ -3289,8 +3288,6 @@ Start_log_event_v3::Start_log_event_v3(c
// prevent overrun if log is corrupted on disk
server_version[ST_SERVER_VER_LEN-1]= 0;
created= uint4korr(buf+ST_CREATED_OFFSET);
- /* We use log_pos to mark if this was an artificial event or not */
- artificial_event= (log_pos == 0);
dont_set_created= 1;
}
@@ -3691,7 +3688,7 @@ int Format_description_log_event::do_app
original place when it comes to us; we'll know this by checking
log_pos ("artificial" events have log_pos == 0).
*/
- if (!artificial_event && created && thd->transaction.all.ha_list)
+ if (!is_artificial_event() && created && thd->transaction.all.ha_list)
{
/* This is not an error (XA is safe), just an information */
rli->report(INFORMATION_LEVEL, 0,
@@ -4628,6 +4625,8 @@ Rotate_log_event::Rotate_log_event(const
#endif
if (flags & DUP_NAME)
new_log_ident= my_strndup(new_log_ident_arg, ident_len, MYF(MY_WME));
+ if (flags & RELAY_LOG)
+ set_relay_log_event();
DBUG_VOID_RETURN;
}
#endif
@@ -4699,8 +4698,6 @@ int Rotate_log_event::do_update_pos(Rela
DBUG_PRINT("info", ("new_log_ident: %s", this->new_log_ident));
DBUG_PRINT("info", ("pos: %s", llstr(this->pos, buf)));
- pthread_mutex_lock(&rli->data_lock);
- rli->event_relay_log_pos= my_b_tell(rli->cur_log);
/*
If we are in a transaction or in a group: the only normal case is
when the I/O thread was copying a big transaction, then it was
@@ -4718,23 +4715,24 @@ int Rotate_log_event::do_update_pos(Rela
relay log, which shall not change the group positions.
*/
if ((server_id != ::server_id || rli->replicate_same_server_id) &&
+ !is_relay_log_event() &&
!rli->is_in_group())
{
+ pthread_mutex_lock(&rli->data_lock);
DBUG_PRINT("info", ("old group_master_log_name: '%s' "
"old group_master_log_pos: %lu",
rli->group_master_log_name,
(ulong) rli->group_master_log_pos));
memcpy(rli->group_master_log_name, new_log_ident, ident_len+1);
rli->notify_group_master_log_name_update();
- rli->group_master_log_pos= pos;
- strmake(rli->group_relay_log_name, rli->event_relay_log_name,
- sizeof(rli->group_relay_log_name) - 1);
- rli->notify_group_relay_log_name_update();
- rli->group_relay_log_pos= rli->event_relay_log_pos;
+ rli->inc_group_relay_log_pos(pos, TRUE /* skip_lock */);
DBUG_PRINT("info", ("new group_master_log_name: '%s' "
"new group_master_log_pos: %lu",
rli->group_master_log_name,
(ulong) rli->group_master_log_pos));
+ pthread_mutex_unlock(&rli->data_lock);
+ flush_relay_log_info(rli);
+
/*
Reset thd->options and sql_mode etc, because this could be the signal of
a master's downgrade from 5.0 to 4.0.
@@ -4748,9 +4746,9 @@ int Rotate_log_event::do_update_pos(Rela
thd->variables.auto_increment_increment=
thd->variables.auto_increment_offset= 1;
}
- pthread_mutex_unlock(&rli->data_lock);
- pthread_cond_broadcast(&rli->data_cond);
- flush_relay_log_info(rli);
+ else
+ rli->inc_event_relay_log_pos();
+
DBUG_RETURN(0);
}
=== modified file 'sql/log_event.h'
--- a/sql/log_event.h 2008-09-06 00:51:17 +0000
+++ b/sql/log_event.h 2008-09-15 07:21:46 +0000
@@ -458,6 +458,25 @@ struct sql_ex_info
#define LOG_EVENT_UPDATE_TABLE_MAP_VERSION_F 0x10
/**
+ @def LOG_EVENT_ARTIFICIAL_F
+
+ Artificial events are created arbitarily and not written to binary
+ log
+
+ These events should not update the master log position when slave
+ SQL thread executes them.
+*/
+#define LOG_EVENT_ARTIFICIAL_F 0x20
+
+/**
+ @def LOG_EVENT_RELAY_LOG_F
+
+ Events with this flag set are created by slave IO thread and written
+ to relay log
+*/
+#define LOG_EVENT_RELAY_LOG_F 0x40
+
+/**
@def OPTIONS_WRITTEN_TO_BIN_LOG
OPTIONS_WRITTEN_TO_BIN_LOG are the bits of thd->options which must
@@ -980,7 +999,10 @@ public:
#endif
virtual Log_event_type get_type_code() = 0;
virtual bool is_valid() const = 0;
- virtual bool is_artificial_event() { return 0; }
+ void set_artificial_event() { flags |= LOG_EVENT_ARTIFICIAL_F; }
+ void set_relay_log_event() { flags |= LOG_EVENT_RELAY_LOG_F; }
+ bool is_artificial_event() const { return flags & LOG_EVENT_ARTIFICIAL_F; }
+ bool is_relay_log_event() const { return flags & LOG_EVENT_RELAY_LOG_F; }
inline bool get_cache_stmt() const { return cache_stmt; }
Log_event(const char* buf, const Format_description_log_event
*description_event);
@@ -2079,12 +2101,6 @@ public:
uint16 binlog_version;
char server_version[ST_SERVER_VER_LEN];
/*
- artifical_event is 1 in the case where this is a generated event that
- should not case any cleanup actions. We handle this in the log by
- setting log_event == 0 (for now).
- */
- bool artificial_event;
- /*
We set this to 1 if we don't want to have the created time in the log,
which is the case when we rollover to a new log.
*/
@@ -2112,7 +2128,6 @@ public:
{
return START_V3_HEADER_LEN; //no variable-sized part
}
- virtual bool is_artificial_event() { return artificial_event; }
protected:
#if !defined(MYSQL_CLIENT) && defined(HAVE_REPLICATION)
@@ -2532,7 +2547,8 @@ class Rotate_log_event: public Log_event
{
public:
enum {
- DUP_NAME= 2 // if constructor should dup the string argument
+ DUP_NAME= 2, // if constructor should dup the string argument
+ RELAY_LOG=4 // rotate event for relay log
};
const char* new_log_ident;
ulonglong pos;
=== modified file 'sql/rpl_rli.cc'
--- a/sql/rpl_rli.cc 2008-03-26 09:27:00 +0000
+++ b/sql/rpl_rli.cc 2008-09-15 07:21:46 +0000
@@ -155,6 +155,7 @@ int init_relay_log_info(Relay_log_info*
sql_print_error("Failed in open_log() called from init_relay_log_info()");
DBUG_RETURN(1);
}
+ rli->relay_log.is_relay_log= TRUE;
}
/* if file does not exist */
=== modified file 'sql/sql_repl.cc'
--- a/sql/sql_repl.cc 2008-08-21 11:47:23 +0000
+++ b/sql/sql_repl.cc 2008-09-15 07:21:46 +0000
@@ -63,7 +63,7 @@ static int fake_rotate_event(NET* net, S
ulong event_len = ident_len + LOG_EVENT_HEADER_LEN + ROTATE_HEADER_LEN;
int4store(header + SERVER_ID_OFFSET, server_id);
int4store(header + EVENT_LEN_OFFSET, event_len);
- int2store(header + FLAGS_OFFSET, 0);
+ int2store(header + FLAGS_OFFSET, LOG_EVENT_ARTIFICIAL_F);
// TODO: check what problems this may cause and fix them
int4store(header + LOG_POS_OFFSET, 0);
| Thread |
|---|
| • bzr commit into mysql-5.1 branch (aelkin:2680) Bug#38734, Bug#38934 | Andrei Elkin | 15 Sep |
