还原br备份后再使用reparo无法还原binlog

脚本小王子 · 2022 年1 月 18 日 11:27

为提高效率，请提供以下信息，问题描述清晰能够更快得到解决：
【 TiDB 使用环境】
备份恢复测试环境

【概述】场景 + 问题概述
1、使用br restore还原2022-01-16 22点的完整备份

[root@pd ~]# time br restore full --pd 172.16.5.11:2379 -s local:///dbbak/tidbFullBak/mg_tidb_full_20220116220201 --log-file restorefull.log # --ratelimit 400  
Detail BR log in restorefull.log 
Full restore <------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------> 100.00%
[2022/01/18 15:01:03.537 +08:00] [INFO] [collector.go:65] ["Full restore success summary"] [total-ranges=62479] [ranges-succeed=62479] [ranges-failed=0] [restore-checksum=4h46m0.548000107s] [split-region=38m9.129771181s] [restore-ranges=50470] [total-take=1h52m45.339087878s] [total-kv=25720602179] [total-kv-size=2.347TB] [average-speed=347MB/s] [restore-data-size(after-compressed)=687.4GB] [Size=687363453940] [BackupTS=430567147706253313]

real    112m45.415s
user    2m32.464s
sys     1m29.979s
[root@pd ~]# tail -1 restorefull.log | grep 'BackupTS' | awk -F"BackupTS=" '{print $NF}' | awk '{print $1}' | sed 's/]//g'
430567147706253313

全备还原没问题

2、还原全备后，取得备份时的tso，再使用reparo还原binlog

[root@tiup ~]# time reparo -config reparo.toml
[2022/01/18 19:24:21.960 +08:00] [INFO] [config.go:160] ["Parsed stop TSO"] [ts=430552645632000000]
[2022/01/18 19:24:21.960 +08:00] [INFO] [version.go:50] ["Welcome to Reparo"] ["Release Version"=v5.3.0] ["Git Commit Hash"=c032e8ba9b524a6a698475a76cc2926db17b3cad] ["Build TS"="2021-11-16 11:54:08"] ["Go Version"=go1.16.4] ["Go OS/Arch"=linux/amd64]
[2022/01/18 19:24:21.960 +08:00] [INFO] [reparo.go:38] ["New Reparo"] [config="{\"data-dir\":\"/data/binlog\",\"start-datetime\":\"\",\"stop-datetime\":\"2022-01-17 22:00:00\",\"start-tso\":430567147706253314,\"stop-tso\":430552645632000000,\"txn-batch\":20,\"worker-count\":32,\"dest-type\":\"mysql\",\"dest-db\":{\"host\":\"172.16.5.4\",\"user\":\"root\",\"password\":\"123456\",\"port\":4000},\"replicate-do-table\":null,\"replicate-do-db\":null,\"replicate-ignore-table\":null,\"replicate-ignore-db\":null,\"log-file\":\"\",\"log-level\":\"info\",\"safe-mode\":false}"]
[2022/01/18 19:24:21.962 +08:00] [INFO] [load.go:223] ["new loader"] [opts="{workerCount:32 batchSize:20 loopBackSyncInfo:<nil> metrics:<nil> saveAppliedTS:false syncMode:1 enableDispatch:true enableCausality:true merge:false}"]
[2022/01/18 19:24:22.304 +08:00] [INFO] [file.go:77] ["after filter files"] [files="[/data/binlog/binlog-0000000000047835-20220117235619]"] ["start tso"=430567147706253314] ["stop tso"=430552645632000000]
[2022/01/18 19:24:24.186 +08:00] [INFO] [read.go:123] ["read file end"] [file=/data/binlog/binlog-0000000000047835-20220117235619]
[2022/01/18 19:24:24.186 +08:00] [INFO] [load.go:830] ["Loader has been closed. Start quitting txnManager"]
[2022/01/18 19:24:24.186 +08:00] [INFO] [load.go:820] ["run()... in txnManager quit"]
[2022/01/18 19:24:24.186 +08:00] [INFO] [load.go:876] ["txnManager has been closed"]
[2022/01/18 19:24:24.186 +08:00] [INFO] [load.go:566] ["{32 20 <nil> <nil> false 1 true true false}"]
[2022/01/18 19:24:24.186 +08:00] [INFO] [load.go:567] ["Run()... in Loader quit"]
[2022/01/18 19:24:24.186 +08:00] [INFO] [mysql.go:114] ["Successes chan quit"]

