sql 执行报错：Fatal error encountered attempting to read the resultset

Kongdom · 2020 年7 月 23 日 12:13

为提高效率，提问时请提供以下信息，问题描述清晰可优先响应。

【TiDB 版本】：5.7.25-TiDB-v4.0.0-rc
【问题描述】：
客户端连接TIDB数据库执行多个insert语句，大概70s左右会报错：

> Fatal error encountered attempting to read the resultset。

网上百度结果是修改net_write_timeout参数，但是修改之后没有改善。发帖想问一下

1、以下几个mysql参数是否支持：
net_write_timeout、net_buffer_length、net_read_timeout、max_allowed_packet
2、C#编写的客户端连接tidb，性能方面与mysql驱动版本有无关系

来了老弟 · 2020 年7 月 23 日 12:24

对于 tidb 数据库的使用，70s 左右的 insert 是同一个事务？
可以将 batch 设置到一个较小的值，insert into tbl values (),()… ,(); 1000-5000 个，可以根据服务器性能进行调整。

可以在文档中搜索下该参数是否支持，这边可以提供到 github 上 tidbserver 的配置文件模板
https://github.com/pingcap/tidb/blob/master/config/config.toml.example

对于驱动的效率可以到其社区咨询下。

Kongdom · 2020 年7 月 23 日 12:25

1、业务已经不允许再切分了。。。
2、我去那边看一下
3、我得意思是tidb版本和mysql驱动是否有版本对应关系，不是想问哪个版本的驱动性能高

Kongdom · 2020 年7 月 23 日 12:28

mysql参数那个，我搜了一下example，没有。但是在tidb下mysql数据库的GLOBAL_VARIABLES表中有。。。所以就不知道有没有实现这个功能。

Kongdom · 2020 年7 月 23 日 12:29

明天吧，我这边不着急这一会

来了老弟 · 2020 年7 月 23 日 12:45

业务使用上应该是可以调整的，如果写入方式对数据库不友好的话，

关于 tidb 系统变量可以通过 set 的方式进行修改。
https://docs.pingcap.com/zh/tidb/stable/system-variables

Kongdom · 2020 年7 月 24 日 00:33

链接中tidb系统变量中没有找到类似相关的变量。

还是希望和研发同事确认一下net_write_timeout这个变量是否兼容。目前表象分析，最有可能的就是这个变量导致的。

同一个语句，在C#程序中调用，超过60-70s就会报错，同样语句放到数据库执行不会报错。

来了老弟 · 2020 年7 月 24 日 02:12

set @@session.net_write_timeout = 60;
set @@global.net_write_timeout = 60;
来修改此值。

Kongdom · 2020 年7 月 24 日 02:35

试过了，没起作用

来了老弟 · 2020 年7 月 24 日 02:37

看下 tidb log 是有有返回报错呢。
可否将程序报错的文本内容也贴出来看下

Kongdom · 2020 年7 月 24 日 02:50

程序报错内容：

其中一个节点的tidb日志

[2020/07/24 10:41:48.373 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=34510]
[2020/07/24 10:41:48.373 +08:00] [INFO] [server.go:388] [“new connection”] [conn=34510] [remoteAddr=192.168.3.222:34148]
[2020/07/24 10:41:48.379 +08:00] [INFO] [set.go:201] [“set session var”] [conn=34510] [name=character_set_results] [val=NULL]
[2020/07/24 10:41:48.395 +08:00] [INFO] [server.go:391] [“connection closed”] [conn=34510]
[2020/07/24 10:41:48.527 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=34511]
[2020/07/24 10:41:48.527 +08:00] [INFO] [server.go:388] [“new connection”] [conn=34511] [remoteAddr=192.168.3.222:54786]
[2020/07/24 10:41:48.532 +08:00] [INFO] [set.go:201] [“set session var”] [conn=34511] [name=character_set_results] [val=NULL]
[2020/07/24 10:41:48.541 +08:00] [INFO] [server.go:391] [“connection closed”] [conn=34511]
[2020/07/24 10:41:49.367 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=34512]
[2020/07/24 10:41:49.367 +08:00] [INFO] [server.go:388] [“new connection”] [conn=34512] [remoteAddr=192.168.1.31:57012]
[2020/07/24 10:41:49.368 +08:00] [INFO] [server.go:391] [“connection closed”] [conn=34512]
[2020/07/24 10:41:51.385 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=34513]

这是另一个节点的日志

