xtrabackup throttle参数及相关问题分析

妖狐艹你老母 2022-12-20 03:15 95阅读 0赞

percona提供的在线物理备份工具xtrabackup相信玩mysql的同学都不陌生。其实现原理和潜在的风险网上已经有很多描述（[1][]、[2][]）。在此不造轮子。本篇文章从一个备份出错例子出发，分析throttle参数对备份的影响。

**问题描述**

看看xtrabackup备份出错日志：

xtrabackup: uses posix\_fadvise().

xtrabackup: cd to /xxx/mysql\_data

xtrabackup: open files limit requested 65534, set to 65535

xtrabackup: using the following InnoDB configuration:

xtrabackup: innodb\_data\_home\_dir = .

xtrabackup: innodb\_data\_file\_path = ibdata1:512M:autoextend

xtrabackup: innodb\_log\_group\_home\_dir = ./

xtrabackup: innodb\_log\_files\_in\_group = 4

xtrabackup: innodb\_log\_file\_size = 2147483648

xtrabackup: using O\_DIRECT

InnoDB: Number of pools: 1

xtrabackup: error: log block numbers mismatch:

xtrabackup: error: expected log block no. 402310195, but got no. 419087395 from the log file.

xtrabackup: error: it looks like InnoDB log has wrapped around before xtrabackup could process all records due to either log copying being too slow, or log files being too small.

xtrabackup: Error: xtrabackup\_copy\_logfile() failed.

看起来还没有开始备份数据就出错了。出错信息很明确，就是读取的日志block number跟预期的block number不一致，进一步得出结论是可能redo拷贝速度比redo产生速度慢，或者举例更好的例子，在ring buffer下，消费速度赶不上生产速度，被生产者套圈了。对应的源码在xtrabackup\_scan\_log\_recs()里，如下：

![0062a86af789279c651254870034c5c9.png][]

如果读取的redo log的lsn换算成的block number与预期的block number不等，但redo log的校验没有问题，则进入到if代码块中。如果读到的block number比预期小，且刚好小一轮，那么说明已经拷完所有的redo，也就是当前的redo log是旧的，对于类似的情况，可以结束redo拷贝（后面还会提到）。否则，先提示mismatch错误：

xtrabackup: error: log block numbers mismatch:

xtrabackup: error: expected log block no. 402310195, but got no. 419087395 from the log file.

进一步判断block number是否比预期大一轮，是的话提示redo log被覆盖：

xtrabackup: error: it looks like InnoDB log has wrapped around before xtrabackup could process all records due to either log copying being too slow, or log files being too small.

**问题分析**

![f302f5a67a775a755a4d0a7a24417452.png][]

从这个图（虽然目前已经不用innobackupex，但原理是一样的）可以看出，xtrabackup启动时会创建redo和ibd文件拷贝线程，这样，redo拷贝和ibd数据文件可以同时进行。拷贝ibd数据时会打印：

Copying ./ibdata1 to /xxx/backuptest/2018-09-06\_11-23-35/ibdata1

或

Copying ./mysql/plugin.ibd to /xxx/backuptest/2018-09-06\_11-23-35/mysql/plugin.ibd

那么问题来了，从日志上看，都还没有开始备份数据，怎么就出现redo被覆盖的错误呢？

**复现问题**

由于xtrabackup提示redo被覆盖，于是用iostat看了下系统负载情况，发现io利用率一直百分百，写入维持在100MB/s以上。这意味着，redo被覆盖的可能性是存在的。再看看xtrabackup备份参数：

sudo innobackupex --defaults-file=/xxx/my.cnf --slave-info --safe-slave-backup --safe-slave-backup-timeout=3600 --lock-wait-timeout=3600 --lock-wait-threshold=5 **--throttle=40** --lock-wait-query-type=all --socket=/tmp/mysql.sock --user=xxx --password=xxx /xxx/backuptest

