TiDB BR 日志备份问题

TiDBer_Kylin · 2026 年8 月 15 日 11:43

TiDB 集群备份 S3 协议的远程存储，快照备份合适，进行日志备份时会在S3 上创建 backup.lock 和 backupmeta ，之后就一直无反应（有数据写入）。排查日志主要信息如下，但是实在不知道如何解决，是哪里的问题！！！请社区的大神支支招？
查看任务状态：

tiup br log status --pd=“10.43.0.35:2379”

Starting component br: /root/.tiup/components/br/v8.5.6/br log status --pd=10.43.0.35:2379
Detail BR log in /tmp/br.log.2026-08-15T19.28.16+0800
● Total 1 Tasks.

#1 <
name: pitr
status: ● NORMAL
start: 2026-08-15 18:56:36.253 +0800
end: 2090-11-18 22:07:45.624 +0800
storage: s3://dbackup/zjy-tidb-cluster/logbackup
speed(est.): 0.00 ops/s
checkpoint[global]: 2026-08-15 18:56:36.253 +0800; gap=31m42s

[root@tidb-monitor ~]# cat /tmp/br.log.2026-08-15T19.34.23+0800 
[2026/08/15 19:34:23.114 +08:00] [INFO] [meminfo.go:196] ["use physical memory hook"] [cgroupMemorySize=9223372036854710272] [physicalMemorySize=32793296896]
[2026/08/15 19:34:23.115 +08:00] [INFO] [cmd.go:157] ["calculate the rest memory"] [memtotal=32793296896] [memused=5904859136] [memlimit=26351566848]
[2026/08/15 19:34:23.115 +08:00] [INFO] [memory_monitor.go:62] ["Memory monitor starting"] [dump_dir=/tmp/br_heap_dumps] [using_temp_dir=false] [memory_usage_alarm_ratio=0.8] [memory_limit_mb=25130]
[2026/08/15 19:34:23.115 +08:00] [INFO] [info.go:53] ["Welcome to Backup & Restore (BR)"] [release-version=v8.5.6] [git-hash=ae18096e023780bb56bfce33698abec0d4640d0a] [git-branch=HEAD] [go-version=go1.25.8] [utc-build-time="2026-04-14 07:15:15"] [race-enabled=false]
[2026/08/15 19:34:23.115 +08:00] [INFO] [common.go:935] [arguments] [__command="br log status"] [pd="[10.43.0.35:2379]"]
[2026/08/15 19:34:23.115 +08:00] [INFO] [common.go:195] ["trying to connect to etcd"] [addr="[10.43.0.35:2379]"]
[2026/08/15 19:34:23.116 +08:00] [INFO] [conn.go:168] ["new mgr"] [pdAddrs="[10.43.0.35:2379]"]
[2026/08/15 19:34:23.118 +08:00] [INFO] [pd_service_discovery.go:999] ["[pd] update member urls"] [old-urls="[http://10.43.0.35:2379]"] [new-urls="[http://10.43.0.12:2379,http://10.43.0.35:2379,http://10.43.0.56:2379]"]
[2026/08/15 19:34:23.118 +08:00] [INFO] [pd_service_discovery.go:1024] ["[pd] switch leader"] [new-leader=http://10.43.0.35:2379] [old-leader=]
[2026/08/15 19:34:23.118 +08:00] [INFO] [pd_service_discovery.go:500] ["[pd] init cluster id"] [cluster-id=7648199718347696509]
[2026/08/15 19:34:23.119 +08:00] [INFO] [client.go:538] ["[pd] changing service mode"] [old-mode=UNKNOWN_SVC_MODE] [new-mode=PD_SVC_MODE]
[2026/08/15 19:34:23.119 +08:00] [INFO] [tso_client.go:297] ["[tso] switch dc tso global allocator serving url"] [dc-location=global] [new-url=http://10.43.0.35:2379]
[2026/08/15 19:34:23.120 +08:00] [INFO] [client.go:544] ["[pd] service mode changed"] [old-mode=UNKNOWN_SVC_MODE] [new-mode=PD_SVC_MODE]
[2026/08/15 19:34:23.120 +08:00] [INFO] [tso_dispatcher.go:140] ["[tso] start tso deadline watcher"] [dc-location=global]
[2026/08/15 19:34:23.120 +08:00] [INFO] [tso_dispatcher.go:198] ["[tso] tso dispatcher created"] [dc-location=global]
[2026/08/15 19:34:23.120 +08:00] [INFO] [tso_dispatcher.go:729] ["[tso] switching tso rpc concurrency"] [old=0] [new=1]
[2026/08/15 19:34:23.120 +08:00] [INFO] [tso_client.go:133] ["[tso] start tso dispatcher check loop"]
[2026/08/15 19:34:23.120 +08:00] [INFO] [tso_dispatcher.go:476] ["[tso] start tso connection contexts updater"] [dc-location=global]
[2026/08/15 19:34:23.121 +08:00] [INFO] [conn.go:142] ["checked alive KV stores"] [aliveStores=3] [totalStores=3]
[2026/08/15 19:34:23.122 +08:00] [INFO] [pd_service_discovery.go:999] ["[pd] update member urls"] [old-urls="[http://10.43.0.35:2379]"] [new-urls="[http://10.43.0.12:2379,http://10.43.0.35:2379,http://10.43.0.56:2379]"]
[2026/08/15 19:34:23.123 +08:00] [INFO] [pd_service_discovery.go:1024] ["[pd] switch leader"] [new-leader=http://10.43.0.35:2379] [old-leader=]
[2026/08/15 19:34:23.123 +08:00] [INFO] [pd_service_discovery.go:500] ["[pd] init cluster id"] [cluster-id=7648199718347696509]
[2026/08/15 19:34:23.123 +08:00] [INFO] [client.go:538] ["[pd] changing service mode"] [old-mode=UNKNOWN_SVC_MODE] [new-mode=PD_SVC_MODE]
[2026/08/15 19:34:23.123 +08:00] [INFO] [tso_client.go:297] ["[tso] switch dc tso global allocator serving url"] [dc-location=global] [new-url=http://10.43.0.35:2379]
[2026/08/15 19:34:23.124 +08:00] [INFO] [client.go:544] ["[pd] service mode changed"] [old-mode=UNKNOWN_SVC_MODE] [new-mode=PD_SVC_MODE]
[2026/08/15 19:34:23.124 +08:00] [INFO] [tso_dispatcher.go:140] ["[tso] start tso deadline watcher"] [dc-location=global]
[2026/08/15 19:34:23.124 +08:00] [INFO] [tso_client.go:133] ["[tso] start tso dispatcher check loop"]
[2026/08/15 19:34:23.124 +08:00] [INFO] [tso_dispatcher.go:198] ["[tso] tso dispatcher created"] [dc-location=global]
[2026/08/15 19:34:23.124 +08:00] [INFO] [tso_dispatcher.go:729] ["[tso] switching tso rpc concurrency"] [old=0] [new=1]
[2026/08/15 19:34:23.124 +08:00] [INFO] [tso_dispatcher.go:476] ["[tso] start tso connection contexts updater"] [dc-location=global]
[2026/08/15 19:34:23.124 +08:00] [INFO] [tikv_driver.go:202] ["using API V1."]
[2026/08/15 19:34:23.209 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.53:20292]
[2026/08/15 19:34:23.212 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.28:20292]
[2026/08/15 19:34:23.221 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.7:20292]
[2026/08/15 19:34:23.241 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.26:20180]
[2026/08/15 19:34:23.241 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.19:20180]
[2026/08/15 19:34:23.243 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.55:20180]
[2026/08/15 19:34:24.288 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.53:20292]
[2026/08/15 19:34:24.288 +08:00] [INFO] [stream_status.go:351] ["calc qps"] [diff=0] [elapsed=1.078586349] [c0=42] [c1=42]
[2026/08/15 19:34:24.296 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.28:20292]
[2026/08/15 19:34:24.296 +08:00] [INFO] [stream_status.go:351] ["calc qps"] [diff=0] [elapsed=1.084058017] [c0=42] [c1=42]
[2026/08/15 19:34:24.307 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.7:20292]
[2026/08/15 19:34:24.307 +08:00] [INFO] [stream_status.go:351] ["calc qps"] [diff=0] [elapsed=1.08529776] [c0=42] [c1=42]
[2026/08/15 19:34:24.353 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.26:20180]
[2026/08/15 19:34:24.353 +08:00] [INFO] [stream_status.go:351] ["calc qps"] [diff=0] [elapsed=1.112228011] [c0=42] [c1=42]
[2026/08/15 19:34:24.357 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.19:20180]
[2026/08/15 19:34:24.357 +08:00] [INFO] [stream_status.go:351] ["calc qps"] [diff=0] [elapsed=1.11607097] [c0=42] [c1=42]
[2026/08/15 19:34:24.361 +08:00] [INFO] [stream_status.go:327] ["get qps"] [matches="[]"] [addr=10.43.0.55:20180]
[2026/08/15 19:34:24.361 +08:00] [INFO] [stream_status.go:351] ["calc qps"] [diff=0] [elapsed=1.117310624] [c0=42] [c1=42]

TiDB 日志报错:

[2026/08/15 19:34:15.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:34:27.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:34:27.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:34:39.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:34:39.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:34:51.405 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:34:51.405 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:03.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:03.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:15.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:15.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:27.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:27.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:39.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:39.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:51.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:35:51.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:36:03.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]
[2026/08/15 19:36:03.401 +08:00] [WARN] [advancer.go:476] ["failed to update global checkpoint: stale"] [old=468396643779346439] [new=0]

TiKV 错误日志：

[2026/08/15 18:56:39.398 +08:00] [WARN] [errors.rs:162] ["backup stream meet error"] [position="Location { file: \"/workspace/source/tikv/components/backup-stream/src/checkpoint_manager.rs\", line: 102, col: 34 }"] [verbose_err=Grpc(RemoteStopped)] [err="gRPC meet error RemoteStopped"] [context="sending subscription"] [thread_id=114]

TiDBer_MHoGysU8 · 2026 年8 月 15 日 11:59

看日志应该是备份任务已创建成功，但TiKV未持续上报checkpoint（new=0），日志流未真正写入S3。查看下S3链路问题（权限/网络/endpoint）或TiKV日志线程异常（region迁移、raft不稳）。日志里的S3仅有backupmeta，像初始化完成但未开始写数据。

kang · 2026 年8 月 16 日 00:30

看你这情况，日志备份任务状态是NORMAL，但checkpoint一直卡在启动时间，说明日志备份没真正跑起来。

先检查几个点：

S3权限问题：确认BR进程对S3 bucket有写权限，特别是PutObject和ListBucket。可以用aws s3 ls s3://dbackup/zjy-tidb-cluster/logbackup/测试下。
BR日志级别：把日志级别调到DEBUG看看具体卡在哪。

拍脑袋小助手 · 2026 年8 月 16 日 01:40

单独测试下S3写入

TiDBer_bawpguhQ · 2026 年8 月 16 日 04:29

任务状态 NORMAL 但 speed=0、checkpoint 不推进，多半是 TiKV log-backup worker 没真正往 S3 写。先确认 tikv 已开 log-backup.enable 并滚动生效；查各 TiKV 日志里 log_backup/upload 报错（鉴权、path-style、区域、连通性）。快照能成只说明读权限够，日志备份还要持续写权限。gap 拉大可先 pause/stop 再重建 log 任务，并核对 S3 上 backup.lock 是否被别的任务占住。

wbslxw · 2026 年8 月 17 日 02:54

TiKV 的日志上传工作线程无法正常向 S3 写入日志流，没有持续上报 checkpoint，备份停滞。
检查一下
S3 权限 & 连通性（最高嫌疑）
TiKV 参数校验
任务锁冲突
打开 DEBUG 日志定位详细报错

Raymond · 2026 年8 月 17 日 03:11

你看下各个tikv，每一个tikv 节点，到s3的网络通不通

TiDBer_Kylin · 2026 年8 月 17 日 08:33

补充说明：
TiKV 到 S3 的网络是通的，且前期也验证过共享存储NFS ，是一样的不写入增量日志。

TiKV 最主要的日志信息如下：

[2026/08/17 13:15:03.398 +08:00] [INFO] [checkpoint_manager.rs:72] ["log backup adding new subscriber"] [id=c2184340-46d4-42a0-ac8d-4b56f23161b8] [thread_id=117]
[2026/08/17 13:15:03.398 +08:00] [INFO] [checkpoint_manager.rs:89] ["log backup sending events"] [downstream=2] [event_len=0] [thread_id=117]
[2026/08/17 13:15:03.398 +08:00] [WARN] [errors.rs:162] ["backup stream meet error"] [position="Location { file: \"/workspace/source/tikv/components/backup-stream/src/checkpoint_manager.rs\", line: 102, col: 34 }"] [verbose_err=Grpc(RemoteStopped)] [err="gRPC meet error RemoteStopped"] [context="sending subscription"] [thread_id=117]
[2026/08/17 13:15:03.398 +08:00] [INFO] [checkpoint_manager.rs:115] ["client is gone, removing subscription"] [id=2c245285-ff44-49f0-aaf2-45c7d9cc9f5e] [thread_id=117]

TiDBer_Kylin · 2026 年8 月 17 日 08:34

网络都是通的，向共享存储 NFS 写也是一样的问题

TiDBer_Kylin · 2026 年8 月 17 日 08:35

S3 和任务锁皆以排除

独善其身 · 2026 年8 月 18 日 01:31

检查 PD、TikV 之间网络，有没有防火墙断开长连接（空闲连接超时）
抓包查看 tikv 访问 S3 的 http 请求返回码（403 权限、404 bucket、503 限流）
检查对象存储侧是否开启了请求频率限流，TiKV 多节点并发上传触发限流

Raymond · 2026 年8 月 19 日 02:40

你是什么版本，我之前v8.5.3 也是不行的，应该就是版本BUG

TiDBer_Kylin · 2026 年8 月 28 日 01:46

找不到问题所在，最后重启 TiKV 之后就合适了！

会飞的小老鼠 · 2026 年8 月 29 日 05:29

Step1：确认所有 TiKV 节点能否访问 S3 存储

快照备份是中控机访问 S3；PITR 是每个 TiKV 节点访问 S3。
在每一台 TiKV 机器执行测试访问你的 s3 桶：

# 使用br工具测试存储访问，必须在tikv节点执行
br debug storage s3://dbackup/zjy-tidb-cluster/logbackup \
--s3.endpoint=xxx --s3.access-key=xxx --s3.secret-key=xxx

如果 TiKV 节点访问报错、超时、权限拒绝，直接命中根因。

Step2：查看每个 TiKV 的 local checkpoint

br log status --pd=10.43.0.35:2379 --detail

观察输出：

如果部分 TiKV 的 local checkpoint 完全不前进，就是这部分 TiKV 备份流异常。
如果全部 TiKV local checkpoint 都不动，TiKV 整体备份流异常。
如果 TiKV local checkpoint 正常往前走，但是 global checkpoint new=0，那就是 advancer 计算 / 对象存储原子写问题。

Step3：检查对象存储是否支持条件 Put（CAS）

PITR advancer 更新 backupmeta 使用 If‑Match 条件写。很多兼容 S3 存储对 If‑Match 支持有 bug。

Minio 旧版本、部分国产对象存储经常踩坑。

4、临时恢复操作流程（生产谨慎）

当前任务已经异常卡死，单纯重启 BR 命令无效，PD 里面任务元数据常驻。

停止 pitr 日志备份任务

br log stop --pd=10.43.0.35:2379

S3 侧：清空 s3://dbackup/zjy‑tidb‑cluster/logbackup 下面所有文件（backup.lock、backupmeta 全部删除）
确认 br log status 确认任务已消失。
修复根因（TiKV 访问 S3、对象存储兼容性）之后，重新创建 log‑backup 任务。

不要直接删除 S3 文件而不执行br log stop，PD 里面任务还在运行，元数据错乱，问题复现。

system · 2026 年9 月 5 日 05:29

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