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

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

  • 【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驱动版本有无关系

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

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

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

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

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

明天吧,我这边不着急这一会:grinning:

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

关于 tidb 系统变量可以通过 set 的方式进行修改。

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

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

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

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

试过了,没起作用

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

程序报错内容:


其中一个节点的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


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

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

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

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

程序报错内容:


其中一个节点的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

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

tidb.log (559.7 KB)

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

一共三台,我都发一下吧