Skip to content

Commit

Permalink
MDEV-7109: Add support for INFORMATION_SCHEMA.INNODB_SEMAPHORE_WAITS
Browse files Browse the repository at this point in the history
    MDEV-7399: Add support for INFORMATION_SCHEMA.INNODB_MUTEXES
    MDEV-7618: Improve semaphore instrumentation

    Introduced two new information schema tables to monitor mutex waits
    and semaphore waits. Added a new configuration variable
    innodb_intrument_semaphores to add thread_id, file name and
    line of current holder of mutex/rw_lock.
  • Loading branch information
Jan Lindström committed Feb 21, 2015
1 parent 9152b83 commit 1cc7bef
Show file tree
Hide file tree
Showing 39 changed files with 2,173 additions and 293 deletions.
8 changes: 7 additions & 1 deletion mysql-test/r/information_schema_all_engines.result
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ INNODB_CMPMEM_RESET
INNODB_CMP_PER_INDEX
INNODB_CMP_RESET
INNODB_LOCK_WAITS
INNODB_MUTEXES
INNODB_SYS_COLUMNS
INNODB_SYS_FIELDS
INNODB_SYS_FOREIGN
Expand Down Expand Up @@ -97,6 +98,7 @@ INNODB_CMPMEM_RESET page_size
INNODB_CMP_PER_INDEX database_name
INNODB_CMP_RESET page_size
INNODB_LOCK_WAITS requesting_trx_id
INNODB_MUTEXES NAME
INNODB_SYS_COLUMNS TABLE_ID
INNODB_SYS_FIELDS INDEX_ID
INNODB_SYS_FOREIGN ID
Expand Down Expand Up @@ -170,6 +172,7 @@ INNODB_CMPMEM_RESET page_size
INNODB_CMP_PER_INDEX database_name
INNODB_CMP_RESET page_size
INNODB_LOCK_WAITS requesting_trx_id
INNODB_MUTEXES NAME
INNODB_SYS_COLUMNS TABLE_ID
INNODB_SYS_FIELDS INDEX_ID
INNODB_SYS_FOREIGN ID
Expand Down Expand Up @@ -248,6 +251,7 @@ INNODB_CMPMEM_RESET information_schema.INNODB_CMPMEM_RESET 1
INNODB_CMP_PER_INDEX information_schema.INNODB_CMP_PER_INDEX 1
INNODB_CMP_RESET information_schema.INNODB_CMP_RESET 1
INNODB_LOCK_WAITS information_schema.INNODB_LOCK_WAITS 1
INNODB_MUTEXES information_schema.INNODB_MUTEXES 1
INNODB_SYS_COLUMNS information_schema.INNODB_SYS_COLUMNS 1
INNODB_SYS_FIELDS information_schema.INNODB_SYS_FIELDS 1
INNODB_SYS_FOREIGN information_schema.INNODB_SYS_FOREIGN 1
Expand Down Expand Up @@ -311,6 +315,7 @@ Database: information_schema
| INNODB_CMP_PER_INDEX |
| INNODB_CMP_RESET |
| INNODB_LOCK_WAITS |
| INNODB_MUTEXES |
| INNODB_SYS_COLUMNS |
| INNODB_SYS_FIELDS |
| INNODB_SYS_FOREIGN |
Expand Down Expand Up @@ -374,6 +379,7 @@ Database: INFORMATION_SCHEMA
| INNODB_CMP_PER_INDEX |
| INNODB_CMP_RESET |
| INNODB_LOCK_WAITS |
| INNODB_MUTEXES |
| INNODB_SYS_COLUMNS |
| INNODB_SYS_FIELDS |
| INNODB_SYS_FOREIGN |
Expand Down Expand Up @@ -417,5 +423,5 @@ Wildcard: inf_rmation_schema
| information_schema |
SELECT table_schema, count(*) FROM information_schema.TABLES WHERE table_schema IN ('mysql', 'INFORMATION_SCHEMA', 'test', 'mysqltest') GROUP BY TABLE_SCHEMA;
table_schema count(*)
information_schema 58
information_schema 59
mysql 30
21 changes: 21 additions & 0 deletions mysql-test/suite/innodb/r/innodb_mutexes.result
Original file line number Diff line number Diff line change
@@ -0,0 +1,21 @@
create table t1(a int not null primary key, b int, c int,d CHAR(100)) engine=innodb;
create procedure innodb_insert_proc (repeat_count int)
begin
declare current_num int;
set current_num = 0;
while current_num < repeat_count do
insert into t1 values(current_num, RAND(), RAND(), substring(MD5(RAND()), -64));
set current_num = current_num + 1;
end while;
end//
commit;
set autocommit=0;
call innodb_insert_proc(20000);
commit;
set autocommit=1;
delete from t1 where a between 1000 and 1300;
update t1 set b=b+1 where a between 2000 and 2600;
insert into t1 select a+30000,b,c,d from t1 where a between 3000 and 4000;
delete from t1 where a between 6000 and 7000;
drop procedure innodb_insert_proc;
drop table t1;
26 changes: 26 additions & 0 deletions mysql-test/suite/innodb/r/innodb_sys_semaphore_waits.result
Original file line number Diff line number Diff line change
@@ -0,0 +1,26 @@
# 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
set DEBUG_DBUG=NULL;
drop table if exists t1;
# Clean exit
1 change: 1 addition & 0 deletions mysql-test/suite/innodb/t/innodb_mutexes-master.opt
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
--innodb-mutexes
66 changes: 66 additions & 0 deletions mysql-test/suite/innodb/t/innodb_mutexes.test
Original file line number Diff line number Diff line change
@@ -0,0 +1,66 @@
--source include/have_innodb.inc

