TiDB通过JDBC写入过程中断开频率较高

【 TiDB 使用环境】
TiDB版本:5.2.0

HAProxy(主机名:jhmk08):

服务器硬件:
10.160.60.18 Cpu 40核,256G内存,机械硬盘
10.160.60.19 Cpu 40核,256G内存,机械硬盘
10.160.60.20 Cpu 40核,256G内存,机械硬盘

【概述】 场景 + 问题概述
通过JDBC(使用HAproxy)批量写入TiDB断开频率较高。

发现TiDB有自动重启现象:
http://10.160.60.19:2379/dashboard/api/diagnose/reports/92b6b872-8698-4541-b792-b7789f1af280/detailc

【TiDB 版本】
TiDB版本:5.2.0

【附件】 相关日志及监控(https://metricstool.pingcap.com/)
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: Communications link failure

The last packet successfully received from the server was 15,400 milliseconds ago. The last packet sent successfully to the server was 15,400 milliseconds ago.
	at sun.reflect.GeneratedConstructorAccessor138.newInstance(Unknown Source)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61)
	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105)
	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151)
	at com.mysql.cj.exceptions.ExceptionFactory.createCommunicationsException(ExceptionFactory.java:167)
	at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:539)
	at com.mysql.cj.protocol.a.NativeProtocol.checkErrorMessage(NativeProtocol.java:703)
	at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:642)
	at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:128)
	at com.mysql.cj.NativeSession.sendCommand(NativeSession.java:311)
	at com.mysql.cj.ServerPreparedQuery.sendExecutePacket(ServerPreparedQuery.java:336)
	at com.mysql.cj.ServerPreparedQuery.serverExecute(ServerPreparedQuery.java:207)
	at com.mysql.cj.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:635)
	... 27 common frames omitted
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
	at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:67)
	at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:63)
	at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:45)
	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:52)
	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:41)
	at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:54)
	at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:44)
	at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:533)
	... 34 common frames omitted

发一下tidb的监控

你的 dashboard 应该是内网地址,我这边无法打开~ 需要提供一些详细信息,可以参考下面的内容

1.目前 5.2.0 版本存在一些问题,建议升级到 5.2.1,详情可以参考官网 release note
2.提供一下完整的拓扑结构,可以通过 tiup display 查看,另外提供下三台 tidb-server 的完整日志以及 error log,包含故障时间段
3.另外再提供一下 tidb 监控面板,24h 即可,确认下 TiDB 重启次数。

1赞

tidb-2021-09-14T09-17-18.871.log (591.5 KB)

三台都提供一下,还有 error log,监控也要完整的哈

简单看了下重启前都是正常的 info 信息,需要咱们这边多提供一些内容

10.160.60.18-tidb-log.tar.gz (21.6 MB) 10.160.60.19.tidb_stderr.log (2.7 MB) 10.160.60.20-tidb-log.tar.gz (23.1 MB)

还有完整的 tidb 面板监控 9 号 - 14 号 这几天的,导出方式 [FAQ] Grafana Metrics 页面的导出和导入

tidb-jhdcp-Performance-Write_2021-09-14T06_21_04.561Z.json (11.5 MB)

还要确认下,这个是官方的 grafana 界面吗 ? 少了一些监控面板。

tidb-jhdcp-TiDB-Summary 拿下这个面板 9 号 - 14 号,用最新的导出下 https://metricstool.pingcap.com/

tidb-jhdcp-TiDB-Summary_2021-09-14T06_57_44.953Z.json (486.8 KB)

是官方的,我按你的方法重导了一下。

:joy: 这次导出的只有 1h,还需要重新导出下…

时间都选择 9.7 - 9.14 号的
需要的监控面板
tidb-jhdcp-TiDB-Summary
tidb-jhdcp-TiDB

另外咱们是什么时间升级的 5.2.0 呀 ?

抱歉,我们再导一次!

大概是5.2.0刚发布的时候更新的

如果业务处于低峰期,是否方便升级到 5.2.1 呢 ? 5.2.0 版本是非稳定的版本,而且我从日志上看从 8 号开始,几乎每天都有重启的情况。

[2021/09/08 13:24:16.810 +08:00] [INFO] [printer.go:33] ["Welcome to TiDB."] 
[2021/09/10 07:29:21.768 +08:00] [INFO] [printer.go:33] ["Welcome to TiDB."]
[2021/09/11 01:25:34.216 +08:00] [INFO] [printer.go:33] ["Welcome to TiDB."] 
[2021/09/12 09:55:36.070 +08:00] [INFO] [printer.go:33] ["Welcome to TiDB."] 
[2021/09/13 16:10:15.860 +08:00] [INFO] [printer.go:33] ["Welcome to TiDB."] 
[2021/09/14 08:38:43.625 +08:00] [INFO] [printer.go:33] ["Welcome to TiDB."] 

好的,我们尝试升级一下版本看看,非常感谢!

好的,升级之后如果还有问题,就帮忙收集一下:

时间都选择 9.7 - 当前时间

需要的监控面板

  • tidb-jhdcp-TiDB-Summary
  • tidb-jhdcp-TiDB

需要的日志

  • 三台 tidb 的日志,以及 error.log

  • dmesg 日志

  • 还请帮忙记录下升级的时间

您好,我们在09-17 12:30左右完成了5.2.0到5.2.1的升级
文件都在附件tidb-log_and_garafana.rar (45.5 MB)
里面包含:

  • tidb-jhdcp-TiDB-Summary
  • tidb-jhdcp-TiDB
  • 三台 tidb 的日志,以及 error.log
  • 系统message 日志

我们发现重启的原因是触发了系统的oom机制,您看下为什么tidb会消耗如此大的资源,我们可以怎么做来避免发生这种问题吗
image