最近讓人頭疼的一個問題,就是服務器在不確定的時間點會出現關于數據庫連接的exception,大致的exception如下:
org.hibernate.util.JDBCExceptionReporter?-?SQL?Error:0,?SQLState:?08S01 org.hibernate.util.JDBCExceptionReporter?-?The?last?packet?successfully?received?from?the?server?was43200?milliseconds?ago. The?last?packet?sent?successfully?to?the?server?was?43200?milliseconds?ago,?which?is?longer?than?the?server?configured? value?of?'wait_timeout'.?You?should?consider?either?expiring?and/or?testing?connection?validity?before?use?in?your?application,? increasing?the?server?configured?values?for?client?timeouts,?or?using?the?Connector/J?connection?'autoReconnect=true'?to?avoid?this?problem. org.hibernate.event.def.AbstractFlushingEventListener?-?Could?not?synchronize?database?state?with?session org.hibernate.exception.JDBCConnectionException:?Could?not?execute?JDBC?batch?update com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException:?Connection.close()?has?already?been?called.?Invalid?operation?in?this?state. org.hibernate.util.JDBCExceptionReporter?-?SQL?Error:0,?SQLState:?08003 org.hibernate.util.JDBCExceptionReporter?-?No?operations?allowed?after?connection?closed.?Connection?was?implicitly?closed?due?to?underlying?exception/error: **?BEGIN?NESTED?EXCEPTION?** com.mysql.jdbc.exceptions.jdbc4.CommunicationsException
先說一下發生這個Exception的大致原因:
MySQL的配置中,有一個叫做“wait_timeout”的參數,這個參數大致的意思是這樣:當一個客戶端連接到exception后,如果客戶端不自己斷開,也不做任何操作,MySQL數據庫會將這個連接保留”wait_timeout”這么長時間(單位是s,默認是28800s,也就是8小時),超過這個時間之后,MySQL數據庫為了節省資源,就會在數據庫端斷開這個連接;當然,在此過程中,如果客戶端在這個連接上有任意的操作,MySQL數據庫都會重新開始計算這個時間。
這么看來,發生上面Exception的原因就是因為我的服務器和MySQL數據庫的連接超過了”wait_timeout”時間,MySQL服務器端將其斷開了,但是我的程序再次使用這個連接時沒有做任何判斷,所以就掛了。
那這個問題怎么解決呢?
在想解決方案的過程中,我發現了幾個讓我不著頭緒的問題:
第一個問題:我們的服務器曾經在設計的過程中考慮過這個事情,所以服務器的主線程有一個定時的check機制,每隔半小時會發送一個”select 1″到數據庫來保證連接是活動的,為什么這個check機制不起作用了呢?
第二個問題:從上面的Exception中可以得到這么一個信息:
The?last?packet?sent?successfully?to?the?server?was?43200?milliseconds?ago,? which?is?longer?than?the?server?configured?value?of?'wait_timeout'.
這個信息說的很明白,最后一個成功發到Server的包是43200毫秒之前。但是43200毫秒才43.2秒,也就是說我們的服務器43.2秒之前才和MySQL服務器通過信,怎么會發生超過”wait_timeout“的問題呢?而且MySQL數據庫的配置也確實是28800秒(8小時),這又是神馬情況呢?
在網上google了n長時間,倒是有不少關于這個問題的討論,但是一直沒有找到讓我覺得有效的方法,只能自己結合google到結果來慢慢琢磨了。
首先,MySQL數據庫那邊的解決方案很單一,就是延長”wait_timeout“的數值。我看有的人直接就延長到一年了,也有人說這個值最大也就是21天,即使值設的再大,MySQL也就只識別21天(這個我沒有具體去MySQL的文檔中去查)。但是這是一個治標不治本的方法,即使可以一年,也還是會有斷的時候,服務器可是要7×24小時在線的呀。
既然MySQL數據庫那邊沒什么好方法,接下來就只能從程序這邊來搞了。
先說說程序這邊的大致結構吧:兩個線程,一個線程負責查詢和上面說到的check機制,另一個線程負責定時更新數據庫,使用hibernate,配置很簡單,都是最基本的,沒有任何關于連接池和緩存的配置,就像下面這樣:
<session-factory> ????<property>org.hibernate.dialect.MySQL5InnoDBDialect</property> ????<property>com.mysql.jdbc.Driver</property> ????<property>true</property> ????<property>UTF-8</property> ????<property>true</property> ????<!-- 以下就全是mapping了,省略 --> </session-factory>
程序中更新的過程大致是這樣:
session?=?org.hibernate.SessionFactory.openSession(); transaction?=?session.beginTransaction(); session.update(something); transaction.commit(); session.close();
在這里,所有關于數據庫Connection的連接和關閉都在Hibernate中,因此,不去挖掘Hibernate的源碼是不可能了。
在挖掘Hibernate源碼之前,必須明確目標:挖掘什么?
其實我的目標很明確,既然斷開連接是MySQL數據庫做的,那么相對于我們程序這邊的問題就是我們在使用完連接之后沒有調用Connection.close(),才會保留一個長連接在那里。那么,Hibernate是什么時候開啟這個連接,又什么時候調用Connection.close()的呢?
接下來就是Hibernate的源碼挖掘中。。。
枯燥的過程就不說了,說說挖掘出的東西:
Hibernate(忘了說了,我們用的Hibernate版本是3.3.2)在上面的那種配置之下,會有一個默認的連接池,名字叫:DriverManagerConnectionProvider;這是一個極其簡單的連接池,默認會在池中保留20個連接,這些連接不是一開始Hibernate初始化時就創建好的,而是在你需要使用連接時創建出來,使用完之后才加入到池中的。這里有一個叫closeConnection(Connection conn)的方法,這個方法很NB,它直接將傳入的連接不做任何處理,放到池中。而這個類內部的連接池實際是一個ArrayList,每次取得時候remove掉ArrayList的第一個連接,用完后直接用add方法加入到ArrayList的最后。
我們的程序更新時,Hibernate會通過DriverManagerConnectionProvider得到一個連接Connection,在使用完之后,調用session.close()時,Hibernate會調用DriverManagerConnectionProvider的closeConnection方法(就是上面說的那個NB方法),這個時候,該連接會直接放到DriverManagerConnectionProvider的ArrayList中,從始至終也沒有地方去調用Connection的close方法。
說到這里,問題就很明顯了。
第一,我們的那個”select 1“的check機制和我們服務器程序中更新的邏輯是兩個線程,check機制工作時,它會向DriverManagerConnectionProvider獲取一個連接,而此時更新邏輯工作時,它會向DriverManagerConnectionProvider獲取另外一個連接,兩個邏輯工作完之后都會將自己獲得的連接放回DriverManagerConnectionProvider的池中,而且是放到那個池的末尾。這樣,check機制再想check這兩個連接就需要運氣了,因為更新邏輯更新完之后就把連接放回池中了,而更新邏輯是定時的,check機制也是定時的,兩個定時機制如果總是能錯開,那么check機制check的永遠都是兩個中的一個連接,另外一個就麻煩了。這也就是為什么check機制不好使的原因。
第二,關于Exception信息中那個43200毫秒的問題也就能說明白了,check機制check的總是一個連接,而另外一個過期的連接被更新線程拿跑了,并且在check機制之后沒多久就有更新發生,43200毫秒恐怕就是它們之間的間隔吧。
到這里問題分析清楚了,怎么解決呢?
最容易想到的方案,也是網上說的最多的方案,就是延長MySQL端”wait_timeout“的時間。我說了,治標不治本,我覺得不爽,不用。
第二個看到最多的就是用”autoReconnect = true”這個方案,郁悶的是MySQL 5之后的數據庫把這個功能給去了,說會有副作用(也沒具體說有啥副作用,我也懶得查),我們用的Hibernate 3.3.2這個版本也沒有autoReconnect這個功能了。
第三個說的最多的就是使用c3p0池了,況且Hibernate官網的文檔中也提到,默認的那個連接池非常的屎,僅供測試使用,推薦使用c3p0(讓我郁悶的是我連c3p0的官網都沒找到,只在sourceForge上有個項目主頁)。好吧,我就決定用c3p0來搞定這個問題。
用c3p0解決這個Exception問題
首先很明了,只要是池它就肯定有這個問題,除非在放入池之前就把連接關閉,那池還頂個屁用。所以我參考的博客里說到,最好的方式就是在獲取連接時check一下,看看該連接是否還有效,即該Connection是否已經被MySQL數據庫那邊給關了,如果關了就重連一個。因此,按照這個思路,我修正了Hibernate的exception,問題得到了解決:
<session-factory> ????<property>org.hibernate.dialect.MySQL5InnoDBDialect</property> ????<property>com.mysql.jdbc.Driver</property> ????<property>true</property> ????<property>UTF-8</property> ????<property>true</property> ????<!-- c3p0在我們使用的Hibernate版本中自帶,不用下載,直接使用 --> ????<property>org.hibernate.connection.C3P0ConnectionProvider</property> ????<property>5</property> ????<property>20</property> ????<property>1800</property> ????<property>50</property> ????<!-- 下面這句很重要,后面有解釋 --> ????<property>true</property> ????<!-- 以下就全是mapping了,省略 --> </session-factory>
上面配置中最重要的就是hibernate.c3p0.testConnectionOnCheckout這個屬性,它保證了我們前面說的每次取出連接時會檢查該連接是否被關閉了。不過這個屬性會對性能有一些損耗,引用我參考的博客上得話:程序能用是第一,之后才是它的性能(又不是不能容忍)。
當然,c3p0自帶類似于select 1這樣的check機制,但是就像我說的,除非你將check機制的間隔時間把握的非常好,否則,問題是沒有解決的。
好了,至此,困擾我的問題解決完了。希望上面的這些整理可以為我以后碰到類似的問題留個思路,也可以為正在被此問題困擾的人提供一絲幫助