Mysql 线程sleep mysql 线程killed三个小时了

转载

mob6454cc70cb6b 2023-07-08 17:00:49

文章标签 Mysql 线程sleep killed 状态 sql 无法 kill sql Server 文章分类 MySQL 数据库

1.版本

1)操作系统

cat /proc/version
Linux version 3.10.0-1127.18.2.el7.x86_64 (mockbuild@kbuilder.bsys.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-39) (GCC) ) #1 SMP Sun Jul 26 15:27:06 UTC 2020

2)mysql数据库版本

mysql> select version();
+-----------+
| version() |
+-----------+
| 8.0.19 |
+-----------+
1 row in set (0.00 sec)

2.问题描述

2.1 发现问题
工作中发现一些会话被kill后一直处于 killed 状态，无法正常结束。

Mysql 线程sleep mysql 线程killed三个小时了_killed 状态

#这么长时间未结束，肯定是有异常的。数据库服务器资源使用如下：

Mysql 线程sleep mysql 线程killed三个小时了_sql 无法 kill_02

## cpu 使用率异常高(服务器8个逻辑cpu)，数据库活跃会话如下(库名，表名已处理)

mysql> select ID,DB,COMMAND,TIME,STATE,substring(INFO, 1, 80),concat('kill ',ID,';') kill_sql   from information_schema.processlist where COMMAND !='Sleep' and COMMAND not like 'Binlog Dump%' and id !=connection_id() order by TIME\G;
*************************** 1. row ***************************
                    ID: 30478672
                    DB: test_job_plat
               COMMAND: Connect
                  TIME: 0
                 STATE: updating
