TiFlash崩溃无法启动

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

[TiDB 版本]
5.7.25-TiDB-v4.0.8 TiDB Server (Apache License 2.0) Community Edition, MySQL 5.7 compatible
[问题描述]
TiFlash于2021年2月24日晚21点40分 左右开始出现异常。于今日2月25日报出磁盘告警,发现机器上面出现大量的corefiles文件。并且查看对应的集群节点状态 ,集群所有的tiflash节点均为down状态,共三台。观察机器上的进程 的确全部无运行。
尝试start tiflash节点 仍无法启动 reload配置也无法启动
附件是其中两台tiflash的相关日志
这边想上传但是被平台拦截了…


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

  1. 是日志太大了吗? 可以找故障点前后的日志 和 当前无法启动的报错日志发一下。
  2. 什么环境? k8s 还是物理机 tiup 安装的,展示下当前节点状态 display 信息。

tiflash机器上面产生了大量的这种文件


tiup物理机部署的,display结果如下

我截取一下日志文件 1w条
tiflash_error.log_150.74_20210225.1w (1.1 MB) tiflash_150.74_20210225.log.1w (4.4 MB)
tiflash.log_150.13_20210225.1w (1.6 MB) tiflash_error.log_150.13_20210225.1w (1.2 MB)
收集异常信息的脚本显示需要有inventory.ini文件 无法使用

故障前有操作过环境吗还是突然间发生的?

目前前段时间均是正常运行的 在dashboard中可以看到对应的节点正常。业务还未完全上线,所有还不太清楚使用情况,详细的我再询问一下业务同学,初次反馈是 只有查询
这个是grafana上 关于tiflash的有个监控面板,还少了一台的监控数据


请问该集群有通过 raw kv 做过什么操作么?看起来存在某个 region 的 meta 是非法的
麻烦用pd ctl 调用 region key --format=hex 7480000000000001FF986183042108469CFF0000000000000000F7 看下这个 region 的信息。

:flushed:raw kv操作具体是啥,不是很懂。在发现异常前都没用做过啥,运维侧只是修改了tidb的tmp-storage-dir这个参数,然后reload的时候因为权限不足重试了。用户那边应该就是正常查询写入吧 再继续跟进反馈。下面这个是调用pd查询的结果

{
  "id": 455355,
  "start_key": "7480000000000001FF986183042108469CFF0000000000000000F7",
  "end_key": "7480000000000001FF9900000000000000F8",
  "epoch": {
    "conf_ver": 275,
    "version": 6038
  },
  "peers": [
    {
      "id": 455356,
      "store_id": 6
    },
    {
      "id": 455357,
      "store_id": 5
    },
    {
      "id": 455358,
      "store_id": 7
    },
    {
      "id": 510266,
      "store_id": 81115,
      "is_learner": true
    },
    {
      "id": 510771,
      "store_id": 50,
      "is_learner": true
    },
    {
      "id": 511242,
      "store_id": 49,
      "is_learner": true
    }
  ],
  "leader": {
    "id": 455356,
    "store_id": 6
  },
  "down_peers": [
    {
      "peer": {
        "id": 510266,
        "store_id": 81115,
        "is_learner": true
      },
      "down_seconds": 146240
    },
    {
      "peer": {
        "id": 510771,
        "store_id": 50,
        "is_learner": true
      },
      "down_seconds": 146358
    },
    {
      "peer": {
        "id": 511242,
        "store_id": 49,
        "is_learner": true
      },
      "down_seconds": 145754
    }
  ],
  "pending_peers": [
    {
      "id": 510266,
      "store_id": 81115,
      "is_learner": true
    },
    {
      "id": 510771,
      "store_id": 50,
      "is_learner": true
    },
    {
      "id": 511242,
      "store_id": 49,
      "is_learner": true
    }
  ],
  "written_bytes": 0,
  "read_bytes": 0,
  "written_keys": 0,
  "read_keys": 0,
  "approximate_size": 1,
  "approximate_keys": 0
}

请问 TiKV 里面的数据,除了通过 TiDB server 层写入,还有其他方式写入的吗?

没有 用户只能通过tidb层写入,

麻烦在 pd 的 log 里 grep 下 7480000000000001FF986183042108469CFF0000000000000000F7 以及 455355 ,看下该 region 被创建时候的上下文。

如果要紧急恢复查询可以先 set tiflash replica 为 0

好的:+1:这个是pd-leader上面的日志信息,下周一再测试设置副本为0时能否正常启动
这个下面是 前后关键词 前后40条记录信息 如果需要再详细我这边再过滤
7480000000000001FF986183042108469CFF0000000000000000F7_455355_40.log (5.5 MB)

