Bug #29008298 MYSQLD CRASHES ITSELF WHEN CREATING INDEX

Problem
-------
A long running ALTER TABLE ADD INDEX with concurrent inserts causes sempahore waits and
eventually crashes the server.

Solution
---------
The indexes on the intermediate tables are built using bulk load insert. A concurrent DML
at this stage does not acquire the index lock. An index lock acquired on the intermediate
table, which is not visible to anyone else, does not block concurrent DMLs.

RB# 22482
Reviewed by: Annamalai Gurusami (annamalai.gurusami@oracle.com)

Author: Rahul Agarkar

mysql-test/r/all_persisted_variables.result

@@ -37,17 +37,17 @@ include/assert.inc [Expect 500+ variables in the table. Due to open Bugs, we are
 
 # Test SET PERSIST
 
-include/assert.inc [Expect 385 persisted variables in the table.]
+include/assert.inc [Expect 386 persisted variables in the table.]
 
 ************************************************************
 * 3. Restart server, it must preserve the persisted variable
 *    settings. Verify persisted configuration.
 ************************************************************
 # restart
 
-include/assert.inc [Expect 385 persisted variables in persisted_variables table.]
-include/assert.inc [Expect 385 persisted variables shown as PERSISTED in variables_info table.]
-include/assert.inc [Expect 385 persisted variables with matching peristed and global values.]
+include/assert.inc [Expect 386 persisted variables in persisted_variables table.]
+include/assert.inc [Expect 386 persisted variables shown as PERSISTED in variables_info table.]
+include/assert.inc [Expect 386 persisted variables with matching peristed and global values.]
 
 ************************************************************
 * 4. Test RESET PERSIST IF EXISTS. Verify persisted variable

mysql-test/suite/sys_vars/r/innodb_semaphore_wait_timeout_debug_basic.result

@@ -0,0 +1,36 @@
+#
+# Basic test for innodb_semaphore_wait_timeout_debug
+#
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+@@global.innodb_semaphore_wait_timeout_debug
+600
+SET GLOBAL innodb_semaphore_wait_timeout_debug = 10;
+Warnings:
+Warning	1292	Truncated incorrect innodb_semaphore_wait_timeout_de value: '10'
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+@@global.innodb_semaphore_wait_timeout_debug
+100
+SET GLOBAL innodb_semaphore_wait_timeout_debug = 200;
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+@@global.innodb_semaphore_wait_timeout_debug
+200
+SET GLOBAL innodb_semaphore_wait_timeout_debug = dummy;
+ERROR 42000: Incorrect argument type to variable 'innodb_semaphore_wait_timeout_debug'
+SET innodb_semaphore_wait_timeout_debug = 100;
+ERROR HY000: Variable 'innodb_semaphore_wait_timeout_debug' is a GLOBAL variable and should be set with SET GLOBAL
+SET GLOBAL innodb_semaphore_wait_timeout_debug = 6000;
+Warnings:
+Warning	1292	Truncated incorrect innodb_semaphore_wait_timeout_de value: '6000'
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+@@global.innodb_semaphore_wait_timeout_debug
+600
+SET GLOBAL innodb_semaphore_wait_timeout_debug = -1;
+Warnings:
+Warning	1292	Truncated incorrect innodb_semaphore_wait_timeout_de value: '-1'
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+@@global.innodb_semaphore_wait_timeout_debug
+100
+SET GLOBAL innodb_semaphore_wait_timeout_debug = default;
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+@@global.innodb_semaphore_wait_timeout_debug
+600

mysql-test/suite/sys_vars/t/innodb_semaphore_wait_timeout_debug_basic.test

@@ -0,0 +1,29 @@
+--echo #
+--echo # Basic test for innodb_semaphore_wait_timeout_debug
+--echo #
+
+# The config variable is a debug variable
+--source include/have_debug.inc
+
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+
+SET GLOBAL innodb_semaphore_wait_timeout_debug = 10;
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+
+SET GLOBAL innodb_semaphore_wait_timeout_debug = 200;
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+
+--error ER_WRONG_TYPE_FOR_VAR
+SET GLOBAL innodb_semaphore_wait_timeout_debug = dummy;
+
+--error ER_GLOBAL_VARIABLE
+SET innodb_semaphore_wait_timeout_debug = 100;
+
+SET GLOBAL innodb_semaphore_wait_timeout_debug = 6000;
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+
+SET GLOBAL innodb_semaphore_wait_timeout_debug = -1;
+SELECT @@global.innodb_semaphore_wait_timeout_debug;
+
+SET GLOBAL innodb_semaphore_wait_timeout_debug = default;
+SELECT @@global.innodb_semaphore_wait_timeout_debug;

mysql-test/t/all_persisted_variables.test

@@ -39,7 +39,7 @@
 call mtr.add_suppression("Failed to set up SSL because of the following SSL library error");
 
 let $total_global_vars=`SELECT COUNT(*) FROM performance_schema.global_variables where variable_name NOT LIKE 'ndb_%'`;
-let $total_persistent_vars=385;
+let $total_persistent_vars=386;
 
 --echo ***************************************************************
 --echo * 0. Verify that variables present in performance_schema.global

storage/innobase/btr/btr0bulk.cc

@@ -56,7 +56,11 @@ dberr_t PageBulk::init() {
 
   mtr = static_cast<mtr_t *>(mem_heap_alloc(m_heap, sizeof(mtr_t)));
   mtr_start(mtr);
-  mtr_x_lock(dict_index_get_lock(m_index), mtr);
+
+  if (!dict_index_is_online_ddl(m_index)) {
+    mtr_x_lock(dict_index_get_lock(m_index), mtr);
+  }
+
   mtr_set_log_mode(mtr, MTR_LOG_NO_REDO);
   mtr_set_flush_observer(mtr, m_flush_observer);
 
@@ -607,7 +611,11 @@ void PageBulk::release() {
 /** Start mtr and latch the block */
 void PageBulk::latch() {
   mtr_start(m_mtr);
-  mtr_x_lock(dict_index_get_lock(m_index), m_mtr);
+
+  if (!dict_index_is_online_ddl(m_index)) {
+    mtr_x_lock(dict_index_get_lock(m_index), m_mtr);
+  }
+
   mtr_set_log_mode(m_mtr, MTR_LOG_NO_REDO);
   mtr_set_flush_observer(m_mtr, m_flush_observer);
 
@@ -631,6 +639,15 @@ void PageBulk::latch() {
   ut_ad(m_cur_rec > m_page && m_cur_rec < m_heap_top);
 }
 
+#ifdef UNIV_DEBUG
+/* Check if an index is locked */
+bool PageBulk::isIndexXLocked() {
+  return (dict_index_is_online_ddl(m_index) &&
+          mtr_memo_contains_flagged(m_mtr, dict_index_get_lock(m_index),
+                                    MTR_MEMO_X_LOCK | MTR_MEMO_SX_LOCK));
+}
+#endif  // UNIV_DEBUG
+
 /** Split a page
 @param[in]	page_bulk	page to split
 @param[in]	next_page_bulk	next page
@@ -697,6 +714,15 @@ dberr_t BtrBulk::pageCommit(PageBulk *page_bulk, PageBulk *next_page_bulk,
     page_bulk->setNext(FIL_NULL);
   }
 
+  /* Assert that no locks are held during bulk load operation
+  in case of a online ddl operation. Insert thread acquires index->lock
+  to check the online status of index. During bulk load index,
+  there are no concurrent insert or reads and hence, there is no
+  need to acquire a lock in that case. */
+  ut_ad(!page_bulk->isIndexXLocked());
+
+  DBUG_EXECUTE_IF("innodb_bulk_load_sleep", os_thread_sleep(1000000););
+
   /* Compress page if it's a compressed table. */
   if (page_bulk->isTableCompressed() && !page_bulk->compress()) {
     return (pageSplit(page_bulk, next_page_bulk));
@@ -742,6 +768,7 @@ BtrBulk::BtrBulk(dict_index_t *index, trx_id_t trx_id, FlushObserver *observer)
   ut_ad(m_flush_observer != nullptr);
 #ifdef UNIV_DEBUG
   fil_space_inc_redo_skipped_count(m_index->space);
+  m_index_online = m_index->online_status;
 #endif /* UNIV_DEBUG */
 }
 
@@ -917,6 +944,7 @@ dberr_t BtrBulk::insert(dtuple_t *tuple, ulint level) {
       return (err);
     }
 
+    DEBUG_SYNC_C("bulk_load_insert");
     m_page_bulks->push_back(new_page_bulk);
     ut_ad(level + 1 == m_page_bulks->size());
     m_root_level = level;
@@ -1016,6 +1044,11 @@ dberr_t BtrBulk::finish(dberr_t err) {
   ut_ad(m_page_bulks);
   ut_ad(!m_index->table->is_temporary());
 
+#ifdef UNIV_DEBUG
+  /* Assert that the index online status has not changed */
+  ut_ad(m_index->online_status == m_index_online);
+#endif  // UNIV_DEBUG
+
   page_no_t last_page_no = FIL_NULL;
 
   if (m_page_bulks->size() == 0) {

storage/innobase/handler/ha_innodb.cc

@@ -21175,6 +21175,13 @@ static MYSQL_SYSVAR_UINT(
     " cache by the specified value dynamically, at the time.",
     NULL, innodb_merge_threshold_set_all_debug_update,
     DICT_INDEX_MERGE_THRESHOLD_DEFAULT, 1, 50, 0);
+
+static MYSQL_SYSVAR_ULONG(
+    semaphore_wait_timeout_debug, srv_fatal_semaphore_wait_threshold,
+    PLUGIN_VAR_RQCMDARG,
+    "Number of seconds that a semaphore can be held. If semaphore wait crosses"
+    "this value, server will crash",
+    NULL, NULL, 600, 100, 600, 0);
 #endif /* UNIV_DEBUG */
 
 static MYSQL_SYSVAR_ULONG(
@@ -22390,6 +22397,7 @@ static SYS_VAR *innobase_system_variables[] = {
     MYSQL_SYSVAR(checkpoint_disabled),
     MYSQL_SYSVAR(buf_flush_list_now),
     MYSQL_SYSVAR(merge_threshold_set_all_debug),
+    MYSQL_SYSVAR(semaphore_wait_timeout_debug),
 #endif /* UNIV_DEBUG */
 #if defined UNIV_DEBUG || defined UNIV_PERF_DEBUG
     MYSQL_SYSVAR(page_hash_locks),

storage/innobase/include/btr0bulk.h

@@ -1,6 +1,6 @@
 /*****************************************************************************
 
-Copyright (c) 2014, 2018, Oracle and/or its affiliates. All Rights Reserved.
+Copyright (c) 2014, 2019, 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, version 2.0, as published by the
@@ -192,6 +192,11 @@ class PageBulk {
   @return true if table is compressed, false otherwise. */
   bool isTableCompressed() const { return (m_page_zip != nullptr); }
 
+#ifdef UNIV_DEBUG
+  /** Check if index is X locked */
+  bool isIndexXLocked();
+#endif  // UNIV_DEBUG
+
  private:
   /** Get page split point. We split a page in half when compression
   fails, and the split record and all following records should be copied
@@ -408,6 +413,13 @@ class BtrBulk {
 
   /** Page cursor vector for all level */
   page_bulk_vector *m_page_bulks;
+
+#ifdef UNIV_DEBUG
+  /** State of the index. Used for asserting at the end of a
+  bulk load operation to ensure that the online status of the
+  index does not change */
+  unsigned m_index_online;
+#endif  // UNIV_DEBUG
 };
 
 #endif

storage/innobase/include/srv0srv.h

@@ -672,7 +672,7 @@ extern bool srv_purge_view_update_only_debug;
 extern bool srv_master_thread_disabled_debug;
 #endif /* UNIV_DEBUG */
 
-extern ulint srv_fatal_semaphore_wait_threshold;
+extern ulong srv_fatal_semaphore_wait_threshold;
 #define SRV_SEMAPHORE_WAIT_EXTENSION 7200
 extern ulint srv_dml_needed_delay;
 

storage/innobase/lob/lob0lob.cc

@@ -425,7 +425,7 @@ dberr_t btr_store_big_rec_extern_fields(trx_t *trx, btr_pcur_t *pcur,
   ut_ad(btr_mtr);
   ut_ad(mtr_memo_contains_flagged(btr_mtr, dict_index_get_lock(index),
                                   MTR_MEMO_X_LOCK | MTR_MEMO_SX_LOCK) ||
-        index->table->is_intrinsic());
+        index->table->is_intrinsic() || !index->is_committed());
   ut_ad(
       mtr_is_block_fix(btr_mtr, rec_block, MTR_MEMO_PAGE_X_FIX, index->table));
   ut_ad(buf_block_get_frame(rec_block) == page_align(rec));

storage/innobase/srv/srv0srv.cc

@@ -108,7 +108,7 @@ bool srv_upgrade_old_undo_found = false;
 #endif /* INNODB_DD_TABLE */
 
 /* The following is the maximum allowed duration of a lock wait. */
-ulint srv_fatal_semaphore_wait_threshold = 600;
+ulong srv_fatal_semaphore_wait_threshold = 600;
 
 /* How much data manipulation language (DML) statements need to be delayed,
 in microseconds, in order to reduce the lagging of the purge thread. */