connect(con1,localhost,root,,);
connect(con2,localhost,root,,);
connect(con3,localhost,root,,);

create table t1(a int not null primary key, b int, c int,d CHAR(100)) engine=innodb;

delimiter //;
create procedure innodb_insert_proc (repeat_count int)
begin
declare current_num int;
set current_num = 0;
while current_num < repeat_count do
insert into t1 values(current_num, RAND(), RAND(), substring(MD5(RAND()), -64));
set current_num = current_num + 1;
end while;
end//
delimiter ;//
commit;

set autocommit=0;
call innodb_insert_proc(20000);
commit;
set autocommit=1;

connection con1;
send delete from t1 where a between 1000 and 1300;

connection con2;
send update t1 set b=b+1 where a between 2000 and 2600;

connection con3;
send insert into t1 select a+30000,b,c,d from t1 where a between 3000 and 4000;

connection default;
send delete from t1 where a between 6000 and 7000;

connection con1;
reap;

connection con2;
reap;

connection con3;
reap;

connection default;
reap;

disconnect con1;
disconnect con2;
disconnect con3;

# test that below does not crash, actual result is not
# repeatable
--disable_query_log
--disable_result_log
--disable_warnings
select * from information_schema.innodb_mutexes;
--enable_query_log
--enable_result_log
--enable_warnings

drop procedure innodb_insert_proc;
drop table t1;
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
--innodb-fatal-semaphore-wait-threshold=1
--innodb-sys-semaphore-waits=1
--innodb-instrument-semaphores=1
119 changes: 119 additions & 0 deletions mysql-test/suite/innodb/t/innodb_sys_semaphore_waits.test
Original file line number Diff line number Diff line change
@@ -0,0 +1,119 @@
--source include/have_innodb.inc
--source include/not_windows.inc
--source include/not_valgrind.inc
--source include/not_embedded.inc
# DEBUG_SYNC must be compiled in.
--source include/have_debug_sync.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;

