MySQL复制从库延迟原因深入分析

数据运维 2024-05-08 穿过生命散发芬芳 手机阅读

背景介绍

近来一套业务系统，从库一直处于延迟状态，无法追上主库，导致业务风险较大。

从资源上看，从库的CPU、IO、网络使用率较低，不存在服务器压力过高导致回放慢的情况；从库开启了并行回放；在从库上执行 SHOW PROCESSLIST 看到没有回放线程阻塞，回放一直在持续；解析relay log日志文件，发现其中并没大事务回放。

过程分析

现象确认

收到运维同事的反馈，有一套从库延迟的非常厉害，提供了SHOW SLAVE STATUS
延迟的截图信息

MySQL复制从库延迟原因深入分析-每日运维

持续观察了一阵SHOW SLAVE STATUS
的变化，发现pos点位信息在不停的变化，Seconds_Behind_master 也是不停的变化的，总体趋势还在不停的变大。

资源使用

观察了服务器资源使用情况，可以看到占用非常低

MySQL复制从库延迟原因深入分析-每日运维

观察从库进程情况，基本上只能看到有一个线程在回放工作

MySQL复制从库延迟原因深入分析-每日运维

并行回放参数说明

在主库设置了binlog_transaction_dependency_tracking = WRITESET

在从库设置了slave_parallel_type = LOGICAL_CLOCK
和slave_parallel_workers = 64

error log日志对比

从error log中取并行回放的日志进行分析

$ grep 010559 100werror3306.log | tail -n 3<br>2024-01-31T14:07:50.172007+08:00 6806 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel 'cluster': seconds elapsed = 120; events assigned = 3318582273; worker queues filled over overrun level = 207029; waite<br>d due a Worker queue full = 238; waited due the total size = 0; waited at clock conflicts = 348754579743300 waited (count) when Workers occupied = 34529247 waited when Workers occupied = 76847369713200<br><br>2024-01-31T14:09:50.078829+08:00 6806 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel 'cluster': seconds elapsed = 120; events assigned = 3319256065; worker queues filled over overrun level = 207029; waite<br>d due a Worker queue full = 238; waited due the total size = 0; waited at clock conflicts = 348851330164000 waited (count) when Workers occupied = 34535857 waited when Workers occupied = 76866419841900<br><br>2024-01-31T14:11:50.060510+08:00 6806 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel 'cluster': seconds elapsed = 120; events assigned = 3319894017; worker queues filled over overrun level = 207029; waite<br>d due a Worker queue full = 238; waited due the total size = 0; waited at clock conflicts = 348943740455400 waited (count) when Workers occupied = 34542790 waited when Workers occupied = 76890229805500<br>

并行度统计

众所周知，MySQL 从库并行回放主要依赖于 binlog 中的  last_commmitted 来做判断，如果事务的 last_commmitted 相同，则基本上可以认为这些事务可以并行回放，下面从环境中获取一个relay log进行并行回放的大概统计

$ mysqlsqlbinlog --no-defaults mysql-bin.046638 |grep -o 'last_committed.*' | sed 's/=/ /g' | awk '{print $2}' |sort -n | uniq -c |awk 'BEGIN {print "last_commited group_count Percentage"} {count[$2]=$1<br>; sum+=$1} END {for (i in count) printf "%d %d %.2f%%\n", i, count[i], (count[i]/sum)*100|"sort -k 1,1n"}' | awk '{if($2>=1 && $2 10){sum+=$2}} END {print sum}'<br>314694<br>

  1. last_commmitted 设置为 m_writeset_history_start，此值为 m_writeset_history 列表中最小的 sequence_number。

  2. 遍历事务的 writeset 列表

    a 如果某个 writeset 在全局 m_writeset_history 中不存在，构建一个 pair