Bug #106897 performance_schema.metadata_locks wrong value for owner_thread_id

Submitted: 2 Apr 2022 0:14 Modified: 29 Aug 2024 23:17
Reporter: Mike Griffin Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Documentation Severity:S3 (Non-critical)
Version:8.0.27, 8.0.28 OS:Linux
Assigned to: Marc ALFF CPU Architecture:Any

[2 Apr 2022 0:14] Mike Griffin
Description:
It appears that the owner_thread_id is a couple thousand larger than the real thread id:

mysql> select max(owner_thread_id) from performance_schema.metadata_locks;
+----------------------+
| max(owner_thread_id) |
+----------------------+
|               518115 |
+----------------------+
1 row in set (0.00 sec)

mysql> system mysql <<< "select connection_id()"
connection_id()
516142

I believe this could lead to blaming the wrong thread:

mysql> select count(*) from performance_schema.metadata_locks; select t1.object_type, t1.lock_type, t1.lock_duration from performance_schema.metadata_locks t1 join information_schema.processlist t2 on t1.owner_thread_id=t2.id;
+----------+
| count(*) |
+----------+
|        8 |
+----------+
1 row in set (0.00 sec)

+-------------+---------------------+---------------+
| object_type | lock_type           | lock_duration |
+-------------+---------------------+---------------+
| GLOBAL      | INTENTION_EXCLUSIVE | STATEMENT     |
| TABLE       | SHARED_WRITE        | TRANSACTION   |
+-------------+---------------------+---------------+
2 rows in set (0.01 sec)

mysql> select count(*) from performance_schema.metadata_locks; select t1.object_type, t1.lock_type, t1.lock_duration from performance_schema.metadata_locks t1 join information_schema.processlist t2 on t1.owner_thread_id=t2.id;
+----------+
| count(*) |
+----------+
|       19 |
+----------+
1 row in set (0.00 sec)

Empty set (0.01 sec)

In this environment, connections do not arrive very frequently through pool reuse:

# mysqladmin -rvi 1 ex | grep Connections
| Connections                                           | 517466                                                                                                                                                                                                                                                                                                                                                                                                                                                              |
| Connections                                           | 1                                                                                                                                                                                                                                                                                                                                                                                                                                                                   |
| Connections                                           | 2                                                                                                                                                                                                                                                                                                                                                                                                                                                                   |

How to repeat:
### session 1

create database dba_test;
use dba_test;
insert into t1 select null, 'foo';
select sleep(15) from dba_test.t1 for update;

### meanwhile session 2

set session lock_wait_timeout=1;
alter table dba_test.t1 default character set utf8mb4;

### back to session 1, wait for sleep to complete

mysql> select * from performance_schema.metadata_locks where object_schema='dba_test'\G
*************************** 1. row ***************************
          OBJECT_TYPE: TABLE
        OBJECT_SCHEMA: dba_test
          OBJECT_NAME: t1
          COLUMN_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139502955417424
            LOCK_TYPE: SHARED_WRITE
        LOCK_DURATION: TRANSACTION
          LOCK_STATUS: GRANTED
               SOURCE: sql_parse.cc:5902
      OWNER_THREAD_ID: 519588
       OWNER_EVENT_ID: 23
1 row in set (0.00 sec)

mysql> select connection_id();
+-----------------+
| connection_id() |
+-----------------+
|          517590 |
+-----------------+
1 row in set (0.00 sec)

mysql> rollback;
Query OK, 0 rows affected (0.00 sec)

mysql> select * from performance_schema.metadata_locks where object_schema='dba_test'\G
Empty set (0.00 sec)

If you do this several times in the same connection, you do get a consistent but wrong owner_thread_id;
[4 Apr 2022 20:52] Mike Griffin
CREATE TABLE `t` (
  `id` bigint unsigned NOT NULL AUTO_INCREMENT,
  `foo` varchar(32) DEFAULT NULL,
  UNIQUE KEY `id` (`id`)
) ENGINE=InnoDB;

INSERT INTO `t` VALUES (1,'foo');

BEGIN;

SELECT foo FROM t FOR UPDATE INTO @x;

SELECT * FROM performance_schema.metadata_locks WHERE object_schema='test';

SELECT CONNECTION_ID();

ROLLBACK;

DROP TABLE IF EXISTS t;
[9 Apr 2022 8:11] MySQL Verification Team
Hello Mike Griffin,

Thank you for the report.

Thanks,
Umesh
[14 Apr 2022 9:40] Marc ALFF
Please note that 'THREAD_ID' columns and related, like OWNER_THREAD_ID,
are different from 'PROCESSLIST_ID'.