[2021/02/24 09:39:41.827 +08:00] [INFO] [cluster.go:542] [“region Version changed”] [region-id=455355] [detail=“StartKey Changed:{7480000000000001FF985F728000000A74FFC8CE5B0000000000FA} -> {7480000000000001FF98617EC9BA5E3933FF0000000000000000F7}, EndKey:{7480000000000001FF9900000000000000F8}”] [old-version=6034] [new-version=6035]
[2021/02/24 09:39:41.827 +08:00] [INFO] [cluster_worker.go:217] [“region batch split, generate new regions”] [region-id=455355] [origin=“id:455479 start_key:“7480000000000001FF985F728000000A74FFC8CE5B0000000000FA” end_key:“7480000000000001FF98617EC9BA5E3933FF0000000000000000F7” region_epoch:<conf_ver:272 version:6035 > peers:<id:455480 store_id:6 > peers:<id:455481 store_id:5 > peers:<id:455482 store_id:7 >”] [total=1]

目前看到出现异常的 region 最早一次分裂是在这个时间,且 end key 变为 7480000000000001FF98617EC9BA5E3933FF0000000000000000F7,这个 key 不适用于 tidb 体系下的编码规则,需要确认下是否有第三方在直接写 tikv。也请麻烦在 tikv 的 log 中 grep 下这个时间点附近和 455355 这个 region 相关的 log。

据用户反馈 2月24号早上9.37.02使用tidb-lightning向集群导入数据,
tidb-lightning版本同集群版本为4.0.8
以下文件是截取其中两个tikv节点的对应关键词日志
tikv_148.160_2k.log (2.4 MB) tikv_148.87_2k.log (4.7 MB)

咨询过 tidb-lightning 相关人员,4.0.8 版本存在 bug。请问当前集群是测试环境还是线上环境?

线上环境,目前是在测试其稳定性阶段,暂未投入生产。想请问两个问题
1.请问官方现在建议如何使用 ?升级tidb版本使用高版本的lightning还是说不需要升级tidb 使用低版本兼容的tidb-lightning?
2.异常原因,lightning假如是有bug,假如是作用于tikv,据了解用户并没有创建tiflash副本 而最后由于 写入tikv的是非法值 导致tiflash异常,不是很理解其中关联。

  1. 建议使用 tiup 将整个集群升级到最新的 4.0.11,包含各个组件的 bug 修复,稳定性更好。
  2. 异常原因:通过 tidb-lighting 导入数据,lighting 会生成 split key 再去 tikv 预先分裂 region 以便于后续直接导入。在 4.0.9 之前的版本,lighting 可能生成非法的 split key。当通过 alter set tiflash replica 后,该表相关的 region 被同步到 tiflash 节点,tiflash 目前对这些非法信息检查比较严格,引起异常退出。

如果没有创建 tiflash 副本,不会有任何数据被同步到 tiflash 节点上,可以通过 select * from INFORMATION_SCHEMA.TIFLASH_REPLICA; 查询 table 的 tiflash replica 信息。

查询发现的确有tiflash副本


查看pd的监控面板可以发现tiflash于24号早上10.15-10.30开始创建,与业务确认的确创建了tiflash副本…

于24日晚出现down的状态

那么对于现在这个集群的状态,这么操作吗?
1.先尝试修复tiflash节点

2.升级集群版本至4.0.11并替换tidb-lightning版本

1、按照该文档介绍:https://docs.pingcap.com/zh/tidb/stable/scale-tidb-using-tiup#缩容-tiflash-节点 ,首先通过设置 tiflash 副本数为 0 之后进行 tiflash 组件缩容(因为已经同步到 tiflash 的问题表在设置副本数为 0 之后并不会删掉数据(正在改进),因此要进行缩容彻底清理数据),然后 truncate 问题表之后进行集群升级,最后扩容加上 tiflash 节点
2、升级对应的 tidb-lighting
3、重新导数

tiflash修复
1.修改相关表的 TiFlash 副本数 set tiflash replica 0成功
2.删除tiflash—15.00开始测试删除
----使用tiup scale-in 尝试缩容一个节点display显示为pending-offine状态半小时无反应
----使用pd-ctl 缩容delete几点后displa 该节点显示offine,也无进一步演示为tombstone
请问是否需要继续等待,或是可直接丢弃tiflash副本
curl -X POST ‘http:///pd/api/v1/store/<store_id>/state?state=Tombstone’,对tikv上的查询有影响吗

offline 的状态持续了多久?时间比较久的话可以直接停掉节点进程并在 PD 里面通过 pd-ctl 删掉节点信息,最好在清理下对应 TiFlash 目录的数据,重新进行扩容试下。当然在进行这一系列操作的时候,所有的查询都要走到 KV 去完成,一些复杂的 AP 查询可能会使得 KV 负载升高。