Description:
In concurrent environment we may end up with a negative value of the lock_row_lock_current_waits counter (see how to repeat for the details on one way to do this):
mysql> select name, count,time_enabled from information_schema.innodb_metrics where name ='lock_row_lock_current_waits';
+-----------------------------+-------+---------------------+
| name | count | time_enabled |
+-----------------------------+-------+---------------------+
| lock_row_lock_current_waits | -1 | 2023-02-16 17:18:53 |
+-----------------------------+-------+---------------------+
1 row in set (0,00 sec)
This is a bug. There were several similar bugs reported (and some fixed), see https://bugs.mysql.com/bug.php?id=81099
How to repeat:
Consider the following test case that requires 3 sessions. In the first session run these:
mysql> set global innodb_lock_wait_timeout=50;
Query OK, 0 rows affected (0,03 sec)
mysql> CREATE TABLE `test` (`col` varchar(10) ) engine=InnoDB;
insert into test values ('a');
select name, count,time_enabled from information_schema.innodb_metrics where name ='lock_row_lock_current_waits';
Query OK, 0 rows affected (0,50 sec)
Query OK, 1 row affected (0,19 sec)
+-----------------------------+-------+---------------------+
| name | count | time_enabled |
+-----------------------------+-------+---------------------+
| lock_row_lock_current_waits | 0 | 2023-02-16 17:01:24 |
+-----------------------------+-------+---------------------+
1 row in set (0,08 sec)
Now start transaction and update the only row in this table from the second session:
mysql> begin;update test set col='c' where col='a';
Query OK, 0 rows affected (0,00 sec)
Query OK, 1 row affected (0,01 sec)
Rows matched: 1 Changed: 1 Warnings: 0
In the third session try to update the same row:
mysql> begin;update test set col='b' where col='a';
Back in the first session we see counter increased, as the third session waits:
mysql> select name, count,time_enabled from information_schema.innodb_metrics where name ='lock_row_lock_current_waits';
+-----------------------------+-------+---------------------+
| name | count | time_enabled |
+-----------------------------+-------+---------------------+
| lock_row_lock_current_waits | 1 | 2023-02-16 17:01:24 |
+-----------------------------+-------+---------------------+
1 row in set (0,00 sec)
No, resent the counter globally:
mysql> 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';
Query OK, 0 rows affected (0,00 sec)
Query OK, 0 rows affected (0,00 sec)
Query OK, 0 rows affected (0,00 sec)
and the value is back to zero:
mysql> select name, count,time_enabled from information_schema.innodb_metrics where name ='lock_row_lock_current_waits';
+-----------------------------+-------+---------------------+
| name | count | time_enabled |
+-----------------------------+-------+---------------------+
| lock_row_lock_current_waits | 0 | 2023-02-16 17:18:53 |
+-----------------------------+-------+---------------------+
1 row in set (0,00 sec)
Now wait until UPDATE in the third session fails with lock wait timeout error:
Query OK, 0 rows affected (0,00 sec)
ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
and try again the first session:
mysql> select name, count,time_enabled from information_schema.innodb_metrics where name ='lock_row_lock_current_waits';
+-----------------------------+-------+---------------------+
| name | count | time_enabled |
+-----------------------------+-------+---------------------+
| lock_row_lock_current_waits | -1 | 2023-02-16 17:18:53 |
+-----------------------------+-------+---------------------+
1 row in set (0,00 sec)
Suggested fix:
Make sure negative values never appear in the information_schema.innodb_metrics table. Or remove the feature entirely if it's so buggy and no longer important.
