Merge branch 'bug1646100-5.6' into bug1646100-5.7

In 5.7 this also fixes bug 1657128 (Deadlock by concurrent SHOW BINLOGS, performance_schema.global_status query, and binlog purge). The merge adds the testcase and its required PFS debug sync point.
percona · Jan 26, 2017 · 9a4a7a3 · 9a4a7a3
2 parents 149cec1 + a1374e9
commit 9a4a7a3
Show file tree

Hide file tree

Showing 5 changed files with 213 additions and 30 deletions.
diff --git a/mysql-test/suite/binlog/r/binlog_consistent_debug.result b/mysql-test/suite/binlog/r/binlog_consistent_debug.result
@@ -0,0 +1,55 @@
+#
+# Debug build tests for consistent binlog snapshot
+#
+RESET MASTER;
+#
+# Bug 1646100: Server becomes unresponsive during flushing after loading
+# big files through LOAD DATA INFILE
+#
+SET @saved_sync_binlog = @@sync_binlog;
+SET GLOBAL sync_binlog = 1;
+CREATE TABLE t1 (a INT);
+# connection con1
+BEGIN;
+INSERT INTO t1 VALUES (0);
+SET DEBUG_SYNC="before_sync_binlog_file SIGNAL commit_ready WAIT_FOR finish_commit";
+COMMIT;
+# connection default
+SET DEBUG_SYNC="now WAIT_FOR commit_ready";
+SHOW STATUS LIKE 'binlog_snapshot_%';
+Variable_name	Value
+Binlog_snapshot_file	master-bin.000001
+Binlog_snapshot_position	POSITION
+SET DEBUG_SYNC="now SIGNAL finish_commit";
+# connection con1
+# connection default
+DROP TABLE t1;
+SET GLOBAL sync_binlog = @saved_sync_binlog;
+#
+# Bug 1657128: Deadlock by concurrent SHOW BINLOGS,
+# performance_schema.global_status query, and binlog purge
+#
+FLUSH LOGS;
+# connection con1
+SET DEBUG_SYNC="purge_logs_after_lock_index_before_thread_count SIGNAL purge_ready WAIT_FOR finish_purge";
+PURGE BINARY LOGS BEFORE '9999-12-31';
+# connection con2
+SET DEBUG_SYNC="materialize_session_status_array_THD_locked SIGNAL pfs_ready WAIT_FOR finish_pfs";
+SELECT * FROM performance_schema.session_status WHERE VARIABLE_NAME LIKE 'Binlog_snapshot_%';;
+# connection con3
+SET DEBUG_SYNC="show_binlogs_after_lock_log_before_lock_index SIGNAL show_ready WAIT_FOR finish_show";
+SHOW BINARY LOGS;
+# connection default
+SET DEBUG_SYNC="now WAIT_FOR purge_ready";
+SET DEBUG_SYNC="now WAIT_FOR pfs_ready";
+SET DEBUG_SYNC="now WAIT_FOR show_ready";
+SET DEBUG_SYNC="now SIGNAL finish_purge";
+SET DEBUG_SYNC="now SIGNAL finish_pfs";
+SET DEBUG_SYNC="now SIGNAL finish_show";
+# connection con1
+# connection con2
+VARIABLE_NAME	VARIABLE_VALUE
+Binlog_snapshot_file	master-bin.000002
+Binlog_snapshot_position	POSITION
+# connection con3
+# connection default
diff --git a/mysql-test/suite/binlog/t/binlog_consistent_debug.test b/mysql-test/suite/binlog/t/binlog_consistent_debug.test
@@ -0,0 +1,116 @@
+--source include/have_debug_sync.inc
+--source include/have_innodb.inc
+--source include/have_log_bin.inc
+--source include/have_perfschema.inc
+
+--echo #
+--echo # Debug build tests for consistent binlog snapshot
+--echo #
+
+RESET MASTER;
+
+--echo #
+--echo # Bug 1646100: Server becomes unresponsive during flushing after loading
+--echo # big files through LOAD DATA INFILE
+--echo #
+
+SET @saved_sync_binlog = @@sync_binlog;
+SET GLOBAL sync_binlog = 1;
+
+CREATE TABLE t1 (a INT);
+
+--source include/count_sessions.inc
+
+--connect(con1,localhost,root,,)
+--echo # connection con1
+
+BEGIN;
+INSERT INTO t1 VALUES (0);
+
+SET DEBUG_SYNC="before_sync_binlog_file SIGNAL commit_ready WAIT_FOR finish_commit";
+
+send COMMIT;
+
+--connection default
+--echo # connection default
+
+SET DEBUG_SYNC="now WAIT_FOR commit_ready";
+
+--replace_result 569 POSITION 590 POSITION
+SHOW STATUS LIKE 'binlog_snapshot_%';
+
+SET DEBUG_SYNC="now SIGNAL finish_commit";
+
+--connection con1
+--echo # connection con1
+reap;
+
+--disconnect con1
+--connection default
+--echo # connection default
+
+DROP TABLE t1;
+
+SET GLOBAL sync_binlog = @saved_sync_binlog;
+
+--echo #
+--echo # Bug 1657128: Deadlock by concurrent SHOW BINLOGS,
+--echo # performance_schema.global_status query, and binlog purge
+--echo #
+
+FLUSH LOGS;
+
+--connect(con1,localhost,root,,)
+--echo # connection con1
+
+SET DEBUG_SYNC="purge_logs_after_lock_index_before_thread_count SIGNAL purge_ready WAIT_FOR finish_purge";
+
+--send PURGE BINARY LOGS BEFORE '9999-12-31'
+
+--connect(con2,localhost,root,,)
+--echo # connection con2
+
+SET DEBUG_SYNC="materialize_session_status_array_THD_locked SIGNAL pfs_ready WAIT_FOR finish_pfs";
+
+--send SELECT * FROM performance_schema.session_status WHERE VARIABLE_NAME LIKE 'Binlog_snapshot_%';
+
+--connect(con3,localhost,root,,)
+--echo # connection con3
+
+SET DEBUG_SYNC="show_binlogs_after_lock_log_before_lock_index SIGNAL show_ready WAIT_FOR finish_show";
+
+--send SHOW BINARY LOGS
+
+--connection default
+--echo # connection default
+
+SET DEBUG_SYNC="now WAIT_FOR purge_ready";
+SET DEBUG_SYNC="now WAIT_FOR pfs_ready";
+SET DEBUG_SYNC="now WAIT_FOR show_ready";
+
+SET DEBUG_SYNC="now SIGNAL finish_purge";
+SET DEBUG_SYNC="now SIGNAL finish_pfs";
+SET DEBUG_SYNC="now SIGNAL finish_show";
+
+--connection con1
+--echo # connection con1
+reap;
+--disconnect con1
+
+--connection con2
+--echo # connection con2
+--replace_result 154 POSITION
+reap;
+--disconnect con2
+
+--connection con3
+--echo # connection con3
+--disable_result_log
+reap;
+--enable_result_log
+--disconnect con3
+
+--connection default
+--echo # connection default
+
+--source include/wait_until_count_sessions.inc
diff --git a/sql/binlog.cc b/sql/binlog.cc
@@ -96,6 +96,11 @@ static int binlog_xa_rollback(handlerton *hton,  XID *xid);
 
 static void exec_binlog_error_action_abort(const char* err_string);
 
