List:Commits« Previous MessageNext Message »
From:Andrei Elkin Date:June 10 2011 8:04am
Subject:bzr commit into mysql-next-mr-wl5569 branch (andrei.elkin:3284) WL#5569
View as plain text  
#At file:///home/andrei/MySQL/BZR/2a-23May/WL/mysql-next-mr-wl5569/ based on revid:andrei.elkin@stripped

 3284 Andrei Elkin	2011-06-10
      wl#5569 MTS
      
      This patch implements Seconds_behind_master (SBM) updating policy for MTS.
      
      The status parameter is updated per some number of processed group of events.
      The number can't be greater than @@global.slave_checkpoint_group and anyway SBM updating
      rate does not exceed @@global.slave_checkpoint_period.
      Notice that SBM is set to a new value after processing the terminal event (e.g Commit) of a group.
      Coordinator resets SBM when notices no more groups left neither to read from Relay-log
      nor to process by Workers.
     @ mysql-test/suite/rpl/t/rpl_parallel_seconds_behind_master.test
        SBM policy for MTS tests are added.
     @ mysql-test/suite/rpl/t/rpl_seconds_behind_master.test
        the currrent version of the test is MTS unfriendly.
     @ sql/log_event.cc
        Deploying association of the being assigned group with its terminal event's
        timestamp corresponding to end of the event execution.
        Making Rotate's update_pos method to modify SBM explicitly through
        reset_notified_checkpoint() rathen than mts_checkpoint_routine().
     @ sql/rpl_rli.cc
        Making reset_notified_checkpoint() to install a new value of SBM.
     @ sql/rpl_rli.h
        Making reset_notified_checkpoint() to install a new value of SBM.
     @ sql/rpl_rli_pdb.h
        |Adding new member to transfer SBM of the group to Coordinator which
        it installs whenever it processes GAQ effectively.
     @ sql/rpl_slave.cc
        Coordinator installs SBM as timestamp of the last group discared from GAQ.
        Wait for new event Coordinator's read-loop is augmented to implement
        SBM resetting.

    added:
      mysql-test/suite/rpl/r/rpl_parallel_seconds_behind_master.result
      mysql-test/suite/rpl/t/rpl_parallel_seconds_behind_master.test
    modified:
      mysql-test/suite/rpl/t/rpl_seconds_behind_master.test
      sql/log_event.cc
      sql/rpl_rli.cc
      sql/rpl_rli.h
      sql/rpl_rli_pdb.h
      sql/rpl_slave.cc
=== added file 'mysql-test/suite/rpl/r/rpl_parallel_seconds_behind_master.result'
--- a/mysql-test/suite/rpl/r/rpl_parallel_seconds_behind_master.result	1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/rpl/r/rpl_parallel_seconds_behind_master.result	2011-06-10 08:04:00 +0000
@@ -0,0 +1,35 @@
+include/master-slave.inc
+[connection master]
+call mtr.add_suppression('Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT');
+include/stop_slave.inc
+set @save.mts_slave_parallel_workers= @@global.mts_slave_parallel_workers;
+set @@global.mts_slave_parallel_workers= 4;
+set @save.mts_checkpoint_period= @@global.mts_checkpoint_period;
+set @@global.mts_checkpoint_period= 500;
+set @save.slave_transaction_retries= @@global.slave_transaction_retries;
+start slave io_thread;
+include/wait_for_slave_io_to_start.inc
+create table t1 (f1 int) engine=innodb;
+create table t2 (f1 int) engine=innodb;
+begin;
+insert into t1 values (sleep(3) + 1);
+Warnings:
+Note	1592	Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement is unsafe because it uses a system function that may return a different value on the slave.
+commit;
+begin;
+insert into t2 values (1);
+commit;
+include/start_slave.inc
+include/sync_slave_io_with_master.inc
+lock table t2 write;
+First transaction is done, now get Seconds_Behind_Master after it...
+include/wait_for_slave_param.inc [Seconds_Behind_Master]
+Seconds_Behind_Master after first transaction is as expected.
+unlock tables;
+include/wait_for_slave_param.inc [Seconds_Behind_Master]
+drop tables t1, t2;
+set @@global.mts_checkpoint_period= @save.mts_checkpoint_period;
+set @@global.mts_slave_parallel_workers= @save.mts_slave_parallel_workers;
+set @@global.slave_transaction_retries= @save.slave_transaction_retries;
+include/rpl_end.inc
+end of the tests

