add histogram for rpl_semi_sync_master_trx_wait

Summary: add histogram for rpl_semi_sync_master_trx_wait.

Test Plan: mtr tests

Reviewers: rongrong

Reviewed By: rongrong

mysql-test/r/show_variables_histogram.result

@@ -16,6 +16,7 @@ SET @start_global_value_step_size_ddl_command = @@GLOBAL.histogram_step_size_ddl
 SET @start_global_value_step_size_transaction_command = @@GLOBAL.histogram_step_size_transaction_command;
 SET @start_global_value_step_size_handler_command = @@GLOBAL.histogram_step_size_handler_command;
 SET @start_global_value_step_size_other_command = @@GLOBAL.histogram_step_size_other_command;
+SET @start_global_value_step_size_semisync_trx_wait = @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
 SHOW VARIABLES LIKE "%histogram%" ;
 Variable_name	Value
 histogram_step_size_binlog_fsync	16ms
@@ -36,6 +37,7 @@ innodb_histogram_step_size_fsync	16ms
 innodb_histogram_step_size_log_write	16us
 innodb_histogram_step_size_sync_read	16us
 innodb_histogram_step_size_sync_write	16us
+rpl_semi_sync_master_histogram_trx_wait_step_size	500us
 SET @@GLOBAL.innodb_histogram_step_size_async_read='16ms';
 SET @@GLOBAL.innodb_histogram_step_size_async_write='16us';
 SET @@GLOBAL.innodb_histogram_step_size_sync_read='32ms';
@@ -54,6 +56,7 @@ SET @@GLOBAL.histogram_step_size_ddl_command='16s';
 SET @@GLOBAL.histogram_step_size_transaction_command='16s';
 SET @@GLOBAL.histogram_step_size_handler_command='16s';
 SET @@GLOBAL.histogram_step_size_other_command='16s';
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='128us';
 SHOW VARIABLES LIKE "%histogram%" ;
 Variable_name	Value
 histogram_step_size_binlog_fsync	16s
@@ -74,6 +77,7 @@ innodb_histogram_step_size_fsync	16s
 innodb_histogram_step_size_log_write	64ms
 innodb_histogram_step_size_sync_read	32ms
 innodb_histogram_step_size_sync_write	32us
+rpl_semi_sync_master_histogram_trx_wait_step_size	128us
 SET @@GLOBAL.innodb_histogram_step_size_async_read = @start_global_value_step_size_async_read;
 SET @@GLOBAL.innodb_histogram_step_size_async_write = @start_global_value_step_size_async_write;
 SET @@GLOBAL.innodb_histogram_step_size_sync_read = @start_global_value_step_size_sync_read;
@@ -92,6 +96,7 @@ SET @@GLOBAL.histogram_step_size_ddl_command = @start_global_value_step_size_ddl
 SET @@GLOBAL.histogram_step_size_transaction_command = @start_global_value_step_size_transaction_command;
 SET @@GLOBAL.histogram_step_size_handler_command = @start_global_value_step_size_handler_command;
 SET @@GLOBAL.histogram_step_size_other_command = @start_global_value_step_size_other_command;
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size = @start_global_value_step_size_semisync_trx_wait;
 SHOW VARIABLES LIKE "%histogram%" ;
 Variable_name	Value
 histogram_step_size_binlog_fsync	16ms
@@ -112,4 +117,5 @@ innodb_histogram_step_size_fsync	16ms
 innodb_histogram_step_size_log_write	16us
 innodb_histogram_step_size_sync_read	16us
 innodb_histogram_step_size_sync_write	16us
+rpl_semi_sync_master_histogram_trx_wait_step_size	500us
 Done

mysql-test/suite/rpl/r/rpl_semi_sync.result

@@ -37,6 +37,23 @@ Rpl_semi_sync_master_status	ON
 show status like 'Rpl_semi_sync_master_yes_tx';
 Variable_name	Value
 Rpl_semi_sync_master_yes_tx	0
