BR备份报错rpc error: code = Canceled

qq24681430 · 2021 年3 月 3 日 06:17

为提高效率，请提供以下信息，问题描述清晰能够更快得到解决：

【TiDB 版本】
4.0.10
【问题描述】
tidb集群安装在了一台机器上了，做的本机备份
br backup db --pd “127.0.0.1:2379” --db test --storage “local:///home/tidb/bak” --log-file /home/tidb/backupfull.log
报错如下backupfull.log (8.8 KB)
[2021/03/03 13:48:46.388 +08:00] [ERROR] [pd.go:130] [“updateTS error”] [error=“rpc error: code = Canceled desc = context canceled”] [errorVerbose=“rpc error: code = Canceled desc = context canceled
github.com/tikv/pd/client.(*client).tsLoop
\tgithub.com/tikv/pd@v1.1.0-beta.0.20201209075645-beb7635d13d2/client/client.go:273
runtime.goexit
\truntime/asm_amd64.s:1357
github.com/tikv/pd/client.(*tsoRequest).Wait
\tgithub.com/tikv/pd@v1.1.0-beta.0.20201209075645-beb7635d13d2/client/client.go:464
github.com/tikv/pd/client.(*client).GetTS
\tgithub.com/tikv/pd@v1.1.0-beta.0.20201209075645-beb7635d13d2/client/client.go:482
github.com/pingcap/tidb/util/execdetails.InterceptedPDClient.GetTS
\tgithub.com/pingcap/tidb@v1.1.0-beta.0.20201214152324-ce2f365189d3/util/execdetails/pd_interceptor.go:60
github.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).getTimestamp
\tgithub.com/pingcap/tidb@v1.1.0-beta.0.20201214152324-ce2f365189d3/store/tikv/oracle/oracles/pd.go:103
github.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).updateTS
\tgithub.com/pingcap/tidb@v1.1.0-beta.0.20201214152324-ce2f365189d3/store/tikv/oracle/oracles/pd.go:128
runtime.goexit
\truntime/asm_amd64.s:1357”] [stack=“github.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).updateTS
\tgithub.com/pingcap/tidb@v1.1.0-beta.0.20201214152324-ce2f365189d3/store/tikv/oracle/oracles/pd.go:130”]

zhenjiaogao · 2021 年3 月 4 日 02:28

1、集群的所有组件，tidb，tikv ，pd 等都安装在一台服务器上，安装配置的时候用的是网卡地址，还是回环地址 127.0.0.1？如果是回环地址，建议使用实际的网卡 ip 地址配置集群 ~

2、如果是实际网卡 ip 配置的集群，那么请使用 pd 的 ip （非回环地址），再次尝试使用 BR 进行本地备份，如果仍然有报错，请继续跟帖 ~

qq24681430 · 2021 年3 月 4 日 03:11

