Re: bzr commit into mysql-5.1 branch (hezx:2666) Bug#38734

[He Zhenxing]

Andrei Elkin wrote: 
> He Zhenxing, hello!
> 
> This patch is even better!
> 
> It looks okay although i have a minor question about start event prior to approve.
> 
> > #At file:///media/sda3/work/mysql/bzrwork/b38734/5.1-rpl/
> >
> >  2666 He Zhenxing	2008-09-11
> >       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
> 
> I see that in the second implementation you changed this flag to
> LOG_EVENT_RELAY_LOG_F.
> Could you please correct this part. Btw, the former name's meaning was
> more transparent to me.
> 

right, the comment should be changed accordingly. The reason I choose a
new name for that is because I think it is more accurate, because Rotate
event generated by relay log should be ingored by SQL thread, but should
not by others, such as IO thread, mysqlbinlog, or others, so I think
LOG_EVENT_RELAY_LOG_F is more acturate to describe what the event is.

> 
> >   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-11 05:59:47 +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();
> 
> Not to request to change, merely a thought.
> Maybe it's the matter of taste, but I prefer a single-liner not to be
> a method which requires to find the definition.
> Should it be 2 or more operations that would make sense.
> 

Yes, I think there are differences of tastes in coding.

> 
> >  
> >        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-11 05:59:47 +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;
> > +
> 
> right, this is better indeed than changing signatures.
> 

Good

> 
> >    /*
> >      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-11 05:59:47 +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)
> 
> so the assignment to artificial_event gets removed from the constructor. But how it
> is
> becomes initialized for using in the following hunk's

I use LOG_EVENT_ARTIFICIAL_F flag bit to indicate wether an event is
artificial or not, so the member 'artificial_event' is removed. And the
flag will be initialized when initializing the `flags` member of
Log_event.

> 
> >  {
> >    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)
> 
> code?
> 
> >    {
> >  #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();
> >    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);
> >    /*
> >      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;
> 
> I think you needed to make a note in the per-file comments about
> removing unnecessary notification for relay-log coordinates change.
> 

OK

> 
> > +    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.
> > @@ -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();
> > +
> >  
> 
> Explaing why explicit broadcast is also something that you might mention
> in comments.
> 

OK

> >    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-11 05:59:47 +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() 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);
> > @@ -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
> 
> shall we call it as "artificial event" ? to mean the event is not from
> the master's binlog and then it should be ignored.
> 

No, artificial events are events generated by master and are not from
master's binlog, while relay_log events are generated by slave and
written to slave's relay log. We have to distinguish these too cases,
for artifical events, the SQL thread will execute them but do not update
the master position and time, for relay log events, they should be
totally ignored by SQL thread.

> 
> >    };
> >    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-11 05:59:47 +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-11 05:59:47 +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);
> >
> >
> > -- 
> > MySQL Code Commits Mailing List
> > For list archives: http://lists.mysql.com/commits
> > To unsubscribe:    http://lists.mysql.com/commits?unsub=1
> >
> 
> cheers,
> 
> Andrei