List:Commits« Previous MessageNext Message »
From:Andrei Elkin Date:April 6 2011 12:52pm
Subject:bzr commit into mysql-next-mr-wl5569 branch (andrei.elkin:3275) 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

 3275 Andrei Elkin	2011-04-06
      wl#5569 MTS
      
      Statistics for Workers and Coordinator incl waiting times, sleeping is reported
      now into the error log as slave stopping time.
     @ sql/log_event.cc
        statistics addded.
     @ sql/rpl_rli.h
        statistics added.
     @ sql/rpl_slave.cc
        print-out mts statistics into the error log at stopping the slave.

    modified:
      mysql-test/extra/rpl_tests/rpl_parallel_load.test
      mysql-test/suite/rpl/r/rpl_sequential.result
      sql/log_event.cc
      sql/rpl_rli.cc
      sql/rpl_rli.h
      sql/rpl_slave.cc
=== modified file 'mysql-test/extra/rpl_tests/rpl_parallel_load.test'
--- a/mysql-test/extra/rpl_tests/rpl_parallel_load.test	2011-04-05 16:26:37 +0000
+++ b/mysql-test/extra/rpl_tests/rpl_parallel_load.test	2011-04-06 12:51:58 +0000
@@ -1,8 +1,8 @@
 #
 # This is a load generator to call from rpl_parallel and rpl_sequential tests
-#
 
 #
+#
 # load volume parameter
 #
 

=== modified file 'mysql-test/suite/rpl/r/rpl_sequential.result'
--- a/mysql-test/suite/rpl/r/rpl_sequential.result	2011-04-03 10:07:30 +0000
+++ b/mysql-test/suite/rpl/r/rpl_sequential.result	2011-04-06 12:51:58 +0000
@@ -16,5 +16,69 @@ select ts from test0.benchmark where sta
 select ts from test0.benchmark where state like 'slave ends load' into @s_1;
 select time_to_sec(@m_1) - time_to_sec(@m_0) as 'delta_m', 
 time_to_sec(@s_1) - time_to_sec(@s_0) as 'delta_s' into outfile 'delta.out';
