Merge lp:~tsarev/percona-server/5.5_fix_bug_878709 into lp:percona-server/5.5

[Oleg Tsarev]

Fixed sporadic test fails of main.percona_status_wait_query_cache_mutex.
Bug #878709.
Reason of bug - incorrect test synchronisation.
I removed sleep(1) from code, replace by "before_query_cache_mutex" and "after_query_cache_mutex" debug sync points.

Clean Jenkins results: http://jenkins.percona.com/view/Percona%20Server%205.5/job/percona-server-5.5-param/188/

[Laurynas Biveinis (laurynas-biveinis)]

What is the original purpose of percona_status_wait_query_cache_mutex test? I.e. what functionality or regression etc. is tested there?

The code part looks OK - IF the test part is OK.

[Oleg Tsarev (tsarev)]

I'm testing the functionality (status "Waiting on query cache mutex" should be available)

[Laurynas Biveinis (laurynas-biveinis)]

1) Please remove the variable mutex_locked and just issue the SELECT directly.
2) There is an MTR var named try_lock_mutex and and DEBUG_SYNC signal name named try_lock_mutex. Please rename one of them/both to make it clearer.
3) If the last statement SET DEBUG_SYNC='reset' is redundant, please remove it.

Thanks!

review: Needs Fixing

=== modified file 'patches/query_cache_enhance.patch'
--- patches/query_cache_enhance.patch	2011-10-07 06:54:28 +0000
+++ patches/query_cache_enhance.patch	2011-11-22 13:46:26 +0000
@@ -267,22 +267,20 @@
  #ifdef EMBEDDED_LIBRARY
  #include "emb_qcache.h"
  #endif
-@@ -454,7 +629,14 @@
+@@ -454,7 +629,12 @@
    Query_cache_wait_state wait_state(thd, __func__, __FILE__, __LINE__);
    DBUG_ENTER("Query_cache::try_lock");
  
 +  const char* old_proc_info= thd->proc_info;
 +  thd_proc_info(thd,"Waiting on query cache mutex");
++  DEBUG_SYNC(thd, "before_query_cache_mutex");
    mysql_mutex_lock(&structure_guard_mutex);
-+  DEBUG_SYNC(thd, "status_waiting_on_query_cache_mutex");
-+  DBUG_EXECUTE_IF("status_waiting_on_query_cache_mutex_sleep", {
-+      sleep(1);
-+    });
++  DEBUG_SYNC(thd, "after_query_cache_mutex");
 +  thd->proc_info = old_proc_info;
    while (1)
    {
      if (m_cache_lock_status == Query_cache::UNLOCKED)
-@@ -1274,6 +1456,8 @@
+@@ -1274,6 +1454,8 @@
        unlock();
        DBUG_VOID_RETURN;
      }
@@ -291,7 +289,7 @@
  
      /* Key is query + database + flag */
      if (thd->db_length)
-@@ -1451,6 +1635,9 @@
+@@ -1451,6 +1633,9 @@
    Query_cache_block_table *block_table, *block_table_end;
    ulong tot_length;
    Query_cache_query_flags flags;