+// The last published global binlog position
+static char binlog_global_snapshot_file[FN_REFLEN];
+static ulonglong binlog_global_snapshot_position;
+
+// Binlog position variables for SHOW STATUS
 static char binlog_snapshot_file[FN_REFLEN];
 static ulonglong binlog_snapshot_position;
 
@@ -7345,6 +7350,7 @@ int MYSQL_BIN_LOG::rotate(bool force_rotate, bool* check_purge)
   {
     error= new_file_without_locking(NULL);
     *check_purge= true;
+    publish_coordinates_for_global_status();
   }
   DBUG_RETURN(error);
 }
@@ -9278,6 +9284,8 @@ int MYSQL_BIN_LOG::ordered_commit(THD *thd, bool all, bool skip_commit)
     handle_binlog_flush_or_sync_error(thd, false /* need_lock_log */);
   }
 
+  publish_coordinates_for_global_status();
+
   DEBUG_SYNC(thd, "bgc_after_flush_stage_before_sync_stage");
 
   /*
@@ -9571,41 +9579,25 @@ int MYSQL_BIN_LOG::recover(IO_CACHE *log, Format_description_log_event *fdle,
 */
 static void set_binlog_snapshot_file(const char *src)
 {
+  mysql_mutex_assert_owner(&LOCK_status);
+
   int dir_len = dirname_length(src);
   strmake(binlog_snapshot_file, src + dir_len,
           sizeof(binlog_snapshot_file) - 1);
 }
 