=== added file 'mysql-test/suite/rpl/t/rpl_parallel_seconds_behind_master.test'
--- a/mysql-test/suite/rpl/t/rpl_parallel_seconds_behind_master.test	1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/rpl/t/rpl_parallel_seconds_behind_master.test	2011-06-10 08:04:00 +0000
@@ -0,0 +1,141 @@
+#
+# Testing of Seconds_Behind_Master (SBM) to behave as the following
+# SBM changes discretely per some number of processed group of events,
+# e.g transactions.
+# The number is either @@global.slave_checkpoint_group or less if
+# @@global.slave_checkpoint_period timer elapses first.
+# The value updates *after* the last group commit is executed.
+# Resetting to zero behaviour when Slave goes to read events is
+# preserved.
+#
+
+-- source include/master-slave.inc
+-- source include/have_debug.inc
+
+# make the test only run once (STMT is actually needed because we rely
+# on SHOW PROCESS LIST output in some of the tests)
+-- source include/have_binlog_format_statement.inc
+
+# todo: sleep() is deterministic!!!
+call mtr.add_suppression('Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT');
+
+# restart slave in MTS mode
+connection slave;
+source include/stop_slave.inc;
+set @save.mts_slave_parallel_workers= @@global.mts_slave_parallel_workers;
+set @@global.mts_slave_parallel_workers= 4;
+set @save.mts_checkpoint_period= @@global.mts_checkpoint_period;
+set @@global.mts_checkpoint_period= 500; # 0.5 sec
+# to avoid warnings
+set @save.slave_transaction_retries= @@global.slave_transaction_retries;
+
+#
+# Idea of demonstration.
+# 
+# Two transactions on the same db are generated for MTS. The first has some
+# natural delay, and the 2nd will be locked out of its data.
+# While the first is being processed Coordinator empties the relay-log
+# to enter waiting for more events.
+# It does so being awakened @@global.slave_checkpoint_period-ically 
+# to check out if some groups of events have been done to update SBM (demo 1). 
+#
+# Resetting of SBM is a possibility whenever Coordinator
+# notices no more groups left neither to read nor to process (demo 2).
+#
+
+start slave io_thread;
+source include/wait_for_slave_io_to_start.inc;
+
+connection master;
+
+create table t1 (f1 int) engine=innodb;
+create table t2 (f1 int) engine=innodb;
+save_master_pos;
+
+# 1st transaction that will be used to compute SBM.
+# It will hang $idle time at least in processing to get min estimate for SBM
+let $idle= 3;
+
+begin;
+  eval insert into t1 values (sleep($idle) + 1);
+commit;
+
+# 2nd transaction to block Coordinator from resetting SBM
+begin;
+  insert into t2 values (1);
+commit;
+
+connection slave;
+source include/start_slave.inc;
+
+#
+# all events are in relay-log
+#
+connection master;
+
+source include/sync_slave_io_with_master.inc;
+
+# tables are created on slave
+connection slave;
+sync_with_master;
+
+connection slave1;
+lock table t2 write;  # to block 2nd trans
+
+connection slave;
+
+let $count= 1;
+let $table= t1;
+source include/wait_until_rows_count.inc;
+
+--echo First transaction is done, now get Seconds_Behind_Master after it...
+
+#
+# demo 1:
+# So now 1st is over, and it SBM must have gain at least $idle seconds.
+#
+let $slave_param= Seconds_Behind_Master;
+let $slave_param_comparison= >=; 
+let $slave_param_value= $idle;
+source include/wait_for_slave_param.inc;
+
+# checking sanity of SBM value
+let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1);
+let $lower_bound= $idle;
+if (`SELECT $sbm < $idle`)
+{
+  -- echo *** Seconds behind master is $sbm less than minimum expected $idle ***
+  -- source include/show_rpl_debug_info.inc
+  -- die
+}
+
+--echo Seconds_Behind_Master after first transaction is as expected.
+
+connection slave1;
+unlock tables;
+
+#
+# demo 2: Resetting of SBM upon all groups have been processed and 
+#         nothing left in relay-log.
+#
+connection slave;
+let $slave_param= Seconds_Behind_Master;
+let $slave_param_comparison= =; 
+let $slave_param_value= 0;
+source include/wait_for_slave_param.inc;
+
+##
+# cleanup
+##
+connection master;
+drop tables t1, t2;
+
+sync_slave_with_master;
+
+set @@global.mts_checkpoint_period= @save.mts_checkpoint_period;
+set @@global.mts_slave_parallel_workers= @save.mts_slave_parallel_workers;
+set @@global.slave_transaction_retries= @save.slave_transaction_retries;
+
+--source include/rpl_end.inc
+
+--echo end of the tests

