server crashing, potentially thread pool related

(gdb) print event_name_array
$39 = (PFS_single_stat *) 0x67
(gdb) print thread->m_instr_class_waits_stats
$40 = (PFS_single_stat *) 0x67

No idea yet why it's corrupted.

For the record, same crash was reproduced with Performance Schema disabled and the problem on a reproducible case on the customer system was reduced to:

CREATE DATABASE ms ;
CREATE TABLE t1 (a INT PRIMARY KEY AUTO_INCREMENT, b INT, c VARCHAR(50)) ;

- Put the following in q.sql:
SELECT FLOOR(RAND() * 1000000), MD5(RAND()), FLOOR(RAND() * 10000) INTO @ri, @rs, @rid
INSERT INTO t1 (b, c) VALUES (@ri, @rs)
INSERT INTO t1 (b, c) VALUES (@ri, @rs)
INSERT INTO t1 (b, c) VALUES (@ri, @rs)
INSERT INTO t1 (b, c) VALUES (@ri, @rs)
UPDATE t1 SET c = 'UPDATED' WHERE a = @rid

- And run:
mysqlslap --create-schema=ms -c 50 -i1000000 -q q.sql

This crashes the server within seconds when I run it with the thread-pool enabled. It is yet to crash the server w/o thread-pool.

See the duplicate bug 1318609 for analysis.

Sergei, is this an upstream issue, does it need reporting there?

There is a commit which intended to fix similar issue for debug builds.

        revno: 0.18338.68
        committer: Andrei Elkin <email address hidden>
        branch nick: 5.6-fixes
        timestamp: Wed 2012-11-21 09:45:32 +0200
        message:
          Bug#15867985 STRESS TESTS CAUSES DBUG SERVER TO EXIT WITH SIGNAL 6

          When run with --mysqld=--binlog-order-commits=1 (default) mysqld executes a
          piece of BGC logics that tames a group of threads in a way that they give up
          their commit execution path to a leader thread.
          This preemption appeared to have a specific to DBUG_ON build flaw in that
          the leader and a follower thread could modify a thread-specific area
          concurrently which led to a segfault.

          Fixed with refining the preemption logics to be thread-safe for the DBUG_ON build.

bzr diff -c0.18338.68 sergei/bzr/issue40387/483
=== modified file 'sql/binlog.cc'
--- sql/binlog.cc 2012-11-15 03:35:25 +0000
+++ sql/binlog.cc 2012-11-21 07:45:32 +0000
@@ -1334,6 +1334,16 @@
   if (!leader)
   {
     mysql_mutex_lock(&m_lock_done);
+#ifndef DBUG_OFF
+ /*
+ Leader can be awaiting all-clear to preempt follower's execution.
+ With setting the status the follower ensures it won't execute anything
+ including thread-specific code.
+ */
+ thd->transaction.flags.ready_preempt= 1;
+ if (leader_await_preempt_status)
+ mysql_cond_signal(&m_cond_preempt);
+#endif
     while (thd->transaction.flags.pending)
       mysql_cond_wait(&m_cond_done, &m_lock_done);
     mysql_mutex_unlock(&m_lock_done);
@@ -1361,6 +1371,22 @@
   DBUG_RETURN(result);
 }

+#ifndef DBUG_OFF
+void Stage_manager::clear_preempt_status(THD *head)
+{
+ DBUG_ASSERT(head);
+
+ mysql_mutex_lock(&m_lock_done);
+ while(!head->transaction.flags.ready_preempt)
+ {
+ leader_await_preempt_status= true;
+ mysql_cond_wait(&m_cond_preempt, &m_lock_done);
+ }
+ leader_await_preempt_status= false;
+ mysql_mutex_unlock(&m_lock_done);
+}
+#endif
+
 /**
   Write a rollback record of the transaction to the binary log.

@@ -6009,6 +6035,9 @@
 {
   mysql_mutex_assert_owner(&LOCK_commit);
   Thread_excursion excursion(thd);
+#ifndef DBUG_OFF
+ thd->transaction.flags.ready_preempt= 1; // formality by the leader
+#endif
   for (THD *head= first ; head ; head = head->next_to_commit)
   {
     DBUG_PRINT("debug", ("Thread ID: %lu, commit_error: %d, flags.pending: %s",
@@ -6022,6 +6051,9 @@
       If flush succeeded, attach to the session and commit it in the
       engines.
     */
+#ifndef DBUG_OFF
+ stage_manager.clear_preempt_status(head);
+#endif
     if (flush_error != 0)
       head->commit_error= flush_error;
     else if (int error= excursion.attach_to(head))
@@ -6031,6 +6063,9 @@
       bool all= head->transaction.flags.real_commit;
       if (head->transaction.flags.commit_low)
       {
+ /* head is parked to have exited append() */
+ DBUG_ASSERT(head->transaction.flags.ready_preempt);
+
         if (int error= ha_commit_low(head, all))
           head->commit_error= error;
         else if (head->transac...

I think that queries and threads become ordered such way to trigger the crash easily with threadpool enabled. I think issue is not threadpool-specific, but is much easier to reproduce with threadpool. So far I had no luck reproducing the crash without threadpool. DEBUG_SYNC is also not much of use because group commit messing with THD and PSI of current thread.

As a workaround we can disable PSI instrumentation of follower thread until leader not done with commit. Just set PSI_thread to NULL in following method:

Stage_manager::enroll_for(StageID stage, THD *thd, mysql_mutex_t *stage_mutex)
{
  // If the queue was empty: we're the leader for this batch
  DBUG_PRINT("debug", ("Enqueue 0x%llx to queue for stage %d",
                       (ulonglong) thd, stage));
  bool leader= m_queue[stage].append(thd);

  /*
    The stage mutex can be NULL if we are enrolling for the first
    stage.
  */
  if (stage_mutex)
    mysql_mutex_unlock(stage_mutex);

  /*
    If the queue was not empty, we're a follower and wait for the
    leader to process the queue. If we were holding a mutex, we have
    to release it before going to sleep.
  */
  if (!leader)
  {
    mysql_mutex_lock(&m_lock_done);
#ifndef DBUG_OFF
    /*
      Leader can be awaiting all-clear to preempt follower's execution.
      With setting the status the follower ensures it won't execute anything
      including thread-specific code.
    */
    thd->transaction.flags.ready_preempt= 1;
    if (leader_await_preempt_status)
      mysql_cond_signal(&m_cond_preempt);
#endif
    while (thd->transaction.flags.pending) {
      mysql_cond_wait(&m_cond_done, &m_lock_done);
    }
    mysql_mutex_unlock(&m_lock_done);
  }
  return leader;
}

Reported upstream based on code analysis http://bugs.mysql.com/bug.php?id=72681

Sergei -

Great work on analysis. Would you be able to check whether 5.5 (with a different group commit implementation and less PFS instrumentation) has a corresponding bug too?

PS 5.5 is not affected. Group commit implementation here does not "attach" leader to follower's threads.

Sergei, Laurynas - I see Oracle has made the bug private. Any other way to know if they intend to fix it (besides scanning changelogs) ? Are we submitting our own fix to PS 5.6 or waiting for an upstream fix ?

We will have our own fix for the time being.

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-782