前往小程序,Get更优阅读体验!
立即前往
首页
学习
活动
专区
工具
TVP
发布
社区首页 >专栏 >备库大的select查询处于killed状态导致备库延迟

备库大的select查询处于killed状态导致备库延迟

原创
作者头像
wangwei-dba
修改2021-06-23 14:17:29
1.4K0
修改2021-06-23 14:17:29
举报
文章被收录于专栏:mysql-dbamysql-dba

mysql版本Version:8.0.18

从监控上看备库延迟越来越大

主从延迟监控
主从延迟监控

show processlist 查看mysql线程

备库在应用主库同步的DDL操作语句处于Waiting for table metadata lock

还看都一个操作相关表的select count(*)操作 ,但这个查询语句处于killed状态

查看事务表select * from information_schema.innodb_trx发现这个select count(*)操作一直在running状态

再次kill这个这个查询,发现查询还是处于killed,事务表中也是一直running

ddl操作语句就是在等待这个查询释放元数据锁,查询一直处于killed状态,所以延迟越来越大

1.尝试停止复制 stop slave命令操作挂起停止不了

2.尝试kill掉复制线程执行的ddl操作,观察select count(*) 还是处于killed状态,启动复制ddl还是处于Waiting for table metadata lock

3.尝试正常停止mysql shutdown 停止操作也挂起

代码语言:javascript
复制
2021-06-22T21:08:39.942759+08:00 899941 [System] [MY-013172] [Server] Received SHUTDOWN from user root. Shutting down mysqld (Version: 8.0.18).
2021-06-22T21:08:40.593579+08:00 0 [Note] [MY-010067] [Server] Giving 56 client threads a chance to die gracefully
2021-06-22T21:08:40.594861+08:00 0 [Note] [MY-010117] [Server] Shutting down slave threads
2021-06-22T21:08:40.596045+08:00 0 [Note] [MY-010054] [Server] Event Scheduler: Killing the scheduler thread, thread id 8
2021-06-22T21:08:40.596081+08:00 0 [Note] [MY-010050] [Server] Event Scheduler: Waiting for the scheduler thread to reply
2021-06-22T21:08:40.596253+08:00 0 [Note] [MY-010048] [Server] Event Scheduler: Stopped
2021-06-22T21:08:42.600319+08:00 0 [Note] [MY-010118] [Server] Forcefully disconnecting 14 remaining clients
2021-06-22T21:08:42.600367+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899872  user: 'root'.
2021-06-22T21:08:42.600413+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899897  user: 'root'.
2021-06-22T21:08:42.600451+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 900002  user: 'root'.
2021-06-22T21:08:42.600485+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899898  user: 'root'.
2021-06-22T21:08:42.600523+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899995  user: 'root'.
2021-06-22T21:08:42.600582+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899851  user: 'root'.
2021-06-22T21:08:42.600618+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899747  user: 'root'.
2021-06-22T21:08:42.600633+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899932  user: 'root'.
2021-06-22T21:08:42.600663+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899988  user: 'root'.
2021-06-22T21:08:42.600697+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899989  user: 'root'.
2021-06-22T21:08:42.600737+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899893  user: 'root'.
2021-06-22T21:08:42.600819+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 182  user: 'root'.
2021-06-22T21:08:42.600910+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899871  user: 'root'.
2021-06-22T21:08:42.600955+08:00 0 [Warning] [MY-010909] [Server] /usr/local/mysql/bin/mysqld: Forcing close of thread 899999  user: 'root'.
2021-06-22T21:08:42.601007+08:00 0 [Note] [MY-010043] [Server] Event Scheduler: Purging the queue. 0 events

4.最后只能kill -9 mysqld的进程,然后再重新启动mysql

