MDEV-297: SHOW EXPLAIN: Server gets stuck until timeout occurs while executing SHOW

INDEX and SHOW EXPLAIN in parallel
- Rework locking code to use the LOCK_thd_data mutex for all synchronization. This also
  fixed MDEV-301.

mysql-test/r/show_explain.result

@@ -596,4 +596,24 @@ count(*)
 212
 set debug_dbug='';
 drop table t1;
+#
+# MDEV-297: SHOW EXPLAIN: Server gets stuck until timeout occurs while
+#           executing SHOW INDEX and SHOW EXPLAIN in parallel
+#
+CREATE TABLE t1(a INT, b INT, c INT, KEY(a), KEY(b), KEY(c));
+INSERT INTO t1 (a) VALUES (3),(1),(5),(1);
+set @show_explain_probe_select_id=1;
+set debug_dbug='d,show_explain_probe_join_exec_start';
+SHOW INDEX FROM t1;
+show explain for $thr2;
+id	select_type	table	type	possible_keys	key	key_len	ref	rows	Extra
+1	SIMPLE	STATISTICS	ALL	NULL	NULL	NULL	NULL	NULL	Skip_open_table; Scanned all databases
+Warnings:
+Note	1003	SHOW INDEX FROM t1
+Table	Non_unique	Key_name	Seq_in_index	Column_name	Collation	Cardinality	Sub_part	Packed	Null	Index_type	Comment	Index_comment
+t1	1	a	1	a	A	NULL	NULL	NULL	YES	BTREE		
+t1	1	b	1	b	A	NULL	NULL	NULL	YES	BTREE		
+t1	1	c	1	c	A	NULL	NULL	NULL	YES	BTREE		
+set debug_dbug='';
+DROP TABLE t1;
 drop table t0;

mysql-test/t/show_explain.test

@@ -581,6 +581,26 @@ reap;
 set debug_dbug='';
 drop table t1;
 
+--echo #
+--echo # MDEV-297: SHOW EXPLAIN: Server gets stuck until timeout occurs while
+--echo #           executing SHOW INDEX and SHOW EXPLAIN in parallel
+--echo #
+CREATE TABLE t1(a INT, b INT, c INT, KEY(a), KEY(b), KEY(c));
+INSERT INTO t1 (a) VALUES (3),(1),(5),(1);
+
+set @show_explain_probe_select_id=1;
+set debug_dbug='d,show_explain_probe_join_exec_start';
+
+send SHOW INDEX FROM t1;
+connection default;
+--source include/wait_condition.inc
+evalp show explain for $thr2;
+connection con1;
+reap;
+set debug_dbug='';
+
+DROP TABLE t1;
+
 
 ## TODO: Test this: have several SHOW EXPLAIN requests be queued up for a
 ##       thread and served together.

sql/my_apc.cc

@@ -9,6 +9,8 @@
 #include <my_pthread.h>
 #include <my_sys.h>
 
+#include "my_apc.h"
+
 #else
 
 #include "sql_priv.h"
@@ -16,7 +18,6 @@
 
 #endif
 
-//#include "my_apc.h"
 
 /*
   Standalone testing:
@@ -33,12 +34,10 @@
   any call requests to it.
   Initial state after initialization is 'disabled'.
 */
