From: Date: December 16 2008 11:15am
Subject: bzr commit into mysql-6.0-bugteam branch (davi:2809) Bug#39897
List-Archive: http://lists.mysql.com/commits/61740
X-Bug: 39897
Message-Id: <20081216101537.ACB34EC029@skynet.ctb.virtua.com.br>
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit

# At a local mysql-6.0-bugteam repository of davi

 2809 Davi Arnaut	2008-12-16
      Bug#39897: lock_multi fails in pushbuild: timeout waiting for processlist
      
      The problem is that relying on the "Table lock" thread state to
      detect that a thread is waiting on a lock is race prone. The "Table
      lock" state change happens before the thread actually tries to grab
      a lock on a table.
      
      The solution is to introduce a new "Waiting for lock" state that is
      set only when a thread is actually going to wait for a lock. The state
      is change happens after the thread fails to grab the lock (because it
      is owned by other thread) and proceeds to wait on a condition.
modified:
  mysql-test/r/sp-threads.result
  mysql-test/suite/binlog/t/binlog_stm_row.test
  mysql-test/suite/maria/t/maria-lock.test
  mysql-test/t/insert_notembedded.test
  mysql-test/t/lock_multi.test
  mysql-test/t/sp_notembedded.test
  mysql-test/t/status.test
  mysys/thr_lock.c

per-file messages:
  mysql-test/r/sp-threads.result
    Update test case result.
  mysql-test/suite/binlog/t/binlog_stm_row.test
    Use new state.
  mysql-test/suite/maria/t/maria-lock.test
    Use new state.
  mysql-test/t/insert_notembedded.test
    Use new state.
  mysql-test/t/lock_multi.test
    Use new state.
  mysql-test/t/sp_notembedded.test
    Use new state.
  mysql-test/t/status.test
    Use new state.
  mysys/thr_lock.c
    Update thread state while waiting for a lock.
=== modified file 'mysql-test/r/sp-threads.result'
--- a/mysql-test/r/sp-threads.result	2007-12-20 15:57:11 +0000
+++ b/mysql-test/r/sp-threads.result	2008-12-16 10:15:24 +0000
@@ -35,7 +35,7 @@ call bug9486();
 show processlist;
 Id	User	Host	db	Command	Time	State	Info
 #	root	localhost	test	Sleep	#	NULL	NULL
-#	root	localhost	test	Query	#	Table lock	update t1, t2 set val= 1 where id1=id2
+#	root	localhost	test	Query	#	Waiting for lock	update t1, t2 set val= 1 where id1=id2
 #	root	localhost	test	Query	#	NULL	show processlist
 #	root	localhost	test	Sleep	#	NULL	NULL
 unlock tables;

=== modified file 'mysql-test/suite/binlog/t/binlog_stm_row.test'
--- a/mysql-test/suite/binlog/t/binlog_stm_row.test	2008-10-07 15:36:44 +0000
+++ b/mysql-test/suite/binlog/t/binlog_stm_row.test	2008-12-16 10:15:24 +0000
@@ -55,7 +55,7 @@ let $wait_condition=
 --echo # con1
 let $wait_condition=
   SELECT COUNT(*) = 1 FROM information_schema.processlist WHERE
-  state = "Table lock" and info = "INSERT INTO t2 VALUES (3)";
+  state = "Waiting for lock" and info = "INSERT INTO t2 VALUES (3)";
 --source include/wait_condition.inc
 SELECT RELEASE_LOCK('Bug#34306');
 --connection con2

=== modified file 'mysql-test/suite/maria/t/maria-lock.test'
--- a/mysql-test/suite/maria/t/maria-lock.test	2008-10-23 16:29:52 +0000
+++ b/mysql-test/suite/maria/t/maria-lock.test	2008-12-16 10:15:24 +0000
@@ -37,7 +37,7 @@ send insert t1 select * from t2;
 connection locker;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "insert t1 select * from t2";
+  where state = "Waiting for lock" and info = "insert t1 select * from t2";
 --source include/wait_condition.inc
 drop table t2;
 --echo "table dropped";
@@ -85,7 +85,7 @@ send insert t1 select * from t2;
 connection locker;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "insert t1 select * from t2";
+  where state = "Waiting for lock" and info = "insert t1 select * from t2";
 --source include/wait_condition.inc
 drop table t2;
 connection reader;

=== modified file 'mysql-test/t/insert_notembedded.test'
--- a/mysql-test/t/insert_notembedded.test	2007-12-20 15:57:11 +0000
+++ b/mysql-test/t/insert_notembedded.test	2008-12-16 10:15:24 +0000
@@ -174,7 +174,7 @@ connection default;
 # we must wait till the insert opens and locks the table
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and id = $ID;
+  where state = "Waiting for lock" and id = $ID;
 --source include/wait_condition.inc
 connect (select,localhost,root,,);
 --echo connection: select

=== modified file 'mysql-test/t/lock_multi.test'
--- a/mysql-test/t/lock_multi.test	2008-10-09 16:13:03 +0000
+++ b/mysql-test/t/lock_multi.test	2008-12-16 10:15:24 +0000
@@ -18,13 +18,13 @@ send update low_priority t1 set n = 4;
 connection reader;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "update low_priority t1 set n = 4";
+  where state = "Waiting for lock" and info = "update low_priority t1 set n = 4";
 --source include/wait_condition.inc
 send select n from t1;
 connection locker;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "select n from t1";
+  where state = "Waiting for lock" and info = "select n from t1";
 --source include/wait_condition.inc
 unlock tables;
 connection writer;
@@ -42,7 +42,7 @@ send update low_priority t1 set n = 4;
 connection reader;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "update low_priority t1 set n = 4";
+  where state = "Waiting for lock" and info = "update low_priority t1 set n = 4";
 --source include/wait_condition.inc
 select n from t1;
 connection locker;
@@ -86,7 +86,7 @@ send insert t1 select * from t2;
 connection locker;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "insert t1 select * from t2";
+  where state = "Waiting for lock" and info = "insert t1 select * from t2";
 --source include/wait_condition.inc
 drop table t2;
 connection reader;
@@ -96,7 +96,7 @@ connection locker;
 drop table t1;
 
 #
-# Same test as above, but with the dropped table locked twice
+# Same test as above, but with the dropped Waiting for locked twice
 #
 
 connection locker;
@@ -108,7 +108,7 @@ send insert t1 select * from t2;
 connection locker;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "insert t1 select * from t2";
+  where state = "Waiting for lock" and info = "insert t1 select * from t2";
 --source include/wait_condition.inc
 drop table t2;
 connection reader;
@@ -151,7 +151,7 @@ send SELECT user.Select_priv FROM user, 
 connection locker;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = 
+  where state = "Waiting for lock" and info = 
   "SELECT user.Select_priv FROM user, db WHERE user.user = db.user LIMIT 1";
 --source include/wait_condition.inc
 # Make test case independent from earlier grants.
@@ -277,13 +277,13 @@ send alter table t1 auto_increment=0;
 connection reader;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "alter table t1 auto_increment=0";
+  where state = "Waiting for lock" and info = "alter table t1 auto_increment=0";
 --source include/wait_condition.inc
 send alter table t1 auto_increment=0;
 connection locker;
 let $wait_condition=
   select count(*) = 2 from information_schema.processlist
-  where state = "Table lock" and info = "alter table t1 auto_increment=0";
+  where state = "Waiting for lock" and info = "alter table t1 auto_increment=0";
 --source include/wait_condition.inc
 unlock tables;
 connection writer;
@@ -628,15 +628,15 @@ connection writer;
 connection reader;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "update t1 set i= 10";
+  where state = "Waiting for lock" and info = "update t1 set i= 10";
 --source include/wait_condition.inc
 --send select * from t1;
 connection default;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "select * from t1";
+  where state = "Waiting for lock" and info = "select * from t1";
 --source include/wait_condition.inc
-let $ID= `select id from information_schema.processlist where state = "Table lock" and info = "update t1 set i= 10"`;
+let $ID= `select id from information_schema.processlist where state = "Waiting for lock" and info = "update t1 set i= 10"`;
 --replace_result $ID ID
 eval kill query $ID;
 connection reader;
@@ -776,7 +776,7 @@ send insert into t1 values(1);
 connection default;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and info = "insert into t1 values(1)";
+  where state = "Waiting for lock" and info = "insert into t1 values(1)";
 --source include/wait_condition.inc
 let $tlwb= `show status like 'Table_locks_waited'`;
 unlock tables;

=== modified file 'mysql-test/t/sp_notembedded.test'
--- a/mysql-test/t/sp_notembedded.test	2008-03-27 19:02:15 +0000
+++ b/mysql-test/t/sp_notembedded.test	2008-12-16 10:15:24 +0000
@@ -316,7 +316,7 @@ set session low_priority_updates=on;
 connection rl_wait;
 let $wait_condition=
   select count(*) = 1 from information_schema.processlist
-  where state = "Table lock" and
+  where state = "Waiting for lock" and
   info = "update t1 set value='updated' where value='old'";
 --source include/wait_condition.inc
 

=== modified file 'mysql-test/t/status.test'
--- a/mysql-test/t/status.test	2008-10-20 19:13:22 +0000
+++ b/mysql-test/t/status.test	2008-12-16 10:15:24 +0000
@@ -49,7 +49,7 @@ let $ID= `select connection_id()`;
 connection con2;
 --echo # Switched to connection: con2
 # wait for the other query to start executing
-let $wait_condition= select 1 from INFORMATION_SCHEMA.PROCESSLIST where ID = $ID and STATE = "Table lock";
+let $wait_condition= select 1 from INFORMATION_SCHEMA.PROCESSLIST where ID = $ID and STATE = "Waiting for lock";
 --source include/wait_condition.inc
 unlock tables;
 

=== modified file 'mysys/thr_lock.c'
--- a/mysys/thr_lock.c	2008-10-20 09:16:47 +0000
+++ b/mysys/thr_lock.c	2008-12-16 10:15:24 +0000
@@ -426,6 +426,7 @@ wait_for_lock(struct st_lock_list *wait,
   struct timespec wait_timeout;
   enum enum_thr_lock_result result= THR_LOCK_ABORTED;
   my_bool can_deadlock= test(data->owner->info->n_cursors);
+  const char *old_proc_info;
   DBUG_ENTER("wait_for_lock");
 
 #if defined(ENABLED_DEBUG_SYNC)
@@ -451,6 +452,9 @@ wait_for_lock(struct st_lock_list *wait,
   thread_var->current_cond=  cond;
   data->cond= cond;
 
+  old_proc_info= proc_info_hook(NULL, "Waiting for lock",
+                                __func__, __FILE__, __LINE__);
+
   if (can_deadlock)
     set_timespec(wait_timeout, table_lock_wait_timeout);
   while (!thread_var->abort || in_wait_list)
@@ -521,6 +525,9 @@ wait_for_lock(struct st_lock_list *wait,
   thread_var->current_mutex= 0;
   thread_var->current_cond=  0;
   pthread_mutex_unlock(&thread_var->mutex);
+
+  proc_info_hook(NULL, old_proc_info, __func__, __FILE__, __LINE__);
+
   DBUG_RETURN(result);
 }