+include/diff_tables.inc [master:test15.v_tm_nk, slave:test15.v_tm_nk]
+include/diff_tables.inc [master:test15.v_ti_nk, slave:test15.v_ti_nk]
+include/diff_tables.inc [master:test15.v_tm_wk, slave:test15.v_tm_wk]
+include/diff_tables.inc [master:test15.v_ti_wk, slave:test15.v_ti_wk]
+include/diff_tables.inc [master:test14.v_tm_nk, slave:test14.v_tm_nk]
+include/diff_tables.inc [master:test14.v_ti_nk, slave:test14.v_ti_nk]
+include/diff_tables.inc [master:test14.v_tm_wk, slave:test14.v_tm_wk]
+include/diff_tables.inc [master:test14.v_ti_wk, slave:test14.v_ti_wk]
+include/diff_tables.inc [master:test13.v_tm_nk, slave:test13.v_tm_nk]
+include/diff_tables.inc [master:test13.v_ti_nk, slave:test13.v_ti_nk]
+include/diff_tables.inc [master:test13.v_tm_wk, slave:test13.v_tm_wk]
+include/diff_tables.inc [master:test13.v_ti_wk, slave:test13.v_ti_wk]
+include/diff_tables.inc [master:test12.v_tm_nk, slave:test12.v_tm_nk]
+include/diff_tables.inc [master:test12.v_ti_nk, slave:test12.v_ti_nk]
+include/diff_tables.inc [master:test12.v_tm_wk, slave:test12.v_tm_wk]
+include/diff_tables.inc [master:test12.v_ti_wk, slave:test12.v_ti_wk]
+include/diff_tables.inc [master:test11.v_tm_nk, slave:test11.v_tm_nk]
+include/diff_tables.inc [master:test11.v_ti_nk, slave:test11.v_ti_nk]
+include/diff_tables.inc [master:test11.v_tm_wk, slave:test11.v_tm_wk]
+include/diff_tables.inc [master:test11.v_ti_wk, slave:test11.v_ti_wk]
+include/diff_tables.inc [master:test10.v_tm_nk, slave:test10.v_tm_nk]
+include/diff_tables.inc [master:test10.v_ti_nk, slave:test10.v_ti_nk]
+include/diff_tables.inc [master:test10.v_tm_wk, slave:test10.v_tm_wk]
+include/diff_tables.inc [master:test10.v_ti_wk, slave:test10.v_ti_wk]
+include/diff_tables.inc [master:test9.v_tm_nk, slave:test9.v_tm_nk]
+include/diff_tables.inc [master:test9.v_ti_nk, slave:test9.v_ti_nk]
+include/diff_tables.inc [master:test9.v_tm_wk, slave:test9.v_tm_wk]
+include/diff_tables.inc [master:test9.v_ti_wk, slave:test9.v_ti_wk]
+include/diff_tables.inc [master:test8.v_tm_nk, slave:test8.v_tm_nk]
+include/diff_tables.inc [master:test8.v_ti_nk, slave:test8.v_ti_nk]
+include/diff_tables.inc [master:test8.v_tm_wk, slave:test8.v_tm_wk]
+include/diff_tables.inc [master:test8.v_ti_wk, slave:test8.v_ti_wk]
+include/diff_tables.inc [master:test7.v_tm_nk, slave:test7.v_tm_nk]
+include/diff_tables.inc [master:test7.v_ti_nk, slave:test7.v_ti_nk]
+include/diff_tables.inc [master:test7.v_tm_wk, slave:test7.v_tm_wk]
+include/diff_tables.inc [master:test7.v_ti_wk, slave:test7.v_ti_wk]
+include/diff_tables.inc [master:test6.v_tm_nk, slave:test6.v_tm_nk]
+include/diff_tables.inc [master:test6.v_ti_nk, slave:test6.v_ti_nk]
+include/diff_tables.inc [master:test6.v_tm_wk, slave:test6.v_tm_wk]
+include/diff_tables.inc [master:test6.v_ti_wk, slave:test6.v_ti_wk]
+include/diff_tables.inc [master:test5.v_tm_nk, slave:test5.v_tm_nk]
+include/diff_tables.inc [master:test5.v_ti_nk, slave:test5.v_ti_nk]
+include/diff_tables.inc [master:test5.v_tm_wk, slave:test5.v_tm_wk]
+include/diff_tables.inc [master:test5.v_ti_wk, slave:test5.v_ti_wk]
+include/diff_tables.inc [master:test4.v_tm_nk, slave:test4.v_tm_nk]
+include/diff_tables.inc [master:test4.v_ti_nk, slave:test4.v_ti_nk]
+include/diff_tables.inc [master:test4.v_tm_wk, slave:test4.v_tm_wk]
+include/diff_tables.inc [master:test4.v_ti_wk, slave:test4.v_ti_wk]
+include/diff_tables.inc [master:test3.v_tm_nk, slave:test3.v_tm_nk]
+include/diff_tables.inc [master:test3.v_ti_nk, slave:test3.v_ti_nk]
+include/diff_tables.inc [master:test3.v_tm_wk, slave:test3.v_tm_wk]
+include/diff_tables.inc [master:test3.v_ti_wk, slave:test3.v_ti_wk]
+include/diff_tables.inc [master:test2.v_tm_nk, slave:test2.v_tm_nk]
+include/diff_tables.inc [master:test2.v_ti_nk, slave:test2.v_ti_nk]
+include/diff_tables.inc [master:test2.v_tm_wk, slave:test2.v_tm_wk]
+include/diff_tables.inc [master:test2.v_ti_wk, slave:test2.v_ti_wk]
+include/diff_tables.inc [master:test1.v_tm_nk, slave:test1.v_tm_nk]
+include/diff_tables.inc [master:test1.v_ti_nk, slave:test1.v_ti_nk]
+include/diff_tables.inc [master:test1.v_tm_wk, slave:test1.v_tm_wk]
+include/diff_tables.inc [master:test1.v_ti_wk, slave:test1.v_ti_wk]
+include/diff_tables.inc [master:test0.v_tm_nk, slave:test0.v_tm_nk]
+include/diff_tables.inc [master:test0.v_ti_nk, slave:test0.v_ti_nk]
+include/diff_tables.inc [master:test0.v_tm_wk, slave:test0.v_tm_wk]
+include/diff_tables.inc [master:test0.v_ti_wk, slave:test0.v_ti_wk]
 set @@global.mts_exp_slave_local_timestamp= @save.mts_exp_slave_local_timestamp;
 include/rpl_end.inc

