Merge lp:~laurynas-biveinis/percona-server/multiple-xa-ses-5.6 into lp:percona-server/5.6

[Laurynas Biveinis]

Fixes for bug 1255549 and bug 1255551, making it possible to have 2 XA storage engines installed and running.

jenkins.percona.com/job/percona-server-5.6-param/423/

Fix bug 1255549 (Crash on startup when XA support functions activated
by a second engine) / http://bugs.mysql.com/bug.php?id=47134.

The fix is a combination of:

- disabling of code in ha_recover() that asserts if more than one XA
  SE is installed;

- MariaDB revisions 2502.102.122, 2502.102.167 (minus PBXT testcase),
  2502.565.20, 2502.102.215 (minus PBXT testcase and a bit that was
  later reverted as MDEV-3850) in lp:maria/5.5. They address:

  - TC_LOG_MMAP::open() performed incorrect pointer arithmetics to set
    the end pointer for each page by adding tc_log_page_size
    (byte-sized) number of XIDs (ulonglong-sized).
  - TC_LOG_MMAP::PAGE::ptr field was never initialized.
  - TC_LOG_MMAP::pool reads and writes in
    TC_LOG_MMAP::get_active_from_pool() failed to be protected by
    TC_LOG_MMAP::LOCK_pool if !syncing.
  - If TC_LOG_MMAP::get_active_from_pool() sees that the first page in
    the pool has no waiters, it returns it as an active page, and
    fails to check whether there is any free space on it.
  - active->free and active->size were accessed without active->lock
    protection in TC_LOG_MMAP::get_active_from_pool().
  - tc_log_cur_pages_used was not protected from race conditions in
    bumping it.
  - The TC_LOG_MMAP::log_xid() return value check was inverted in
    TC_LOG_MMAP::commit().
  - active == NULL in TC_LOG_MMAP::log_xid() would result in the new
    active page lock locked twice.
  - LOCK_active was released too early in TC_LOG_MMAP::log_xid(),
    resulting in TC_LOG_MMAP::active access race conditions.
  - There was a lock order violation between LOCK_sync and page locks
    in TC_LOG_MMAP::log_xid().
  - LOCK_active was held needlessly, and page field accesses were not
    protected by a page lock in TC_LOG_MMAP::log_xid() if
    TC_LOG_MMAP::syncing != NULL.
  - TC_LOG_MMAP::sync() requested to sync only 1 byte from the page
    being synced.
  - TC_LOG_MMAP::sync() broadcasted syncing->cond too early.
  - TC_LOG_MMAP::sync() could dereference NULL active.
  - TC_LOG_MMAP::unlog() performed page writes without the page lock
    locked.
  - Do not assert but return error in the case the opened log was
    shorter than three pages long in TC_LOG_MMAP::open().
  - If TC_LOG_MMAP::get_active_from_pool() chooses the last pool page
    to be made active, it was not unlinked from the pool.

- backport of the tc_log_mmap unit test from MySQL 5.7.2 with a
  supporting TC_LOG_MMAP::size() method.

Fix bug 1255551 (Tc_log_page_size should be unflushable or server
crashes if 2 XA SEs installed) / upstream
http://bugs.mysql.com/bug.php?id=70854.

The issue is FLUSH STATUS resetting tc_log_page_size to zero and a
later TC_LOG_MMAP::unlog() attempt to divide by it.

Fixed by making it unflushable.

[George Ormond Lorch III (gl-az)]

review: Approve (g2)

[Stewart Smith (stewart)]

A few small notes:
- We should bring in the (C) headers from MariaDB for files where the code came from MariaDB.
- I'd love it if we had the test case from http://bugs.mysql.com/bug.php?id=70854 (modifying EXAMPLE engine... or copy&pasting it and having an engine for such test cases)

otherwise i think it's okay

review: Needs Fixing

[Laurynas Biveinis (laurynas-biveinis)]

> A few small notes:
> - We should bring in the (C) headers from MariaDB for files where the code
> came from MariaDB.

Ack

> - I'd love it if we had the test case from
> http://bugs.mysql.com/bug.php?id=70854 (modifying EXAMPLE engine... or
> copy&pasting it and having an engine for such test cases)

