TiDB节点下线状态一直是offline，迟迟没有变成tombstone，业务访问也有报错

Asiaye · 2021 年10 月 25 日 07:09

为提高效率，请提供以下信息，问题描述清晰能够更快得到解决：
【 TiDB 使用环境】
32核心CPU、128G内存、4T nvme SSD
线上环境

【概述】
某个节点所在的服务器需要回收，采用tikv的scale in操作缩绒，结果节点一直是offline状态，无法变成tombstone，业务访问部分表报错。
scale-in命令：
tiup cluster scale-in tidb_sherlock --node 10.182.1.159:20153

【背景】
某个节点所在的服务器需要回收，执行tikv的scale in 操作，节点一直无法下线

【现象】
节点一直显示下线中，但是数据库部分表访问报错

【业务影响】
业务访问报错，信息如下：

【TiDB 版本】5.0.0
【附件】

相关日志和监控

TiUP Cluster Display 信息

image1763×757 48.7 KB
TiUP Cluster Edit Config 信息
edit-config.txt (9.7 KB)
TiDB- Overview 监控

对应模块日志（包含问题前后1小时日志）

zhenjiaogao · 2021 年10 月 25 日 07:20

如果是节点下线慢，可以参考下下面的文档：

https://docs.pingcap.com/zh/tidb/stable/pd-scheduling-best-practices#节点下线速度慢

Asiaye · 2021 年10 月 25 日 07:23

剩余节点的磁盘还有很多。已经有十几天了，目前要下线的节点的region的数量不再变化了。

zhenjiaogao · 2021 年10 月 25 日 11:34

参照这个文档，调整相关 schedule limit 以及添加 evict-leader 有帮助吗？

Asiaye · 2021 年11 月 10 日 07:32

» config show
{
“replication”: {
“enable-placement-rules”: “true”,
“isolation-level”: “”,
“location-labels”: “host”,
“max-replicas”: 3,
“strictly-match-label”: “false”
},
“schedule”: {
“enable-cross-table-merge”: “true”,
“enable-debug-metrics”: “false”,
“enable-joint-consensus”: “true”,
“enable-location-replacement”: “true”,
“enable-make-up-replica”: “true”,
“enable-one-way-merge”: “false”,
“enable-remove-down-replica”: “true”,
“enable-remove-extra-replica”: “true”,
“enable-replace-offline-replica”: “true”,
“high-space-ratio”: 0.7,
“hot-region-cache-hits-threshold”: 3,
“hot-region-schedule-limit”: 4,
“leader-schedule-limit”: 4,
“leader-schedule-policy”: “count”,
“low-space-ratio”: 0.8,
“max-merge-region-keys”: 200000,
“max-merge-region-size”: 20,
“max-pending-peer-count”: 16,
“max-snapshot-count”: 4,
“max-store-down-time”: “30m0s”,
“merge-schedule-limit”: 8,
“patrol-region-interval”: “100ms”,
“region-schedule-limit”: 2048,
“region-score-formula-version”: “v2”,
“replica-schedule-limit”: 128,
“scheduler-max-waiting-operator”: 5,
“split-merge-interval”: “1h0m0s”,
“store-limit-mode”: “manual”,
“tolerant-size-ratio”: 0
}
}

------------以下是我执行的------------
» config set replica-schedule-limit 512
Success!

» config set max-snapshot-count 16
Success!

» config set max-pending-peer-count 64
Success!

» scheduler add evict-leader-scheduler 302321060
Success!

等待了好几天之后，依旧没有结果，还是有1032个region，无法迁移，监控显示下线中…

zhenjiaogao · 2021 年11 月 10 日 09:41

请再重新使用 pd 命令拿下被下线节点 store 302321060 的信息
使用下面的命令看下被下线 store 中的 1032 个 region 的具体的情况：
```
tiup ctl:v5.0.0 pd -u pd_ip:pd_port region store 302321060
```
被下线节点 store 302321060 的服务器是否已下架回收？