[2020/07/24 10:41:48.069 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:1.00156244s txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:48.373 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:1.107969073s txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:48.450 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:1.016492356s txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:48.523 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:311.862041ms txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:48.730 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:926.580353ms txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:49.138 +08:00] [WARN] [pd.go:109] [“get timestamp too slow”] [“cost time”=139.23929ms]
[2020/07/24 10:41:49.467 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=27918]
[2020/07/24 10:41:49.467 +08:00] [INFO] [server.go:388] [“new connection”] [conn=27918] [remoteAddr=192.168.1.31:46224]
[2020/07/24 10:41:49.476 +08:00] [INFO] [server.go:391] [“connection closed”] [conn=27918]
[2020/07/24 10:41:51.367 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=27919]

一共三个节点，1、2节点的内容一样，是图2，3节点是图3

Kongdom · 2020 年7 月 24 日 03:15

这个是网上搜的解决方案，所以发帖问一下，这个mysql的系统参数，在tidb里有没有支持

来了老弟 · 2020 年7 月 24 日 03:19

支持的，但是不确定是否是这个原因导致的，或者自行调整到一个超大的值试下？所以建议看下 tidb log 是否有信息可以确定下报错。

Kongdom · 2020 年7 月 24 日 03:44

嗯，tidb log已发，麻烦看一下

来了老弟 · 2020 年7 月 24 日 07:00

hi，帖子中没有看到 tidb log 辛苦再确认下

Kongdom · 2020 年7 月 24 日 07:32

程序报错内容：

其中一个节点的tidb日志

[2020/07/24 10:41:48.373 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=34510]
[2020/07/24 10:41:48.373 +08:00] [INFO] [server.go:388] [“new connection”] [conn=34510] [remoteAddr=192.168.3.222:34148]
[2020/07/24 10:41:48.379 +08:00] [INFO] [set.go:201] [“set session var”] [conn=34510] [name=character_set_results] [val=NULL]
[2020/07/24 10:41:48.395 +08:00] [INFO] [server.go:391] [“connection closed”] [conn=34510]
[2020/07/24 10:41:48.527 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=34511]
[2020/07/24 10:41:48.527 +08:00] [INFO] [server.go:388] [“new connection”] [conn=34511] [remoteAddr=192.168.3.222:54786]
[2020/07/24 10:41:48.532 +08:00] [INFO] [set.go:201] [“set session var”] [conn=34511] [name=character_set_results] [val=NULL]
[2020/07/24 10:41:48.541 +08:00] [INFO] [server.go:391] [“connection closed”] [conn=34511]
[2020/07/24 10:41:49.367 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=34512]
[2020/07/24 10:41:49.367 +08:00] [INFO] [server.go:388] [“new connection”] [conn=34512] [remoteAddr=192.168.1.31:57012]
[2020/07/24 10:41:49.368 +08:00] [INFO] [server.go:391] [“connection closed”] [conn=34512]
[2020/07/24 10:41:51.385 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=34513]

这是另一个节点的日志

[2020/07/24 10:41:48.069 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:1.00156244s txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:48.373 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:1.107969073s txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:48.450 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:1.016492356s txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:48.523 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:311.862041ms txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:48.730 +08:00] [INFO] [coprocessor.go:863] [“[TIME_COP_PROCESS] resp_time:926.580353ms txnStartTS:418266088956755972 region_id:6129 store_addr:192.168.1.36:20160”] [conn=27908]
[2020/07/24 10:41:49.138 +08:00] [WARN] [pd.go:109] [“get timestamp too slow”] [“cost time”=139.23929ms]
[2020/07/24 10:41:49.467 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=27918]
[2020/07/24 10:41:49.467 +08:00] [INFO] [server.go:388] [“new connection”] [conn=27918] [remoteAddr=192.168.1.31:46224]
[2020/07/24 10:41:49.476 +08:00] [INFO] [server.go:391] [“connection closed”] [conn=27918]
[2020/07/24 10:41:51.367 +08:00] [WARN] [conn.go:572] [“open new session failure”] [conn=27919]

一共三个节点，1、2节点的内容一样，是图2，3节点是图3

来了老弟 · 2020 年7 月 24 日 07:40

程序报错是， 10：42：48 。tidb log 中是 10：41：48 左右，在时间上对应不上啊，如果方便可以在帮忙上传下，或者上传完整的 tidb log 我们可以摘取。

Kongdom · 2020 年7 月 24 日 08:07

tidb.log (559.7 KB)

来了老弟 · 2020 年7 月 24 日 09:05

tidb log 中没有有效的信息可以获取，问题下当前 tidb server 是否仅为此一台。

Kongdom · 2020 年7 月 24 日 09:24

一共三台，我都发一下吧