[看到底部更新]JDBC連接200840秒
我使用JDBC來運行對SQL Server 2008 R2從一個Windows 2008 R2機器上發言運行帶有2.6.32-32-server內核的Ubuntu 10.04 LTS的機器。我正在使用當前用於Ubuntu的Sun Java 6 build(sun-java6-jdk 6.24-1build0.10.04.1)和MS當前的JDBC 3.0驅動程序(sqljdbc_3.0.1301.101_enu)。
當一個語句需要超過40秒才能完成並且它不返回ResultSet(例如'stmt.executeUpdate(「SELECT * INTO BAR FROM FOO」)),程序將終止連接重置:
Exception in thread "main" com.microsoft.sqlserver.jdbc.SQLServerException: Connection reset
at com.microsoft.sqlserver.jdbc.SQLServerConnection.terminate(SQLServerConnection.java:1352)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.terminate(SQLServerConnection.java:1339)
at com.microsoft.sqlserver.jdbc.TDSChannel.read(IOBuffer.java:1654)
at com.microsoft.sqlserver.jdbc.TDSReader.readPacket(IOBuffer.java:3694)
at com.microsoft.sqlserver.jdbc.TDSCommand.startResponse(IOBuffer.java:5022)
at com.microsoft.sqlserver.jdbc.SQLServerStatement.doExecuteStatement(SQLServerStatement.java:773)
at com.microsoft.sqlserver.jdbc.SQLServerStatement$StmtExecCmd.doExecute(SQLServerStatement.java:676)
at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:4575)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:1400)
at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:179)
at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:154)
at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeUpdate(SQLServerStatement.java:633)
at TestTimeout.main(TestTimeout.java:42)
如果我的語句確實返回了ResultSet(例如'ResultSet res = stmt.executeQuery(「SELECT * FROM FOO」)'),則連接不會超時。
當我在Win2003R2上運行SQL2005中沒有返回ResultSet對數據庫副本的語句時,該語句在40秒內沒有連接重置的情況下完成。
我啓用了日誌記錄,並比較了SQL2005語句的日誌,該日誌完成了SQL2008R2語句,但沒有完成,並且它們在2008年查詢中一直等同於連接重置消息;看行於下午12時54分47秒:
Jun 6, 2011 12:54:07 PM com.microsoft.sqlserver.jdbc.TDSCommand onRequestComplete
FINEST: [email protected] (SQLServerStatement:1 executeXXX): request complete
Jun 6, 2011 12:54:07 PM com.microsoft.sqlserver.jdbc.TDSCommand startResponse
FINEST: [email protected] (SQLServerStatement:1 executeXXX): Reading response...
Jun 6, 2011 12:54:47 PM com.microsoft.sqlserver.jdbc.TDSChannel read
FINE: TDSChannel (ConnectionID:1) read failed:Connection reset
Jun 6, 2011 12:54:47 PM com.microsoft.sqlserver.jdbc.SQLServerException logException
FINE: *** SQLException:ConnectionID:1 com.microsoft.sqlserver.jdbc.SQLServerException: Connection reset Connection reset
Jun 6, 2011 12:54:47 PM com.microsoft.sqlserver.jdbc.SQLServerException logException
FINE: com.microsoft.sqlserver.jdbc.SQLServerConnection.terminate(SQLServerConnection.java:1352)com.microsoft.sqlserver.jdbc.SQLServerConnection.terminate(SQLServerConnection.java:1339)com.microsoft.sqlserver.jdbc.TDSChannel.read(IOBuffer.java:1654)com.microsoft.sqlserver.jdbc.TDSReader.readPacket(IOBuffer.java:3694)com.microsoft.sqlserver.jdbc.TDSCommand.startResponse(IOBuffer.java:5022)com.microsoft.sqlserver.jdbc.SQLServerStatement.doExecuteStatement(SQLServerStatement.java:773)com.microsoft.sqlserver.jdbc.SQLServerStatement$StmtExecCmd.doExecute(SQLServerStatement.java:676)com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:4575)com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:1400)com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:179)com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:154)com.microsoft.sqlserver.jdbc.SQLServerStatement.executeUpdate(SQLServerStatement.java:633)TestTimeout.main(TestTimeout.java:42)
[...]
下面是對應的線,從對2005年的數據庫語句的工作原理:
Jun 6, 2011 2:02:20 PM com.microsoft.sqlserver.jdbc.TDSCommand onRequestComplete
FINEST: [email protected] (SQLServerStatement:1 executeXXX): request complete
Jun 6, 2011 2:02:20 PM com.microsoft.sqlserver.jdbc.TDSCommand startResponse
FINEST: [email protected] (SQLServerStatement:1 executeXXX): Reading response...
Jun 6, 2011 2:02:57 PM com.microsoft.sqlserver.jdbc.TDSChannel logPacket
FINEST: /XXX.XXX.XXX.XXX:60091 SPID:73 [email protected] (ConnectionID:1) received Packet:1 (13 bytes)
XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX .....I..........
XX XX XX XX XX .....
Jun 6, 2011 2:02:57 PM com.microsoft.sqlserver.jdbc.TDSCommand onResponseEOM
FINEST: [email protected] (SQLServerStatement:1 executeXXX): disabling interrupts
Jun 6, 2011 2:02:57 PM com.microsoft.sqlserver.jdbc.TDSReader nextPacket
FINEST: [email protected] (ConnectionID:1) Moving to next packet -- unlinking consumed packet
Jun 6, 2011 2:02:57 PM com.microsoft.sqlserver.jdbc.TDSParser parse
FINEST: [email protected] (ConnectionID:1): getNextResult: Processing TDS_DONE (0xFD)
[...]
我使用tcpdump的捕捉到SQL服務器之間的所有通信主機和Linux主機以及所有ICMP流量,並且我注意到2008和2005服務器都在語句開始執行後30秒向Linux發送一個TCP保持活動數據包; Linux主機使用ACK確認從2005服務器保持活動狀態,但在連接到2008服務器時,Linux主機不發送ACK,並且2008服務器重新啓動9次(每秒一次)重新傳輸保持活動狀態連接(因此直到超時40秒)。現在我注意到Win2003/SQL2005和Win2008R2/SQL2008R2主機傳輸的保持活動數據包之間存在差異:較新的OS使用TCP窗口縮放,窗口大小爲66560.所以現在我想知道TCP窗口大小是否大於65535導致Linux機器上的iptables或tcp/ip堆棧無聲地忽略數據包。但之後連接中的其他數據包的縮放窗口大小爲66560,並且它們被Linux服務器確認。日誌文件中沒有任何內容表明這些數據包正在被丟棄或導致任何問題。
最後一點:在追逐這個問題的過程中,我們不得不重新啓動Linux服務器幾次因爲更新,並且這兩次連接都沒有超時一兩天。
所以我很困惑,我希望你們中的一個人可能對我有線索。
更新
我發現我可以消除在Linux服務器上禁用TCP時間戳連接超時。禁用窗口縮放對問題沒有影響。追求禁用tcp時間戳的含義似乎更多地是serverfault.com的問題,所以我會在這裏看到關於遷移這個問題的信息。
更新2
比較與不適用的一個工程連接(Win2003的/ SQL2003)的數據包的痕跡(Win2008R2/SQL2008R2),我注意到,在Win2003的連接的存活時間有沒有選項(儘管它在早期數據包中使用tcp時間戳),並且斷開連接的keepalive(除非時間戳被禁用),keepalive中有tcp選項,即時間戳。所以現在看起來像Ubuntu機器響應沒有tcp選項的keepalive,但忽略tcp選項的keeplive。這實際上是一個關於兩臺主機上的tcp/ip問題的問題。
最後更新 我所追求的Linux網絡開發列表關於這個問題,現在我相信,這個問題是由於Windows錯誤會導致錯誤校驗對於具有TCP時間戳TCP持久連接中產生(但是,顯然,沒有其他數據包)。 See the thread on the netdev list。這個問題應該關閉。
我開始認爲這個問題屬於serverfault.com而不是在stackoverflow.com上。我正在考慮遷移它。 – ChuckB 2011-06-07 14:21:04
進一步的調查使我確信問題出在tcp/ip堆棧層面,如果問題被移植,上述問題的措辭只會分散真正的問題。所以我現在的願望是,這個問題簡單地被關閉,我可以在serverfault.com上問一個更直接和相關的問題版本。 – ChuckB 2011-06-07 19:53:07