--error 0,1040,1053,2002,2003,2006,2013
select * from information_schema.innodb_sys_semaphore_waits;

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
set DEBUG_DBUG=NULL;
drop table if exists t1;
--enable_warnings

--echo # Clean exit
1 change: 1 addition & 0 deletions mysql-test/suite/sys_vars/r/all_vars.result
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ there should be *no* long test name listed below:
select distinct variable_name as `there should be *no* variables listed below:` from t2
left join t1 on variable_name=test_name where test_name is null;
there should be *no* variables listed below:
innodb_instrument_semaphores
strict_password_validation
drop table t1;
drop table t2;
45 changes: 45 additions & 0 deletions mysql-test/suite/sys_vars/r/innodb_instrument_semaphores.result
Original file line number Diff line number Diff line change
@@ -0,0 +1,45 @@
#
# innodb_instrument_semaphores
#
# save the initial value
SET @innodb_instrument_semaphores_global_saved = @@global.innodb_instrument_semaphores;
# default
SELECT @@global.innodb_instrument_semaphores;
@@global.innodb_instrument_semaphores
0

# scope
SELECT @@session.innodb_instrument_semaphores;
ERROR HY000: Variable 'innodb_instrument_semaphores' is a GLOBAL variable
SET @@global.innodb_instrument_semaphores=OFF;
SELECT @@global.innodb_instrument_semaphores;
@@global.innodb_instrument_semaphores
0
SET @@global.innodb_instrument_semaphores=ON;
SELECT @@global.innodb_instrument_semaphores;
@@global.innodb_instrument_semaphores
1

# valid values
SET @@global.innodb_instrument_semaphores='OFF';
SELECT @@global.innodb_instrument_semaphores;
@@global.innodb_instrument_semaphores
0
SET @@global.innodb_instrument_semaphores=ON;
SELECT @@global.innodb_instrument_semaphores;
@@global.innodb_instrument_semaphores
1
SET @@global.innodb_instrument_semaphores=default;
SELECT @@global.innodb_instrument_semaphores;
@@global.innodb_instrument_semaphores
0

# invalid values
SET @@global.innodb_instrument_semaphores=NULL;
ERROR 42000: Variable 'innodb_instrument_semaphores' can't be set to the value of 'NULL'
SET @@global.innodb_instrument_semaphores='junk';
ERROR 42000: Variable 'innodb_instrument_semaphores' can't be set to the value of 'junk'

# restore the initial value
SET @@global.innodb_instrument_semaphores = @innodb_instrument_semaphores_global_saved;
# End of test
14 changes: 14 additions & 0 deletions mysql-test/suite/sys_vars/r/sysvars_innodb.result
Original file line number Diff line number Diff line change
Expand Up @@ -1209,6 +1209,20 @@ NUMERIC_BLOCK_SIZE NULL
ENUM_VALUE_LIST NULL
READ_ONLY NO
COMMAND_LINE_ARGUMENT REQUIRED
VARIABLE_NAME INNODB_INSTRUMENT_SEMAPHORES
SESSION_VALUE NULL
GLOBAL_VALUE OFF
GLOBAL_VALUE_ORIGIN COMPILE-TIME
DEFAULT_VALUE OFF
VARIABLE_SCOPE GLOBAL
VARIABLE_TYPE BOOLEAN
VARIABLE_COMMENT Enable semaphore request instrumentation. This could have some effect on performance but allows better information on long semaphore wait problems. (Default: not enabled)
NUMERIC_MIN_VALUE NULL
NUMERIC_MAX_VALUE NULL
NUMERIC_BLOCK_SIZE NULL
ENUM_VALUE_LIST NULL
READ_ONLY NO
COMMAND_LINE_ARGUMENT OPTIONAL
VARIABLE_NAME INNODB_IO_CAPACITY
SESSION_VALUE NULL
GLOBAL_VALUE 200
Expand Down
Loading

0 comments on commit 1cc7bef

Please sign in to comment.