Merge MDEV-6981 and MDEV-6981 (from danblack) into MariaDB 10.1

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;

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;

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 ====

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;

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.

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;
 }
 
 /*

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},

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;
 }

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

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;