From 96ae37abc51a622e271d23875970a2e86c7a1883 Mon Sep 17 00:00:00 2001 From: Vlad Lesin Date: Tue, 3 Oct 2023 20:07:39 +0300 Subject: [PATCH] MDEV-30658 lock_row_lock_current_waits counter in information_schema.innodb_metrics may become negative MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit MONITOR_OVLD_ROW_LOCK_CURRENT_WAIT monitor should has MONITOR_DISPLAY_CURRENT flag set in its definition, as it shows the current state and does not accumulate anything. Reviewed by: Marko Mäkelä --- .../r/innodb_skip_innodb_is_tables.result | 2 +- .../r/mon_lock_wait_current_count.result | 54 +++++++++++++ .../innodb/t/mon_lock_wait_current_count.test | 76 +++++++++++++++++++ storage/innobase/lock/lock0wait.cc | 1 + storage/innobase/srv/srv0mon.cc | 2 +- 5 files changed, 133 insertions(+), 2 deletions(-) create mode 100644 mysql-test/suite/innodb/r/mon_lock_wait_current_count.result create mode 100644 mysql-test/suite/innodb/t/mon_lock_wait_current_count.test diff --git a/mysql-test/suite/innodb/r/innodb_skip_innodb_is_tables.result b/mysql-test/suite/innodb/r/innodb_skip_innodb_is_tables.result index 26f3267440e..486a9fd7c8f 100644 --- a/mysql-test/suite/innodb/r/innodb_skip_innodb_is_tables.result +++ b/mysql-test/suite/innodb/r/innodb_skip_innodb_is_tables.result @@ -50,7 +50,7 @@ lock_rec_locks lock 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL disabl lock_table_lock_created lock 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL disabled counter Number of table locks created lock_table_lock_removed lock 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL disabled counter Number of table locks removed from the lock queue lock_table_locks lock 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL disabled counter Current number of table locks on tables -lock_row_lock_current_waits lock 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL disabled status_counter Number of row locks currently being waited for (innodb_row_lock_current_waits) +lock_row_lock_current_waits lock 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL disabled value Number of row locks currently being waited for (innodb_row_lock_current_waits) lock_row_lock_time lock 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL disabled status_counter Time spent in acquiring row locks, in milliseconds (innodb_row_lock_time) lock_row_lock_time_max lock 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL disabled value The maximum time to acquire a row lock, in milliseconds (innodb_row_lock_time_max) lock_row_lock_waits lock 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL disabled status_counter Number of times a row lock had to be waited for (innodb_row_lock_waits) diff --git a/mysql-test/suite/innodb/r/mon_lock_wait_current_count.result b/mysql-test/suite/innodb/r/mon_lock_wait_current_count.result new file mode 100644 index 00000000000..d30bf863001 --- /dev/null +++ b/mysql-test/suite/innodb/r/mon_lock_wait_current_count.result @@ -0,0 +1,54 @@ +connect prevent_purge,localhost,root,,; +START TRANSACTION WITH CONSISTENT SNAPSHOT; +connection default; +SET GLOBAL innodb_monitor_disable='all'; +SET GLOBAL innodb_monitor_enable='lock_row_lock_current_waits'; +CREATE TABLE `t` (a INT PRIMARY KEY) engine=InnoDB STATS_PERSISTENT=0; +INSERT INTO t VALUES (5); +SELECT name, count FROM information_schema.innodb_metrics +WHERE name ='lock_row_lock_current_waits'; +name count +lock_row_lock_current_waits 0 +connect con1,localhost,root,,; +BEGIN; +SELECT * FROM t FOR UPDATE; +a +5 +connect con2,localhost,root,,; +SET DEBUG_SYNC="lock_wait_before_suspend SIGNAL blocked WAIT_FOR cont"; +BEGIN; +SELECT * FROM t FOR UPDATE; +connection default; +SET DEBUG_SYNC="now WAIT_FOR blocked"; +SELECT name, count FROM information_schema.innodb_metrics +WHERE name ='lock_row_lock_current_waits'; +name count +lock_row_lock_current_waits 1 +SET GLOBAL innodb_monitor_disable='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_reset_all='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_enable='lock_row_lock_current_waits'; +SELECT name, count FROM information_schema.innodb_metrics +WHERE name ='lock_row_lock_current_waits'; +name count +lock_row_lock_current_waits 1 +SET DEBUG_SYNC="now SIGNAL cont"; +disconnect con1; +connection con2; +a +5 +COMMIT; +disconnect con2; +connection default; +SET DEBUG_SYNC="reset"; +SELECT name, count FROM information_schema.innodb_metrics +WHERE name ='lock_row_lock_current_waits'; +name count +lock_row_lock_current_waits 0 +DROP TABLE `t`; +SET GLOBAL innodb_monitor_disable='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_reset_all='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_enable='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_disable=default; +SET GLOBAL innodb_monitor_reset_all=default; +SET GLOBAL innodb_monitor_enable=default; +disconnect prevent_purge; diff --git a/mysql-test/suite/innodb/t/mon_lock_wait_current_count.test b/mysql-test/suite/innodb/t/mon_lock_wait_current_count.test new file mode 100644 index 00000000000..5bceb1ec881 --- /dev/null +++ b/mysql-test/suite/innodb/t/mon_lock_wait_current_count.test @@ -0,0 +1,76 @@ +# Check if lock_row_lock_current_waits counter in +# information_schema.innodb_metrics does not become negative after disabling, +# resetting and enabling. + +--source include/have_innodb.inc +--source include/have_debug.inc +--source include/count_sessions.inc + +--connect (prevent_purge,localhost,root,,) +START TRANSACTION WITH CONSISTENT SNAPSHOT; + +--connection default +SET GLOBAL innodb_monitor_disable='all'; +SET GLOBAL innodb_monitor_enable='lock_row_lock_current_waits'; +CREATE TABLE `t` (a INT PRIMARY KEY) engine=InnoDB STATS_PERSISTENT=0; +INSERT INTO t VALUES (5); +SELECT name, count FROM information_schema.innodb_metrics + WHERE name ='lock_row_lock_current_waits'; + +--connect (con1,localhost,root,,) +BEGIN; +SELECT * FROM t FOR UPDATE; + +--connect (con2,localhost,root,,) +SET DEBUG_SYNC="lock_wait_before_suspend SIGNAL blocked WAIT_FOR cont"; +BEGIN; +--send SELECT * FROM t FOR UPDATE + +--connection default +SET DEBUG_SYNC="now WAIT_FOR blocked"; +SELECT name, count FROM information_schema.innodb_metrics + WHERE name ='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_disable='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_reset_all='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_enable='lock_row_lock_current_waits'; +###################################### +# Equals to zero if the bug is not fixed, as MONITOR_DISPLAY_CURRENT is not +# set for this counter and its value is reset during previous +# "SET GLOBAL innodb_monitor_reset_all='lock_row_lock_current_waits'" execution. +##### +SELECT name, count FROM information_schema.innodb_metrics + WHERE name ='lock_row_lock_current_waits'; +SET DEBUG_SYNC="now SIGNAL cont"; + +--disconnect con1 + +--connection con2 +--reap +COMMIT; +--disconnect con2 + +--connection default +SET DEBUG_SYNC="reset"; +###################################### +# Equals to -1 if the bug is not fixed. I.e. +# innodb_counter_value[MONITOR_OVLD_ROW_LOCK_CURRENT_WAIT].mon_start_value is +# set to 1 during +# "set global innodb_monitor_disable='lock_row_lock_current_waits'" execution, +# and the value is counted as +# (value = 0) - (mon_value_reset = 0) - (mon_start_value = 1) + +# (mon_last_value = 0) = -1. See MONITOR_SET_DIFF() macro in +# srv_mon_process_existing_counter() for details. +##### +SELECT name, count FROM information_schema.innodb_metrics + WHERE name ='lock_row_lock_current_waits'; +DROP TABLE `t`; +SET GLOBAL innodb_monitor_disable='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_reset_all='lock_row_lock_current_waits'; +SET GLOBAL innodb_monitor_enable='lock_row_lock_current_waits'; +--disable_warnings +SET GLOBAL innodb_monitor_disable=default; +SET GLOBAL innodb_monitor_reset_all=default; +SET GLOBAL innodb_monitor_enable=default; +--enable_warnings +--disconnect prevent_purge +--source include/wait_until_count_sessions.inc diff --git a/storage/innobase/lock/lock0wait.cc b/storage/innobase/lock/lock0wait.cc index a26b3a6efaa..18d5eba6b48 100644 --- a/storage/innobase/lock/lock0wait.cc +++ b/storage/innobase/lock/lock0wait.cc @@ -340,6 +340,7 @@ lock_wait_suspend_thread( thd_wait_begin(trx->mysql_thd, THD_WAIT_TABLE_LOCK); } + DEBUG_SYNC_C("lock_wait_before_suspend"); os_event_wait(slot->event); DBUG_EXECUTE_IF("small_sleep_after_lock_wait", { diff --git a/storage/innobase/srv/srv0mon.cc b/storage/innobase/srv/srv0mon.cc index 97ea562140c..2c46a41b122 100644 --- a/storage/innobase/srv/srv0mon.cc +++ b/storage/innobase/srv/srv0mon.cc @@ -145,7 +145,7 @@ static monitor_info_t innodb_counter_info[] = "Number of row locks currently being waited for" " (innodb_row_lock_current_waits)", static_cast( - MONITOR_EXISTING | MONITOR_DEFAULT_ON), + MONITOR_EXISTING | MONITOR_DISPLAY_CURRENT | MONITOR_DEFAULT_ON), MONITOR_DEFAULT_START, MONITOR_OVLD_ROW_LOCK_CURRENT_WAIT}, {"lock_row_lock_time", "lock",