Hi Jason!
The patch looks good, but I have some comments below.
Just my few cents,
Mats Kindahl
He Zhenxing wrote:
> #At file:///media/sda3/work/mysql/bzrwork/b38734/5.1-rpl/
>
> 2666 He Zhenxing 2008-09-10
> BUG#38734 rpl_server_id2 sync_with_master failed
>
> Rotate event is automatically generated and written when rotating binary
> log or relay log. Rotate events for relay logs are usually ignored by slave
> SQL thread becuase they have the same server id as that of the slave.
> However, if --replicate-same-server-id is enabled, rotate event
> for relay log would be treated as if it's a rotate event from master, and
> would be executed by slave to update the rli->group_master_log_name and
> rli->group_master_log_pos to a wrong value and cause the MASTER_POS_WAIT
> function to fail and return NULL.
>
> This patch fixed this problem by setting a flag bit (LOG_EVENT_RELAY_LOG_F)
> in the event to tell the SQL thread to ignore these Rotate events generated
> for relay logs.
>
> This patch also added another binlog event flag bit (LOG_EVENT_ARTIFICIAL_F)
> to distinquish faked events, the method used before this was by checking if
> log_pos was zero.
> modified:
> 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:
> sql/log.cc
> Add a parameter to MYSQL_BIN_LOG::new_file to distinguish create new file for
> binary log or relay log.
> sql/log.h
> Add a parameter to MYSQL_BIN_LOG::new_file to distinguish create new file for
> binary log or relay log.
> sql/log_event.cc
> If LOG_EVENT_IGNORE_F is set in the event flags, ignore it
> sql/log_event.h
> Add LOG_EVENT_IGNORE_F flag to Log_event flags, events has this flags set will be
> ignored by slave SQL thread
> Add RELAY_LOG flag to Rotate_log_event flags
> === modified file 'sql/log.cc'
> --- a/sql/log.cc 2008-08-22 10:40:21 +0000
> +++ b/sql/log.cc 2008-09-10 07:10:50 +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-10 07:10:50 +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-08-06 10:41:27 +0000
> +++ b/sql/log_event.cc 2008-09-10 07:10:50 +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;
> }
> @@ -2625,7 +2624,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);
> }
> @@ -2673,7 +2672,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
> /*
> @@ -2715,8 +2714,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;
> }
>
> @@ -3117,7 +3114,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,
> @@ -4054,6 +4051,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();
OK.
> DBUG_VOID_RETURN;
> }
> #endif
> @@ -4125,8 +4124,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);
So, rotate events does not update even the event_relay_log_pos. It seems it was
only used to update the group_relay_log_pos below since normally
event_relay_log_pos is updated from the future_event_relay_log_pos.
> /*
> 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
> @@ -4144,23 +4141,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 */);
It seems this code was left over from a previous refactoring, because this code
(below), which is very similar to the above, is in inc_group_relay_log_pos().
if (!skip_lock)
pthread_mutex_lock(&data_lock);
inc_event_relay_log_pos();
group_relay_log_pos= event_relay_log_pos;
strmake(group_relay_log_name,event_relay_log_name,
sizeof(group_relay_log_name)-1);
notify_group_relay_log_name_update();
However, the end effect of the code is now to set group_relay_log_pos to
future_event_relay_log_pos instead of my_b_tell(rli->cur_log). Since
future_event_relay_log_pos is set to my_b_tell(rli->cur_log) in next_event()
prior to calling this code, it should be fine.
> 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.
> @@ -4174,9 +4172,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();
> +
OK. AIUI, you basically either increase the group position and flush the data,
or increase the event position but does not flush the data.
>
> DBUG_RETURN(0);
> }
>
> === modified file 'sql/log_event.h'
> --- a/sql/log_event.h 2008-07-31 06:24:27 +0000
> +++ b/sql/log_event.h 2008-09-10 07:10:50 +0000
> @@ -450,6 +450,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
> @@ -966,7 +985,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() { return flags & LOG_EVENT_ARTIFICIAL_F; }
Make methods const in this case, it will pay off in the long run.
bool is_artificial_event() const { return flags & LOG_EVENT_ARTIFICIAL_F; }
> + bool is_relay_log_event() { return flags & LOG_EVENT_RELAY_LOG_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);
> @@ -2065,12 +2087,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.
> */
> @@ -2098,7 +2114,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)
> @@ -2518,7 +2533,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;
> @@ -2551,6 +2567,7 @@ public:
>
> private:
> #if !defined(MYSQL_CLIENT) && defined(HAVE_REPLICATION)
> +// virtual int do_apply_event(Relay_log_info *rli);
Huh?
> virtual int do_update_pos(Relay_log_info *rli);
> virtual enum_skip_reason do_shall_skip(Relay_log_info *rli);
> #endif
>
> === 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-10 07:10:50 +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-02-19 12:58:08 +0000
> +++ b/sql/sql_repl.cc 2008-09-10 07:10:50 +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);
>
>
--
Mats Kindahl
Lead Software Developer
Replication Team
MySQL AB, www.mysql.com
