List:Commits« Previous MessageNext Message »
From:He Zhenxing Date:September 11 2008 6:00am
Subject:bzr commit into mysql-5.1 branch (hezx:2666) Bug#38734
View as plain text  
#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
  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();
 
       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;
+
   /*
     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)
 {
   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();
   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;
+    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();
+
 
   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
   };
   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);

Thread
bzr commit into mysql-5.1 branch (hezx:2666) Bug#38734He Zhenxing11 Sep
  • Re: bzr commit into mysql-5.1 branch (hezx:2666) Bug#38734Andrei Elkin15 Sep
    • Re: bzr commit into mysql-5.1 branch (hezx:2666) Bug#38734He Zhenxing18 Sep
    • Re: bzr commit into mysql-5.1 branch (hezx:2666) Bug#38734He Zhenxing22 Sep