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)

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。

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 參數說明如下：”specifies the maximum number of open cursors a session can have at once. can use this parameter to prevent a session from opening an excessive number of cursors. Range: [0, 65535] in integer.”

圖片

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 The last packet successfully received from the server was 9 milliseconds ago. 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；

7.參考鏈接

• https://open.oceanbase.com/blog/10900349
• https://www.oceanbase.com/knowledge-base/oceanbase-database-1000000000763298
• https://segmentfault.com/a/1190000042448986/en