List:Commits« Previous MessageNext Message »
From:Dao-Gang.Qu Date:August 30 2010 10:59am
Subject:bzr commit into mysql-next-mr-bugfixing branch (Dao-Gang.Qu:3192) Bug#53167
View as plain text  
#At file:///home/daogangqu/mysql/bzrwork1/bug53167/mysql-next-mr-bugfixing/ based on revid:vvaintroub@stripped

 3192 Dao-Gang.Qu@stripped	2010-08-30
      Bug #53167  	Seconds_Behind_Master is wrong after start slave
      
      When a slave server has an existing relay log and the user issues
      START SLAVE, the output from "SHOW SLAVE STATUS" shows a wrong
      value for Seconds_Behind_Master until the first event from the relay
      log has finished executing. The displayed value for Seconds_Behind_Master
      is calculated based on the timestamp of the Format_Description_Log_Event
      from master. This can be a very big number if the relay log was created
      long ago.
      
      The Timestamp recorded in Format_Description_Log_Event should not be used
      when executing the Format_Description_Log_Event on slave. So do not assign
      the Timestamp of the Format_Description_Log_Event to last_master_timestamp.
      Then the peak value will disappear.
     @ mysql-test/suite/rpl/t/rpl_delayed_slave.test
        Upadted to test the patch of Bug #53167.
     @ sql/binlog.cc
        Added code to set LOG_EVENT_RELAY_LOG_F flag for relay log's FD
     @ sql/rpl_slave.cc
        Added code to update the last_master_timestamp at the end of a
        transaction(to non-transation, treat every statement as a transaction
        as it is enclosed with 'BEGIN' and 'COMMIT' in binary log) for
        making the value of Seconds_Behind_Master more reasonable.

    modified:
      mysql-test/suite/rpl/t/rpl_delayed_slave.test
      sql/binlog.cc
      sql/rpl_slave.cc
=== modified file 'mysql-test/suite/rpl/t/rpl_delayed_slave.test'
--- a/mysql-test/suite/rpl/t/rpl_delayed_slave.test	2010-06-21 12:32:29 +0000
+++ b/mysql-test/suite/rpl/t/rpl_delayed_slave.test	2010-08-30 10:59:23 +0000
@@ -183,15 +183,16 @@ INSERT INTO t1(a) VALUES (delay_on_slave
 --echo # sleep 1*T
 --sleep $time1
 
+let $bug_53167_is_fixed= 1;
 if ($bug_53167_is_fixed) {
-
---let $seconds_behind_master= query_get_value(SHOW SLAVE STATUS, Seconds_Behind_Master, 1)
-if (`SELECT $seconds_behind_master <= 0 OR $seconds_behind_master >= $time2`) {
-  --echo Seconds_Behind_Master was $seconds_behind_master. Expected that 0 < Seconds_Behind_Master < SQL_Delay = $time2
-  --source include/show_rpl_debug_info.inc
-  --die Seconds_Behind_Master was wrong
-}
-
+  --let $seconds_behind_master= query_get_value(SHOW SLAVE STATUS, Seconds_Behind_Master, 1)
+  # The value of Seconds_Behind_Master will be zero
+  # before the first non-FD event is executed.
+  if (`SELECT $seconds_behind_master < 0 OR $seconds_behind_master >= $time2`) {
+    --echo Seconds_Behind_Master was $seconds_behind_master. Expected that 0 =< Seconds_Behind_Master < SQL_Delay = $time2
+    --source include/show_rpl_debug_info.inc
+    --die Seconds_Behind_Master was wrong
+  }
 }
 
 --echo # sleep 1*T

=== modified file 'sql/binlog.cc'
--- a/sql/binlog.cc	2010-07-29 12:32:36 +0000
+++ b/sql/binlog.cc	2010-08-30 10:59:23 +0000
@@ -1597,6 +1597,9 @@ bool MYSQL_BIN_LOG::open(const char *log
       if (!s.is_valid())
         goto err;
       s.dont_set_created= null_created_arg;
+      /* Set LOG_EVENT_RELAY_LOG_F flag for relay log's FD */
+      if (is_relay_log)
+        s.flags|= LOG_EVENT_RELAY_LOG_F;
       if (s.write(&log_file))
         goto err;
       bytes_written+= s.data_written;

=== modified file 'sql/rpl_slave.cc'
--- a/sql/rpl_slave.cc	2010-08-04 10:34:01 +0000
+++ b/sql/rpl_slave.cc	2010-08-30 10:59:23 +0000
@@ -2679,16 +2679,17 @@ static int exec_relay_log_event(THD* thd
   {
     int exec_res;
 
-    /* 
+    /*
       Even if we don't execute this event, we keep the master timestamp,
       so that seconds behind master shows correct delta (there are events
       that are not replayed, so we keep falling behind).
 
       If it is an artificial event, or a relay log event (IO thread generated
-      event) or ev->when is set to 0, we don't update the 
+      event) or ev->when is set to 0, or a FD from master, we don't update the
       last_master_timestamp.
-     */
-    if (!(ev->is_artificial_event() || ev->is_relay_log_event() || (ev->when == 0)))
+    */
+    if (!(ev->is_artificial_event() || ev->is_relay_log_event() ||
+          (ev->when == 0) || ev->get_type_code() == FORMAT_DESCRIPTION_EVENT))
     {
       rli->last_master_timestamp= ev->when + (time_t) ev->exec_time;
       DBUG_ASSERT(rli->last_master_timestamp >= 0);


Attachment: [text/bzr-bundle] bzr/dao-gang.qu@sun.com-20100830105923-9mpmvzrwtaumssrv.bundle
Thread
bzr commit into mysql-next-mr-bugfixing branch (Dao-Gang.Qu:3192) Bug#53167Dao-Gang.Qu30 Aug
Re: bzr commit into mysql-next-mr-bugfixing branch (Dao-Gang.Qu:3192)Bug#53167Daogang Qu30 Aug