I considered making EXAMPLE a XA engine but in the end decided not to. Neither MySQL nor MariaDB has done it despite the change being simple and, at least in MySQL, the developer who fixed #47134 did this change in order to perform manual testing but mentions in the commit that "I think it won't be correct to modify EXAMPLE".

Maybe it's because making EXAMPLE a XA engine forces TC_LOG_MMAP overhead if binlog is disabled even if the engine is unused. Now TC_LOG_DUMMY is used in that case.

Maybe adding some CMake glue so that EXAMPLE can be compiled into two engines, EXAMPLE and EXAMPLE_XA, from the same sources would be a better option? But IMHO this falls outside the scope of this MP and is more of a Wishlist thing.

What do you think?

=== modified file 'Percona-Server/sql/handler.cc'
--- Percona-Server/sql/handler.cc	2013-12-16 12:54:12 +0000
+++ Percona-Server/sql/handler.cc	2013-12-18 04:49:35 +0000
@@ -1920,7 +1920,7 @@
   if (info.commit_list)
     sql_print_information("Starting crash recovery...");
 
-#ifndef WILL_BE_DELETED_LATER
+#if 0
   /*
     for now, only InnoDB supports 2pc. It means we can always safely
     rollback all pending transactions, without risking inconsistent data

=== modified file 'Percona-Server/sql/log.cc'
--- Percona-Server/sql/log.cc	2013-12-16 08:45:31 +0000
+++ Percona-Server/sql/log.cc	2013-12-18 04:49:35 +0000
@@ -1,4 +1,5 @@
 /* Copyright (c) 2000, 2013 Oracle and/or its affiliates. All rights reserved.
+   Copyright (c) 2009, 2013, Monty Program Ab
    Copyright (C) 2012 Percona Inc.
 
    This program is free software; you can redistribute it and/or modify
@@ -2639,7 +2640,8 @@
   inited=2;
 
   npages=(uint)file_length/tc_log_page_size;
-  DBUG_ASSERT(npages >= 3);             // to guarantee non-empty pool
+  if (npages < 3)             // to guarantee non-empty pool
+    goto err;
   if (!(pages=(PAGE *)my_malloc(npages*sizeof(PAGE), MYF(MY_WME|MY_ZEROFILL))))
     goto err;
   inited=3;
@@ -2650,9 +2652,10 @@
     pg->state=PS_POOL;
     mysql_mutex_init(key_PAGE_lock, &pg->lock, MY_MUTEX_INIT_FAST);
     mysql_cond_init(key_PAGE_cond, &pg->cond, 0);
-    pg->start=(my_xid *)(data + i*tc_log_page_size);
-    pg->end=(my_xid *)(pg->start + tc_log_page_size);
+    pg->ptr= pg->start=(my_xid *)(data + i*tc_log_page_size);
     pg->size=pg->free=tc_log_page_size/sizeof(my_xid);
+    pg->end=pg->start + pg->size;
+
   }
   pages[0].size=pages[0].free=
                 (tc_log_page_size-TC_LOG_HEADER_SIZE)/sizeof(my_xid);
@@ -2678,8 +2681,9 @@
 
   syncing= 0;
   active=pages;
+  DBUG_ASSERT(npages >= 2);
   pool=pages+1;
-  pool_last=pages+npages-1;
+  pool_last_ptr= &((pages+npages-1)->next);
 
   return 0;
 
@@ -2688,6 +2692,17 @@
   return 1;
 }
 
+
+/**
+   Get the total amount of potentially usable slots for XIDs in TC log.
+*/
+
+uint TC_LOG_MMAP::size() const
+{
+  return (tc_log_page_size-TC_LOG_HEADER_SIZE)/sizeof(my_xid) +
+         (npages - 1) * (tc_log_page_size/sizeof(my_xid));
+}
+
 /**
   there is no active page, let's got one from the pool.
 
@@ -2705,13 +2720,12 @@
   PAGE **p, **best_p=0;
   int best_free;
 
-  if (syncing)
-    mysql_mutex_lock(&LOCK_pool);
+  mysql_mutex_lock(&LOCK_pool);
 
   do
   {
     best_p= p= &pool;
-    if ((*p)->waiters == 0) // can the first page be used ?
+    if ((*p)->waiters == 0 && (*p)->free > 0) // can the first page be used ?
       break;                // yes - take it.
 
     best_free=0;            // no - trying second strategy
@@ -2726,20 +2740,21 @@
   }
   while ((*best_p == 0 || best_free == 0) && overflow());
 
+  mysql_mutex_assert_owner(&LOCK_active);
   active=*best_p;
+
+  /* Unlink the page from the pool. */
+  if (!(*best_p)->next)
+    pool_last_ptr= best_p;
+  *best_p=(*best_p)->next;
+  mysql_mutex_unlock(&LOCK_pool);
+
+  mysql_mutex_lock(&active->lock);
   if (active->free == active->size) // we've chosen an empty page
   {
-    tc_log_cur_pages_used++;
+    thread_safe_increment(tc_log_cur_pages_used, &LOCK_status);
     set_if_bigger(tc_log_max_pages_used, tc_log_cur_pages_used);
   }
