From 7bf391c2059f452eafb424336faa30d402f92b67 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Lindstr=C3=B6m?= Date: Mon, 17 Nov 2014 09:55:55 +0200 Subject: [PATCH] MDEV-7108: Make long semaphore wait timeout configurable Merge Facebook commit https://github.com/facebook/mysql-5.6/commit/cd063ab930f05efdba39d504543998512d1bd71f authored by Peng Tian from https://github.com/facebook/mysql-5.6 Introduced a new configuration variable innodb_fatal_semaphore_wait_threshold, it makes the fatal semaphore timeout configurable. Modified original commit so that no MariaDB server files are changed, instead introduced a new InnoDB/XtraDB configuration variable. Its default/min/max vlaues are 600/1/2^32-1 in seconds (it was hardcoded as 600, now its default value is 600, so the default behavior of this diff should be no change). --- ...nodb_fatal_semaphore_wait_threshold.result | 25 ++++ ...atal_semaphore_wait_threshold_basic.result | 21 +++ .../suite/sys_vars/r/sysvars_innodb.result | 14 ++ ..._fatal_semaphore_wait_threshold-master.opt | 1 + ...innodb_fatal_semaphore_wait_threshold.test | 120 ++++++++++++++++++ ..._fatal_semaphore_wait_threshold_basic.test | 21 +++ storage/innobase/handler/ha_innodb.cc | 15 ++- storage/innobase/include/srv0srv.h | 6 +- storage/innobase/lock/lock0lock.cc | 3 + storage/innobase/srv/srv0srv.cc | 2 +- storage/xtradb/handler/ha_innodb.cc | 15 ++- storage/xtradb/include/srv0srv.h | 6 +- storage/xtradb/lock/lock0lock.cc | 3 + storage/xtradb/srv/srv0srv.cc | 2 +- 14 files changed, 246 insertions(+), 8 deletions(-) create mode 100644 mysql-test/suite/sys_vars/r/innodb_fatal_semaphore_wait_threshold.result create mode 100644 mysql-test/suite/sys_vars/r/innodb_fatal_semaphore_wait_threshold_basic.result create mode 100644 mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold-master.opt create mode 100644 mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold.test create mode 100644 mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold_basic.test diff --git a/mysql-test/suite/sys_vars/r/innodb_fatal_semaphore_wait_threshold.result b/mysql-test/suite/sys_vars/r/innodb_fatal_semaphore_wait_threshold.result new file mode 100644 index 00000000000..40ab0f458fa --- /dev/null +++ b/mysql-test/suite/sys_vars/r/innodb_fatal_semaphore_wait_threshold.result @@ -0,0 +1,25 @@ +# Establish connection con1 (user=root) +# Establish connection con2 (user=root) +drop table if exists t1; +# Switch to connection con1 +create table t1 (id integer, x integer) engine = InnoDB; +insert into t1 values(0, 0); +set @@debug_dbug="d,fatal-semaphore-timeout"; +set autocommit=0; +# Sending query on con1, +# the session will hold lock table mutex and sleep +SELECT * from t1 where id = 0 FOR UPDATE; +# Switch to connection con2 +set autocommit=0; +# Sending query on con2, +# the session will be blocked on the lock table mutex and +# thus be put into sync arry +SELECT * from t1 where id = 0 FOR UPDATE; +# Switched to the default connection +# Waitting for mysqld to crash +# Mysqld crash was detected +# Waitting for reconnect after mysqld restarts +# Reconnected after mysqld was successfully restarted +# Cleaning up before exit +drop table if exists t1; +# Clean exit diff --git a/mysql-test/suite/sys_vars/r/innodb_fatal_semaphore_wait_threshold_basic.result b/mysql-test/suite/sys_vars/r/innodb_fatal_semaphore_wait_threshold_basic.result new file mode 100644 index 00000000000..4e1f4721530 --- /dev/null +++ b/mysql-test/suite/sys_vars/r/innodb_fatal_semaphore_wait_threshold_basic.result @@ -0,0 +1,21 @@ +select @@global.innodb_fatal_semaphore_wait_threshold; +@@global.innodb_fatal_semaphore_wait_threshold +600 +select @@session.innodb_fatal_semaphore_wait_threshold; +ERROR HY000: Variable 'innodb_fatal_semaphore_wait_threshold' is a GLOBAL variable +show global variables like 'innodb_fatal_semaphore_wait_threshold'; +Variable_name Value +innodb_fatal_semaphore_wait_threshold 600 +show session variables like 'innodb_fatal_semaphore_wait_threshold'; +Variable_name Value +innodb_fatal_semaphore_wait_threshold 600 +select * from information_schema.global_variables where variable_name='innodb_fatal_semaphore_wait_threshold'; +VARIABLE_NAME VARIABLE_VALUE +INNODB_FATAL_SEMAPHORE_WAIT_THRESHOLD 600 +select * from information_schema.session_variables where variable_name='innodb_fatal_semaphore_wait_threshold'; +VARIABLE_NAME VARIABLE_VALUE +INNODB_FATAL_SEMAPHORE_WAIT_THRESHOLD 600 +set global innodb_fatal_semaphore_wait_threshold=1; +ERROR HY000: Variable 'innodb_fatal_semaphore_wait_threshold' is a read only variable +set session innodb_fatal_semaphore_wait_threshold=1; +ERROR HY000: Variable 'innodb_fatal_semaphore_wait_threshold' is a read only variable diff --git a/mysql-test/suite/sys_vars/r/sysvars_innodb.result b/mysql-test/suite/sys_vars/r/sysvars_innodb.result index 6de55595e2d..214ec950675 100644 --- a/mysql-test/suite/sys_vars/r/sysvars_innodb.result +++ b/mysql-test/suite/sys_vars/r/sysvars_innodb.result @@ -663,6 +663,20 @@ NUMERIC_BLOCK_SIZE 0 ENUM_VALUE_LIST NULL READ_ONLY NO COMMAND_LINE_ARGUMENT OPTIONAL +VARIABLE_NAME INNODB_FATAL_SEMAPHORE_WAIT_THRESHOLD +SESSION_VALUE NULL +GLOBAL_VALUE 600 +GLOBAL_VALUE_ORIGIN COMPILE-TIME +DEFAULT_VALUE 600 +VARIABLE_SCOPE GLOBAL +VARIABLE_TYPE BIGINT UNSIGNED +VARIABLE_COMMENT Maximum number of seconds that semaphore times out in InnoDB. +NUMERIC_MIN_VALUE 1 +NUMERIC_MAX_VALUE 4294967295 +NUMERIC_BLOCK_SIZE 0 +ENUM_VALUE_LIST NULL +READ_ONLY YES +COMMAND_LINE_ARGUMENT REQUIRED VARIABLE_NAME INNODB_FILE_FORMAT SESSION_VALUE NULL GLOBAL_VALUE Antelope diff --git a/mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold-master.opt b/mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold-master.opt new file mode 100644 index 00000000000..51d18e632be --- /dev/null +++ b/mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold-master.opt @@ -0,0 +1 @@ +--innodb-fatal-semaphore-wait-threshold=1 diff --git a/mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold.test b/mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold.test new file mode 100644 index 00000000000..866c652321f --- /dev/null +++ b/mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold.test @@ -0,0 +1,120 @@ +# Only test in debug mode since DBUG_EXECUTE_IF is used +--source include/have_debug.inc + +# Can't test this with embedded server +--source include/not_embedded.inc + +# Don't test this with valgrind +--source include/not_valgrind.inc + +# Only test for innodb +--source include/have_innodb.inc + +--echo # Establish connection con1 (user=root) +connect (con1,localhost,root,,); +--echo # Establish connection con2 (user=root) +connect (con2,localhost,root,,); + +--disable_warnings +drop table if exists t1; +--enable_warnings + +--echo # Switch to connection con1 +connection con1; +eval create table t1 (id integer, x integer) engine = InnoDB; +insert into t1 values(0, 0); + +# Enable the debug injection. +set @@debug_dbug="d,fatal-semaphore-timeout"; +set autocommit=0; + +# The following query will hang for an hour since the debug injection +# code will sleep an hour after holding the lock table mutex +--echo # Sending query on con1, +--echo # the session will hold lock table mutex and sleep +--send +SELECT * from t1 where id = 0 FOR UPDATE; + +# To make sure con1 holding the lock table mutex and sleeping +--sleep 2 + +--echo # Switch to connection con2 +connection con2; +set autocommit=0; + +# The following query will be blocked on the lock table mutex held by +# con1 so it will be put into sync array. +--echo # Sending query on con2, +--echo # the session will be blocked on the lock table mutex and +--echo # thus be put into sync arry +--send +SELECT * from t1 where id = 0 FOR UPDATE; + +# Waitting for mysqld to abort due to fatal semaphore timeout. +# Please note that, in the master.opt file, the fatal timeout +# was set to 1 second, but in mysqld debug mode, this timeout +# value will be timed 10 because UNIV_DEBUG_VALGRIND is set +# (see sync_array_print_long_waits_low() in storage/innobase/sync/sync0arr.cc) +# so the actual timeout will be 1 * 10 = 10 seconds. Besides, +# mysqld will abort after detecting this fatal timeout 10 times in +# a loop with interval of 1 second (see srv_error_monitor_thread +# thread in torage/innobase/srv/srv0srv.cc), so mysqld will abort +# in 1 * 10 + 1 * 10 = 20 seconds after con2 being blocked on +# the lock table mutex. +# +# P.S. the default fatal sempahore timeout is 600 seconds, +# so mysqld will abort after 600 * 10 + 1 * 10 = 6010 seconds +# in debug mode and 600 + 1 * 10 = 610 seconds in release mode. + +--echo # Switched to the default connection +connection default; + +--disable_result_log +--disable_query_log + +# Since this test generates lot of errors in log, suppress checking errors +call mtr.add_suppression(".*"); + +# The crash is expected +exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect; + +--echo # Waitting for mysqld to crash + +# It will take 20 seconds to detect the long semaphore and mysqld to abort. +# This test will be treated as pass as long as mysqld crash/restart is dectected +# in 60 seconds. +let $counter= 60; +let $mysql_errno= 0; +while (!$mysql_errno) +{ + --error 0,1040,1053,2002,2003,2006,2013 + show status; + + dec $counter; + if (!$counter) + { + # This will fail this test. + --die Server failed to dissapear + } + --sleep 1 +} + +--echo # Mysqld crash was detected +--echo # Waitting for reconnect after mysqld restarts + +enable_reconnect; +connection default; + +--exec echo "restart:--log-error=$error_log" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect + +# Call script that will poll the server waiting for it to be back online again +source include/wait_until_connected_again.inc; + +--echo # Reconnected after mysqld was successfully restarted + +--echo # Cleaning up before exit +--disable_warnings +drop table if exists t1; +--enable_warnings + +--echo # Clean exit diff --git a/mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold_basic.test b/mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold_basic.test new file mode 100644 index 00000000000..dcb6fff8751 --- /dev/null +++ b/mysql-test/suite/sys_vars/t/innodb_fatal_semaphore_wait_threshold_basic.test @@ -0,0 +1,21 @@ +--source include/have_innodb.inc +# bool readonly + +# +# show values; +# +select @@global.innodb_fatal_semaphore_wait_threshold; +--error ER_INCORRECT_GLOBAL_LOCAL_VAR +select @@session.innodb_fatal_semaphore_wait_threshold; +show global variables like 'innodb_fatal_semaphore_wait_threshold'; +show session variables like 'innodb_fatal_semaphore_wait_threshold'; +select * from information_schema.global_variables where variable_name='innodb_fatal_semaphore_wait_threshold'; +select * from information_schema.session_variables where variable_name='innodb_fatal_semaphore_wait_threshold'; + +# +# show that it's read-only +# +--error ER_INCORRECT_GLOBAL_LOCAL_VAR +set global innodb_fatal_semaphore_wait_threshold=1; +--error ER_INCORRECT_GLOBAL_LOCAL_VAR +set session innodb_fatal_semaphore_wait_threshold=1; diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index 02f511d7a6d..8c00961f1d2 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -13219,7 +13219,7 @@ ha_innobase::check( CHECK TABLE. */ os_increment_counter_by_amount( server_mutex, - srv_fatal_semaphore_wait_threshold, + srv_fatal_semaphore_wait_threshold, SRV_SEMAPHORE_WAIT_EXTENSION); bool valid = btr_validate_index(index, prebuilt->trx); @@ -13227,7 +13227,7 @@ ha_innobase::check( CHECK TABLE. */ os_decrement_counter_by_amount( server_mutex, - srv_fatal_semaphore_wait_threshold, + srv_fatal_semaphore_wait_threshold, SRV_SEMAPHORE_WAIT_EXTENSION); if (!valid) { @@ -18836,6 +18836,15 @@ static MYSQL_SYSVAR_BOOL(use_mtflush, srv_use_mtflush, "Use multi-threaded flush. Default FALSE.", NULL, NULL, FALSE); +static MYSQL_SYSVAR_ULONG(fatal_semaphore_wait_threshold, srv_fatal_semaphore_wait_threshold, + PLUGIN_VAR_RQCMDARG | PLUGIN_VAR_READONLY, + "Maximum number of seconds that semaphore times out in InnoDB.", + NULL, NULL, + DEFAULT_SRV_FATAL_SEMAPHORE_TIMEOUT, /* Default setting */ + 1, /* Minimum setting */ + UINT_MAX32, /* Maximum setting */ + 0); + static struct st_mysql_sys_var* innobase_system_variables[]= { MYSQL_SYSVAR(additional_mem_pool_size), MYSQL_SYSVAR(api_trx_level), @@ -19010,6 +19019,8 @@ static struct st_mysql_sys_var* innobase_system_variables[]= { MYSQL_SYSVAR(compression_algorithm), MYSQL_SYSVAR(mtflush_threads), MYSQL_SYSVAR(use_mtflush), + + MYSQL_SYSVAR(fatal_semaphore_wait_threshold), NULL }; diff --git a/storage/innobase/include/srv0srv.h b/storage/innobase/include/srv0srv.h index c3c9083f3cd..e87750b7540 100644 --- a/storage/innobase/include/srv0srv.h +++ b/storage/innobase/include/srv0srv.h @@ -492,7 +492,6 @@ extern my_bool srv_ibuf_disable_background_merge; extern my_bool srv_purge_view_update_only_debug; #endif /* UNIV_DEBUG */ -extern ulint srv_fatal_semaphore_wait_threshold; #define SRV_SEMAPHORE_WAIT_EXTENSION 7200 extern ulint srv_dml_needed_delay; @@ -531,6 +530,11 @@ extern srv_stats_t srv_stats; /** Simulate compression failures. */ extern uint srv_simulate_comp_failures; +/** Fatal semaphore wait threshold = maximum number of seconds +that semaphore times out in InnoDB */ +#define DEFAULT_SRV_FATAL_SEMAPHORE_TIMEOUT 600 +extern ulong srv_fatal_semaphore_wait_threshold; + # ifdef UNIV_PFS_THREAD /* Keys to register InnoDB threads with performance schema */ extern mysql_pfs_key_t buf_page_cleaner_thread_key; diff --git a/storage/innobase/lock/lock0lock.cc b/storage/innobase/lock/lock0lock.cc index bd88e7e94de..8dbe1668e36 100644 --- a/storage/innobase/lock/lock0lock.cc +++ b/storage/innobase/lock/lock0lock.cc @@ -4987,6 +4987,9 @@ lock_table( lock_mutex_enter(); + DBUG_EXECUTE_IF("fatal-semaphore-timeout", + { os_thread_sleep(3600000000); }); + /* We have to check if the new lock is compatible with any locks other transactions have in the table lock queue. */ diff --git a/storage/innobase/srv/srv0srv.cc b/storage/innobase/srv/srv0srv.cc index c61a098d146..d56f942f661 100644 --- a/storage/innobase/srv/srv0srv.cc +++ b/storage/innobase/srv/srv0srv.cc @@ -80,7 +80,7 @@ extern int wsrep_debug; extern int wsrep_trx_is_aborting(void *thd_ptr); #endif /* The following is the maximum allowed duration of a lock wait. */ -UNIV_INTERN ulint srv_fatal_semaphore_wait_threshold = 600; +UNIV_INTERN ulong srv_fatal_semaphore_wait_threshold = DEFAULT_SRV_FATAL_SEMAPHORE_TIMEOUT; /* How much data manipulation language (DML) statements need to be delayed, in microseconds, in order to reduce the lagging of the purge thread. */ diff --git a/storage/xtradb/handler/ha_innodb.cc b/storage/xtradb/handler/ha_innodb.cc index e321feb77f3..f0b848a6e21 100644 --- a/storage/xtradb/handler/ha_innodb.cc +++ b/storage/xtradb/handler/ha_innodb.cc @@ -13897,7 +13897,7 @@ ha_innobase::check( CHECK TABLE. */ os_increment_counter_by_amount( server_mutex, - srv_fatal_semaphore_wait_threshold, + srv_fatal_semaphore_wait_threshold, SRV_SEMAPHORE_WAIT_EXTENSION); bool valid = btr_validate_index(index, prebuilt->trx); @@ -13905,7 +13905,7 @@ ha_innobase::check( CHECK TABLE. */ os_decrement_counter_by_amount( server_mutex, - srv_fatal_semaphore_wait_threshold, + srv_fatal_semaphore_wait_threshold, SRV_SEMAPHORE_WAIT_EXTENSION); if (!valid) { @@ -20128,6 +20128,15 @@ static MYSQL_SYSVAR_BOOL(use_mtflush, srv_use_mtflush, "Use multi-threaded flush. Default FALSE.", NULL, NULL, FALSE); +static MYSQL_SYSVAR_ULONG(fatal_semaphore_wait_threshold, srv_fatal_semaphore_wait_threshold, + PLUGIN_VAR_RQCMDARG | PLUGIN_VAR_READONLY, + "Maximum number of seconds that semaphore times out in InnoDB.", + NULL, NULL, + DEFAULT_SRV_FATAL_SEMAPHORE_TIMEOUT, /* Default setting */ + 1, /* Minimum setting */ + UINT_MAX32, /* Maximum setting */ + 0); + static struct st_mysql_sys_var* innobase_system_variables[]= { MYSQL_SYSVAR(log_block_size), MYSQL_SYSVAR(additional_mem_pool_size), @@ -20340,6 +20349,8 @@ static struct st_mysql_sys_var* innobase_system_variables[]= { MYSQL_SYSVAR(compression_algorithm), MYSQL_SYSVAR(mtflush_threads), MYSQL_SYSVAR(use_mtflush), + + MYSQL_SYSVAR(fatal_semaphore_wait_threshold), NULL }; diff --git a/storage/xtradb/include/srv0srv.h b/storage/xtradb/include/srv0srv.h index c892e21db9d..4a18c0711f3 100644 --- a/storage/xtradb/include/srv0srv.h +++ b/storage/xtradb/include/srv0srv.h @@ -585,7 +585,6 @@ extern my_bool srv_ibuf_disable_background_merge; extern my_bool srv_purge_view_update_only_debug; #endif /* UNIV_DEBUG */ -extern ulint srv_fatal_semaphore_wait_threshold; #define SRV_SEMAPHORE_WAIT_EXTENSION 7200 extern ulint srv_dml_needed_delay; extern long long srv_kill_idle_transaction; @@ -670,6 +669,11 @@ extern my_bool srv_fake_changes_locks; /** Simulate compression failures. */ extern uint srv_simulate_comp_failures; +/** Fatal semaphore wait threshold = maximum number of seconds +that semaphore times out in InnoDB */ +#define DEFAULT_SRV_FATAL_SEMAPHORE_TIMEOUT 600 +extern ulong srv_fatal_semaphore_wait_threshold; + # ifdef UNIV_PFS_THREAD /* Keys to register InnoDB threads with performance schema */ extern mysql_pfs_key_t buf_page_cleaner_thread_key; diff --git a/storage/xtradb/lock/lock0lock.cc b/storage/xtradb/lock/lock0lock.cc index 30ad3ee7922..0df0d790925 100644 --- a/storage/xtradb/lock/lock0lock.cc +++ b/storage/xtradb/lock/lock0lock.cc @@ -5028,6 +5028,9 @@ lock_table( lock_mutex_enter(); + DBUG_EXECUTE_IF("fatal-semaphore-timeout", + { os_thread_sleep(3600000000); }); + /* We have to check if the new lock is compatible with any locks other transactions have in the table lock queue. */ diff --git a/storage/xtradb/srv/srv0srv.cc b/storage/xtradb/srv/srv0srv.cc index 3495302a45f..6af5f0d782c 100644 --- a/storage/xtradb/srv/srv0srv.cc +++ b/storage/xtradb/srv/srv0srv.cc @@ -95,7 +95,7 @@ in the server */ UNIV_INTERN ulint srv_activity_count = 0; /* The following is the maximum allowed duration of a lock wait. */ -UNIV_INTERN ulint srv_fatal_semaphore_wait_threshold = 600; +UNIV_INTERN ulong srv_fatal_semaphore_wait_threshold = DEFAULT_SRV_FATAL_SEMAPHORE_TIMEOUT; /**/ UNIV_INTERN long long srv_kill_idle_transaction = 0;