hibernate 连接 mysql BEGIN NESTED EXCEPTION 错误

发信人: Neverwinter (nez@Atlantis), 信区: Database
标  题: [原创]一个MySQL连接问题的解决
发信站: 北邮人论坛 (Tue Sep  5 19:34:07 2006), 站内

【 以下文字转载自 SoftDesign 讨论区 】
发信人: Neverwinter (nez@Atlantis), 信区: SoftDesign
标  题: [原创]一个MySQL连接问题的解决
发信站: 北邮人论坛 (Fri Sep  1 17:32:13 2006), 站内

使用Spring+Hibernate开发的一个J2EE服务，数据库使用MySQL 5.0，部署容器是Tomcat 5.5。
一般情况下，服务运行正常。但是如果长时间没有连接连上服务器，过一段时间后再次连接就会失败。但是重启Tomcat服务器，服务又会正常运行。

Log中的输入（部分）如下：
2006-08-28 14:34:31,981 ERROR [org.springframework.transaction.interceptor.TransactionInterceptor] - <Application exception overridden by rollback exception>
org.springframework.jdbc.UncategorizedSQLException: Hibernate operation: could not execute query; uncategorized SQLException for SQL [select userprofil0_.uid as uid6_, userprofil0_.name as name6_, userprofil0_.mails as mails6_, userprofil0_.phones as phones6_, userprofil0_.mobiles as mobiles6_, userprofil0_.addrs as addrs6_, userprofil0_.gender as gender6_, userprofil0_.age as age6_, userprofil0_.vs_path as vs9_6_, userprofil0_.passwd as passwd6_, userprofil0_.logo_path as logo11_6_, userprofil0_.vs_size as vs12_6_ from user_profile userprofil0_ where userprofil0_.uid=? and userprofil0_.passwd=?]; SQL state [08003]; error code [0]; No operations allowed after connection closed.Connection was implicitly closed due to underlying exception/error:


** BEGIN NESTED EXCEPTION ** 

com.mysql.jdbc.CommunicationsException
MESSAGE: Communications link failure due to underlying exception: 

** BEGIN NESTED EXCEPTION ** 

java.net.SocketException
MESSAGE: Software caused connection abort: socket write error

STACKTRACE:

java.net.SocketException: Software caused connection abort: socket write error
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(Unknown Source)
    at java.net.SocketOutputStream.write(Unknown Source)
    at java.io.BufferedOutputStream.flushBuffer(Unknown Source)
    at java.io.BufferedOutputStream.flush(Unknown Source)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2739)
......

Last packet sent to the server was 0 ms ago.
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2757)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2650)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1581)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1695)
    at com.mysql.jdbc.Connection.execSQL(Connection.java:3004)
......

从log中可以看出，Tomcat服务器与MySQL服务器之间已经失去连接。

上网搜索，发现原来MySQL wait timeout的值默认是28800 (3600*8)，即一个连接在8小时内没有活动，就会自动断开该连接。
wait timeout的值可以设定，但最多只能是32767，不能再大了。

然后搜到解决这个问题的一个办法是在hibernate.cfg.xml中，在url的连接后加上autoReconnect=true

修改url后再试，还是有错误，不过有所变化：
2006-08-30 15:40:31,109 WARN [org.hibernate.util.JDBCExceptionReporter] - <SQL Error: 0, SQLState: 08S01>
2006-08-30 15:40:31,109 ERROR [org.hibernate.util.JDBCExceptionReporter] - <Communications link failure due to underlying exception: 

** BEGIN NESTED EXCEPTION ** 

java.net.SocketException
MESSAGE: Software caused connection abort: socket write error

STACKTRACE:

java.net.SocketException: Software caused connection abort: socket write error
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(Unknown Source)
    at java.net.SocketOutputStream.write(Unknown Source)
    at java.io.BufferedOutputStream.flushBuffer(Unknown Source)
    at java.io.BufferedOutputStream.flush(Unknown Source)
......

Last packet sent to the server was 0 ms ago.>
2006-08-30 15:40:31,109 ERROR [org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/ds].[ds]] - <Servlet.service() for servlet ds threw exception>
org.springframework.jdbc.UncategorizedSQLException: Hibernate operation: could not execute query; uncategorized SQLException for SQL [select userprofil0_.uid as uid6_, userprofil0_.name as name6_, userprofil0_.mails as mails6_, userprofil0_.phones as phones6_, userprofil0_.mobiles as mobiles6_, userprofil0_.addrs as addrs6_, userprofil0_.gender as gender6_, userprofil0_.age as age6_, userprofil0_.vs_path as vs9_6_, userprofil0_.passwd as passwd6_, userprofil0_.logo_path as logo11_6_, userprofil0_.vs_size as vs12_6_ from user_profile userprofil0_ where userprofil0_.uid=? and userprofil0_.passwd=?]; SQL state [08S01]; error code [0]; Communications link failure due to underlying exception: 

** BEGIN NESTED EXCEPTION ** 

java.net.SocketException
MESSAGE: Software caused connection abort: socket write error

STACKTRACE:

java.net.SocketException: Software caused connection abort: socket write error
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(Unknown Source)
    at java.net.SocketOutputStream.write(Unknown Source)
    at java.io.BufferedOutputStream.flushBuffer(Unknown Source)
    at java.io.BufferedOutputStream.flush(Unknown Source)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2739)
......

上网搜索，在MySQL的论坛上找到一个办法，就是如果在执行sql语句的时候发生了上述异常，就将sql语句重新执行一次。
试验发现，这个办法对我这个使用spring+hibernate的服务无效。
进一步搜索发现，MySQL官方不推荐使用autoReconnect=true，参见http://bugs.mysql.com/bug.php?id=5020
需要另外找别的办法来解决这个问题。

由于问题产生的根本原因在于服务到数据库的连接长时间没活动，既然重新连接的办法无效，就可以尝试另外一种办法，就是反空闲。
自己写一个线程来反空闲的话，比较麻烦。
最后在网上找到一个办法。为hibernate配置连接池，推荐用c3p0，然后配置c3p0的反空闲设置idle_test_period，只要小于MySQL的wait timeout即可。
在hibernate.cfg.xml中增加下面几项：
<!-- configuration pool via c3p0-->
<property name="hibernate.connection.provider_class">org.hibernate.connection.C3P0ConnectionProvider</property>
<property name="c3p0.min_size">5</property>
<property name="c3p0.max_size">30</property>
<property name="c3p0.time_out">1800</property> <!-- seconds --><!-- default: 0 -->
<property name="c3p0.max_statement">50</property> <!-- default: 0 -->
<property name="c3p0.acquire_increment">1</property> <!-- default: 1 -->
<property name="c3p0.idle_test_period">120</property>  <!-- seconds --><!-- default: 0 -->
<property name="c3p0.validate">true</property>

修改完后测试，问题解决。
--
[QMD No. 2]
程序是程序员才有的高尚爱好
程序是程序员才懂的欣赏的艺术
程序是只有程序员才能领悟的哲学
程序是永远的程序员的思维的结晶
作为程序员应该以自己是程序员而骄傲