-
-  if ((*best_p)->next)              // unlink the page from the pool
-    *best_p=(*best_p)->next;
-  else
-    pool_last=*best_p;
-
-  if (syncing)
-    mysql_mutex_unlock(&LOCK_pool);
 }
 
 /**
@@ -2772,7 +2787,7 @@
   my_xid xid= thd->transaction.xid_state.xid.get_my_xid();
 
   if (all && xid)
-    if ((cookie= log_xid(thd, xid)))
+    if (!(cookie= log_xid(thd, xid)))
       DBUG_RETURN(RESULT_ABORTED);    // Failed to log the transaction
 
   if (ha_commit_low(thd, all))
@@ -2834,9 +2849,17 @@
   /* no active page ? take one from the pool */
   if (active == 0)
     get_active_from_pool();
+  else
+    mysql_mutex_lock(&active->lock);
 
   p=active;
-  mysql_mutex_lock(&p->lock);
+
+  /*
+    p->free is always > 0 here because to decrease it one needs
+    to take p->lock and before it one needs to take LOCK_active.
+    But checked that active->free > 0 under LOCK_active and
+    haven't release it ever since
+  */
 
   /* searching for an empty slot */
   while (*p->ptr)
@@ -2851,37 +2874,49 @@
   p->free--;
   p->state= PS_DIRTY;
 
-  /* to sync or not to sync - this is the question */
-  mysql_mutex_unlock(&LOCK_active);
+  mysql_mutex_unlock(&p->lock);
+
   mysql_mutex_lock(&LOCK_sync);
-  mysql_mutex_unlock(&p->lock);
-
   if (syncing)
   {                                          // somebody's syncing. let's wait
+    mysql_mutex_unlock(&LOCK_active);
+    mysql_mutex_lock(&p->lock);
     p->waiters++;
     /*
       note - it must be while (), not do ... while () here
       as p->state may be not PS_DIRTY when we come here
     */
     while (p->state == PS_DIRTY && syncing)
+    {
+      mysql_mutex_unlock(&p->lock);
       mysql_cond_wait(&p->cond, &LOCK_sync);
+      mysql_mutex_lock(&p->lock);
+    }
     p->waiters--;
     err= p->state == PS_ERROR;
     if (p->state != PS_DIRTY)                   // page was synced
     {
+      mysql_mutex_unlock(&LOCK_sync);
       if (p->waiters == 0)
         mysql_cond_signal(&COND_pool);       // in case somebody's waiting
-      mysql_mutex_unlock(&LOCK_sync);
+      mysql_mutex_unlock(&p->lock);
       goto done;                             // we're done
     }
-  }                                          // page was not synced! do it now
-  DBUG_ASSERT(active == p && syncing == 0);
-  mysql_mutex_lock(&LOCK_active);
-  syncing=p;                                 // place is vacant - take it
+    DBUG_ASSERT(!syncing);
+    mysql_mutex_unlock(&p->lock);
+    syncing = p;
+    mysql_mutex_unlock(&LOCK_sync);
+
+    mysql_mutex_lock(&LOCK_active);
+  }
+  else
+  {
+    syncing=p;                               // place is vacant - take it
+    mysql_mutex_unlock(&LOCK_sync);
+  }
   active=0;                                  // page is not active anymore
   mysql_cond_broadcast(&COND_active);        // in case somebody's waiting
   mysql_mutex_unlock(&LOCK_active);
