List:Commits« Previous MessageNext Message »
From:Sven Sandberg Date:May 23 2011 4:28pm
Subject:bzr commit into mysql-5.1 branch (sven.sandberg:3625) Bug#12574820
View as plain text  
#At file:///home/sven/bzr/b12574820-reset_logs_lock_order/5.1/ based on revid:vasil.dimov@stripped

 3625 Sven Sandberg	2011-05-23
      BUG#12574820: binlog.binlog_tmp_table timing out in daily and weekly trunk run
      Problem: MYSQL_BIN_LOG::reset_logs acquires mutexes in wrong order.
      The correct order is first LOCK_thread_count and then LOCK_log. This function
      does it the other way around. This leads to deadlock when run in parallel
      with a thread that takes the two locks in correct order. For example, a thread
      that disconnects will take the locks in the correct order.
      Fix: change order of the locks in MYSQL_BIN_LOG::reset_logs:
      first LOCK_thread_count and then LOCK_log.
     @ mysql-test/suite/binlog/r/binlog_reset_master.result
        added result file
     @ mysql-test/suite/binlog/t/binlog_reset_master.test
        Added test case that demonstrates deadlock because of wrong mutex order.
        The deadlock is between two threads:
         - RESET MASTER acquires mutexes in wrong order.
         - client thread shutdown code acquires mutexes in right order.
        Actually, this test case does not produce deadlock in 5.1, probably
        the client thread shutdown code does not hold both mutexes at the same
        time. However, the bug existed in 5.1 (mutexes are taken in the wrong
        order) so we push the test case to 5.1 too, to prevent future
        regressions.
     @ sql/log.cc
        Change mutex acquisition to the correct order:
        first LOCK_thread_count, then LOCK_log.
     @ sql/mysqld.cc
        Add debug code to synchronize test case.

    added:
      mysql-test/suite/binlog/r/binlog_reset_master.result
      mysql-test/suite/binlog/t/binlog_reset_master.test
    modified:
      sql/log.cc
      sql/mysqld.cc
=== added file 'mysql-test/suite/binlog/r/binlog_reset_master.result'
--- a/mysql-test/suite/binlog/r/binlog_reset_master.result	1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/binlog/r/binlog_reset_master.result	2011-05-23 16:28:17 +0000
@@ -0,0 +1 @@
+RESET MASTER;

=== added file 'mysql-test/suite/binlog/t/binlog_reset_master.test'
--- a/mysql-test/suite/binlog/t/binlog_reset_master.test	1970-01-01 00:00:00 +0000
+++ b/mysql-test/suite/binlog/t/binlog_reset_master.test	2011-05-23 16:28:17 +0000
@@ -0,0 +1,26 @@
+# ==== Purpose ====
+#
+# Test bugs in RESET MASTER.
+
+--source include/have_debug.inc
+--source include/have_log_bin.inc
+
+#######################################################################
+# BUG#12574820: binlog.binlog_tmp_table timing out in daily and weekly trunk run
+# Problem: MYSQL_BIN_LOG::reset_logs acquired LOCK_thread_count and
+# LOCK_log in the wrong order. This could cause a deadlock when
+# RESET MASTER was run concurrently with a disconnecting thread.
+#######################################################################
+
+# We use sleep, not debug_sync, because the sync point needs to be in
+# the thread shut down code after the debug sync facility has been
+# shut down.
+--let $write_var= SET DEBUG="+d,sven,sleep_after_lock_thread_count_before_delete_thd"; CREATE TEMPORARY TABLE test.t1 (a INT);
+--let $write_to_file= GENERATE
+--disable_query_log
+--source include/write_var_to_file.inc
+--enable_query_log
+
+--exec $MYSQL < $write_to_file
+RESET MASTER;
+--remove_file $write_to_file

=== modified file 'sql/log.cc'
--- a/sql/log.cc	2011-02-22 21:03:32 +0000
+++ b/sql/log.cc	2011-05-23 16:28:17 +0000
@@ -2989,12 +2989,6 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd)
   DBUG_ENTER("reset_logs");
 
   ha_reset_logs(thd);
-  /*
-    We need to get both locks to be sure that no one is trying to
-    write to the index log file.
-  */
-  pthread_mutex_lock(&LOCK_log);
-  pthread_mutex_lock(&LOCK_index);
 
   /*
     The following mutex is needed to ensure that no threads call
@@ -3002,7 +2996,14 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd)
     thread. If the transaction involved MyISAM tables, it should go
     into binlog even on rollback.
   */
-  VOID(pthread_mutex_lock(&LOCK_thread_count));
+  pthread_mutex_lock(&LOCK_thread_count);
+
+  /*
+    We need to get both locks to be sure that no one is trying to
+    write to the index log file.
+  */
+  pthread_mutex_lock(&LOCK_log);
+  pthread_mutex_lock(&LOCK_index);
 
   /* Save variables so that we can reopen the log */
   save_name=name;

=== modified file 'sql/mysqld.cc'
--- a/sql/mysqld.cc	2011-03-25 10:57:27 +0000
+++ b/sql/mysqld.cc	2011-05-23 16:28:17 +0000
@@ -1903,6 +1903,12 @@ void unlink_thd(THD *thd)
   pthread_mutex_unlock(&LOCK_connection_count);
 
   (void) pthread_mutex_lock(&LOCK_thread_count);
+  /*
+    Used by binlog_reset_master.  It would be cleaner to use
+    DEBUG_SYNC here, but that's not possible because the THD's debug
+    sync feature has been shut down at this point.
+  */
+  DBUG_EXECUTE_IF("sleep_after_lock_thread_count_before_delete_thd", sleep(5););
   thread_count--;
   delete thd;
   DBUG_VOID_RETURN;


Attachment: [text/bzr-bundle] bzr/sven.sandberg@oracle.com-20110523162817-s2cywi621ms67kar.bundle
Thread
bzr commit into mysql-5.1 branch (sven.sandberg:3625) Bug#12574820Sven Sandberg23 May
  • Re: bzr commit into mysql-5.1 branch (sven.sandberg:3625) Bug#12574820Luís Soares25 May