=== modified file 'sql/log_event.cc'
--- a/sql/log_event.cc	2011-03-30 14:11:24 +0000
+++ b/sql/log_event.cc	2011-04-06 12:51:58 +0000
@@ -2714,7 +2714,7 @@ void append_item_to_jobs(slave_job_item 
 
     sprintf(wait_info, info_format, new_pend_size);
     rli->mts_wqs_oversize= TRUE;
-    rli->wait_jobs++;
+    rli->wait_jobs++; // waiting due to the total size
     old_msg= thd->enter_cond(&rli->pending_jobs_cond, &rli->pending_jobs_lock,
                              wait_info);
     mysql_cond_wait(&rli->pending_jobs_cond, &rli->pending_jobs_lock);
@@ -2741,6 +2741,7 @@ void append_item_to_jobs(slave_job_item 
     // todo: experiment with weight to get a good approximation formula
     ulong nap_weight= rli->mts_wqs_overrun + 1;
     my_sleep(nap_weight * rli->mts_coordinator_basic_nap);
+    rli->mts_wqs_underrun_cnt++;
   }
 
   ret= -1;
@@ -2761,6 +2762,7 @@ void append_item_to_jobs(slave_job_item 
     old_msg= thd->enter_cond(&w->jobs_cond, &w->jobs_lock, wait_info);
     w->jobs.overfill= TRUE;
     w->jobs.waited_overfill++;
+    rli->mts_wqs_overfill_cnt++;
     mysql_cond_wait(&w->jobs_cond, &w->jobs_lock);
     thd->exit_cond(old_msg);
     
@@ -3066,6 +3068,7 @@ int slave_worker_exec_job(Slave_worker *
   if (w->jobs.len == w->jobs.s - 1 && w->jobs.overfill == TRUE)
   {
     w->jobs.overfill= FALSE;
+    // todo: w->hungry_cnt++;
     mysql_cond_signal(&w->jobs_cond);
   }
   mysql_mutex_unlock(&w->jobs_lock);
@@ -3081,8 +3084,7 @@ int slave_worker_exec_job(Slave_worker *
   if ((rli->mts_worker_underrun_level * w->jobs.s) / 100 >  w->jobs.len)
   {
     rli-> mts_wqs_underrun_w_id= w->id;
-    // todo:
-    // w->underrun_cnt++;
+    // todo: w->underrun_cnt++;
   } else if (rli->mts_wqs_underrun_w_id == w->id)
   {
     rli->mts_wqs_underrun_w_id= (ulong) -1;
@@ -3093,8 +3095,7 @@ int slave_worker_exec_job(Slave_worker *
   {
     rli->mts_wqs_overrun++;
     w->wq_overrun_set= TRUE;
-    // todo:
-    // w->underrun_cnt++;
+    // todo: w->underrun_cnt++;
   }
   else if (w->wq_overrun_set == TRUE)
   {

=== modified file 'sql/rpl_rli.cc'
--- a/sql/rpl_rli.cc	2011-02-27 17:35:25 +0000
+++ b/sql/rpl_rli.cc	2011-04-06 12:51:58 +0000
@@ -107,6 +107,7 @@ void Relay_log_info::init_workers(ulong 
     whether the feature is or going to be active or not.
   */
   trans_jobs= stmt_jobs= pending_jobs= wait_jobs= 0;
+  mts_wqs_underrun_cnt= mts_wqs_overfill_cnt= 0;
 
   key_mutex_slave_parallel_worker= new PSI_mutex_key[slave_parallel_workers];
   key_cond_slave_parallel_worker= new PSI_cond_key[slave_parallel_workers];

=== modified file 'sql/rpl_rli.h'
--- a/sql/rpl_rli.h	2011-02-27 17:35:25 +0000
+++ b/sql/rpl_rli.h	2011-04-06 12:51:58 +0000
@@ -436,7 +436,7 @@ public:
   */
   DYNAMIC_ARRAY workers; // number's is determined by global slave_parallel_workers
   volatile ulong pending_jobs;
-  ulong trans_jobs, wait_jobs, stmt_jobs; // live time is one trans, statement (ndb epoch)
+  ulong trans_jobs, wait_jobs, stmt_jobs; // wait_jobs - waiting times due to the total size
   mysql_mutex_t pending_jobs_lock;
   mysql_cond_t pending_jobs_cond;
   ulong       mts_slave_worker_queue_len_max;
@@ -451,6 +451,8 @@ public:
   bool curr_group_isolated;     // Trans is exec:d by Worker but in exclusive env
   volatile ulong mts_wqs_underrun_w_id;  // Id of a Worker whose queue is getting empty
   volatile long mts_wqs_overrun;   // W to incr and decr
+  ulong mts_wqs_underrun_cnt;  // Coord goes to sleep when senses Workers are content
+  ulong mts_wqs_overfill_cnt;  // Coord waits if a W's queue is full
   long  mts_worker_underrun_level; // percent of WQ size at which Worker claims hungry
   ulong mts_coordinator_basic_nap; // C sleeps to avoid WQs overrun
   Slave_worker* get_current_worker() const;

=== modified file 'sql/rpl_slave.cc'
--- a/sql/rpl_slave.cc	2011-03-30 14:11:24 +0000
+++ b/sql/rpl_slave.cc	2011-04-06 12:51:58 +0000
@@ -3784,6 +3784,12 @@ pthread_handler_t handle_slave_worker(vo
 
   mysql_mutex_lock(&w->jobs_lock);
   w->jobs.len= rli->mts_slave_worker_queue_len_max + 1;
+  sql_print_information("Worker %lu statistics: "
+                        "events processed = %lu "
+                        "hungry waits = %lu "
+                        "priv queue overfills = %llu "
+                        ,w->id, w->stmt_jobs, w->wait_jobs, w->jobs.waited_overfill);
+
   mysql_cond_signal(&w->jobs_cond);  // famous last goodbye
   mysql_mutex_unlock(&w->jobs_lock);
 
@@ -4437,6 +4443,13 @@ void slave_stop_workers(Relay_log_info *
     delete w;
   }
 
+  sql_print_information("MTS coordinator statistics: "
+                        "events processed = %lu "
+                        "waits due a Worker queue full = %lu "
+                        "waits due the total size = %lu "
+                        "sleeps when Workers occupied = %lu "
+                        ,rli->stmt_jobs, rli->mts_wqs_overfill_cnt, rli->wait_jobs, rli->mts_wqs_underrun_cnt);
+
   DBUG_ASSERT(rli->pending_jobs == 0);
   DBUG_ASSERT(rli->mts_pending_jobs_size == 0);
 


Attachment: [text/bzr-bundle] bzr/andrei.elkin@oracle.com-20110406125158-3k421grajdyow645.bundle
Thread
bzr commit into mysql-next-mr-wl5569 branch (andrei.elkin:3275) WL#5569Andrei Elkin6 Apr