4.0.5版本执行select触发tikvRPC backoffer.maxSleep

🪐 TiDB 技术问题 部署&运维管理
23

知道是 tidb 报错，但这个错误通常是和 kv 交互导致 可以看下 10.10.111.193:20160 对应的 tikv 的日志情况，最好也检查下这台 tidb 到 10.10.111.193:20160 的网络联通情况

24

你好，已补充tikv log
tikv_20200914.log (102.3 KB)

25

对了 另外可以帮

select @@tidb_config;

看下 enable-streaming 的值

26

enable-streaming": false

28
  1. 方便查看下 mysql.stats_histograms 有多少数据量吗？
  2. 能否反馈 explain analyze 3 个多小时，这段时间里的 over-view，tidb 和 detail-tikv 的监控信息，多谢。

(1)、chrome 安装这个插件https://chrome.google.com/webstore/detail/full-page-screen-capture/fdpohaocaechififmbbbbbknoalclacl

(2)、鼠标焦点置于 Dashboard 上，按 ?可显示所有快捷键，先按 d 再按 E 可将所有 Rows 的 Panels 打开，需等待一段时间待页面加载完成。

(3)、使用这个 full-page-screen-capture 插件进行截屏保存

  1. 慢的这段时间，从第一次正常执行，到第二次慢30s，这几分钟的tidb.log 和 tikv.log 完整日志麻烦都发下，多谢。
29

1.mysql.stats_histograms表数据量为25642
3.楼上提供的tidb与tikv的log就是包含第一次正常执行与第二次慢的
2.explain analyze没有3个多小时，我在14：16分又触发了一下问题，下图为触发问题时间附近15分钟监控截图
overview

utidb01-overview-2020-09-16-14_21_25
utidb01-overview-2020-09-16-14_21_252502×14774 3.93 MB

tidb，图片太大，改为压缩文件
tidb.zip (5.9 MB)

tikv-detail,图片太大，改为压缩文件
utidb01-tikv-details-2020-09-16-14_25_34.png.zip (6.5 MB)
utidb01-tikv-details-2020-09-16-14_25_34-2.png.zip (5.7 MB)
utidb01-tikv-details-2020-09-16-14_25_34-3.png.zip (6.4 MB)
utidb01-tikv-details-2020-09-16-14_25_34-4.png.zip (1018.9 KB)

30

再补充一下14：16分触发时tidb与tikv的完整log
tidb.log.20200916 (197.5 KB)

tikv1.log.20200916 (219.2 KB)
tikv2.log.20200916 (241.9 KB)
tikv3.log.20200916 (247.5 KB)

31
  1. 从 tidb.log 和 tikv.log 看，有一些 region 选不出 leader ，term 不一致，这套集群出问题前，出现过什么问题？ 比如掉电，或者使用过 tikv-ctl 删除副本之类的？

image
image3177×499 568 KB

32

没有做过其他操作，只做了升级与几次reload，其中一次用了–force，reload是修改线程池配置

33

term不一致有什么办法修复吗

36

暂时没有找到，另外请问下除了 explain 的问题，select insert 这些偶尔会遇到报错吗？业务目前还可以正常使用吗？

37

执行select才会触发，explain慢是因为触发了tikvRPC backoffer.maxSleep 40000ms，这个时候执行什么都会卡住一会，另外就是我们确实没有做过其他不规范操作，升级后就这样了，是否存在bug？

38

我仔细查了一下升级前的日志，发现升级前也有很多not leader的warning，但是触发tikvRPC backoffer.maxSleep确实是升级后才有的，所以之前说的term不符的情况可能不是问题原因

39
  1. 好的，如果您确认是升级前就有的，那么暂时可以先考虑其他方面
  2. 麻烦 pd-ctl 反馈 store 信息
  3. explain 使用 limit 10 看一下是否还有问题，多谢。
40