-  mysql_mutex_unlock(&LOCK_sync);
   err= sync();
 
 done:
@@ -2898,22 +2933,31 @@
     sit down and relax - this can take a while...
     note - no locks are held at this point
   */
-  err= my_msync(fd, syncing->start, 1, MS_SYNC);
+  err= my_msync(fd, syncing->start, syncing->size * sizeof(my_xid), MS_SYNC);
 
   /* page is synced. let's move it to the pool */
   mysql_mutex_lock(&LOCK_pool);
-  pool_last->next=syncing;
-  pool_last=syncing;
+  (*pool_last_ptr)= syncing;
+  pool_last_ptr= &(syncing->next);
   syncing->next=0;
   syncing->state= err ? PS_ERROR : PS_POOL;
-  mysql_cond_broadcast(&syncing->cond);      // signal "sync done"
   mysql_cond_signal(&COND_pool);             // in case somebody's waiting
   mysql_mutex_unlock(&LOCK_pool);
 
   /* marking 'syncing' slot free */
   mysql_mutex_lock(&LOCK_sync);
+  mysql_cond_broadcast(&syncing->cond);      // signal "sync done"
   syncing=0;
-  mysql_cond_signal(&active->cond);        // wake up a new syncer
+  /*
+    we check the "active" pointer without LOCK_active. Still, it's safe -
+    "active" can change from NULL to not NULL any time, but it
+    will take LOCK_sync before waiting on active->cond. That is, it can never
+    miss a signal.
+    And "active" can change to NULL only by the syncing thread
+    (the thread that will send a signal below)
+  */
+  if (active)
+      mysql_cond_signal(&active->cond);        // wake up a new syncer
   mysql_mutex_unlock(&LOCK_sync);
   return err;
 }
@@ -2930,9 +2974,9 @@
 
   DBUG_ASSERT(*x == xid);
   DBUG_ASSERT(x >= p->start && x < p->end);
+
+  mysql_mutex_lock(&p->lock);
   *x=0;
-
-  mysql_mutex_lock(&p->lock);
   p->free++;
   DBUG_ASSERT(p->free <= p->size);
   set_if_smaller(p->ptr, x);

=== modified file 'Percona-Server/sql/log.h'
--- Percona-Server/sql/log.h	2013-06-20 15:16:00 +0000
+++ Percona-Server/sql/log.h	2013-12-18 04:49:35 +0000
@@ -149,7 +149,7 @@
   my_off_t file_length;
   uint npages, inited;
   uchar *data;