最开始是这样执行的： br backup db --pd “168.0.1.60:2379” --db test --storage “local:///home/tidb/bak” --log-file /home/tidb/backupfull.log
报错如下backupfull.log (44.8 KB) ：
[“[pd] failed to get cluster id”] [url=http://168.0.1.60:2379] [error=“[PD:client:ErrClientGetMember]error:rpc error: code = DeadlineExceeded desc = context deadline exceeded target:168.0.1.60:2379 status:CONNECTING”]

zhenjiaogao · 2021 年3 月 4 日 07:42

1、tiup cluster display 查看下当前集群的拓扑
2、使用 tiup ctl pd 子命令，查看下当前 pd member 以及 health 状态

qq24681430 · 2021 年4 月 6 日 03:18

[tidb@crm209 tmp]$ tiup cluster display test-cluster
Found cluster newer version:

The latest version:         v1.4.0
Local installed version:    v1.3.5
Update current component:   tiup update cluster
Update all components:      tiup update --all

Starting component cluster: /home/tidb/.tiup/components/cluster/v1.3.5/tiup-cluster display test-cluster
Cluster type: tidb
Cluster name: test-cluster
Cluster version: v4.0.0
SSH type: builtin
Dashboard URL: http://192.168.0.209:2379/dashboard
ID Role Host Ports OS/Arch Status Data Dir Deploy Dir

192.168.0.209:9093 alertmanager 192.168.0.209 9093/9094 linux/x86_64 Up /home/tidb/deploy/data.alertmanager /home/tidb/deploy
192.168.0.209:3000 grafana 192.168.0.209 3000 linux/x86_64 Up - /home/tidb/deploy
192.168.0.209:2379 pd 192.168.0.209 2379/2380 linux/x86_64 Up|L|UI /home/tidb/deploy/data.pd /home/tidb/deploy
192.168.0.209:9090 prometheus 192.168.0.209 9090 linux/x86_64 Up /home/tidb/deploy/prometheus2.0.0.data.metrics /home/tidb/deploy
192.168.0.209:4000 tidb 192.168.0.209 4000/10080 linux/x86_64 Up - /home/tidb/deploy
192.168.0.209:9000 tiflash 192.168.0.209 9000/8123/3930/20170/20292/8234 linux/x86_64 Up /home/tidb/deploy/tiflash-9000/data /home/tidb/deploy/tiflash-9000
192.168.0.209:20160 tikv 192.168.0.209 20160/20180 linux/x86_64 Up /home/tidb/deploy/data /home/tidb/deploy
Total nodes: 7
[tidb@crm209 tmp]$

zhenjiaogao · 2021 年4 月 6 日 06:15

看集群的拓扑信息，这个是 pd server 的 ip 和端口信息，那么在使用 BR 备份时，请使用相应的 ip 和端口。示例如下，仅供参考，请根据实际情况进行修改：
br backup full --pd "${PDIP}:2379" -s "local:///tmp/backup"

另外，看到你这里新建了一个帖子，也是关于 BR 备份的，这两个问题都在这个帖子跟进处理吧。备份 20% 报错问题需要提供下：

完整的 BR 备份命令
完整的 BR 备份的日志
BR 备份这个命令也是在这台 192.168.0.209 发起的吗？如果是，请将 grafana 监控 node-exporter 这台服务器备份期间的相关信息导出

qq24681430 · 2021 年4 月 6 日 06:51

备份命令我写了个脚本：

qq24681430 · 2021 年4 月 6 日 06:52

#vi /home/tidb/tidbbr #复制下面内容，并保存

pd=192.168.0.209

nfsip=192.168.0.247

if [ -n “$(df|grep br_bak)” ]; then

sudo umount /br_bak #如果NFS挂载了，则卸载

fi

sudo mount -t nfs -o nosuid,noexec,nodev,rw ${nfsip}:/home/data /br_bak #重启挂载是为了避免报错

mysql -h$pd -uroot -ppass -P4000 $1 -e"UPDATE mysql.tidb SET VARIABLE_VALUE = ‘15h’ WHERE VARIABLE_NAME = ‘tikv_gc_life_time’;" #TiDB v4.0.8 及以下版本，需要手工修改GC时间，时间要大于备份时长

cd /br_bak

dir=${1}$(date +%w) #确定备份目录

rm ${dir} -rf #存在目录则删除，因为是按周的循环备份

if [ ! -d ${dir} ]; then

mkdir $dir #不存在则创建

fi

if [ $(date +%w) != “0” ]; then #一周全备一次，周日为0周六为6

#增量

LAST_BACKUP_TS=/home/tidb/.tiup/storage/cluster/clusters/test-cluster/ansible-backup/resources/bin/br validate decode --field="end-version" -s local:///br_bak/${1}$(date -d yesterday +%w) #取上次备份的TS

LAST_BACKUP_TS="–lastbackupts "${LAST_BACKUP_TS}

fi

/home/tidb/.tiup/storage/cluster/clusters/test-cluster/ansible-backup/resources/bin/br backup db --db ${1} -s local:///br_bak/${dir} --pd ${pd}:2379 ${LAST_BACKUP_TS} #有TS则增量备份，否则全备份，TIUP安装的BR不是这个路径

mysql -h$pd -uroot -ppass -P4000 $1 -e"UPDATE mysql.tidb SET VARIABLE_VALUE = ‘1h’ WHERE VARIABLE_NAME = ‘tikv_gc_life_time’;" #还原GC时间

使用：

#su - tidb

$/home/tidb/tidbbr EnjoyCRM_DataCenter >>/home/tidb/br$(date).log

qq24681430 · 2021 年4 月 6 日 07:16

[br.log.2021-04-05T21.08.52 0800|attachment](upload://pFjrXkgZ1gvZZDs1XP62wbguaH9.52 0800) (5.0 MB)

qq24681430 · 2021 年4 月 6 日 07:18

[tidb@crm209 tmp]$ df -h
文件系统容量已用可用已用% 挂载点
devtmpfs 63G 0 63G 0% /dev
tmpfs 63G 0 63G 0% /dev/shm
tmpfs 63G 4.1G 59G 7% /run
tmpfs 63G 0 63G 0% /sys/fs/cgroup
/dev/mapper/centos-root 200G 3.6G 197G 2% /
/dev/sda2 1014M 172M 843M 17% /boot
/dev/sda1 200M 12M 189M 6% /boot/efi
/dev/mapper/centos-home 3.5T 1.7T 1.8T 49% /home
tmpfs 13G 0 13G 0% /run/user/0
192.168.0.247:/home/data 3.1T 1.4T 1.7T 46% /br_bak

zhenjiaogao · 2021 年4 月 6 日 08:31

这个备份文件上传有问题，请重新上传 ~

这部分信息请确认下 ~

qq24681430 · 2021 年4 月 6 日 09:38

br.log.2021-04-05T21.08.zip (383.0 KB)

zhenjiaogao · 2021 年4 月 6 日 10:17

BR 的备份日志显示的报错是 RPC 通信相关的报错，为便于问题的排查和定位，故辛苦提供备份期间下述 list 中的信息，：

20:00 ~ 24:00 PD leader 的 log
20:00 ~ 24:00 PD Grafana 监控 Dashboard
20:00 ~ 24:00 PD 服务器 Grafana Node-Exporter 监控 Dashboard

Grafana 监控导出方式参考：
[FAQ] Grafana Metrics 页面的导出和导入

qq24681430 · 2021 年4 月 6 日 15:09

Tidb-Cluster-Node_exporter_2021-04-06T15_08_08.598Z.zip (185.6 KB)

zhenjiaogao · 2021 年4 月 7 日 02:50

备份期间的这些信息也请一并上传下~

另外，BR 的备份命令是从 192.168.0.209 发起的，还是从另外一台服务器发起的？

qq24681430 · 2021 年4 月 7 日 02:52

是在192.168.0.209 发起的

qq24681430 · 2021 年4 月 7 日 02:59

test-cluster-PD_2021-04-07T02_57_39.501Z.json (258.0 KB) 数据库第一次备份是成功的，大小有800G多

qq24681430 · 2021 年4 月 7 日 03:05

logs.tar (52 KB)

zhenjiaogao · 2021 年4 月 7 日 03:22

pd 监控缺失很多信息~

另外从 pd leader 的日志可见下述信息：

[2021/04/05 23:38:50.334 +08:00] [Warn] [util.go:144] ["apply request took too long"] [took=9.040793436s] [expected-duration=100ms] [prefix=] [request="header:<ID:17284947797083594697 > txn:<compare:<> success:<request_put:<key:\"/pd/6846941113233660477/gc/safe_point/service/br\" value_size:72 >> failure:<>>"] [response=size:20] []

可能是 PD 处理消息的速度过慢，导致 BR 超时报错退出，故 PD Grafana 监控信息需要在监控信息均加载完毕后，再导出。辛苦重新导出下 PD 的监控 ~

qq24681430 · 2021 年4 月 7 日 06:25

test-cluster-PD_2021-04-07T06_23_32.933Z.json (786.0 KB)