@@ -301,7 +299,7 @@
    DBUG_ENTER("Query_cache::send_result_to_client");
  
    /*
-@@ -1472,21 +1659,103 @@
+@@ -1472,21 +1657,103 @@
  
    {
      uint i= 0;
@@ -418,7 +416,7 @@
      if ((my_toupper(system_charset_info, sql[i])     != 'S' ||
           my_toupper(system_charset_info, sql[i + 1]) != 'E' ||
           my_toupper(system_charset_info, sql[i + 2]) != 'L') &&
-@@ -1521,6 +1790,12 @@
+@@ -1521,6 +1788,12 @@
      goto err_unlock;
  
    Query_cache_block *query_block;
@@ -431,7 +429,7 @@
  
    tot_length= query_length + thd->db_length + 1 + QUERY_CACHE_FLAGS_SIZE;
    if (thd->db_length)
-@@ -1587,6 +1862,8 @@
+@@ -1587,6 +1860,8 @@
  	 (uchar*) &flags, QUERY_CACHE_FLAGS_SIZE);
    query_block = (Query_cache_block *)  my_hash_search(&queries, (uchar*) sql,
                                                        tot_length);
@@ -2785,32 +2783,6 @@
 +SET GLOBAL query_cache_size= default;
 +set global query_cache_strip_comments=OFF;
 --- /dev/null
-+++ b/mysql-test/r/percona_status_wait_query_cache_mutex.result
-@@ -0,0 +1,23 @@
-+SET GLOBAL query_cache_size=1355776;
-+flush query cache;
-+flush query cache;
-+reset query cache;
-+flush status;
-+DROP TABLE IF EXISTS t;
-+CREATE TABLE t(id INT, number INT);
-+INSERT INTO t VALUES (0,1);
-+INSERT INTO t VALUES (1,2);
-+INSERT INTO t VALUES (2,3);
-+SET SESSION debug="+d,status_waiting_on_query_cache_mutex_sleep";
-+SET DEBUG_SYNC='status_waiting_on_query_cache_mutex SIGNAL thread_ready';
-+SELECT number from t where id > 0;
-+SHOW PROCESSLIST;
-+Id	User	Host	db	Command	Time	State	Info	Rows_sent	Rows_examined	Rows_read
-+###	root	###	test	Query	###	NULL	SHOW PROCESSLIST	###	###	###
-+###	root	###	test	Query	###	Waiting on query cache mutex	SELECT number from t where id > 0	###	###	###
-+SELECT id, info, state FROM INFORMATION_SCHEMA.PROCESSLIST ORDER BY id;
-+id	info	state
-+###	SELECT id, info, state FROM INFORMATION_SCHEMA.PROCESSLIST ORDER BY id	executing
-+###	SELECT number from t where id > 0	Waiting on query cache mutex
-+DROP TABLE t;
-+SET GLOBAL query_cache_size=0;
---- /dev/null
 +++ b/mysql-test/t/percona_query_cache_with_comments.test
 @@ -0,0 +1,5 @@
 +--disable_ps_protocol
@@ -3062,37 +3034,41 @@
 +set global query_cache_strip_comments=OFF;
 --- /dev/null
 +++ b/mysql-test/t/percona_status_wait_query_cache_mutex.test
-@@ -0,0 +1,31 @@
+@@ -0,0 +1,35 @@
 +--source include/have_query_cache.inc
 +--source include/have_debug.inc
 +--source include/have_debug_sync.inc
 +SET GLOBAL query_cache_size=1355776;
 +--source include/percona_query_cache_with_comments_clear.inc
-+
-+-- disable_warnings
-+DROP TABLE IF EXISTS t;
-+-- enable_warnings
-+CREATE TABLE t(id INT, number INT);
-+INSERT INTO t VALUES (0,1);
-+INSERT INTO t VALUES (1,2);
-+INSERT INTO t VALUES (2,3);
-+
-+--connect (conn,localhost,root,,)
-+
-+--connection conn
-+SET SESSION debug="+d,status_waiting_on_query_cache_mutex_sleep";
-+SET DEBUG_SYNC='status_waiting_on_query_cache_mutex SIGNAL thread_ready';
-+SEND SELECT number from t where id > 0;
-+
-+--connection default
-+--replace_column 1 ### 3 ### 6 ### 9 ### 10 ### 11 ###
-+SHOW PROCESSLIST;
-+
-+--replace_column 1 ###
-+SELECT id, info, state FROM INFORMATION_SCHEMA.PROCESSLIST ORDER BY id;
-+
-+--disconnect conn
-+DROP TABLE t;
++--let try_lock_mutex_query=SELECT "try_lock_mutex_query" as action
++
++--connect (mutex_locked_conn, localhost, root,,)
++--connect (try_mutex_lock_conn, localhost, root,,)
++
++--connection mutex_locked_conn
++SET DEBUG_SYNC='after_query_cache_mutex SIGNAL mutex_locked WAIT_FOR unlock_mutex';
++send SELECT "mutex_locked_query" as action;
++
++--connection default
++SET DEBUG_SYNC='now WAIT_FOR mutex_locked';
++
++--connection try_mutex_lock_conn
++SET DEBUG_SYNC='before_query_cache_mutex SIGNAL try_lock_mutex';
++send_eval $try_lock_mutex_query;
++
++--connection default
++SET DEBUG_SYNC='now WAIT_FOR try_lock_mutex';
++eval SELECT SQL_NO_CACHE state FROM INFORMATION_SCHEMA.PROCESSLIST WHERE info='$try_lock_mutex_query';
++SET DEBUG_SYNC='now SIGNAL unlock_mutex';
++
++--connection mutex_locked_conn
++reap;
++--connection try_mutex_lock_conn
++reap;
++
++--connection default
++--disconnect mutex_locked_conn
++--disconnect try_mutex_lock_conn
 +SET GLOBAL query_cache_size=0;
 --- a/mysql-test/r/mysqld--help-notwin.result
 +++ b/mysql-test/r/mysqld--help-notwin.result
@@ -3115,3 +3091,26 @@
  query-cache-type ON
  query-cache-wlock-invalidate FALSE
  query-prealloc-size 8192
+--- /dev/null
++++ b/mysql-test/r/percona_status_wait_query_cache_mutex.result
+@@ -0,0 +1,20 @@
++SET GLOBAL query_cache_size=1355776;
++flush query cache;
++flush query cache;
++reset query cache;
++flush status;
++SET DEBUG_SYNC='after_query_cache_mutex SIGNAL mutex_locked WAIT_FOR unlock_mutex';
++SELECT "mutex_locked_query" as action;
++SET DEBUG_SYNC='now WAIT_FOR mutex_locked';
++SET DEBUG_SYNC='before_query_cache_mutex SIGNAL try_lock_mutex';
++SELECT "try_lock_mutex_query" as action;
++SET DEBUG_SYNC='now WAIT_FOR try_lock_mutex';
++SELECT SQL_NO_CACHE state FROM INFORMATION_SCHEMA.PROCESSLIST WHERE info='SELECT "try_lock_mutex_query" as action';
++state
++Waiting on query cache mutex
++SET DEBUG_SYNC='now SIGNAL unlock_mutex';
++action
++mutex_locked_query
++action
++try_lock_mutex_query
++SET GLOBAL query_cache_size=0;