2.store信息如下
{
“count”: 3,
“stores”: [
{
“store”: {
“id”: 4,
“address”: “10.10.56.107:20160”,
“version”: “4.0.5”,
“status_address”: “10.10.56.107:20180”,
“git_hash”: “f39927a3529d40a6bb4e6c54854a94fdac996e92”,
“start_timestamp”: 1599728419,
“deploy_path”: “/data/deploy/bin”,
“last_heartbeat”: 1600331069288607658,
“state_name”: “Up”
},
“status”: {
“capacity”: “1.153TiB”,
“available”: “577GiB”,
“used_size”: “587.9GiB”,
“leader_count”: 12883,
“leader_weight”: 1,
“leader_score”: 12883,
“leader_size”: 1004549,
“region_count”: 38652,
“region_weight”: 1,
“region_score”: 3012114,
“region_size”: 3012114,
“start_ts”: “2020-09-10T17:00:19+08:00”,
“last_heartbeat_ts”: “2020-09-17T16:24:29.288607658+08:00”,
“uptime”: “167h24m10.288607658s”
}
},
{
“store”: {
“id”: 5,
“address”: “10.10.73.149:20160”,
“version”: “4.0.5”,
“status_address”: “10.10.73.149:20180”,
“git_hash”: “f39927a3529d40a6bb4e6c54854a94fdac996e92”,
“start_timestamp”: 1599728275,
“deploy_path”: “/data/deploy/bin”,
“last_heartbeat”: 1600331067855881086,
“state_name”: “Up”
},
“status”: {
“capacity”: “1.153TiB”,
“available”: “575.7GiB”,
“used_size”: “588.4GiB”,
“leader_count”: 12885,
“leader_weight”: 1,
“leader_score”: 12885,
“leader_size”: 1003833,
“region_count”: 38652,
“region_weight”: 1,
“region_score”: 3012114,
“region_size”: 3012114,
“start_ts”: “2020-09-10T16:57:55+08:00”,
“last_heartbeat_ts”: “2020-09-17T16:24:27.855881086+08:00”,
“uptime”: “167h26m32.855881086s”
}
},
{
“store”: {
“id”: 1,
“address”: “10.10.111.193:20160”,
“version”: “4.0.5”,
“status_address”: “10.10.111.193:20180”,
“git_hash”: “f39927a3529d40a6bb4e6c54854a94fdac996e92”,
“start_timestamp”: 1599728575,
“deploy_path”: “/data/deploy/bin”,
“last_heartbeat”: 1600331072542851261,
“state_name”: “Up”
},
“status”: {
“capacity”: “1.153TiB”,
“available”: “576.9GiB”,
“used_size”: “587.5GiB”,
“leader_count”: 12884,
“leader_weight”: 1,
“leader_score”: 12884,
“leader_size”: 1003732,
“region_count”: 38652,
“region_weight”: 1,
“region_score”: 3012114,
“region_size”: 3012114,
“start_ts”: “2020-09-10T17:02:55+08:00”,
“last_heartbeat_ts”: “2020-09-17T16:24:32.542851261+08:00”,
“uptime”: “167h21m37.542851261s”
}
}
]
}

3.跟explain没关系，之前explain慢是因为执行explain前的select触发了backoff sleep，我执行select * from supplies limit 10 依然可以复现问题，但是如果用select * from supplies where id = 1226507（这个id为limit 10查出来的一个结果）这种方式查询则不会触发问题

41

感谢，当前看问题可能在tidb 一直访问 tikv 报 cancel 是会尝试其他 peer 导致 kv 看到一些 not leader 错误的。 您能否尝试下重启 tidb-server ？ 只重启 tidb-server 试试？

42

这个问题发生后，pd、tidb、tikv都有重启过，不过问题还是存在

43

好的，明天我们用一个 binary 版本打印下日志，看看能否找到问题。

44

感谢pingcap的荣毅龙与苏立两位同学，通过修改配置项
tikv-client.max-batch-size: 128
问题得到解决

45

:handshake: