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

🛰️ 应用开发者专区
1

【 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

restart
restart1312×376 199 KB

【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
2

发一下tidb的监控

3

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

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

1 个赞
4

1
11769×577 244 KB

5

2
21197×339 415 KB

6

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

7

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

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

image
image1856×1490 587 KB

8

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)

9

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

10

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

11

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

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

12

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

13

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

14

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

image
image2830×754 192 KB

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

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

15

抱歉，我们再导一次！

16

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

17

image
image1654×1172 177 KB

如果业务处于低峰期，是否方便升级到 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."]
18

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

19

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

时间都选择 9.7 - 当前时间

需要的监控面板

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

需要的日志

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

  • dmesg 日志

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

20

您好，我们在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
image1357×468 25.8 KB