substring(INFO, 1, 80): DELETE FROM test_job_plat.test_job_qrtz_trigger_log WHERE trigger_time < DATE(DAT
              kill_sql: kill 30478672;
*************************** 2. row ***************************
                    ID: 29820448
                    DB: test_pay_order
               COMMAND: Query
                  TIME: 0
                 STATE: waiting for handler commit
substring(INFO, 1, 80): SELECT  sum(driver_amount) as test_order_amount
        FROM t_pay_order
        WHER
              kill_sql: kill 29820448;
*************************** 3. row ***************************
                    ID: 29964731
                    DB: test_lr_order
               COMMAND: Query
                  TIME: 0
                 STATE: update
substring(INFO, 1, 80): insert into test_order_review_flow ( order_no, flow_no, guid, flow_type, message_ty
              kill_sql: kill 29964731;
*************************** 4. row ***************************
                    ID: 4
                    DB: NULL
               COMMAND: Daemon
                  TIME: 0
                 STATE: Waiting for next activation
substring(INFO, 1, 80): NULL
              kill_sql: kill 4;
*************************** 5. row ***************************
                    ID: 30454412
                    DB: test_pay_account
               COMMAND: Query
                  TIME: 0
                 STATE: starting
substring(INFO, 1, 80): select account_id from test_wal_user_wallet_account where uid='Dfc15560c53714a5aa71
              kill_sql: kill 30454412;
*************************** 6. row ***************************
                    ID: 29964869
                    DB: test_lr_settlement
               COMMAND: Query
                  TIME: 0
                 STATE: update
substring(INFO, 1, 80): insert into test_statement_order_track ( is_lasted,  order_no,  biz_type,  vehicle_
              kill_sql: kill 29964869;
*************************** 7. row ***************************
                    ID: 29964725
                    DB: test_lr_order
               COMMAND: Query
                  TIME: 0
                 STATE: update
substring(INFO, 1, 80): insert into test_order_review_flow ( order_no, flow_no, guid, flow_type, message_ty
              kill_sql: kill 29964725;
*************************** 8. row ***************************
                    ID: 9609259
                    DB: test_cms_config
               COMMAND: Query
                  TIME: 1
                 STATE: executing
substring(INFO, 1, 80): SELECT tcvf.id, tcvf.config_type, tcvf.config_file_name, tcvf.size  FROM test_cfg_v
              kill_sql: kill 9609259;
*************************** 9. row ***************************
                    ID: 13489028
                    DB: test_cms_config
               COMMAND: Query
                  TIME: 2
                 STATE: executing
substring(INFO, 1, 80): SELECT tcvf.id, tcvf.config_type, tcvf.config_file_name, tcvf.size  FROM test_cfg_v
              kill_sql: kill 13489028;
*************************** 10. row ***************************
                    ID: 30161038
                    DB: test_trip_netveh
               COMMAND: Query
                  TIME: 20
                 STATE: executing
substring(INFO, 1, 80): SELECT distinct driver_id FROM test_driver_time WHERE update_time > date_sub(now(),
              kill_sql: kill 30161038;
*************************** 11. row ***************************
                    ID: 30477068
                    DB: test_info
               COMMAND: Query
                  TIME: 51
                 STATE: Waiting for table flush
substring(INFO, 1, 80): insert into test_span_info_minute(minute, service_name, ip, type, action, stats_ser
              kill_sql: kill 30477068;
*************************** 12. row ***************************
                    ID: 30474567
                    DB: testest_t_coupon
               COMMAND: Query
                  TIME: 126
                 STATE: executing
substring(INFO, 1, 80): select status from test_t_coupon where order_no='6bb08eadAae306Aa4e7bAab1a1Aa14f8bdef
              kill_sql: kill 30474567;
*************************** 13. row ***************************
                    ID: 30474518
                    DB: testest_t_coupon
               COMMAND: Query
                  TIME: 128
                 STATE: executing
substring(INFO, 1, 80): select status from test_t_coupon where order_no='455e4b96Aa3321Aa466eAaade5Aab8f53a58
              kill_sql: kill 30474518;
*************************** 14. row ***************************
                    ID: 30468705
                    DB: test_info
               COMMAND: Query
                  TIME: 292
                 STATE: Waiting for table flush
substring(INFO, 1, 80): insert into test_span_info_minute(minute, service_name, ip, type, action, stats_ser
              kill_sql: kill 30468705;
*************************** 15. row ***************************
                    ID: 29110810
                    DB: NULL
               COMMAND: Query
                  TIME: 41052
                 STATE: Waiting for table flush
substring(INFO, 1, 80): show create table `test_info`.`test_span_info_minute`
              kill_sql: kill 29110810;
*************************** 16. row ***************************
                    ID: 26884899
                    DB: NULL
               COMMAND: Query
                  TIME: 99552
                 STATE: Waiting for table flush
substring(INFO, 1, 80): show create table `test_info`.`test_span_info_minute`
              kill_sql: kill 26884899;
*************************** 17. row ***************************
                    ID: 16892083
                    DB: NULL
               COMMAND: Query
                  TIME: 383144
                 STATE: Waiting for table flush
substring(INFO, 1, 80): show create table `test_info`.`test_span_info_minute`
              kill_sql: kill 16892083;
*************************** 18. row ***************************
                    ID: 15741584
                    DB: test_info
               COMMAND: Killed
                  TIME: 420354
                 STATE: executing
substring(INFO, 1, 80): SELECT COUNT(1) FROM test_span_info_minute WHERE 1
              kill_sql: kill 15741584;
*************************** 19. row ***************************
                    ID: 15572803
                    DB: test_info
               COMMAND: Killed
                  TIME: 425803
                 STATE: executing
substring(INFO, 1, 80): SELECT COUNT(1) FROM test_span_info_minute WHERE 1
              kill_sql: kill 15572803;
*************************** 20. row ***************************
                    ID: 15153874
                    DB: test_info
               COMMAND: Killed
                  TIME: 435244
                 STATE: executing
substring(INFO, 1, 80): SELECT COUNT(1) FROM test_span_info_minute WHERE 1
              kill_sql: kill 15153874;
*************************** 21. row ***************************
                    ID: 14806283
                    DB: test_info
               COMMAND: Killed
                  TIME: 446256
                 STATE: executing
substring(INFO, 1, 80): SELECT COUNT(1) FROM test_span_info_minute WHERE 1
              kill_sql: kill 14806283;
21 rows in set (0.01 sec)

ERROR: 
No query specified

perf top -p 结果如下

Mysql 线程sleep mysql 线程killed三个小时了_Mysql 线程sleep_03

3. 处理方案

##尝试关闭实例，发现实例 shutdown 的操作也一致被卡主。最后 kill -9 mysqld 进程后重启数据库恢复

mysqladmin -uroot -p -h127.0.0.1 -P3306 shutdown 后一直卡在 [Note] [MY-010043] [Server] Event Scheduler: Purging the queue. 0 events(这时mysqld函数调用情况也是Parallel_reader::Ctx::move_to_next_node)

2021-03-05T10:13:10.365056+08:00 3192266 [System] [MY-013172] [Server] Received SHUTDOWN from user dba_pit. Shutting down mysqld (Version: 8.0.19).
2021-03-05T10:13:10.382309+08:00 0 [Note] [MY-010067] [Server] Giving 14 client threads a chance to die gracefully
2021-03-05T10:13:10.382376+08:00 0 [Note] [MY-010117] [Server] Shutting down slave threads
2021-03-05T10:13:10.392506+08:00 0 [Note] [MY-010054] [Server] Event Scheduler: Killing the scheduler thread, thread id 4
2021-03-05T10:13:10.392535+08:00 0 [Note] [MY-010050] [Server] Event Scheduler: Waiting for the scheduler thread to reply
2021-03-05T10:13:10.392638+08:00 0 [Note] [MY-010048] [Server] Event Scheduler: Stopped
2021-03-05T10:13:12.392752+08:00 0 [Note] [MY-010118] [Server] Forcefully disconnecting 13 remaining clients
2021-03-05T10:13:12.392817+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3151976  user: 'dba_pit'.
2021-03-05T10:13:12.392833+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3190089  user: 'dba_pit'.
2021-03-05T10:13:12.392963+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3189754  user: 'dba_pit'.
2021-03-05T10:13:12.393036+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3189746  user: 'dba_pit'.
2021-03-05T10:13:12.393085+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3190914  user: 'dba_pit'.
2021-03-05T10:13:12.393234+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3190084  user: 'dba_pit'.
2021-03-05T10:13:12.393280+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 2962052  user: 'common_msgservice'.
2021-03-05T10:13:12.393656+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3191972  user: 'dba_pit'.
2021-03-05T10:13:12.393807+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3191981  user: 'dba_pit'.
2021-03-05T10:13:12.394091+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3189277  user: 'dba_pit'.
2021-03-05T10:13:12.394134+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3189749  user: 'dba_pit'.
2021-03-05T10:13:12.394223+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3191462  user: 'dba_pit'.
2021-03-05T10:13:12.394358+08:00 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 3191039  user: 'dba_pit'.
2021-03-05T10:13:12.394423+08:00 0 [Note] [MY-010043] [Server] Event Scheduler: Purging the queue. 0 events

https://bugs.mysql.com/bug.php?id=100326

本文章为转载内容，我们尊重原作者对文章享有的著作权。如有内容错误或侵权问题，欢迎原作者联系我们进行内容更正或删除文章。