mysql> use test;
Database changed
mysql> 
mysql> CREATE TABLE `t` (
    ->   `id` bigint unsigned NOT NULL AUTO_INCREMENT,
    ->   `foo` varchar(32) DEFAULT NULL,
    ->   UNIQUE KEY `id` (`id`)
    -> ) ENGINE=InnoDB;
Query OK, 0 rows affected (0.02 sec)

mysql> 
mysql> INSERT INTO `t` VALUES (1,'foo');
Query OK, 1 row affected (0.01 sec)

mysql> 
mysql> BEGIN;
Query OK, 0 rows affected (0.00 sec)

mysql> 
mysql> SELECT foo FROM t FOR UPDATE INTO @x;
Query OK, 1 row affected (0.00 sec)

mysql> 
mysql> SELECT * FROM performance_schema.metadata_locks WHERE object_schema='test';
+-------------+---------------+-------------+-------------+-----------------------+--------------+---------------+-------------+-------------------+-----------------+----------------+
| OBJECT_TYPE | OBJECT_SCHEMA | OBJECT_NAME | COLUMN_NAME | OBJECT_INSTANCE_BEGIN | LOCK_TYPE    | LOCK_DURATION | LOCK_STATUS | SOURCE            | OWNER_THREAD_ID | OWNER_EVENT_ID |
+-------------+---------------+-------------+-------------+-----------------------+--------------+---------------+-------------+-------------------+-----------------+----------------+
| TABLE       | test          | t           | NULL        |       140352095361648 | SHARED_WRITE | TRANSACTION   | GRANTED     | sql_parse.cc:6008 |              52 |          20540 |
+-------------+---------------+-------------+-------------+-----------------------+--------------+---------------+-------------+-------------------+-----------------+----------------+
1 row in set (0.00 sec)

mysql> 
mysql> SELECT CONNECTION_ID(), PS_CURRENT_THREAD_ID();
+-----------------+------------------------+
| CONNECTION_ID() | PS_CURRENT_THREAD_ID() |
+-----------------+------------------------+
|              12 |                     52 |
+-----------------+------------------------+
1 row in set (0.00 sec)

mysql> 
mysql> SELECT THREAD_ID, NAME, PROCESSLIST_ID
    ->    FROM performance_schema.threads
    ->   WHERE PROCESSLIST_ID = CONNECTION_ID();
+-----------+---------------------------+----------------+
| THREAD_ID | NAME                      | PROCESSLIST_ID |
+-----------+---------------------------+----------------+
|        52 | thread/sql/one_connection |             12 |
+-----------+---------------------------+----------------+
1 row in set (0.00 sec)

mysql> 
mysql> SELECT THREAD_ID, NAME, PROCESSLIST_ID
    ->    FROM performance_schema.threads
    ->   WHERE THREAD_ID = PS_CURRENT_THREAD_ID();
+-----------+---------------------------+----------------+
| THREAD_ID | NAME                      | PROCESSLIST_ID |
+-----------+---------------------------+----------------+
|        52 | thread/sql/one_connection |             12 |
+-----------+---------------------------+----------------+
1 row in set (0.00 sec)

mysql> 
mysql> ROLLBACK;
Query OK, 0 rows affected (0.00 sec)

mysql> 
mysql> DROP TABLE IF EXISTS t;
Query OK, 0 rows affected (0.01 sec)
[14 Apr 2022 10:09] Marc ALFF
To clarify,

The following are all 'PROCESSLIST_ID':
- Column ID in INFORMATION_SCHEMA.PROCESSLIST
- Column ID in SHOW PROCESSLIST
- Column ID in performance_schema.processlist
- native function CONNECTION_ID()
- Column PROCESSLIST_ID in performance_schema.threads;

The following are all 'THREAD_ID':
- Column THREAD_ID in performance_schema.threads
- Column THREAD_ID in performance_schema tables in general
- Column OWNER_THREAD_ID in performance_schema.metadata_locks
- native function PS_CURRENT_THREAD_ID()

THREAD_ID and PROCESSLIST_ID are different, and can not be compared or joined.

See also the native function PS_THREAD_ID(connection_id)

Instead of joining:
- column OWNER_THREAD_ID in performance_schema.metadata_locks
- column ID in information_schema.processlist
which compares a THREAD_ID with a PROCESSLIST_ID (incorrect),
use:
- column OWNER_THREAD_ID in performance_schema.metadata_locks
- column THREAD_ID in performance_schema.threads

Instead of using:
- native function CONNECTION_ID()
use:
- native function PS_CURRENT_THREAD_ID()
to get the thread_id of the current session.

Closing as not a bug, since the server works as expected.

Thanks for the detailed report and test case.
[29 Aug 2024 23:17] Jon Stephens
Accepted as a Docs bug; we'll see what we can use from Marc's explanation for the Manual.

Thanks!

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.057 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.