Asiaye · 2021 年11 月 10 日 11:16

------[1]----------------
» store 302321060
{
“store”: {
“id”: 302321060,
“address”: “10.182.1.159:20153”,
“state”: 1,
“labels”: [
{
“key”: “host”,
“value”: “10.182.1.159”
}
],
“version”: “5.0.0”,
“status_address”: “10.182.1.159:20188”,
“git_hash”: “7706b9634bd901c9fe8dbe6a556025abbfd0793d”,
“start_timestamp”: 1631503670,
“deploy_path”: “/data1/tidb-deploy/tikv-20153/bin”,
“last_heartbeat”: 1632278808069766287,
“state_name”: “Offline”
},
“status”: {
“capacity”: “0B”,
“available”: “0B”,
“used_size”: “0B”,
“leader_count”: 1132,
“leader_weight”: 1,
“leader_score”: 1132,
“leader_size”: 0,
“region_count”: 2437,
“region_weight”: 1,
“region_score”: 0,
“region_size”: 0,
“start_ts”: “2021-09-13T11:27:50+08:00”,
“last_heartbeat_ts”: “2021-09-22T10:46:48.069766287+08:00”,
“uptime”: “215h18m58.069766287s”
}
}
-----------[2]--------------
region.txt (2.0 MB)

------------[3]---------------
节点没有回收。还在线上，目录是：

包含一个tidb-data和tidb-deploy目录。

Asiaye · 2021 年11 月 10 日 11:25

除此之外，operator show 可以发现很多最新的调度。
operator_show_result.txt (448.2 KB)

zhenjiaogao · 2021 年11 月 11 日 04:08

收到，这个问题目前看可能是 operator 卡住了，辛苦再收集下下面 11 号 10 点 ~ 11 点的信息，这边再看下：

导出 Grafana PD 监控，文档参考
[FAQ] Grafana Metrics 页面的导出和导入
pd leader 的 pd.log
pd-ctl config show all
pd-ctl scheduler show

Asiaye · 2021 年11 月 11 日 06:29

1、所有PD在10:00~11:00的监控
tidb_sherlock-PD_2021-11-11T06_17_55.988Z.json (8.8 MB)
2、pd leader的pd.log
pd-2021-11-11T13-32-12.873.log (79.3 MB)
3、config show all结果
config_show_all_result.txt (7.3 KB)
4、scheduler_show结果
scheduler_show_result.txt (250 字节)

烦请帮忙查看，如果有其他需要提供的信息，请随时联系

zhenjiaogao · 2021 年11 月 11 日 07:44

1、通过 pd leader 的 log 可以看到下面的报错，remove peer from store 302321060 超时了：

[2021/11/11 10:00:01.288 +08:00] [INFO] [operator_controller.go:566] ["operator timeout"] [region-id=452012551] [takes=10m0.448444918s] [operator="\"replace-rule-offline-peer {mv peer: store [302321060] to [8]} (kind:region,replica, region:452012551(1411,9443), createAt:2021-11-11 09:50:00.839618883 +0800 CST m=+17752685.808705574, startAt:2021-11-11 09:50:00.840552274 +0800 CST m=+17752685.809639001, currentStep:0, steps:[add learner peer 18559976572 on store 8, use joint consensus, promote learner peer 18559976572 on store 8 to voter, demote voter peer 452012553 on store 302321060 to learner, leave joint state, promote learner peer 18559976572 on store 8 to voter, demote voter peer 452012553 on store 302321060 to learner, remove peer on store 302321060]) timeout\""]

2、在 grafana 监控中没有找到 store 302321060 相关的信息，所以，请到服务器 10.182.1.159 上确认下 store 302321060 的状态是怎样的？进程是否仍然存在

3、如果 store 302321060 的进程存在，那么辛苦拿下 11 日 10~11 点的 tikv.log 日志

Asiaye · 2021 年11 月 11 日 08:25

进程似乎在自动重启，时有时无。

tikv.log.2021-11-11-16_06_58.603637856 (6.2 MB)