+show status like 'Rpl_semi_sync_master_trx_wait_histogram%';
+Variable_name	Value
+Rpl_semi_sync_master_trx_wait_histogram_0-500us	0
+Rpl_semi_sync_master_trx_wait_histogram_500-1000us	0
+Rpl_semi_sync_master_trx_wait_histogram_1000-1500us	0
+Rpl_semi_sync_master_trx_wait_histogram_1500-2000us	0
+Rpl_semi_sync_master_trx_wait_histogram_2000-2500us	0
+Rpl_semi_sync_master_trx_wait_histogram_2500-3000us	0
+Rpl_semi_sync_master_trx_wait_histogram_3000-3500us	0
+Rpl_semi_sync_master_trx_wait_histogram_3500-4000us	0
+Rpl_semi_sync_master_trx_wait_histogram_4000-4500us	0
+Rpl_semi_sync_master_trx_wait_histogram_4500-5000us	0
+Rpl_semi_sync_master_trx_wait_histogram_5000-5500us	0
+Rpl_semi_sync_master_trx_wait_histogram_5500-6000us	0
+Rpl_semi_sync_master_trx_wait_histogram_6000-6500us	0
+Rpl_semi_sync_master_trx_wait_histogram_6500-7000us	0
+Rpl_semi_sync_master_trx_wait_histogram_7000-7500us	0
 #
 # BUG#45672 Semisync repl: ActiveTranx:insert_tranx_node: transaction node allocation failed
 # BUG#45673 Semisynch reports correct operation even if no slave is connected

mysql-test/suite/rpl/t/rpl_semi_sync.test

