通過wireshark分析tcpdump網路數據包進而快速排查解決某環境OceanBase頻現的TCP連接異常斷開問題

2024.12.08

1.問題現象

某客戶反饋，在其某個驗收環境，業務同學在進行普通的業務測試時（非性能壓測場景），某個微服務在進行資料庫操作時頻繁出現異常，微服務日誌提示其底層原因是：

com.alipay.oceanbase.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure\n\nThe last packet successfully received from the server was 9 milliseconds ago.  The last packet sent successfully to the server was 2 milliseconds ago.
at sun.reflect.GeneratedConstructorAccessor143.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.alipay.oceanbase.jdbc.Util.handleNewInstance(Util.java:439)
at com.alipay.oceanbase.jdbc.SQLError.createCommunicationsException(SQLError.java:1236)
at com.alipay.oceanbase.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:4394)
at com.alipay.oceanbase.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:4252)
at com.alipay.oceanbase.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4789)
at com.alipay.oceanbase.jdbc.MysqlIO.sendCommand(MysqlIO.java:2993)
at com.alipay.oceanbase.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1396)
at com.alipay.oceanbase.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:831)
at com.alipay.oceanbase.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2042)
at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)
at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:696)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:638)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:688)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:720)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:730)
at org.springframework.jdbc.core.JdbcTemplate.queryForObject(JdbcTemplate.java:798)
at org.springframework.jdbc.core.JdbcTemplate.queryForObject(JdbcTemplate.java:817)1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.

2.問題背景

該環境資料庫服務端OceanBase 版本為observer 4.2.1.x，而微服務使用的OceanBase JDBC驅動版本為1.1.7。從OB官方瞭解到，1.1.7及之前版本的OceanBase JDBC驅動，是容易有這個連接異常斷開的問題，OB 官方給的方案是升級 JDBC 驅動，建議至少使用2.4.x以上的版本。但客戶反饋，其它環境包括生產環境，有些微服務使用了相同版本的 OceanBase JDBC 驅動，資料庫服務端也使用了相同版本的OceanBase，但基本都沒有出現該問題，或出現該問題的頻率很低，仍希望我們能排查下是否有其它原因，比如是否跟資料庫或操作系統的具體配置，甚至網路狀況有關，希望能夠在短時間內不升級驅動的情況下，通過調整參數緩解該問題。

3.問題初步分析

異常com.alipay.oceanbase.jdbc.exceptions.jdbc4.CommunicationsException：Communications link failure 其實指的就是 TCP 連接異常斷開，但從從上述報錯日誌來看，微服務上次成功收到來自obproxy的數據包是 15 毫秒之前，微服務上次成功發送數據包到 obproxy是1毫秒之前，時間都很短，而且我們業務流量不大（場景是正常業務測試，非性能壓測），初步推測可能不是網路丟包問題，而是 obproxy 或伺服器的配置問題。
為排除網路問題，我們通過 ping 初步測試了下該環境的網路狀況，結果數據如下，可以看到，內網環境網路狀況良好，延遲很低且沒有丟包：

ping -c 10 -i 1 172.253.34.74
PING 172.253.34.74 (172.253.34.74) 56(84) bytes of data.
64 bytes from 172.253.34.74: icmp_seq=1 ttl=61 time=0.727 ms
64 bytes from 172.253.34.74: icmp_seq=2 ttl=61 time=0.231 ms
64 bytes from 172.253.34.74: icmp_seq=3 ttl=61 time=0.278 ms
64 bytes from 172.253.34.74: icmp_seq=4 ttl=61 time=0.227 ms
64 bytes from 172.253.34.74: icmp_seq=5 ttl=61 time=0.219 ms
64 bytes from 172.253.34.74: icmp_seq=6 ttl=61 time=0.227 ms
64 bytes from 172.253.34.74: icmp_seq=7 ttl=61 time=0.384 ms
64 bytes from 172.253.34.74: icmp_seq=8 ttl=61 time=0.235 ms
64 bytes from 172.253.34.74: icmp_seq=9 ttl=61 time=0.232 ms
64 bytes from 172.253.34.74: icmp_seq=10 ttl=61 time=0.331 ms
--- 172.253.34.74 ping statistics ---
10 packets transmitted, 10 received, 0% packet loss, time 9000ms
rtt min/avg/max/mdev = 0.219/0.309/0.727/0.148 ms。1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.

4.問題原因

