Mysql作為一個常用數據庫，在互聯網系統應用很多。有些故障是其自身的bug，有些則不是，這裡以前段時間遇到的問題舉例。
當時遇到的症狀是這樣的，我們的應用在線上測試環境，JMeter測試過程中，發現每次壓力測試開始時訪問低前幾個http request請求會超時，而之後的請求持續測試中都不會。最後一點是Tomcat的log並沒有報什麼錯誤。
壓測的內容就是起200線程不停的向這個http頁面發送請求，這個頁面邏輯也比較簡單，會在後端向數據庫插入一條數據，連接池采用阿裡的Druid（這個坑先留在這），tomcat中運行的是常規web app應用，每個應用的JDBC連接池最大連接數只設了30，就是說就算4個tomcat一起連數據庫，最大也沒有多少連接。
由於tomcat的log並沒有什麼錯，所以先開始嘗試重現錯誤。 錯誤重現開始並不容易，因為看起來比較隨機，後來經過總結，發現每次都是出現問題都是應用放了一晚上後，測試人員早上過來開始壓力測試時出現，開始懷疑跟閒置有關，所以後面的重現都按這個方式來，閒置半小時再開始嘗試重現。
沒有log，就要看下JVM的stack信息了。重現故障，上該機器上用jstack直接抓問題tomcat 的jvm信息。
jps
列出機器的java進程號
jstack javaid
dump該java進程的stack信息
拿到的stack信息中發現了有用的東西：
“http-bio-8081-exec-4975” daemon prio=10 tid=0x00007f9d4c127000 nid=0x65db runnable [0x00007f9cc4544000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114)
at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161)
at **com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189)
- locked <0x0000000684d608c8> (a com.mysql.jdbc.util.ReadAheadInputStream)**
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3014)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3467)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3456)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3997)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468)
at com.mysql.jdbc.ConnectionImpl.pingInternal(ConnectionImpl.java:4092)
at com.mysql.jdbc.ConnectionImpl.ping(ConnectionImpl.java:4069)
at sun.reflect.GeneratedMethodAccessor94.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.alibaba.druid.pool.vendor.MySqlValidConnectionChecker.isValidConnection(MySqlValidConnectionChecker.java:98)
at com.alibaba.druid.pool.DruidAbstractDataSource.testConnectionInternal(DruidAbstractDataSource.java:1235)
at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:928)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:882)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:872)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:97)
at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:202)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:372)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:417)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:255)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
at com.sun.proxy.$Proxy27.insert(Unknown Source)
可以看到HTTP請求從前端容器直到數據庫讀取時為止，卡在了數據庫讀取的地方，而且並不是JDBC驅動代碼裡的問題，而且出在socket讀取的地方：
com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189)
- locked <0x0000000684d608c8> (a com.mysql.jdbc.util.ReadAheadInputStream)*
根據這個錯誤搜索了下，唯一有價值的就是N年前mysql官網上報的一個bug，同樣的錯誤，但處理的辦法並不治本。如提到了將JDBC連接字串改為：
useReadAheadInput=false&useUnbufferedInput=false
這只是讓socket不去預讀網絡緩沖區，但實際上這個時候Mysql的連接已經斷開了，並不知道是web應用這裡斷的還是Mysql斷的。
由於根據log看起來是應用的客戶端在socket上讀不到東西，肯定是應用與mysql的tcp連接斷了，所以開始排查應用連接池設置與mysql的連接超時設置。
應用連接池設置
name=”maxWait” value=”60000”
獲取連接最大等待60秒
name=”testWhileIdle” value=”true”
測試空閒連接
name=”minEvictableIdleTimeMillis” value=”300000”
name=”timeBetweenEvictionRunsMillis” value=”60000”
Destroy線程會檢測連接的間隔時間
應用端的連接池設置沒有主動斷掉的設置。
mysql連接超時設置
show global variables like ‘%timeout%’
看到mysql維持連接的timeout時間為28800，即8小時，數據庫端不會斷掉這個連接。
至此，問題的排查進入死胡同，兩邊都不會主動斷開連接，為什麼客戶端在閒置幾分鐘後會被斷掉？
還有一個疑點是同樣的代碼，數據庫也沒什麼變動，在另一個純測試環境完全沒有這個問題。
現在問題的重點懷疑方向就是線上環境網絡問題。於是找運維的同事查看了下數據庫機器上linux有沒有什麼異常的配置，結果是沒有。
期間也懷疑為什麼用了阿裡druid的連接池，現在設成每分鐘檢測連接池裡的連接，還是會在拿到連接的時候有失效的連接。
斷斷續續折騰了2天，抱著死馬當活馬醫去咨詢了其他部門的同事，結果那兄弟說是不是閒置後卡在socketRead上？然後問了應用與數據庫是不是在不同網段上，馬上建議找網絡的人查一下防火牆對tcp長連接超時的設置。
這時候基本上就肯定是防火牆設置的問題，排查後發現兩個網段間華為交換機的長連接超時設了3分鐘，由於java應用的連接池是盡量長時間的維持連接（幾個小時，低於數據庫的最長8小時設置），而防火牆認為超過3分鐘的連接是有問題的，直接斷掉了，這時應用與mysql都不知道tcp連接已經被斷了。
此次故障還暴露了阿裡Druid開源連接池對連接處理邏輯的問題，連接池並沒有用單獨的線程去檢測所有連接有沒有斷開，查代碼後發現其只是在拿到連接時測試連接是否有效，處理邏輯沒有老牌c3p0嚴謹，之後將應用連接池實現更換為c3p0。