@@ -66,6 +66,7 @@ echo [ status of semi-sync on master should be ON even without any semi-sync sla
 show status like 'Rpl_semi_sync_master_clients';
 show status like 'Rpl_semi_sync_master_status';
 show status like 'Rpl_semi_sync_master_yes_tx';
+show status like 'Rpl_semi_sync_master_trx_wait_histogram%';
 
 --echo #
 --echo # BUG#45672 Semisync repl: ActiveTranx:insert_tranx_node: transaction node allocation failed

mysql-test/suite/sys_vars/r/rpl_semi_sync_master_histogram_trx_wait_step_size_basic.result

@@ -0,0 +1,75 @@
+SELECT COUNT(@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size);
+COUNT(@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size)
+1
+1 Expected
+SET @start_global_value = @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+SELECT @start_global_value;
+@start_global_value
+500us
+16ms Expected
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='16us';
+select @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size
+16us
+16us Expected
+select * from information_schema.global_variables where variable_name='rpl_semi_sync_master_histogram_trx_wait_step_size';
+VARIABLE_NAME	VARIABLE_VALUE
+RPL_SEMI_SYNC_MASTER_HISTOGRAM_TRX_WAIT_STEP_SIZE	16us
+SELECT @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size = VARIABLE_VALUE
+FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES
+WHERE VARIABLE_NAME='rpl_semi_sync_master_histogram_trx_wait_step_size';
+@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size = VARIABLE_VALUE
+1
+1 Expected
+SELECT COUNT(@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size);
+COUNT(@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size)
+1
+1 Expected
+SELECT COUNT(VARIABLE_VALUE)
+FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES
+WHERE VARIABLE_NAME='rpl_semi_sync_master_histogram_trx_wait_step_size';
+COUNT(VARIABLE_VALUE)
+1
+1 Expected
+SELECT COUNT(@@local.rpl_semi_sync_master_histogram_trx_wait_step_size);
+ERROR HY000: Variable 'rpl_semi_sync_master_histogram_trx_wait_step_size' is a GLOBAL variable
+Expected error 'Variable is a GLOBAL variable'
+SELECT COUNT(@@SESSION.rpl_semi_sync_master_histogram_trx_wait_step_size);
+ERROR HY000: Variable 'rpl_semi_sync_master_histogram_trx_wait_step_size' is a GLOBAL variable
+Expected error 'Variable is a GLOBAL variable'
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='32';
+ERROR 42000: Variable 'rpl_semi_sync_master_histogram_trx_wait_step_size' can't be set to the value of '32'
+Expected error 'Variable cannot be set to this value';
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='0';
+select @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size
+0
+0 Expected
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='ms32';
+ERROR 42000: Variable 'rpl_semi_sync_master_histogram_trx_wait_step_size' can't be set to the value of 'ms32'
+Expected error 'Variable cannot be set to this value';
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='32ps';
+ERROR 42000: Variable 'rpl_semi_sync_master_histogram_trx_wait_step_size' can't be set to the value of '32ps'
+Expected error 'Variable cannot be set to this value';
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='3s2';
+ERROR 42000: Variable 'rpl_semi_sync_master_histogram_trx_wait_step_size' can't be set to the value of '3s2'
+Expected error 'Variable cannot be set to this value';
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='32@s';
+ERROR 42000: Variable 'rpl_semi_sync_master_histogram_trx_wait_step_size' can't be set to the value of '32@s'
+Expected error 'Variable cannot be set to this value';
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='32s.';
+ERROR 42000: Variable 'rpl_semi_sync_master_histogram_trx_wait_step_size' can't be set to the value of '32s.'
+Expected error 'Variable cannot be set to this value';
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='s';
+ERROR 42000: Variable 'rpl_semi_sync_master_histogram_trx_wait_step_size' can't be set to the value of 's'
+Expected error 'Variable cannot be set to this value'
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='16.5us';
+select @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size
+16.5us
+16.5us Expected
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size = @start_global_value;
+SELECT @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size
+500us
+16ms Expected

mysql-test/suite/sys_vars/t/rpl_semi_sync_master_histogram_trx_wait_step_size_basic.test

@@ -0,0 +1,75 @@
+--source include/have_innodb.inc
+
+SELECT COUNT(@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size);
+--echo 1 Expected
+
+SET @start_global_value = @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+SELECT @start_global_value;
+--echo 16ms Expected
+
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='16us';
+select @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+--echo 16us Expected
+
+select * from information_schema.global_variables where variable_name='rpl_semi_sync_master_histogram_trx_wait_step_size';
+
+SELECT @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size = VARIABLE_VALUE
+FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES
+WHERE VARIABLE_NAME='rpl_semi_sync_master_histogram_trx_wait_step_size';
+--echo 1 Expected
+
+SELECT COUNT(@@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size);
+--echo 1 Expected
+
+SELECT COUNT(VARIABLE_VALUE)
+FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES
+WHERE VARIABLE_NAME='rpl_semi_sync_master_histogram_trx_wait_step_size';
+--echo 1 Expected
+
+--Error ER_INCORRECT_GLOBAL_LOCAL_VAR
+SELECT COUNT(@@local.rpl_semi_sync_master_histogram_trx_wait_step_size);
+--echo Expected error 'Variable is a GLOBAL variable'
+
+--Error ER_INCORRECT_GLOBAL_LOCAL_VAR
+SELECT COUNT(@@SESSION.rpl_semi_sync_master_histogram_trx_wait_step_size);
+--echo Expected error 'Variable is a GLOBAL variable'
+
+--Error ER_WRONG_VALUE_FOR_VAR
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='32';
+--echo Expected error 'Variable cannot be set to this value';
+
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='0';
+select @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+--echo 0 Expected
+
+--Error ER_WRONG_VALUE_FOR_VAR
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='ms32';
+--echo Expected error 'Variable cannot be set to this value';
+
+--Error ER_WRONG_VALUE_FOR_VAR
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='32ps';
+--echo Expected error 'Variable cannot be set to this value';
+
+--Error ER_WRONG_VALUE_FOR_VAR
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='3s2';
+--echo Expected error 'Variable cannot be set to this value';
+
+--Error ER_WRONG_VALUE_FOR_VAR
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='32@s';
+--echo Expected error 'Variable cannot be set to this value';
+
+--Error ER_WRONG_VALUE_FOR_VAR
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='32s.';
+--echo Expected error 'Variable cannot be set to this value';
+
+--Error ER_WRONG_VALUE_FOR_VAR
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='s';
+--echo Expected error 'Variable cannot be set to this value'
+
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='16.5us';
+select @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+--echo 16.5us Expected
+
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size = @start_global_value;
+SELECT @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
+--echo 16ms Expected

mysql-test/t/show_variables_histogram.test

@@ -21,6 +21,7 @@ SET @start_global_value_step_size_ddl_command = @@GLOBAL.histogram_step_size_ddl
 SET @start_global_value_step_size_transaction_command = @@GLOBAL.histogram_step_size_transaction_command;
 SET @start_global_value_step_size_handler_command = @@GLOBAL.histogram_step_size_handler_command;
 SET @start_global_value_step_size_other_command = @@GLOBAL.histogram_step_size_other_command;
+SET @start_global_value_step_size_semisync_trx_wait = @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size;
 
 SHOW VARIABLES LIKE "%histogram%" ;
 
@@ -42,6 +43,7 @@ SET @@GLOBAL.histogram_step_size_ddl_command='16s';
 SET @@GLOBAL.histogram_step_size_transaction_command='16s';
 SET @@GLOBAL.histogram_step_size_handler_command='16s';
 SET @@GLOBAL.histogram_step_size_other_command='16s';
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size='128us';
 
 SHOW VARIABLES LIKE "%histogram%" ;
 
@@ -63,6 +65,7 @@ SET @@GLOBAL.histogram_step_size_ddl_command = @start_global_value_step_size_ddl
 SET @@GLOBAL.histogram_step_size_transaction_command = @start_global_value_step_size_transaction_command;
 SET @@GLOBAL.histogram_step_size_handler_command = @start_global_value_step_size_handler_command;
 SET @@GLOBAL.histogram_step_size_other_command = @start_global_value_step_size_other_command;
+SET @@GLOBAL.rpl_semi_sync_master_histogram_trx_wait_step_size = @start_global_value_step_size_semisync_trx_wait;
 
 SHOW VARIABLES LIKE "%histogram%" ;
 

plugin/semisync/semisync_master.cc

@@ -45,6 +45,10 @@ unsigned long rpl_semi_sync_master_clients          = 0;
 unsigned long long rpl_semi_sync_master_net_wait_time = 0;
 unsigned long long rpl_semi_sync_master_trx_wait_time = 0;
 char rpl_semi_sync_master_wait_no_slave = 1;
+char *histogram_trx_wait_step_size = 0;
+latency_histogram histogram_trx_wait;
+SHOW_VAR latency_histogram_trx_wait[NUMBER_OF_HISTOGRAM_BINS + 1];
+ulonglong histogram_trx_wait_values[NUMBER_OF_HISTOGRAM_BINS];
 
 
 static int getWaitTime(const struct timespec& start_ts);
@@ -419,6 +423,7 @@ int ReplSemiSyncMaster::initObject()
   else
     result = disableMaster();
 
+  latency_histogram_init(&histogram_trx_wait, histogram_trx_wait_step_size);
   return result;
 }
 