TCP 連接異常斷開的原因比較複雜，除了跟用戶端 jdbc 驅動版本和服務端obproxy 版本有關，也跟資料庫的具體配置，用戶端與服務端的操作系統的具體配置，甚至網路情況有關。
由於相關配置參數太多，為快速排查確認問題，我們準備先從網路數據包上進行分析。
經過協調，我們首先在微服務端使用「tcpdump -i any port 2883 -w 2883.pcap」抓取了約5分鐘的網路包，通過微服務日誌可以確認，5分鐘內出現了上述問題，即 com.alipay.oceanbase.jdbc.exceptions.jdbc4.CommunicationsException：Communications link failure。
通過wireshark打開上述命令抓取的pcap網路包後，查看發現有些TCP連接確實是通過 RST 異常關閉的，如下圖所示，注意這裡的 2883埠即服務端 obproxy的監聽埠：

圖片

為進一步確認問題，我們又協調在 obproxy 服務端也進行了抓包，通過 wireshark 打開抓取的 pcap網路包后，發現其現象跟用戶端一致，即有些TCP連接確實是通過 RST 異常關閉的，如下圖所示，注意這裡的 2883埠即服務端 obproxy的監聽埠：

圖片

按照用戶端抓包結果來梳理下：

在TCP連接成功創建並正常使用的過程中，微服務通過ob jdbc驅動發送了SQL請求到服務端 obproxy;
在約0.001448秒后，服務端 obproxy （2883埠）主動發送了 [FIN，ACK] 信號來關閉該 tcp 連接，這是第一個不太正常的地方，因為正常情況下，obproxy 不會主動關閉 tcp 連接;
在約0.03107秒后，微服務收到了來自 obproxy 的 [FIN，ACK] 的關閉連接信號后，並回復了 [PUSH，ACK] 信號以確認收到了關閉連接的信號;
在約 0.000033秒后，微服務[FIN，ACK] 來關閉該 TCP 連接，這是第二個不太正常的地方，因為正常情況下，微服務在等待來自服務端的SQL執行結果時，是不會主動關閉 tcp 連接的;
在約0.000172秒和0.000043秒后，服務端 obproxy （2883埠）主動發送了兩個 [RST] 信號來重置該 tcp 連接; （結合服務端抓包可知，這兩個 [RST] 其實分別是對客戶端發送的[PUSH，ACK] 和 [FIN，ACK] 數據包的回應）;

至此問題的直接原因確認了，不是網路超時或網路丟包引起的，而是 obproxy 因為某種原因，主動發送了[FIN，ACK]來斷開連接！

進一步跟蹤該TCP流，發現 obproxy 在此之前其實有回復異常資訊給用戶端：“HY000ORA-01000： maximum open cursors exceeded”，如下圖所示：

圖片

進一步通過命令show parameters like '%cursor%' 查看發現，該環境中 open_cursors 參數被配置為 50，而其它沒有此類報錯的環境中，該參數被配置為500甚至1500！
所以該問題的根本原因是，該環境中該 open_cursors參數配置值過低，當某個會話底層實際打開的遊標數大於該參數值時，服務端 observer出於自我保護的原因，就發送 [FIN] 主動關閉了該 TCP 連接！這也解釋了為什麼用戶端，會發現頻繁創建新的 JDBC 連接的相關日誌。
open_cursors 參數說明如下：「指定工作階段一次可以具有的最大打開遊標數。可以使用此參數來防止會話打開過多的遊標。範圍：[0， 65535] 整數。

圖片

5.問題解決

在該驗收環境中，使用命令「alter system set open_cursors=1500; “，將該參數open_cursors的值從50改到1500，問題成功解決。另經諮詢DBA，相關規範如下：

參數open_cursors：【租戶級別生效】，用於設置單個session打開的遊標數量，預設是50，太小容易出現ORA-01000 maxium open cursors exceeded ，可根據情況情況修改，計算公式如下：租戶記憶體（64G）*_temporary_file_io_area_size（5%）/巨集塊（2m） =1600，修改命令如下： alter system set open_cursors=1500;
參數temporary_file_io_area_size：【租戶級別生效】，SQL中間結果（比如hash join）在存儲層能使用的總大小，可適當調大（租戶級別參數，需要通過sys租戶來調整），修改命令如下：alter system set “_temporary_file_io_area_size” = 5;

6.問題跟進

微服務的異常日誌列印邏輯需要優化下，當前的日誌揭示了底層原因是「com.alipay.oceanbase.jdbc.exceptions.jdbc4.CommunicationsException：Communications link failure\n\n 從伺服器成功接收的最後一個數據包是在 9 毫秒前。The last packet sent successfully to the server was 2 milliseconds ago.“，但並沒有揭示更底層的原因，即 ”HY000ORA-01000： maximum open cursors exceeded“，這個最底層的原因也需要體現在日誌中，以方便問題排查;
後續微服務需要升級 OB JDBC 驅動版本，建議升級為官方建議的最低版本，比如 OB JDBC 驅動2.4.3;

新聞