代码语言:javascript
复制
2021-06-22T21:11:33.091811+08:00 0 [Warning] [MY-011069] [Server] The syntax '--slave-rows-search-algorithms' is deprecated and will be removed in a future release.
2021-06-22T21:11:33.094381+08:00 0 [Warning] [MY-010101] [Server] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2021-06-22T21:11:33.094526+08:00 0 [Note] [MY-010949] [Server] Basedir set to /usr/local/mysql-8.0.18-linux-glibc2.12-x86_64/.
2021-06-22T21:11:33.094543+08:00 0 [System] [MY-010116] [Server] /usr/local/mysql/bin/mysqld (mysqld 8.0.18) starting as process 30056
2021-06-22T21:11:33.097219+08:00 0 [Warning] [MY-013242] [Server] --character-set-server: 'utf8' is currently an alias for the character set UTF8MB3, but will be an alias for UTF8MB4 in a future release. Please consider using UTF8MB4 in order to be unambiguous.
2021-06-22T21:11:33.110038+08:00 0 [Note] [MY-012366] [InnoDB] Using Linux native AIO
2021-06-22T21:11:33.110291+08:00 0 [Warning] [MY-013267] [InnoDB] The setting INNODB_UNDO_TABLESPACES is deprecated and is no longer used.  InnoDB always creates 2 undo tablespaces to start with. If you need more, please use CREATE UNDO TABLESPACE.
2021-06-22T21:11:33.110637+08:00 0 [Note] [MY-010747] [Server] Plugin 'FEDERATED' is disabled.
2021-06-22T21:11:33.117187+08:00 1 [Note] [MY-012944] [InnoDB] Uses event mutexes
2021-06-22T21:11:33.119270+08:00 1 [Note] [MY-013251] [InnoDB] Number of pools: 1
2021-06-22T21:11:33.119645+08:00 1 [Note] [MY-012951] [InnoDB] Not using CPU crc32 instructions
2021-06-22T21:11:33.120718+08:00 1 [Note] [MY-012203] [InnoDB] Directories to scan './;./;undolog'
2021-06-22T21:11:33.120919+08:00 1 [Note] [MY-012204] [InnoDB] Scanning './'
2021-06-22T21:11:34.062668+08:00 1 [Note] [MY-012208] [InnoDB] Completed space ID check of 1824 files.
2021-06-22T21:11:34.065216+08:00 1 [Note] [MY-012955] [InnoDB] Initializing buffer pool, total size = 20.000000G, instances = 4, chunk size =128.000000M
2021-06-22T21:11:35.997031+08:00 1 [Note] [MY-012957] [InnoDB] Completed initialization of buffer pool
2021-06-22T21:11:36.047647+08:00 0 [Note] [MY-011952] [InnoDB] If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2021-06-22T21:11:36.117710+08:00 1 [Note] [MY-012560] [InnoDB] The log sequence number 34857307986779 in the system tablespace does not match the log sequence number 46364465298844 in the ib_logfiles!
2021-06-22T21:11:36.117905+08:00 1 [Note] [MY-012551] [InnoDB] Database was not shutdown normally!
2021-06-22T21:11:36.118027+08:00 1 [Note] [MY-012552] [InnoDB] Starting crash recovery.
2021-06-22T21:11:36.121404+08:00 1 [Note] [MY-013086] [InnoDB] Starting to parse redo log at lsn = 46364465298473, whereas checkpoint_lsn = 46364465298844
2021-06-22T21:11:36.121564+08:00 1 [Note] [MY-012550] [InnoDB] Doing recovery: scanned up to log sequence number 46364465298844
2021-06-22T21:11:36.158466+08:00 1 [Note] [MY-013083] [InnoDB] Log background threads are being started...
2021-06-22T21:11:36.159180+08:00 1 [Note] [MY-012532] [InnoDB] Applying a batch of 0 redo log records ...
2021-06-22T21:11:36.159345+08:00 1 [Note] [MY-012535] [InnoDB] Apply batch completed!
2021-06-22T21:11:36.260456+08:00 1 [Note] [MY-013252] [InnoDB] Using undo tablespace './undolog/undo_001'.
2021-06-22T21:11:36.261472+08:00 1 [Note] [MY-013252] [InnoDB] Using undo tablespace './undolog/undo_002'.
2021-06-22T21:11:36.265180+08:00 1 [Note] [MY-012910] [InnoDB] Opened 2 existing undo tablespaces.
2021-06-22T21:11:36.265373+08:00 1 [Note] [MY-011980] [InnoDB] GTID recovery trx_no: 29493469719
2021-06-22T21:11:36.545810+08:00 1 [Note] [MY-012255] [InnoDB] Removed temporary tablespace data file: "ibtmp1"
2021-06-22T21:11:36.545993+08:00 1 [Note] [MY-012923] [InnoDB] Creating shared tablespace for temporary tables
2021-06-22T21:11:36.546176+08:00 1 [Note] [MY-012265] [InnoDB] Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2021-06-22T21:11:36.614254+08:00 1 [Note] [MY-012266] [InnoDB] File './ibtmp1' size is now 12 MB.
2021-06-22T21:11:36.614610+08:00 1 [Note] [MY-011825] [InnoDB] Scanning temp tablespace dir:'./#innodb_temp/'
2021-06-22T21:11:36.682093+08:00 1 [Note] [MY-013018] [InnoDB] Created 128 and tracked 128 new rollback segment(s) in the temporary tablespace. 128 are now active.
2021-06-22T21:11:36.682863+08:00 1 [Note] [MY-012976] [InnoDB] 8.0.18 started; log sequence number 46364465298844
2021-06-22T21:11:36.697816+08:00 1 [Note] [MY-011089] [Server] Data dictionary restarting version '80017'.
2021-06-22T21:11:36.868743+08:00 1 [Note] [MY-012357] [InnoDB] Reading DD tablespace files
2021-06-22T21:11:37.174511+08:00 1 [Note] [MY-012356] [InnoDB] Validated 1826/1826  tablespaces
2021-06-22T21:11:37.196510+08:00 1 [Note] [MY-010006] [Server] Using data dictionary with version '80017'.
2021-06-22T21:11:37.252967+08:00 0 [Note] [MY-010855] [Server] Recovering after a crash using /data_binlog/mysql/mysql3312/logs/mysql-bin
2021-06-22T21:11:37.643538+08:00 0 [System] [MY-010229] [Server] Starting crash recovery...
2021-06-22T21:11:37.651222+08:00 0 [System] [MY-010232] [Server] Crash recovery finished.
2021-06-22T21:11:37.659491+08:00 0 [Note] [MY-012487] [InnoDB] DDL log recovery : begin
2021-06-22T21:11:37.660204+08:00 0 [Note] [MY-012488] [InnoDB] DDL log recovery : end
2021-06-22T21:11:37.660978+08:00 0 [Note] [MY-011946] [InnoDB] Loading buffer pool(s) from /data/mysql/mysql3312/data/ib_buffer_pool
2021-06-22T21:11:37.676498+08:00 0 [Note] [MY-012922] [InnoDB] Waiting for purge to start
2021-06-22T21:11:38.078245+08:00 0 [Note] [MY-010182] [Server] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2021-06-22T21:11:38.078625+08:00 0 [Note] [MY-010304] [Server] Skipping generation of SSL certificates as certificate files are present in data directory.
2021-06-22T21:11:38.081555+08:00 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2021-06-22T21:11:38.081943+08:00 0 [Note] [MY-010308] [Server] Skipping generation of RSA key pair through --sha256_password_auto_generate_rsa_keys as key files are present in data directory.
2021-06-22T21:11:38.082164+08:00 0 [Note] [MY-010308] [Server] Skipping generation of RSA key pair through --caching_sha2_password_auto_generate_rsa_keys as key files are present in data directory.
2021-06-22T21:11:38.083177+08:00 0 [Note] [MY-010252] [Server] Server hostname (bind-address): '*'; port: 3312

启动好之后,查询事务表select * from information_schema.innodb_trx发现事务记录已经没有了

启动复制start slave

复制恢复正常,过一段时间复制延迟变为0了

最后疑问不知道为什么kill掉select 会话一直处于killed的状态不释放,查询资料发现bug

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

bug描述
bug描述

原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。

如有侵权,请联系 cloudcommunity@tencent.com 删除。

原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。

如有侵权,请联系 cloudcommunity@tencent.com 删除。

评论
登录后参与评论
0 条评论
热度
最新
推荐阅读
相关产品与服务
云数据库 SQL Server
腾讯云数据库 SQL Server (TencentDB for SQL Server)是业界最常用的商用数据库之一,对基于 Windows 架构的应用程序具有完美的支持。TencentDB for SQL Server 拥有微软正版授权,可持续为用户提供最新的功能,避免未授权使用软件的风险。具有即开即用、稳定可靠、安全运行、弹性扩缩等特点。
领券
问题归档专栏文章快讯文章归档关键词归档开发者手册归档开发者手册 Section 归档