重新执行一遍，还是上述错误，但发现在打印了日志“InnoDB: Number of pools: 1”，经过了数分钟才打印后续的错误信息。尝试将throttle参数去掉后，xtrabackup正常开始备份。重复几遍均是如此，基本上可以确定跟throttle参数有关。

**出错前在做什么**

现在的问题是：**加--throttle=40后报错前这段时间xtrabackup在做什么呢？** 使用gdb多次attach到xtrabackup进程上，每次的调用栈信息均如下所示：

\#0 0x00007f721838d344 in pthread\_cond\_wait@@GLIBC\_2.3.2 () from /lib/x86\_64-linux-gnu/libpthread.so.0

\#1 0x0000000000aa991b in wait (this=<optimized out>)

at /home/rds-user/percona-xtrabackup/storage/innobase/os/[http://os0event.cc:165][http_os0event.cc_165]

\#2 os\_event::wait\_low (this=0x27384f0, reset\_sig\_count=<optimized out>)

at /home/rds-user/percona-xtrabackup/storage/innobase/os/[http://os0event.cc:335][http_os0event.cc_335]

\#3 0x00000000008e53dd in xtrabackup\_copy\_logfile (from\_lsn=910958226733, is\_last=is\_last@entry=0 '\\000')

at /home/rds-user/percona-xtrabackup/storage/innobase/xtrabackup/src/[http://xtrabackup.cc:3075][http_xtrabackup.cc_3075]

\#4 0x00000000008e6406 in xtrabackup\_backup\_func ()

at /home/rds-user/percona-xtrabackup/storage/innobase/xtrabackup/src/[http://xtrabackup.cc:4762][http_xtrabackup.cc_4762]

\#5 0x00000000008bfe65 in main (argc=<optimized out>, argv=<optimized out>)

at /home/rds-user/percona-xtrabackup/storage/innobase/xtrabackup/src/[http://xtrabackup.cc:8702][http_xtrabackup.cc_8702]

对应代码：

![095174018447a9589b1a95389285355f.png][]

xtrabackup每次从redo log文件读取数据（log\_group\_read\_log\_seg()）前都会执行xtrabackup\_io\_throttling()，函数实现如下：

![f62c966eb4d7b02a3a99093ec159a1d1.png][]

如果设置了throttle，那么会对io\_ticket执行建议操作，如果值小于0，那么就会重置wait\_throttle event，并等待其被设置。而wait\_throttle是在另一个线程io\_watching\_thread上被设置。

![fab0aa0a9bfd4c312c9515523f3bb3c8.png][]

该线程每隔1s将io\_throttle设置为用户设置的throttle值，并设置wait\_throttle。

结合gdb attach的信息和代码，以及throttle[官方解释][Link 1]，可以得出：此时xtrabackup在拷贝redo，但由于throttle的限制，每秒的绝大部分时间都花在os\_event\_wait(wait\_throttle)上了。这就回答了xtrabackup在出错前都在干什么的问题。进一步地，由于拷贝速度比redo产生速度慢，从而导致所需拷贝的redo被新日志覆盖。

**问题解释**

**为何仅拷贝redo**

那么另一个问题，为什么这段时间只拷贝redo，而不拷贝idb数据文件呢？这其实是目前网上对xtrabackup备份流程进行分析时都没有详细说明的地方。仔细分析代码发现执行redo拷贝任务的函数xtrabackup\_copy\_logfile()在2个地方调用到，一处是大家熟悉的redo拷贝线程log\_copying\_thread，而另一处是在xtrabackup备份主函数，即下图红框处：

![4a187006bdf4a2b998bfcd1caa212d6d.png][]

该函数什么时候返回由xtrabackup\_scan\_log\_recs()确定，在文章分析错误日志时已经提及。正常情况下，只有拷贝完所有新的redo日志才返回，如下：

![cfc472f27c851bd163560dd42147d229.png][]

**xtrabackup备份流程细化**

根据上面的描述，xtrabackup的备份流程进一步细化开来是这样的：

1、先获取innodb最后一次checkpoint对应的redo log lsn；

2、xtrabackup主线程从checkpoint lsn开始将之后新产生的redo都拷贝到xtrabackup\_logfile上；

3、只有拷完所有的redo日志后，才会开启redo拷贝线程和ibd拷贝线程。并行执行redo和ibd数据拷贝；

4、ibd拷贝线程完成所有数据拷贝；

5、xtrabackup执行flush table with read lock，拷贝MyISAM表等非事务表数据；

6、获取Binlog文件及偏移位置，获取gtid\_executed等信息；

7、执行FLUSH NO\_WRITE\_TO\_BINLOG ENGINE LOGS；

8、等待redo拷贝进程退出；

9、执行unlock tables；

10、执行备份所需其他操作后退出；

**throttle参数设置**

所以，正确设置throttle很关键，过小的throttle会由于redo拷贝不及时而被覆盖，过大的throttle或不设置会导致备份操作影响线上业务性能。一般来说，throttle的设置需要评估MySQL数据盘的IO性能，盘的性能越好，相对的每秒产生的redo量可能越多，throttle需要更大。将数据盘从HDD升级为SSD后，一定要调整原有xtrabackup备份脚本的throttle参数，否则极有可能出现由于redo被覆盖导致备份出错的问题。

[1]: https://link.zhihu.com/?target=http%3A//mysql.taobao.org/monthly/2016/03/07/
[2]: https://link.zhihu.com/?target=http%3A//www.innomysql.com/xtrabackup%25E5%25A4%2587%25E4%25BB%25BD%25E5%258E%259F%25E7%2590%2586%25E5%25AE%259E%25E7%258E%25B0%25E7%25BB%2586%25E8%258A%2582-%25E5%25AF%25B9%25E6%25B7%2598%25E5%25AE%259D%25E6%2595%25B0%25E6%258D%25AE%25E5%25BA%2593%25E5%2586%2585%25E6%25A0%25B8%25E6%259C%2588%25E6%258A%25A5%25E8%25A1%25A5/
[0062a86af789279c651254870034c5c9.png]: /images/20221120/1af9e5c1073b415f97258c2588b4e228.png
[f302f5a67a775a755a4d0a7a24417452.png]: /images/20221120/ba8fc03e43574bfa8b4cbf16a8a55d40.png
[http_os0event.cc_165]: https://link.zhihu.com/?target=http%3A//os0event.cc%3A165
[http_os0event.cc_335]: https://link.zhihu.com/?target=http%3A//os0event.cc%3A335
[http_xtrabackup.cc_3075]: https://link.zhihu.com/?target=http%3A//xtrabackup.cc%3A3075
[http_xtrabackup.cc_4762]: https://link.zhihu.com/?target=http%3A//xtrabackup.cc%3A4762
[http_xtrabackup.cc_8702]: https://link.zhihu.com/?target=http%3A//xtrabackup.cc%3A8702
[095174018447a9589b1a95389285355f.png]: /images/20221120/0ae98b832d8147c88a0210a9db7ecc02.png
[f62c966eb4d7b02a3a99093ec159a1d1.png]: /images/20221120/6b2e7248fa7f4d17a2770deb8fdccbf7.png
[fab0aa0a9bfd4c312c9515523f3bb3c8.png]: https://img-blog.csdnimg.cn/img_convert/fab0aa0a9bfd4c312c9515523f3bb3c8.png
[Link 1]: https://link.zhihu.com/?target=https%3A//www.percona.com/doc/percona-xtrabackup/LATEST/xtrabackup_bin/throttling_backups.html%23throttling-backups-xbk
[4a187006bdf4a2b998bfcd1caa212d6d.png]: https://img-blog.csdnimg.cn/img_convert/4a187006bdf4a2b998bfcd1caa212d6d.png
[cfc472f27c851bd163560dd42147d229.png]: https://img-blog.csdnimg.cn/img_convert/cfc472f27c851bd163560dd42147d229.png