-  struct st_page *pages, *syncing, *active, *pool, *pool_last;
+  struct st_page *pages, *syncing, *active, *pool, **pool_last_ptr;
   /*
     note that, e.g. LOCK_active is only used to protect
     'active' pointer, to protect the content of the active page
@@ -167,6 +167,7 @@
   int rollback(THD *thd, bool all)      { return ha_rollback_low(thd, all); }
   int prepare(THD *thd, bool all)       { return ha_prepare_low(thd, all); }
   int recover();
+  uint size() const;
 
 private:
   int log_xid(THD *thd, my_xid xid);
@@ -174,6 +175,8 @@
   void get_active_from_pool();
   int sync();
   int overflow();
+
+  friend class TCLogMMapTest;
 };
 #else
 #define TC_LOG_MMAP TC_LOG_DUMMY

=== modified file 'Percona-Server/sql/mysqld.cc'
--- Percona-Server/sql/mysqld.cc	2013-12-16 08:45:31 +0000
+++ Percona-Server/sql/mysqld.cc	2013-12-18 04:49:35 +0000
@@ -8217,7 +8217,7 @@
   {"Table_open_cache_overflows",(char*) offsetof(STATUS_VAR, table_open_cache_overflows), SHOW_LONGLONG_STATUS},
 #ifdef HAVE_MMAP
   {"Tc_log_max_pages_used",    (char*) &tc_log_max_pages_used,  SHOW_LONG},
-  {"Tc_log_page_size",         (char*) &tc_log_page_size,       SHOW_LONG},
+  {"Tc_log_page_size",         (char*) &tc_log_page_size,       SHOW_LONG_NOFLUSH},
   {"Tc_log_page_waits",        (char*) &tc_log_page_waits,      SHOW_LONG},
 #endif
 #ifdef HAVE_POOL_OF_THREADS

=== modified file 'Percona-Server/unittest/gunit/CMakeLists.txt'
--- Percona-Server/unittest/gunit/CMakeLists.txt	2013-12-05 17:23:10 +0000
+++ Percona-Server/unittest/gunit/CMakeLists.txt	2013-12-18 04:49:35 +0000
@@ -270,6 +270,7 @@
   segfault
   sql_table
   table_cache
+  tc_log_mmap
 )
 
 ## Merging tests into fewer executables saves *a lot* of

=== added file 'Percona-Server/unittest/gunit/tc_log_mmap-t.cc'
--- Percona-Server/unittest/gunit/tc_log_mmap-t.cc	1970-01-01 00:00:00 +0000
+++ Percona-Server/unittest/gunit/tc_log_mmap-t.cc	2013-12-18 04:49:35 +0000
@@ -0,0 +1,201 @@
+/* Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved.
+
+   This program is free software; you can redistribute it and/or modify
+   it under the terms of the GNU General Public License as published by
+   the Free Software Foundation; version 2 of the License.
+
+   This program is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY; without even the implied warranty of
+   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+   GNU General Public License for more details.
+
+   You should have received a copy of the GNU General Public License
+   along with this program; if not, write to the Free Software
+   Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA */
+
+#include "my_config.h"
+#include <gtest/gtest.h>
+#include "log.h"
+#include "sql_class.h"
+#include "test_utils.h"
+#include "thread_utils.h"
+
+using my_testing::Server_initializer;
+
+/*
+  Override msync/fsync, saves a *lot* of time during unit testing.
+ */
+class TC_LOG_MMAP_no_msync : public TC_LOG_MMAP
+{
+protected:
+  virtual int do_msync_and_fsync(int fd, void *addr, size_t len, int flags)
+  {
+    return 0;
+  }
+};
+
+/*
+  This class is a friend of TC_LOG_MMAP, so it needs to be outside the unittest
+  namespace.
+*/
+class TCLogMMapTest : public ::testing::Test
+{
+public:
+  virtual void SetUp()
+  {
+    initializer.SetUp();
+    total_ha_2pc= 2;
+    tc_heuristic_recover= 0;
+    EXPECT_EQ(0, tc_log_mmap.open("tc_log_mmap_test"));
+  }
+
+  virtual void TearDown()
+  {
+    tc_log_mmap.close();
+    initializer.TearDown();
+  }
+
+  THD *thd()
+  {
+    return initializer.thd();
+  }
+
+  void testCommit(ulonglong xid)
+  {
+    thd()->transaction.xid_state.xid.set(xid);
+    EXPECT_EQ(TC_LOG_MMAP::RESULT_SUCCESS, tc_log_mmap.commit(thd(), true));
+    thd()->transaction.cleanup();
+  }
+
+  ulong testLog(ulonglong xid)
+  {
+    return tc_log_mmap.log_xid(thd(), xid);
+  }
+
+  void testUnlog(ulong cookie, ulonglong xid)
+  {
+    tc_log_mmap.unlog(cookie, xid);
+  }
+
+protected:
+  TC_LOG_MMAP_no_msync tc_log_mmap;
+  Server_initializer initializer;
+};
+
+namespace tc_log_mmap_unittest {
+
+TEST_F(TCLogMMapTest, TClogCommit)
+{
+  // test calling of log/unlog for xid=1
+  testCommit(1);
+}
+
+class TC_Log_MMap_thread : public thread::Thread
+{
+public:
+  TC_Log_MMap_thread()
+  : m_start_xid(0), m_end_xid(0),
+    m_tc_log_mmap(NULL)
+  {
+  }
+
+  void init (ulonglong start_value, ulonglong end_value,
+             TCLogMMapTest* tc_log_mmap)
+  {
+    m_start_xid= start_value;
+    m_end_xid= end_value;
+    m_tc_log_mmap= tc_log_mmap;
+  }
+
+  virtual void run()
+  {
+    ulonglong xid= m_start_xid;
+    while (xid < m_end_xid)
+    {
+      m_tc_log_mmap->testCommit(xid++);
+    }
+  }
+
+protected:
+  ulonglong m_start_xid, m_end_xid;
+  TCLogMMapTest* m_tc_log_mmap;
+};
+
+TEST_F(TCLogMMapTest, ConcurrentAccess)
+{
+  static const unsigned MAX_WORKER_THREADS= 10;
+  static const unsigned VALUE_INTERVAL= 100;
+
+  TC_Log_MMap_thread tclog_threads[MAX_WORKER_THREADS];
+
+  ulonglong start_value= 0;
+  for (unsigned i=0; i < MAX_WORKER_THREADS; ++i)
+  {
+    tclog_threads[i].init(start_value, start_value + VALUE_INTERVAL, this);
+    tclog_threads[i].start();
+    start_value+= VALUE_INTERVAL;
+  }
+
+  for (unsigned i=0; i < MAX_WORKER_THREADS; ++i)
+    tclog_threads[i].join();
+}
+
+
+TEST_F(TCLogMMapTest, FillAllPagesAndReuse)
+{
+  /* Get maximum number of XIDs which can be stored in TC log. */
+  const uint MAX_XIDS= tc_log_mmap.size();
+  ulong cookie;
+  /* Fill TC log. */
+  for(my_xid xid= 1; xid < MAX_XIDS; ++xid)
+    (void)testLog(xid);
+  cookie= testLog(MAX_XIDS);
+  /*
+    Now free one slot and try to reuse it.
+    This should work and not crash on assert.
+  */
+  testUnlog(cookie, MAX_XIDS);
+  testLog(MAX_XIDS + 1);
+}
+
+
+TEST_F(TCLogMMapTest, ConcurrentOverflow)
+{
+  const uint WORKER_THREADS= 10;
+  const uint XIDS_TO_REUSE= 100;
+  /* Get maximum number of XIDs which can be stored in TC log. */
+  const uint MAX_XIDS= tc_log_mmap.size();
+  ulong cookies[XIDS_TO_REUSE];
+
+  /* Fill TC log. Remember cookies for last XIDS_TO_REUSE xids. */
+  for(my_xid xid= 1; xid <= MAX_XIDS - XIDS_TO_REUSE; ++xid)
+    testLog(xid);
+  for (uint i= 0; i < XIDS_TO_REUSE; ++i)
+    cookies[i]= testLog(MAX_XIDS - XIDS_TO_REUSE + 1 + i);
+
+  /*
+    Now create several threads which will try to do commit.
+    Since log is full they will have to wait until we free some slots.
+  */
+  TC_Log_MMap_thread threads[WORKER_THREADS];
+  for (uint i= 0; i < WORKER_THREADS; ++i)
+  {
+    threads[i].init(MAX_XIDS + i * (XIDS_TO_REUSE/WORKER_THREADS),
+                    MAX_XIDS + (i + 1) * (XIDS_TO_REUSE/WORKER_THREADS), this);
+    threads[i].start();
+  }
+
+  /*
+    Once started all threads should block since we are out of free slots
+    in the log, Resume threads by freeing necessary slots. Resumed thread
+    should not hang or assert.
+  */
+  for (uint i= 0; i < XIDS_TO_REUSE; ++i)
+    testUnlog(cookies[i], MAX_XIDS - XIDS_TO_REUSE + 1 + i);
+
+  /* Wait till all threads are done. */
+  for (uint i=0; i < WORKER_THREADS; ++i)
+    threads[i].join();
+}
+
+}