-/*
-  Copy out current values of status variables, for SHOW STATUS or
-  information_schema.global_status.
 
-  This is called only under LOCK_status, so we can fill in a static array.
-*/
-void MYSQL_BIN_LOG::set_status_variables(THD *thd)
+/** Copy the current binlog coordinates to the variables used for the
+not-in-consistent-snapshot case of SHOW STATUS */
+void MYSQL_BIN_LOG::publish_coordinates_for_global_status(void) const
 {
-  binlog_cache_mngr *cache_mngr;
-
-  if (thd && opt_bin_log)
-    cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
-  else
-    cache_mngr= 0;
-
-  bool have_snapshot= (cache_mngr &&
-                       cache_mngr->binlog_info.log_file_name[0] != '\0');
-  mysql_mutex_lock(&LOCK_log);
-  if (!have_snapshot)
-  {
-    set_binlog_snapshot_file(log_file_name);
-    binlog_snapshot_position= my_b_tell(&log_file);
-  }
-  mysql_mutex_unlock(&LOCK_log);
+  mysql_mutex_assert_owner(&LOCK_log);
 
-  if (have_snapshot)
-  {
-    set_binlog_snapshot_file(cache_mngr->binlog_info.log_file_name);
-    binlog_snapshot_position= cache_mngr->binlog_info.pos;
-  }
+  mysql_mutex_lock(&LOCK_status);
+  strcpy(binlog_global_snapshot_file, log_file_name);
+  binlog_global_snapshot_position=
+      my_b_inited(&log_file) ? my_b_tell(&log_file) : 0;
+  mysql_mutex_unlock(&LOCK_status);
 }
 
 
@@ -11980,8 +11972,26 @@ int THD::binlog_query(THD::enum_binlog_query_type qtype, const char *query_arg,
 
 static int show_binlog_vars(THD *thd, SHOW_VAR *var, char *buff)
 {
-  if (mysql_bin_log.is_open())
-    mysql_bin_log.set_status_variables(thd);
+  mysql_mutex_assert_owner(&LOCK_status);
+
+  const binlog_cache_mngr *cache_mngr
+    = (thd && opt_bin_log)
+    ? static_cast<binlog_cache_mngr *>(thd_get_ha_data(thd, binlog_hton))
+    : NULL;
+
+  const bool have_snapshot= (cache_mngr &&
+                       cache_mngr->binlog_info.log_file_name[0] != '\0');
+
+  if (have_snapshot)
+  {
+    set_binlog_snapshot_file(cache_mngr->binlog_info.log_file_name);
+    binlog_snapshot_position= cache_mngr->binlog_info.pos;
+  }
+  else if (mysql_bin_log.is_open())
+  {
+    set_binlog_snapshot_file(binlog_global_snapshot_file);
+    binlog_snapshot_position= binlog_global_snapshot_position;
+  }
   else
   {
     binlog_snapshot_file[0]= '\0';

diff --git a/sql/binlog.h b/sql/binlog.h
@@ -943,7 +943,6 @@ class MYSQL_BIN_LOG: public TC_LOG
   mysql_mutex_t* get_binlog_end_pos_lock() { return &LOCK_binlog_end_pos; }
   void lock_binlog_end_pos() { mysql_mutex_lock(&LOCK_binlog_end_pos); }
   void unlock_binlog_end_pos() { mysql_mutex_unlock(&LOCK_binlog_end_pos); }
-  void set_status_variables(THD *thd);
 
   /**
     Deep copy global_sid_map to @param sid_map and
@@ -961,6 +960,8 @@ class MYSQL_BIN_LOG: public TC_LOG
       @retval !=0    Error
   */
   int get_gtid_executed(Sid_map *sid_map, Gtid_set *gtid_set);
+private:
+  void publish_coordinates_for_global_status(void) const;
 };
 
 typedef struct st_load_file_info

diff --git a/storage/perfschema/pfs_variable.cc b/storage/perfschema/pfs_variable.cc
@@ -991,6 +991,7 @@ int PFS_status_variable_cache::do_materialize_all(THD* unsafe_thd)
     /* Get and lock a validated THD from the thread manager. */
   if ((m_safe_thd= get_THD(unsafe_thd)) != NULL)
   {
+    DEBUG_SYNC(m_current_thd, "materialize_session_status_array_THD_locked");
     /*
       Build the status variable cache using the SHOW_VAR array as a reference.
       Use the status values from the THD protected by the thread manager lock.