20220612-MySQL数据库故障分析-锁等待(一)

在这里插入图片描述

环境说明:

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###
欢迎关注我的公众号《IT小Chen

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值