MySQL数据延迟跳动的问题分析

数据库 MySQL
今天分析了另外一个关于数据库延迟跳动的问题,也算是比较典型,这个过程中也有一些分析问题的方法和技巧工参考。

 今天分析了另外一个关于数据库延迟跳动的问题,也算是比较典型,这个过程中也有一些分析问题的方法和技巧工参考。

[[338618]]

首先在高可用检测中,有一套环境的检测时断时续,经过排查发现是数据库产生了延迟,在登录到从库show slave status查看,会发现Seconds_behind_master的值是不断跳动的,即从0~39~0~39这样的频率不断跳动,让人很搓火。

查看数据库的相关日志发现竟然没有任何可以参考的日志记录,怎么分析这个问题呢,我们先来复现,于是我按照节奏抓取了3次问题出现的日志,即通过show slave status连续监测,抓取show slave status输出的结果保存下来,这样我们就得到了一个问题发生过程中的偏移量变化,而这个变化则是在SQLThread在回放过程中产生的问题。

比如下面的一段输出,我截取的是Slave端的relay log进行分析,相应的字段为Relay_Log_Pos

 

  1. Slave_IO_State: Waiting for master to send event 
  2.                   Master_Host: xxxx 
  3.                   Master_User: dba_repl 
  4.                   Master_Port: 4306 
  5.                 Connect_Retry: 60 
  6.               Master_Log_File: mysqlbin.000044 
  7.           Read_Master_Log_Pos: 386125369 
  8.                Relay_Log_File: slave-relay-bin.000066 
  9.                 Relay_Log_Pos: 386125580 
  10.         Relay_Master_Log_File: mysqlbin.000044 

所以很快得到了偏移量的变化情况:385983806 ,386062813 ,386125580

接着我使用mysqlbinlog开始分析这些日志过程中的明细,根据如下的命令可以很快得到转储的日志中相关的表有3张。

 

  1. # grep INSERT  relaylog_xxxx.dump |awk '{print $3 " " $4}'|sed 's/INTO//g'|sort|uniq 
  2.  act_action_exec_info 
  3.  act_join_desc 
  4.  dic_subsidy_marketing_querylog_202008 

我逐步分析了每张表的数据操作情况,得到的信息还是比较有限,继续做更进一步的分析,比如我们分析一下整个日志中的事务量大小:

 

  1. # mysqlbinlog slave-relay-bin.000066 | grep "GTID$(printf '\t')last_committed" -B 1 \ 
  2. >                                     | grep -E '^# at' | awk '{print $3}' \ 
  3. >                                     | awk 'NR==1 {tmp=$1} NR>1 {print ($1-tmp);tmp=$1}' \ 
  4. >                                     | sort -n -r | head -n 100 
  5. mysqlbinlog: [Warning] unknown variable 'loose-default-character-set=utf8' 
  6. 5278 
  7. 5268 
  8. 5268 
  9. 5268 
  10. 5253 
  11. 5253 
  12. 5253 
  13. 5253 
  14. 5253 

可以看到是5K左右,算是比较大了,而这些额外的信息从哪里获得呢,我在主库开启了general_log,这样就能够得到更细粒度的操作日志了。

进一步分析发现,整个业务使用了显示事务的方式:SET autocommit=0,整个事务中包含了几个大SQL,里面存储了很多操作日志明细,而且在事务操作过程中还基于Mybatis框架调用了多次select count(1) from xxx的操作。

经过和业务沟通也基本明确了以上问题。

 

责任编辑:华轩 来源: 杨建荣的学习笔记
相关推荐

2023-12-28 11:18:01

MySQL数据库级联从库

2024-03-08 17:54:44

MySQL函数数据

2017-12-27 13:07:52

数据库MySQL主从复制

2023-06-12 08:18:19

MySQLDDL数据

2019-07-16 06:30:19

MySQL同步延迟数据库

2023-06-07 17:21:43

大数据低延迟分析

2020-09-21 14:15:58

Redis数据库命令

2018-02-01 13:22:50

数据库MySQL同步延迟

2018-07-16 11:16:59

MYSQL磁盘IO数据库

2018-04-25 09:56:35

MYSQLCPU数据库

2021-11-08 15:38:15

消息延迟堆积

2017-07-19 09:53:42

Oracle分区问题

2022-07-18 16:02:10

数据库实践

2017-12-04 10:56:47

MySQL问题分析解决对策

2022-07-08 17:13:32

MySQL数据死锁

2018-04-04 13:44:59

数据库MySQL延迟

2019-05-14 16:17:03

MySQL延迟从库数据库

2021-03-26 10:40:16

MySQL锁等待死锁

2022-03-07 10:41:09

云计算容器Kubernetes

2009-09-09 09:48:43

Linq延迟加载
点赞
收藏

51CTO技术栈公众号