-void Apc_target::init()
+void Apc_target::init(mysql_mutex_t *target_mutex)
 {
-  // todo: should use my_pthread_... functions instead?
   DBUG_ASSERT(!enabled);
-  (void)pthread_mutex_init(&LOCK_apc_queue, MY_MUTEX_INIT_SLOW);
+  LOCK_thd_data_ptr= target_mutex;
-
 #ifndef DBUG_OFF
   n_calls_processed= 0;
 #endif
@@ -51,7 +50,6 @@ void Apc_target::init()
 void Apc_target::destroy()
 {
   DBUG_ASSERT(!enabled);
-  pthread_mutex_destroy(&LOCK_apc_queue);
 }
 
 
@@ -60,9 +58,8 @@ void Apc_target::destroy()
 */
 void Apc_target::enable()
 {
-  pthread_mutex_lock(&LOCK_apc_queue);
+  /* Ok to do without getting/releasing the mutex: */
   enabled++;
-  pthread_mutex_unlock(&LOCK_apc_queue);
 }
 
 
@@ -76,16 +73,16 @@ void Apc_target::enable()
 void Apc_target::disable()
 {
   bool process= FALSE;
-  pthread_mutex_lock(&LOCK_apc_queue);
+  mysql_mutex_lock(LOCK_thd_data_ptr);
   if (!(--enabled))
     process= TRUE;
-  pthread_mutex_unlock(&LOCK_apc_queue);
+  mysql_mutex_unlock(LOCK_thd_data_ptr);
   if (process)
     process_apc_requests();
 }
 
 
-/* (internal) Put request into the request list */
+/* [internal] Put request qe into the request list */
 
 void Apc_target::enqueue_request(Call_request *qe)
 {
@@ -108,7 +105,7 @@ void Apc_target::enqueue_request(Call_request *qe)
 
 
 /* 
-  (internal) Remove given request from the request queue. 
+  [internal] Remove request qe from the request queue. 
   
   The request is not necessarily first in the queue.
 */
@@ -131,11 +128,14 @@ void Apc_target::dequeue_request(Call_request *qe)
 
 
 /*
-  Make an APC (Async Procedure Call) in another thread. 
+  Make an APC (Async Procedure Call) to another thread. 
+
+  - The caller is responsible for making sure he's not calling to the same
+    thread.
+
+  - The caller should have locked target_thread_mutex.
+
 
-  The caller is responsible for making sure he's not calling an Apc_target 
-  that is serviced by the same thread it is called from.
-  
   psergey-todo: Should waits here be KILLable? (it seems one needs 
   to use thd->enter_cond() calls to be killable)
 */
@@ -146,7 +146,6 @@ bool Apc_target::make_apc_call(apc_func_t func, void *func_arg,
   bool res= TRUE;
   *timed_out= FALSE;
 
-  pthread_mutex_lock(&LOCK_apc_queue);
   if (enabled)
   {
     /* Create and post the request */
@@ -154,51 +153,48 @@ bool Apc_target::make_apc_call(apc_func_t func, void *func_arg,
     apc_request.func= func;
     apc_request.func_arg= func_arg;
     apc_request.processed= FALSE;
-    (void)pthread_cond_init(&apc_request.COND_request, NULL);
+    mysql_cond_init(0 /* do not track in PS */, &apc_request.COND_request, NULL);
-    (void)pthread_mutex_init(&apc_request.LOCK_request, MY_MUTEX_INIT_SLOW);
-    pthread_mutex_lock(&apc_request.LOCK_request);
     enqueue_request(&apc_request);
     apc_request.what="enqueued by make_apc_call";
-    pthread_mutex_unlock(&LOCK_apc_queue);
  
     struct timespec abstime;
     const int timeout= timeout_sec;
     set_timespec(abstime, timeout);
-    
+
     int wait_res= 0;
     /* todo: how about processing other errors here? */
     while (!apc_request.processed && (wait_res != ETIMEDOUT))
     {
-      wait_res= pthread_cond_timedwait(&apc_request.COND_request,
+      /* We own LOCK_thd_data_ptr */
-                                       &apc_request.LOCK_request, &abstime);
+      wait_res= mysql_cond_timedwait(&apc_request.COND_request,
+                                     LOCK_thd_data_ptr, &abstime);
+                                      // &apc_request.LOCK_request, &abstime);
     }
 
     if (!apc_request.processed)
     {
-      /* The wait has timed out. Remove the request from the queue */
+      /* 
+        The wait has timed out. Remove the request from the queue (ok to do
+        because we own LOCK_thd_data_ptr.
+      */
       apc_request.processed= TRUE;
-      *timed_out= TRUE;
-      pthread_mutex_unlock(&apc_request.LOCK_request);
-      //psergey-todo: "Whoa rare event" refers to this part, right? put a comment.
-      pthread_mutex_lock(&LOCK_apc_queue);
       dequeue_request(&apc_request);
-      pthread_mutex_unlock(&LOCK_apc_queue);
+      *timed_out= TRUE;
       res= TRUE;
     }
     else
     {
       /* Request was successfully executed and dequeued by the target thread */
-      pthread_mutex_unlock(&apc_request.LOCK_request);
       res= FALSE;
     }
+    mysql_mutex_unlock(LOCK_thd_data_ptr);
 
     /* Destroy all APC request data */
-    pthread_mutex_destroy(&apc_request.LOCK_request);
+    mysql_cond_destroy(&apc_request.COND_request);
-    pthread_cond_destroy(&apc_request.COND_request);
   }
   else
   {
-    pthread_mutex_unlock(&LOCK_apc_queue);
+    mysql_mutex_unlock(LOCK_thd_data_ptr);
   }
   return res;
 }
@@ -211,58 +207,37 @@ bool Apc_target::make_apc_call(apc_func_t func, void *func_arg,
 
 void Apc_target::process_apc_requests()
 {
+  if (!get_first_in_queue())
+    return;
+
   while (1)
   {
     Call_request *request;
-    
+ 
-    pthread_mutex_lock(&LOCK_apc_queue);
+    mysql_mutex_lock(LOCK_thd_data_ptr);
     if (!(request= get_first_in_queue()))
     {
-      pthread_mutex_unlock(&LOCK_apc_queue);
+      /* No requests in the queue */
+      mysql_mutex_unlock(LOCK_thd_data_ptr);
       break;
     }
 
-    request->what="seen by process_apc_requests";
-    pthread_mutex_lock(&request->LOCK_request);
-
-    if (request->processed)
-    {
-      /*
-        We can get here when
-        - the requestor thread has been waiting for this request
-        - the wait has timed out
-        - it has set request->done=TRUE
-        - it has released LOCK_request, because its next action
-          will be to remove the request from the queue, however,
-          it could not attempt to lock the queue while holding the lock on
-          request, because that would deadlock with this function 
-          (we here first lock the queue and then lock the request)
-      */
-      pthread_mutex_unlock(&request->LOCK_request);
-      pthread_mutex_unlock(&LOCK_apc_queue);
-      fprintf(stderr, "Whoa rare event #1!\n");
-      continue;
-    }
     /* 
-      Remove the request from the queue (we're holding its lock so we can be 
+      Remove the request from the queue (we're holding queue lock so we can be 
       sure that request owner won't try to remove it)
     */
     request->what="dequeued by process_apc_requests";
     dequeue_request(request);
     request->processed= TRUE;
 
-    pthread_mutex_unlock(&LOCK_apc_queue);
-
     request->func(request->func_arg);
     request->what="func called by process_apc_requests";
 
 #ifndef DBUG_OFF
     n_calls_processed++;
 #endif
-
+    mysql_cond_signal(&request->COND_request);
-    pthread_cond_signal(&request->COND_request);
+    mysql_mutex_unlock(LOCK_thd_data_ptr);
-
-    pthread_mutex_unlock(&request->LOCK_request);
   }
 }
 
@@ -280,6 +255,7 @@ volatile int apcs_missed=0;
 volatile int apcs_timed_out=0;
 
 Apc_target apc_target;
+mysql_mutex_t target_mutex;
 
 int int_rand(int size)
 {
@@ -290,7 +266,8 @@ int int_rand(int size)
 void *test_apc_service_thread(void *ptr)
 {
   my_thread_init();
-  apc_target.init();
+  mysql_mutex_init(0, &target_mutex, MY_MUTEX_INIT_FAST);
+  apc_target.init(&target_mutex);
   apc_target.enable();
   started= TRUE;
   fprintf(stderr, "# test_apc_service_thread started\n");

sql/my_apc.h

@@ -22,15 +22,16 @@
 */
 
 /*
-  Target for asynchronous calls.
+  Target for asynchronous procedue calls (APCs).
 */
 class Apc_target
 {
+  mysql_mutex_t *LOCK_thd_data_ptr;
 public:
   Apc_target() : enabled(0), apc_calls(NULL) /*, call_queue_size(0)*/ {} 
   ~Apc_target() { DBUG_ASSERT(!enabled && !apc_calls);}
 
-  void init();
+  void init(mysql_mutex_t *target_mutex);
   void destroy();
   void enable();
   void disable();
@@ -68,14 +69,31 @@ private:
   /* 
     Circular, double-linked list of all enqueued call requests. 
     We use this structure, because we 
-     - process requests sequentially 
+     - process requests sequentially (i.e. they are removed from the front)
      - a thread that has posted a request may time out (or be KILLed) and 
-       cancel the request, which means we'll need to remove its request at 
+       cancel the request, which means we need a fast request-removal
-       arbitrary point in time.
+       operation.
   */
   Call_request *apc_calls;
+ 
 
-  pthread_mutex_t LOCK_apc_queue;
+  /*
+    This mutex is used to
+    - make queue put/remove operations atomic (one must be in posession of the
+      mutex when putting/removing something from the queue)
+
+    - make sure that nobody enqueues a request onto an Apc_target which has 
+      disabled==TRUE. The idea is:
+      = requestor must be in possession of the mutex and check that
+        disabled==FALSE when he is putting his request into the queue.
+      = When the owner (ie. service) thread changes the Apc_target from 
+        enabled to disabled, it will acquire the mutex, disable the 
+        Apc_target (preventing any new requests), and then serve all pending 
+        requests. 
+      That way, we will never have the situation where the Apc_target is 
+      disabled, but there are some un-served requests.
+  */
+  //pthread_mutex_t LOCK_apc_queue;
 
   class Call_request
   {
@@ -84,13 +102,16 @@ private:
     void *func_arg;  /* Argument to pass it */
     bool processed;
 
-    pthread_mutex_t LOCK_request;
+    //pthread_mutex_t LOCK_request;
-    pthread_cond_t COND_request;
+    //pthread_cond_t COND_request;
+
+    /* Condition that will be signalled when the request has been served */
+    mysql_cond_t COND_request;
 
     Call_request *next;
     Call_request *prev;
     
-    const char *what; /* State of the request */
+    const char *what; /* (debug) state of the request */
   };
 
   void enqueue_request(Call_request *qe);

sql/sql_class.cc

@@ -1196,7 +1196,7 @@ void THD::init(void)
   /* Initialize the Debug Sync Facility. See debug_sync.cc. */
   debug_sync_init_thread(this);
 #endif /* defined(ENABLED_DEBUG_SYNC) */
-  apc_target.init();
+  apc_target.init(&LOCK_thd_data);
 }
 
  
@@ -1372,6 +1372,8 @@ THD::~THD()
 {
   THD_CHECK_SENTRY(this);
   DBUG_ENTER("~THD()");
+  //psergey-todo: assert that the queue is disabled and empty.
+
   /* Ensure that no one is using THD */
   mysql_mutex_lock(&LOCK_thd_data);
   mysys_var=0;					// Safety (shouldn't be needed)

sql/sql_show.cc

@@ -2063,7 +2063,8 @@ void mysqld_show_explain(THD *thd, ulong thread_id)
     explain_req.target_thd= tmp;
     explain_req.request_thd= thd;
     explain_req.failed_to_produce= FALSE;
-
+    
+    /* Ok, we have a lock on target->LOCK_thd_data, can call: */
     bres= tmp->apc_target.make_apc_call(Show_explain_request::get_explain_data,
                                         (void*)&explain_req,
                                         timeout_sec, &timed_out);
@@ -2090,7 +2091,7 @@ void mysqld_show_explain(THD *thd, ulong thread_id)
       push_warning(thd, MYSQL_ERROR::WARN_LEVEL_NOTE,
                    ER_YES, explain_req.query_str.c_ptr_safe());
     }
-    mysql_mutex_unlock(&tmp->LOCK_thd_data);
+    //mysql_mutex_unlock(&tmp->LOCK_thd_data);
     if (!bres)
     {
       explain_buf->flush_data();