diff --git a/mysql-test/r/max_statement_time.result b/mysql-test/r/max_statement_time.result index 38334c59baa..93c793b265a 100644 --- a/mysql-test/r/max_statement_time.result +++ b/mysql-test/r/max_statement_time.result @@ -87,6 +87,7 @@ SLEEP(2) 1 SHOW STATUS LIKE '%timeout%'; Variable_name Value +Master_gtid_wait_timeouts 0 Ssl_default_timeout 0 Ssl_session_cache_timeouts 0 SET @@max_statement_time=0; diff --git a/mysql-test/suite/rpl/r/rpl_gtid_basic.result b/mysql-test/suite/rpl/r/rpl_gtid_basic.result index f3b52d89eb4..22f284d6716 100644 --- a/mysql-test/suite/rpl/r/rpl_gtid_basic.result +++ b/mysql-test/suite/rpl/r/rpl_gtid_basic.result @@ -231,6 +231,15 @@ NULL SELECT master_gtid_wait('', NULL); master_gtid_wait('', NULL) 0 +SHOW STATUS LIKE 'Master_gtid_wait_count'; +Variable_name Value +Master_gtid_wait_count 1 +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +Variable_name Value +Master_gtid_wait_timeouts 0 +SHOW STATUS LIKE 'Master_gtid_wait_time'; +Variable_name Value +Master_gtid_wait_time 0 SELECT master_gtid_wait(@pos, 0.5); master_gtid_wait(@pos, 0.5) -1 @@ -271,13 +280,46 @@ SELECT master_gtid_wait('2-1-5'); SELECT master_gtid_wait('2-1-10'); SELECT master_gtid_wait('2-1-5,1-1-4,0-1-110'); SELECT master_gtid_wait('2-1-2'); +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +Variable_name Value +Master_gtid_wait_timeouts 0 +SHOW STATUS LIKE 'Master_gtid_wait_count'; +Variable_name Value +Master_gtid_wait_count 3 SELECT master_gtid_wait('1-1-1'); master_gtid_wait('1-1-1') 0 +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +Variable_name Value +Master_gtid_wait_timeouts 0 +SHOW STATUS LIKE 'Master_gtid_wait_count'; +Variable_name Value +Master_gtid_wait_count 4 +SET @a= MASTER_GTID_WAIT_TIME; +SELECT IF(@a <= 100*1000*1000, "OK", CONCAT("Error: wait time ", @a, " is larger than expected")) +AS Master_gtid_wait_time_as_expected; +Master_gtid_wait_time_as_expected +OK SELECT master_gtid_wait('0-1-109'); +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +Variable_name Value +Master_gtid_wait_timeouts 0 +SHOW STATUS LIKE 'Master_gtid_wait_count'; +Variable_name Value +Master_gtid_wait_count 4 SELECT master_gtid_wait('2-1-2', 0.5); master_gtid_wait('2-1-2', 0.5) -1 +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +Variable_name Value +Master_gtid_wait_timeouts 1 +SHOW STATUS LIKE 'Master_gtid_wait_count'; +Variable_name Value +Master_gtid_wait_count 5 +SET @a= MASTER_GTID_WAIT_TIME; +SELECT IF(@a BETWEEN 0.4*1000*1000 AND 100*1000*1000, "OK", CONCAT("Error: wait time ", @a, " not as expected")) AS Master_gtid_wait_time_as_expected; +Master_gtid_wait_time_as_expected +OK KILL QUERY KILL_ID; ERROR 70100: Query execution was interrupted SET gtid_domain_id=2; diff --git a/mysql-test/suite/rpl/r/rpl_skip_error.result b/mysql-test/suite/rpl/r/rpl_skip_error.result index aff83e1b99e..105b9d5c65f 100644 --- a/mysql-test/suite/rpl/r/rpl_skip_error.result +++ b/mysql-test/suite/rpl/r/rpl_skip_error.result @@ -95,6 +95,9 @@ t2 CREATE TABLE `t2` ( `data` int(11) DEFAULT NULL, PRIMARY KEY (`id`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1 +show global status like 'slave_skipped_errors'; +Variable_name Value +Slave_skipped_errors 4 INSERT INTO t2 VALUES(1, 1); INSERT INTO t2 VALUES(2, 1); INSERT INTO t2 VALUES(3, 1); @@ -104,6 +107,9 @@ DELETE FROM t2 WHERE id = 5; SET SQL_LOG_BIN=1; UPDATE t2 SET id= id + 3, data = 2; +show global status like 'slave_skipped_errors'; +Variable_name Value +Slave_skipped_errors 5 **** We cannot execute a select as there are differences in the **** behavior between STMT and RBR. ==== Clean Up ==== diff --git a/mysql-test/suite/rpl/t/rpl_gtid_basic.test b/mysql-test/suite/rpl/t/rpl_gtid_basic.test index 778cf427d99..b6a4c7f7e2b 100644 --- a/mysql-test/suite/rpl/t/rpl_gtid_basic.test +++ b/mysql-test/suite/rpl/t/rpl_gtid_basic.test @@ -232,6 +232,10 @@ eval SET @pos= '$pos'; SELECT master_gtid_wait(NULL); # Check empty argument returns immediately. SELECT master_gtid_wait('', NULL); +# Check this gets counted +SHOW STATUS LIKE 'Master_gtid_wait_count'; +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +SHOW STATUS LIKE 'Master_gtid_wait_time'; # Let's check that we get a timeout SELECT master_gtid_wait(@pos, 0.5); SELECT * FROM t1 ORDER BY a; @@ -276,7 +280,7 @@ SELECT master_gtid_wait('1-1-1', 0); send SELECT master_gtid_wait('2-1-1,1-1-4,0-1-110'); --connect (s2,127.0.0.1,root,,test,$SERVER_MYPORT_2,) -# This will time out. +# This will time out. No event 0-1-1000 exists send SELECT master_gtid_wait('0-1-1000', 0.5); --connect (s3,127.0.0.1,root,,test,$SERVER_MYPORT_2,) @@ -306,14 +310,35 @@ send SELECT master_gtid_wait('2-1-2'); --connection server_2 # This one completes immediately. +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +SHOW STATUS LIKE 'Master_gtid_wait_count'; SELECT master_gtid_wait('1-1-1'); +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +SHOW STATUS LIKE 'Master_gtid_wait_count'; +let $wait_time = query_get_value(SHOW STATUS LIKE 'Master_gtid_wait_time', Value, 1); +--replace_result $wait_time MASTER_GTID_WAIT_TIME +eval SET @a= $wait_time; +SELECT IF(@a <= 100*1000*1000, "OK", CONCAT("Error: wait time ", @a, " is larger than expected")) + AS Master_gtid_wait_time_as_expected; + --connect (s10,127.0.0.1,root,,test,$SERVER_MYPORT_2,) send SELECT master_gtid_wait('0-1-109'); --connection server_2 # This one should time out. +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +SHOW STATUS LIKE 'Master_gtid_wait_count'; SELECT master_gtid_wait('2-1-2', 0.5); +SHOW STATUS LIKE 'Master_gtid_wait_timeouts'; +SHOW STATUS LIKE 'Master_gtid_wait_count'; +let $wait_time = query_get_value(SHOW STATUS LIKE 'Master_gtid_wait_time', Value, 1); +--replace_result $wait_time MASTER_GTID_WAIT_TIME +eval SET @a= $wait_time; +# We expect a wait time of just a bit over 0.5 seconds. But thread scheduling +# and timer inaccuracies could introduce significant jitter. So allow a +# generous interval. +SELECT IF(@a BETWEEN 0.4*1000*1000 AND 100*1000*1000, "OK", CONCAT("Error: wait time ", @a, " not as expected")) AS Master_gtid_wait_time_as_expected; --replace_result $kill1_id KILL_ID eval KILL QUERY $kill1_id; diff --git a/mysql-test/suite/rpl/t/rpl_skip_error.test b/mysql-test/suite/rpl/t/rpl_skip_error.test index 142cd53b9dd..4348675884b 100644 --- a/mysql-test/suite/rpl/t/rpl_skip_error.test +++ b/mysql-test/suite/rpl/t/rpl_skip_error.test @@ -140,6 +140,7 @@ connection slave; CREATE TABLE t2(id INT NOT NULL PRIMARY KEY, data INT) Engine=MyIsam; SHOW CREATE TABLE t2; +show global status like 'slave_skipped_errors'; connection master; @@ -157,6 +158,7 @@ sync_slave_with_master; let $error= query_get_value("SHOW SLAVE STATUS", Last_SQL_Error, 1); echo $error; +show global status like 'slave_skipped_errors'; --echo **** We cannot execute a select as there are differences in the --echo **** behavior between STMT and RBR. diff --git a/sql/log_event.cc b/sql/log_event.cc index ad9d8f317e6..650610fab84 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -428,8 +428,12 @@ inline int idempotent_error_code(int err_code) inline int ignored_error_code(int err_code) { - return ((err_code == ER_SLAVE_IGNORED_TABLE) || - (use_slave_mask && bitmap_is_set(&slave_error_mask, err_code))); + if (use_slave_mask && bitmap_is_set(&slave_error_mask, err_code)) + { + statistic_increment(slave_skipped_errors, LOCK_status); + return 1; + } + return err_code == ER_SLAVE_IGNORED_TABLE; } /* diff --git a/sql/mysqld.cc b/sql/mysqld.cc index ccd291cf226..f33df61a0ce 100644 --- a/sql/mysqld.cc +++ b/sql/mysqld.cc @@ -519,6 +519,7 @@ ulong binlog_stmt_cache_use= 0, binlog_stmt_cache_disk_use= 0; ulong max_connections, max_connect_errors; ulong extra_max_connections; ulong slave_retried_transactions; +ulonglong slave_skipped_errors; ulong feature_files_opened_with_delayed_keys; ulonglong denied_connections; my_decimal decimal_zero; @@ -8217,6 +8218,9 @@ SHOW_VAR status_vars[]= { {"Key", (char*) &show_default_keycache, SHOW_FUNC}, {"Last_query_cost", (char*) offsetof(STATUS_VAR, last_query_cost), SHOW_DOUBLE_STATUS}, {"Max_statement_time_exceeded", (char*) offsetof(STATUS_VAR, max_statement_time_exceeded), SHOW_LONG_STATUS}, + {"Master_gtid_wait_count", (char*) offsetof(STATUS_VAR, master_gtid_wait_count), SHOW_LONGLONG_STATUS}, + {"Master_gtid_wait_timeouts", (char*) offsetof(STATUS_VAR, master_gtid_wait_timeouts), SHOW_LONGLONG_STATUS}, + {"Master_gtid_wait_time", (char*) offsetof(STATUS_VAR, master_gtid_wait_time), SHOW_LONGLONG_STATUS}, {"Max_used_connections", (char*) &max_used_connections, SHOW_LONG}, {"Memory_used", (char*) &show_memory_used, SHOW_SIMPLE_FUNC}, {"Not_flushed_delayed_rows", (char*) &delayed_rows_in_use, SHOW_LONG_NOFLUSH}, @@ -8259,6 +8263,7 @@ SHOW_VAR status_vars[]= { {"Slave_received_heartbeats",(char*) &show_slave_received_heartbeats, SHOW_SIMPLE_FUNC}, {"Slave_retried_transactions",(char*)&slave_retried_transactions, SHOW_LONG}, {"Slave_running", (char*) &show_slave_running, SHOW_SIMPLE_FUNC}, + {"Slave_skipped_errors", (char*) &slave_skipped_errors, SHOW_LONGLONG}, #endif {"Slow_launch_threads", (char*) &slow_launch_threads, SHOW_LONG}, {"Slow_queries", (char*) offsetof(STATUS_VAR, long_query_count), SHOW_LONG_STATUS}, diff --git a/sql/rpl_gtid.cc b/sql/rpl_gtid.cc index 92dba552a57..1dc6a2720ad 100644 --- a/sql/rpl_gtid.cc +++ b/sql/rpl_gtid.cc @@ -1995,10 +1995,14 @@ gtid_waiting::wait_for_pos(THD *thd, String *gtid_str, longlong timeout_us) rpl_gtid *wait_pos; uint32 count, i; struct timespec wait_until, *wait_until_ptr; + ulonglong before; /* Wait for the empty position returns immediately. */ if (gtid_str->length() == 0) + { + status_var_increment(thd->status_var.master_gtid_wait_count); return 0; + } if (!(wait_pos= gtid_parse_string_to_list(gtid_str->ptr(), gtid_str->length(), &count))) @@ -2006,6 +2010,8 @@ gtid_waiting::wait_for_pos(THD *thd, String *gtid_str, longlong timeout_us) my_error(ER_INCORRECT_GTID_STATE, MYF(0)); return 1; } + status_var_increment(thd->status_var.master_gtid_wait_count); + before= microsecond_interval_timer(); if (timeout_us >= 0) { @@ -2020,6 +2026,15 @@ gtid_waiting::wait_for_pos(THD *thd, String *gtid_str, longlong timeout_us) if ((err= wait_for_gtid(thd, &wait_pos[i], wait_until_ptr))) break; } + switch (err) + { + case -1: + status_var_increment(thd->status_var.master_gtid_wait_timeouts); + /* Deliberate fall through. */ + case 0: + status_var_add(thd->status_var.master_gtid_wait_time, + microsecond_interval_timer() - before); + } my_free(wait_pos); return err; } diff --git a/sql/slave.h b/sql/slave.h index e16f801b577..fc48476a6d8 100644 --- a/sql/slave.h +++ b/sql/slave.h @@ -130,6 +130,7 @@ extern my_bool opt_log_slave_updates; extern char *opt_slave_skip_errors; extern my_bool opt_replicate_annotate_row_events; extern ulonglong relay_log_space_limit; +extern ulonglong slave_skipped_errors; /* 3 possible values for Master_info::slave_running and diff --git a/sql/sql_class.h b/sql/sql_class.h index 47426693d3b..44e4be74695 100644 --- a/sql/sql_class.h +++ b/sql/sql_class.h @@ -738,6 +738,11 @@ typedef struct system_status_var ulong feature_trigger; /* +1 opening a table with triggers */ ulong feature_xml; /* +1 when XPATH is used */ + /* From MASTER_GTID_WAIT usage */ + ulonglong master_gtid_wait_timeouts; /* Number of timeouts */ + ulonglong master_gtid_wait_time; /* Time in microseconds */ + ulonglong master_gtid_wait_count; + ulong empty_queries; ulong access_denied_errors; ulong lost_connections;