zhenjiaogao · 2021 年11 月 11 日 09:12

TiKV 的日志显示，store 不停重启的原因如下，相同的 address 10.182.1.159:20153，下有两个 store 分别是 store 302321060，7748745185：

[2021/11/11 10:00:08.771 +08:00] [FATAL] [server.rs:706] ["failed to start node: Grpc(RpcFailure(RpcStatus { status: 2-UNKNOWN, details: Some(\"duplicated store address: id:7748745185 address:\\\"10.182.1.159:20153\\\" labels:<key:\\\"host\\\" value:\\\"10.182.1.159\\\" > version:\\\"5.0.0\\\" status_address:\\\"10.182.1.159:20180\\\" 
git_hash:\\\"7706b9634bd901c9fe8dbe6a556025abbfd0793d\\\" start_timestamp:1636596003 deploy_path:\\\"/data1/tidb-deploy/tikv-20153/bin\\\" , already registered by id:302321060 address:\\\"10.182.1.159:20153\\\" state:Offline labels:<key:\\\"host\\\" value:\\\"10.182.1.159\\\" > version:\\\"5.0.0\\\" status_address:\\\"10.182.1.159:20188\\\" git_hash:\\\"7706b9634bd901c9fe8dbe6a556025abbfd0793d\\\" start_timestamp:1631503670 deploy_path:\\\"/data1/tidb-deploy/tikv-20153/bin\\\" last_heartbeat:1632278808069766287 \") }))"]

辛苦确认下下面的信息：

通过 PD 的 API 拿下当前集群的 store 列表
```
curl pd-addr:port/pd/api/v1/stores
```
确认下当前这套集群 address 10.182.1.159:20153 整体扩缩容的历史操作信息，比如 store 302321060，7748745185 扩容的缩容的时间点以及线，是在 2021-11-11 10:00:03 左右有使用 10.182.1.159:20153 新 start 了一个 store 并且 store id 为 7748745185 吗？

Asiaye · 2021 年11 月 11 日 11:27

stores列表
stores_result.txt (23.4 KB)
单独过滤store
[root@ v5.0.0]# /root/.tiup/components/ctl/v5.0.0/pd-ctl -i -u http://xxxxxxx:2379
» store 7748745185
Failed to get store: [404] “store 7748745185 not found”

经过详细操作排查，经历的过程应该是：
1、9月24日操作缩容scale-in 10.182.1.159:20153，然后迟迟offline状态，不变为tombstone
2、10月13日重新利用scale-out 扩容，扩容的scale-out.yaml文件里面的确包含了10.182.1.159:20153（相当于下线了一半，又上线了）

第2次操作和第一次操作，中间间隔了19天，10.182.1.159这个节点还是offline状态，不是tombstone。

目前，最新的拓扑里面：
tiup cluster display tidb_xxx

Asiaye · 2021 年11 月 12 日 02:25

集群监控里面也显示下线中。。。

zhenjiaogao · 2021 年11 月 12 日 02:29

这个不是 pd-ctl 命令，是直接在服务器执行 curl 命令哈，完整的命令是『curl pd-addr:port/pd/api/v1/stores』

Asiaye · 2021 年11 月 12 日 02:31

上面那个store_result就是执行你这个命令的结果。

zhenjiaogao · 2021 年11 月 12 日 03:16

我们通过 pd 的监控看到在当前的集群中，存在一个 tombstone 节点：

请再使用 curl 10.75.18.36:2379/pd/api/v1/stores?state=2 看下当前集群中的 tombstone 节点信息

另外，在使用 tiup scale-out 时，扩容成功了吗，当时的 tiup log 还有保留吗？

Asiaye · 2021 年11 月 12 日 06:07

1、

2、当时应该是成功了，当时的tiup log没有保存，一般都是shell页面上输出的。

Asiaye · 2021 年11 月 12 日 06:17

现在这个问题，具体应该怎么解决啊？？？下线中的状态持续很久了。有什么办法能够将这个IP上的region给迁移走吗？