=== modified file 'mysql-test/suite/rpl/t/rpl_seconds_behind_master.test'
--- a/mysql-test/suite/rpl/t/rpl_seconds_behind_master.test	2010-12-19 17:22:30 +0000
+++ b/mysql-test/suite/rpl/t/rpl_seconds_behind_master.test	2011-06-10 08:04:00 +0000
@@ -5,6 +5,10 @@
 # on SHOW PROCESS LIST output in some of the tests)
 -- source include/have_binlog_format_statement.inc
 
+# this test logics requires adaption to MTS policies for SBM
+# (see rpl_parallel_seconds_behind_master.test)
+-- source include/not_mts_slave_parallel_workers.inc
+
 SET @old_debug= @@global.debug;
 call mtr.add_suppression('Unsafe statement binlogged in statement format since BINLOG_FORMAT = STATEMENT');
 

=== modified file 'sql/log_event.cc'
--- a/sql/log_event.cc	2011-06-08 20:18:08 +0000
+++ b/sql/log_event.cc	2011-06-10 08:04:00 +0000
@@ -2635,6 +2635,7 @@ Slave_worker *Log_event::get_slave_worke
       ret_worker->checkpoint_notified= TRUE;
     }
     ptr_g->checkpoint_seqno= rli->checkpoint_seqno;
+    ptr_g->ts= when + (time_t) exec_time;
     rli->checkpoint_seqno++;
   }
   