real    0m2.274s
user    0m4.071s
sys     0m0.399s
[root@tiup ~]# echo $?
0
[root@tiup ~]#

执行没报错信息，但一闪就过了，binlog数据没还原

reparo.toml文件如下：

# Drainer 输出的 protobuf 格式 binlog 文件的存储路径。
# data-dir = "/data/tidb-data/drainer-8249"
data-dir = "/data/binlog"

# 日志输出信息等级设置：debug, info, warn, error, fatal (默认值：info)。
log-level = "info"

# 使用 start-datetime 和 stop-datetime 来选择恢复指定时间范围内的 binlog，格式为 “2006-01-02 15:04:05”。
# start-datetime = "2022-01-17 16:20:41"
# stop-datetime = ""

# start-tso、stop-tso 分别对应 start-datetime 和 stop-datetime，也是用于恢复指定时间范围内的 binlog，用 tso 的值来设置。如果已经设置了 start-datetime 和 stop-datetime，就不需要再设置 start-tso 和 stop-tso。
start-tso = 430567147706253314
# stop-tso = 
stop-datetime = "2022-01-17 22:00:00"

# 下游服务类型。 取值为 print, mysql（默认值：print）。当值为 print 时，只做解析打印到标准输出，不执行 SQL；如果为 mysql，则需要在 [dest-db] 中配置 host、port、user、password 等信息。
dest-type = "mysql"

# 输出到下游数据库一个事务的 SQL 语句数量（默认 20）。
txn-batch = 20

# 同步下游的并发数，该值设置越高同步的吞吐性能越好（默认 16）。
worker-count = 32

# 安全模式配置。取值为 true 或 false（默认值：false）。当值为 true 时，Reparo 会将 update 语句拆分为 delete + replace 语句。
safe-mode = false

# replicate-do-db 和 replicate-do-table 用于指定恢复的库和表，replicate-do-db 的优先级高于 replicate-do-table。支持使用正则表达式来配置，需要以 '~' 开始声明使用正则表达式。
# 注：replicate-do-db 和 replicate-do-table 使用方式与 Drainer 的使用方式一致。
# replicate-do-db = ["~^b.*","s1"]
# [[replicate-do-table]]
# db-name ="test"
# tbl-name = "log"
# [[replicate-do-table]]
# db-name ="test"
# tbl-name = "~^a.*"

# 如果 dest-type 设置为 mysql, 需要配置 dest-db。
[dest-db]
host = "172.16.5.4"
port = 4000
user = "root"
password = "123456"

【备份和数据迁移策略逻辑】
使用br做全备，使用binlog做每天的增量备，方便可还原到任意时间点

【问题】当前遇到的问题
无法还原binlog

【TiDB 版本】
V5.3.0

【附件】

相关日志、配置文件、Grafana 监控（https://metricstool.pingcap.com/)
TiUP Cluster Display 信息
TiUP CLuster Edit config 信息
TiDB-Overview 监控
对应模块的 Grafana 监控（如有 BR、TiDB-binlog、TiCDC 等）
对应模块日志（包含问题前后 1 小时日志）

若提问为性能优化、故障排查类问题，请下载脚本运行。终端输出的打印结果，请务必全选并复制粘贴上传。

lonng · 2022 年1 月 18 日 11:52

start tso 比 stop tso 还小，所以其实没有数据会还原，麻烦再看看时间是否正确。

脚本小王子 · 2022 年1 月 18 日 11:57

我全备是2022-01-16 22:00:00的，还原全备输出的BackupTS=430567147706253313，按官档说的应该加1，然后再指定 stop-datetime = “2022-01-17 22:00:00”，请问下为何stop tso会比start tso小呢？是不是我的理解有问题，不应该这样还原？

脚本小王子 · 2022 年1 月 18 日 12:17

原来不能看br还原的日志取得tso，需要使用以下语句获得备份的tso

LAST_BACKUP_TS=`br validate decode --field="end-version" -s local:///dbbak/tidbFullBak/mg_tidb_full_20220116220201  | tail -n1`
echo $LAST_BACKUP_TS

system · 2022 年10 月 31 日 19:08

此话题已在最后回复的 1 分钟后被自动关闭。不再允许新回复。