@@ -489,6 +494,7 @@ int ReplSemiSyncMaster::disableMaster()
 
 void ReplSemiSyncMaster::cleanup()
 {
+  free_latency_histogram_sysvars(latency_histogram_trx_wait);
   if (init_done_)
   {
     mysql_mutex_destroy(&LOCK_binlog_);
@@ -828,6 +834,9 @@ int ReplSemiSyncMaster::commitTrx(const char* trx_wait_binlog_name,
         {
           rpl_semi_sync_master_trx_wait_num++;
           rpl_semi_sync_master_trx_wait_time += wait_time;
+          if (histogram_trx_wait_step_size)
+            latency_histogram_increment(&histogram_trx_wait,
+              microseconds_to_my_timer((double)wait_time), 1);
         }
       }
     }
@@ -1287,6 +1296,11 @@ void ReplSemiSyncMaster::setExportStats()
      (unsigned long)((double)rpl_semi_sync_master_net_wait_time /
                      ((double)rpl_semi_sync_master_net_wait_num)) : 0);
 
+  for (size_t i_bins = 0; i_bins < NUMBER_OF_HISTOGRAM_BINS; ++i_bins) {
+    histogram_trx_wait_values[i_bins] =
+      latency_histogram_get_count(&histogram_trx_wait, i_bins);
+  }
+
   unlock();
 }
 
@@ -1315,3 +1329,11 @@ static int getWaitTime(const struct timespec& start_ts)
 
   return (int)(end_usecs - start_usecs);
 }
+
+void
+ReplSemiSyncMaster::update_histogram_trx_wait_step_size(const char *step_size)
+{
+  lock();
+  latency_histogram_init(&histogram_trx_wait, step_size);
+  unlock();
+}

plugin/semisync/semisync_master.h

@@ -630,6 +630,14 @@ class ReplSemiSyncMaster
    * go off for that.
    */
   int resetMaster();
+
+  /* Reinitializes the latency histogram when trx_wait_step_size
+   * is updated.
+   *
+   * Input:
+   *   step_size - (IN)  updated step_size
+   */
+  void update_histogram_trx_wait_step_size(const char *step_size);
 };
 
 /* System and status variables for the master component */
@@ -653,6 +661,12 @@ extern unsigned long long rpl_semi_sync_master_trx_wait_num;
 extern unsigned long long rpl_semi_sync_master_net_wait_time;
 extern unsigned long long rpl_semi_sync_master_trx_wait_time;
 
+extern char* histogram_trx_wait_step_size;
+extern latency_histogram histogram_trx_wait;
+/* status variables for trx_wait_time histogram */
+extern SHOW_VAR latency_histogram_trx_wait[NUMBER_OF_HISTOGRAM_BINS + 1];
+extern ulonglong histogram_trx_wait_values[NUMBER_OF_HISTOGRAM_BINS];
+
 /*
   This indicates whether we should keep waiting if no semi-sync slave
   is available.