我有一个 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” 显然表示客户端超时状态。因此,我的 Web 应用程序表示 HAProxy 拒绝接受新连接,而 HAProxy 则表示我的 Web 应用程序不接受数据返回。
我没有包括我的 HAProxy 配置,因为我尝试了许多不同的参数值,但结果基本相同。特别是,我在全局和服务器部分将 maxconn 设置为高值和低值,而统计数据中始终出现的是最大会话数不超过 7。我的 JDBC 池大小也很高。
一般情况下,同时使用 JDBC 池和 HAProxy 池可以吗?以前有人遇到过这种问题吗?
我有一个解决这个问题的主意,就是在每次查询之前发送一个“验证查询”。但这样做会有一定的开销,而且我仍然想知道为什么我的 webapp 直接进入 MySQL 时会成功,但通过 HAProxy 时会断开连接。
我如何进一步调试并获取除“cD”之外的更多信息?我尝试在调试模式下运行 HAProxy,但似乎没有显示更多信息。
更新 - 1 月 4 日星期五 11:49:28 ICT 2013(回复 JimB)
从 haproxy 获取更多信息的唯一方法是定期使用
show sess
或show 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 client
75 秒,现在上述错误似乎比以前更少发生:
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
保持连接处于活动状态,因为每隔几秒钟的几个数据包也可能会缓解这个问题。
如果没有其他办法,我建议开发人员尝试这些选项。
答案1
从 haproxy 获取更多信息的唯一方法是定期使用show sess
或show sess <id>
命令来监视每个 tcp 连接的状态,但我不确定您是否会获得更多有用的信息。
终止状态cD
是您拥有的最有用的信息。它确切的意思是与客户端建立的连接已超时。这在 haproxy 中通过timeout client
配置中的参数进行控制,全局设置,或在前端或监听部分中设置。
您说您没有看到并发连接数超过 7,而此日志条目表明故障发生在只有 3 个连接时,所以我怀疑您存在连接限制问题(甚至在 haproxy 的控制之外)。
因此,看起来发生的情况是,池偶尔会添加一个新连接,用于处理一些查询,然后处于空闲状态。当该连接处于空闲状态的时间超过timeout client
haproxy 中的设置时,haproxy 将自行终止该连接。下次从池中使用该连接时,您将收到上述错误。
Haproxy 的默认超时时间为 10 秒(我认为示例配置的超时时间为 50 秒)。我不太熟悉 JDBC,但从 Tomcat 的文档来看,有一个设置minEvictableIdleTimeMillis
,它将从池中驱逐空闲连接,默认为 60 秒,可能最多为 65 秒,因为timeBetweenEvictionRunsMillis
默认情况下为 5 秒。基本上,您需要确保您的 haproxy 超时足够高,以解决池中的这些空闲连接。
另一种方法是使用testWhileIdle
并valildationQuery
保持连接处于活动状态,因为每隔几秒钟的几个数据包也可能会缓解这个问题。
[编辑] 回应@quanta 的补充信息:
即使 haproxy 超时现在是 75 秒,您肯定仍会遇到会话超时。我不知道 JDBC 连接的总生命周期中可能还有一些额外的作用。由于这种类型的服务所需的连接很少,因此将超时增加到极高的值(大约一小时或更长时间)也没有错。如果 JDBC 池确实在释放旧连接时遇到问题,这只会掩盖问题,但也可能很容易修复。