HAProxy，从 JDBC 池连接时客户端超时

Question

我有一个 web 应用程序（Tomcat/Hibernate/DBCP 1.4），它运行对 MySQL 的查询，这对于特定的负载很有效，比如每秒 50 个查询。当我通过 HAProxy 路由相同的中等负载（仍然只使用一个数据库）时，我会失败，可能每 500 次查询就会失败。我的应用报告：

Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 196,898 milliseconds ago.    The last packet sent successfully to the server was 0 milliseconds ago.
at sun.reflect.GeneratedConstructorAccessor210.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1117)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3567)
...
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.jdbc.MysqlIO.readFully(MysqlIO.java:3017)
...

同时 HAProxy 日志显示了很多条目，例如：

27] mysql mysql/db03 0/0/34605 2364382 cD 3/3/3/3/0 0/0
Oct 15 15:43:12 localhost haproxy[3141]: 127.0.0.1:35500 [15/Oct/2012:15:42:50.0

“cD”显然表示客户端超时状态。因此，虽然我的 webapp 说 HAProxy 拒绝接受新连接，但 HAProxy 说我的 webapp 不接受数据。

我不包括我的 HAProxy 配置，因为我尝试了许多不同的参数值，结果基本相同。特别是，我在全局和服务器部分都将 maxconn 设置为高值和低值，并且在统计信息中总是会出现最大会话数上升到不超过 7 的情况。我的 JDBC 池大小也很高。

通常可以一起使用 JDBC 池和 HAProxy 池吗？人们以前遇到过这种问题吗？

我有一个关于如何解决这个问题的想法，即在每次查询之前发送一个“验证查询”。但是那里有一定的开销，我仍然想知道为什么我的 webapp 在它直接进入 MySQL 时会成功，但在通过 HAProxy 时连接断开。

我怎样才能进一步调试并获得比“CD”更多的信息？我尝试在调试模式下运行 HAProxy，但它似乎没有透露更多信息。

---

更新 - 2013 年 1 月 4 日星期五 11:49:28 ICT（回复 JimB）

从 haproxy 获取比您拥有的更多信息的唯一方法是定期使用show sessorshow sess <id>命令来观察每个 tcp 连接的状态

以下是有关会议的一些信息：

0x31f4310: proto=tcpv4 src=192.168.3.40:60401 fe=FE_mysql be=BE_mysql srv=mysql3 ts=08 age=1m2s calls=2 rq[f=909202h,l=0,an=00h,rx=13s,wx=,ax=] rp[f=109202h,l=0,an=00h,rx=13s,wx=,ax=] s0=[7,18h,fd=0,ex=] s1=[7,18h,fd=1,ex=] exp=13s

0x31fca50: proto=tcpv4 src=192.168.3.40:60423 fe=FE_mysql be=BE_mysql srv=mysql1 ts=08 age=2s calls=2 rq[f=909202h,l=0,an=00h,rx=1m13s,wx=,ax=] rp[f=109202h,l=0,an=00h,rx=1m13s,wx=,ax=] s0=[7,18h,fd=9,ex=] s1=[7,18h,fd=12,ex=] exp=1m13s

Haproxy 的默认超时时间为 10 秒（我认为示例配置有 50 秒）。我对 JDBC 不太熟悉，但是从 Tomcat 的文档来看，有一个设置minEvictableIdleTimeMillis，它将从池中驱逐空闲连接，默认为 60 秒，可能最多 65 秒，因为 timeBetweenEvictionRunsMillis默认情况下为 5 秒。基本上，您需要确保您的 haproxy 超时时间足够长，以考虑池中的这些空闲连接。

我已将时间增加到timeout client75 秒，现在上述错误似乎比以前少了：

2013-01-04 11:59:59 调试：通信链接失败

从服务器成功接收的最后一个数据包是 145,255 毫秒前。最后一个成功发送到服务器的数据包是 10 毫秒前。

我还想指出的是：除上述之外，还有一些错误是这样的：

通信链路故障 最后一个成功发送到服务器的数据包是 0 毫秒前。驱动程序没有收到来自服务器的任何数据包。

在服务器端，有时我会sD在断开连接时看到标志：

haproxy[15770]: 192.168.3.40:56944 [04/Jan/2013:11:06:55.895] FE_mysql BE_mysql/mysql1 0/0/77153 1954480 sD 1/1/1/1/0 0/0

的timeout server也被设定为75秒。

另一种方法是使用testWhileIdle并 valildationQuery保持连接处于活动状态，因为每隔几秒钟发送一些流量数据包也可能会缓解该问题。

如果没有其他方法，我会建议开发人员尝试这些选项。

Answer 1

从 haproxy 获取比您拥有的信息更多的信息的唯一方法是定期使用show sessorshow sess <id>命令来观察每个 tcp 连接的状态，尽管我不确定您是否会获得更多有用的信息。

该cD终止状态是最有帮助的一块信息你有。它的确切含义是与客户端建立的连接超时。这是通过timeout client配置中的参数在 haproxy 中控制的，全局设置，或者在前端或监听部分。

你说你没有看到并发连接超过 7，并且这个日志条目显示只有 3 个连接时发生了故障，所以我怀疑你有连接限制问题（即使在 haproxy 的控制之外）。

所以看起来正在发生的是，池偶尔会添加一个新连接，它处理一些查询，然后闲置。当该连接的空闲时间超过timeout clienthaproxy 中的设置时，haproxy 将终止连接本身。下次从池中使用该连接时，您会收到上述错误。

Haproxy 的默认超时时间为 10 秒（我认为示例配置有 50 秒）。我对 JDBC 不太熟悉，但是从 Tomcat 的文档来看，有一个设置minEvictableIdleTimeMillis，它将从池中驱逐空闲连接，默认为 60 秒，可能最多 65 秒，因为timeBetweenEvictionRunsMillis默认情况下为 5 秒。基本上，您需要确保您的 haproxy 超时时间足够长，以考虑池中的这些空闲连接。

另一种方法是使用testWhileIdle并valildationQuery保持连接处于活动状态，因为每隔几秒钟发送一些流量数据包也可能会缓解该问题。

[编辑] 回应@quanta 的附加信息：

即使 haproxy 超时现在是 75 秒，您肯定仍然会遇到会话超时。在 JDBC 连接的整个生命周期中可能会有一些我不知道的额外作用。由于此类服务所需的连接很少，因此将超时增加到非常高的值（大约一个小时或更长时间）也没有错。如果 JDBC 池确实在释放旧连接时遇到问题，这只会掩盖问题，但它也可以是一个简单的解决方案。