环境说明: MySQL:5.7.34 双主 OS:Redhat 7.5 问题现象: XXX应用登录,提示数据库连接失败。 问题原因: 有一张权限表,同时执行了delete和truncate操作,并且长时间没有提交,导致metadata lock无法释放,应用登录时无法正常读取权限表,导致应用无法登录。 初步怀疑应用在执行delete操作时开启了事务,并且没有及时提交,导致锁无法释放。 解决方案: 和应用相关同事沟通,杀掉相关会话后,恢复正常。 问题重现: 1.开启锁监控。
MySQL [cjc]> select * from performance_schema.setup_instruments where name like '%lock%' limit 20; +---------------------------------------------------------+---------+-------+ | NAME | ENABLED | TIMED | +---------------------------------------------------------+---------+-------+ | wait/synch/mutex/sql/TC_LOG_MMAP::LOCK_tc | NO | NO | | wait/synch/mutex/sql/LOCK_des_key_file | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_commit | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_commit_queue | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_done | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_flush_queue | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_index | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_log | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_binlog_end_pos | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_sync | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_sync_queue | NO | NO | | wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_xids | NO | NO | | wait/synch/mutex/sql/MYSQL_RELAY_LOG::LOCK_commit | NO | NO | | wait/synch/mutex/sql/MYSQL_RELAY_LOG::LOCK_commit_queue | NO | NO | | wait/synch/mutex/sql/MYSQL_RELAY_LOG::LOCK_done | NO | NO | | wait/synch/mutex/sql/MYSQL_RELAY_LOG::LOCK_flush_queue | NO | NO | | wait/synch/mutex/sql/MYSQL_RELAY_LOG::LOCK_index | NO | NO | | wait/synch/mutex/sql/MYSQL_RELAY_LOG::LOCK_log | NO | NO | | wait/synch/mutex/sql/MYSQL_RELAY_LOG::LOCK_sync | NO | NO | | wait/synch/mutex/sql/MYSQL_RELAY_LOG::LOCK_sync_queue | NO | NO | +---------------------------------------------------------+---------+-------+ 20 rows in set (0.00 sec)
开启监控
MySQL [cjc]> update performance_schema.setup_instruments set enabled = 'YES' where name like '%lock%'; Query OK, 173 rows affected (0.00 sec) Rows matched: 180 Changed: 173 Warnings: 0
2.关闭自动提交 注意:关闭自动提交的用户权限需要小于启动mysql的用户权限,否则关闭自动提交不生效,而且没有任何提示。
MySQL [cjc]> set autocommit=0; Query OK, 0 rows affected (0.00 sec) MySQL [cjc]> show variables like 'autocommit'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | autocommit | OFF | +---------------+-------+ 1 row in set (0.00 sec)
3.会话1,删除表,不提交。 delete from t2; 4.会话2,可以正常查询表数据。
MySQL [cjc]> select * from t2; +------+------+ | id | age | +------+------+ | 1 | 100 | | 2 | 30 | | 3 | 80 | +------+------+ 3 rows in set (0.01 sec)
5.会话3,执行truncate操作,被阻塞 truncate table t2; 卡住 6.会话2,仍然可以查询表数据。
MySQL [cjc]> select * from t2; +------+------+ | id | age | +------+------+ | 1 | 100 | | 2 | 30 | | 3 | 80 | +------+------+ 3 rows in set (0.01 sec)
7.打开另一个新的会话4,无法查询数据,被阻塞 MySQL [cjc]> select * from t2; 卡住 8.打开会话5,执行数据库备份,被阻塞。 执行备份
[mysql@mysql01 backup]$ mysqldump -uroot -p cjc > /home/mysql/backup/cjc.sql
卡住 9.打开会话6,查询会话信息id 16,31,33都被阻塞
MySQL [(none)]> select id,host,user,command,time,state,info from information_schema.processlist where command !='sleep'; +----+-----------+------+---------+------+---------------------------------+---------------------------------------------------------------------------------------------------------+ | id | host | user | command | time | state | info | +----+-----------+------+---------+------+---------------------------------+---------------------------------------------------------------------------------------------------------+ | 34 | localhost | root | Query | 0 | executing | select id,host,user,command,time,state,info from information_schema.processlist where command !='sleep' | | 31 | localhost | cjc | Query | 253 | Waiting for table metadata lock | select * from t2 | | 16 | localhost | cjc | Query | 269 | Waiting for table metadata lock | truncate table t2 | | 33 | localhost | root | Query | 171 | Waiting for table metadata lock | LOCK TABLES `t1` READ /*!32311 LOCAL */,`t2` READ /*!32311 LOCAL */ | +----+-----------+------+---------+------+---------------------------------+---------------------------------------------------------------------------------------------------------+ 4 rows in set (0.00 sec)
10.查看锁阻塞源头
MySQL [(none)]> select * from performance_schema.metadata_locks where OWNER_THREAD_ID !=sys.ps_thread_id(connection_id())\G; *************************** 1. row *************************** OBJECT_TYPE: TABLE OBJECT_SCHEMA: cjc OBJECT_NAME: t2 OBJECT_INSTANCE_BEGIN: 139671541629072 LOCK_TYPE: SHARED_WRITE LOCK_DURATION: TRANSACTION LOCK_STATUS: GRANTED SOURCE: OWNER_THREAD_ID: 37 OWNER_EVENT_ID: 36 *************************** 2. row *************************** OBJECT_TYPE: GLOBAL OBJECT_SCHEMA: NULL OBJECT_NAME: NULL OBJECT_INSTANCE_BEGIN: 139671933907680 LOCK_TYPE: INTENTION_EXCLUSIVE LOCK_DURATION: STATEMENT LOCK_STATUS: GRANTED SOURCE: OWNER_THREAD_ID: 41 OWNER_EVENT_ID: 26 *************************** 3. row *************************** OBJECT_TYPE: SCHEMA OBJECT_SCHEMA: cjc OBJECT_NAME: NULL OBJECT_INSTANCE_BEGIN: 139671933882208 LOCK_TYPE: INTENTION_EXCLUSIVE LOCK_DURATION: TRANSACTION LOCK_STATUS: GRANTED SOURCE: OWNER_THREAD_ID: 41 OWNER_EVENT_ID: 26 *************************** 4. row *************************** OBJECT_TYPE: TABLE OBJECT_SCHEMA: cjc OBJECT_NAME: t2 OBJECT_INSTANCE_BEGIN: 139671933942976 LOCK_TYPE: EXCLUSIVE LOCK_DURATION: TRANSACTION LOCK_STATUS: PENDING SOURCE: OWNER_THREAD_ID: 41 OWNER_EVENT_ID: 26 *************************** 5. row *************************** OBJECT_TYPE: TABLE OBJECT_SCHEMA: cjc OBJECT_NAME: t2 OBJECT_INSTANCE_BEGIN: 139671799800656 LOCK_TYPE: SHARED_READ LOCK_DURATION: TRANSACTION LOCK_STATUS: PENDING SOURCE: OWNER_THREAD_ID: 56 OWNER_EVENT_ID: 9 *************************** 6. row *************************** OBJECT_TYPE: TABLE OBJECT_SCHEMA: cjc OBJECT_NAME: t1 OBJECT_INSTANCE_BEGIN: 139672135191008 LOCK_TYPE: SHARED_READ LOCK_DURATION: TRANSACTION LOCK_STATUS: GRANTED SOURCE: OWNER_THREAD_ID: 58 OWNER_EVENT_ID: 10 *************************** 7. row *************************** OBJECT_TYPE: TABLE OBJECT_SCHEMA: cjc OBJECT_NAME: t2 OBJECT_INSTANCE_BEGIN: 139672135191104 LOCK_TYPE: SHARED_READ LOCK_DURATION: TRANSACTION LOCK_STATUS: PENDING SOURCE: OWNER_THREAD_ID: 58 OWNER_EVENT_ID: 10 7 rows in set (0.10 sec) ERROR: No query specified
MySQL [(none)]> select THREAD_ID,PROCESSLIST_ID,name,type from performance_schema.threads where PROCESSLIST_ID is not NULL;
+-----------+----------------+--------------------------------+------------+ | THREAD_ID | PROCESSLIST_ID | name | type | +-----------+----------------+--------------------------------+------------+ | 28 | 3 | thread/sql/compress_gtid_table | FOREGROUND | | 37 | 12 | thread/sql/one_connection | FOREGROUND | | 41 | 16 | thread/sql/one_connection | FOREGROUND | | 56 | 31 | thread/sql/one_connection | FOREGROUND | | 57 | 32 | thread/sql/one_connection | FOREGROUND | | 58 | 33 | thread/sql/one_connection | FOREGROUND | | 59 | 34 | thread/sql/one_connection | FOREGROUND | +-----------+----------------+--------------------------------+------------+ 7 rows in set (0.00 sec
可以看到阻塞源头是THREAD_ID=37 PROCESSLIST_ID=12
| 37 | 12 | thread/sql/one_connection | FOREGROUND | select * from performance_schema.events_statements_current where thread_id=37\G;
查看最后一次执行的命令
MySQL [(none)]> select * from performance_schema.events_statements_current where thread_id=37\G; *************************** 1. row *************************** THREAD_ID: 37 EVENT_ID: 35 END_EVENT_ID: 35 EVENT_NAME: statement/sql/delete SOURCE: TIMER_START: 6409813713486000 TIMER_END: 6409813929865000 TIMER_WAIT: 216379000 LOCK_TIME: 64000000 SQL_TEXT: delete from t2 DIGEST: 3ba93c5fbd4c5721001bc1856c74459a DIGEST_TEXT: DELETE FROM `t2` CURRENT_SCHEMA: cjc OBJECT_TYPE: NULL OBJECT_SCHEMA: NULL OBJECT_NAME: NULL OBJECT_INSTANCE_BEGIN: NULL MYSQL_ERRNO: 0 RETURNED_SQLSTATE: 00000 MESSAGE_TEXT: NULL ERRORS: 0 WARNINGS: 0 ROWS_AFFECTED: 3 ROWS_SENT: 0 ROWS_EXAMINED: 3 CREATED_TMP_DISK_TABLES: 0 CREATED_TMP_TABLES: 0 SELECT_FULL_JOIN: 0 SELECT_FULL_RANGE_JOIN: 0 SELECT_RANGE: 0 SELECT_RANGE_CHECK: 0 SELECT_SCAN: 0 SORT_MERGE_PASSES: 0 SORT_RANGE: 0 SORT_ROWS: 0 SORT_SCAN: 0 NO_INDEX_USED: 0 NO_GOOD_INDEX_USED: 0 NESTING_EVENT_ID: NULL NESTING_EVENT_TYPE: NULL NESTING_EVENT_LEVEL: 0 1 row in set (0.00 sec) ERROR: No query specified
在刚刚执行delete操作的窗口查询,确实是12。
MySQL [cjc]> select connection_id(); +-----------------+ | connection_id() | +-----------------+ | 12 | +-----------------+ 1 row in set (0.00 sec)
11.终止12会话 MySQL [(none)]> kill 12; Query OK, 0 rows affected (0.00 sec) 12.验证 查询t2数据已经被清空 MySQL [(none)]> select * from cjc.t2; Empty set (0.00 sec) 锁已释放 MySQL [(none)]> select id,host,user,command,time,state,info from information_schema.processlist where command !='sleep' and user !='root';
###chenjuchao 20220612###