@@ -6514,17 +6515,17 @@ int Rotate_log_event::do_update_pos(Rela
       ((!rli->is_parallel_exec() && !rli->is_in_group()) ||
        rli->mts_group_status != Relay_log_info::MTS_IN_GROUP))
   {
+    if (rli->is_parallel_exec())
+    {
+      (void) mts_checkpoint_routine(rli, 0, FALSE, TRUE);  // todo: error branch
+    }
+
     mysql_mutex_lock(&rli->data_lock);
     DBUG_PRINT("info", ("old group_master_log_name: '%s'  "
                         "old group_master_log_pos: %lu",
                         rli->get_group_master_log_name(),
                         (ulong) rli->get_group_master_log_pos()));
 
-    if (rli->is_parallel_exec())
-    {
-      (void) mts_checkpoint_routine(rli, 0, FALSE, TRUE);  // todo: error branch
-    }
-
     memcpy((void *)rli->get_group_master_log_name(),
            new_log_ident, ident_len + 1);
     rli->notify_group_master_log_name_update();
@@ -6537,7 +6538,7 @@ int Rotate_log_event::do_update_pos(Rela
     mysql_mutex_unlock(&rli->data_lock);
     rli->flush_info(TRUE);  // todo: error branch
     if (rli->is_parallel_exec())
-      rli->reset_notified_checkpoint(0);
+      rli->reset_notified_checkpoint(0, when + (time_t) exec_time);
 
     /*
       Reset thd->variables.option_bits and sql_mode etc, because this could be the signal of

=== modified file 'sql/rpl_rli.cc'
--- a/sql/rpl_rli.cc	2011-06-08 20:18:08 +0000
+++ b/sql/rpl_rli.cc	2011-06-10 08:04:00 +0000
@@ -191,8 +191,14 @@ void Relay_log_info::reset_notified_rela
    Worker notices the new checkpoint value at the group commit
    to reset the current bitmap and starts using the clean bitmap
    indexed from zero of being reset checkpoint_seqno.
+   New seconds_behind_master timestamp is installed.
+
+   @param shift  number of bits to shift by Worker due to the current
+                 checkpoint change.
+   @param new_ts new seconds_behind_master timestamp value unless zero.
+                 Zero could be due to FD event.
 */
-void Relay_log_info::reset_notified_checkpoint(ulong shift)
+void Relay_log_info::reset_notified_checkpoint(ulong shift, time_t new_ts= 0)
 {
   if (!is_parallel_exec())
     return;
@@ -207,6 +213,13 @@ void Relay_log_info::reset_notified_chec
     w->bitmap_shifted += shift; // to reset at passing the accumulate value into GAQ
   }
   checkpoint_seqno= 0;
+
+  if (new_ts)
+  {
+    mysql_mutex_lock(&data_lock);
+    last_master_timestamp= new_ts;
+    mysql_mutex_unlock(&data_lock);
+  }
 }
 
 static inline int add_relay_log(Relay_log_info* rli,LOG_INFO* linfo)

=== modified file 'sql/rpl_rli.h'
--- a/sql/rpl_rli.h	2011-06-08 20:18:08 +0000
+++ b/sql/rpl_rli.h	2011-06-10 08:04:00 +0000
@@ -537,7 +537,7 @@ public:
      Coordinator notifies Workers about this event. Coordinator and Workers
      maintain a bitmap of executed group that is reset with a new checkpoint. 
   */
-  void reset_notified_checkpoint(ulong);
+  void reset_notified_checkpoint(ulong, time_t);
 
   /**
     Helper function to do after statement completion.

=== modified file 'sql/rpl_rli_pdb.h'
--- a/sql/rpl_rli_pdb.h	2011-06-08 20:18:08 +0000
+++ b/sql/rpl_rli_pdb.h	2011-06-10 08:04:00 +0000
@@ -144,7 +144,8 @@ typedef struct st_slave_job_group
   my_off_t checkpoint_relay_log_pos; // T-event lop_pos filled by W for CheckPoint
   char*    checkpoint_relay_log_name;
   volatile uchar done;  // Flag raised by W,  read and reset by C
-  ulong shifted;          // shift the last CP bitmap at receiving a new CP
+  ulong    shifted;     // shift the last CP bitmap at receiving a new CP
+  time_t   ts;          // Group's timestampt to update Seconds_behind_master
 } Slave_job_group;
 
 #define retrieve_job(from, to) \

=== modified file 'sql/rpl_slave.cc'
--- a/sql/rpl_slave.cc	2011-06-08 20:18:08 +0000
+++ b/sql/rpl_slave.cc	2011-06-10 08:04:00 +0000
@@ -3088,7 +3088,8 @@ static int exec_relay_log_event(THD* thd
       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() ||
+    if (!(rli->is_parallel_exec() ||
+          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;
@@ -4153,7 +4154,7 @@ bool mts_checkpoint_routine(Relay_log_in
     } // end of commit_positions
   */
 
-  rli->reset_notified_checkpoint(cnt);
+  rli->reset_notified_checkpoint(cnt, rli->gaq->lwm.ts);
 
 end:
   set_timespec_nsec(rli->last_clock, 0);
@@ -6005,7 +6006,8 @@ static Log_event* next_event(Relay_log_i
 
         /* shows zero while it is sleeping (and until the next event 
            is about to be executed) */
-        rli->last_master_timestamp= 0;
+        if (!rli->is_parallel_exec())
+          rli->last_master_timestamp= 0;
 
         DBUG_ASSERT(rli->relay_log.get_open_count() ==
                     rli->cur_log_old_open_count);
@@ -6089,6 +6091,8 @@ static Log_event* next_event(Relay_log_i
             mysql_mutex_unlock(log_lock);
             mts_checkpoint_routine(rli, period, FALSE, FALSE); // TODO: ALFRANIO ERROR
             mysql_mutex_lock(log_lock);
+            if (rli->gaq->empty())
+              rli->last_master_timestamp= 0;
 
             set_timespec_nsec(waittime, period);
             thd->enter_cond(log_cond, log_lock,


Attachment: [text/bzr-bundle] bzr/andrei.elkin@oracle.com-20110610080400-yo3gawj9c42sq8wm.bundle
Thread
bzr commit into mysql-next-mr-wl5569 branch (andrei.elkin:3284) WL#5569Andrei Elkin10 Jun