jdbc訪問KingbaseES資料庫發生異常：SocketTimeoutException Read timed out
一、異常現象：
應用顯示ERROR資訊：
Caused By: java.net.SocketTimeoutException: Read timed out
at java.base/java.net.SocketInputStream.socketRead(Native Method)
at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:168)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140)
...
Com.kingbase8.util.KSQLException: An I/O error occurred while sending to this backend.
at com.kingbase8.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:345)
at com.kingbase8.jdbc.KbStatement.executeInternal(KbStatement.java:472)
at com.kingbase8.jdbc.KbStatement.execute(KbStatement.java:392)
at com.kingbase8.jdbc.KbPreparedStatement.executeWithFlags(KbPreparedStatement.java:191)
at com.kingbase8.jdbc.KbPreparedStatement.execute(KbPreparedStatement.java:180)
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_executeQuery(FilterChainImpl.java:3446)
at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_executeQuery(FilterEventAdapter.java:434)
at com.alibaba.druid.filter.FilterChainImpl.peparedStatement_executeQuery(FilterChainImpl.java:3444)
at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_executeQuery(FilterAdapter.java:434)
二、基本資訊：
Java 應用 + SpingBoot 框架 + Druid-1.2.15版本資料來源 + CentOS Linux release 7.9(2009)
應用伺服器IP地址10.10.10.16，資料庫伺服器IP地址10.10.10.36
三、排查過程：
使用到的系統工具：tcpdump、strace
tcpdump 是一款 Linux 平臺的抓包工具。它可以抓取涵蓋整個 TCP/IP 協議族的資料包，支援針對網路層、協議、主機、埠的過濾，並提供 and、or、not 等邏輯語句來過濾無用的資訊。tcpdump基於底層libpcap庫開發，執行需要root許可權。
strace是一個可用於診斷、除錯和分析的Linux使用者空間跟蹤器。可以使用它來監控使用者空間程式和核心的互動，比如系統呼叫、訊號傳遞、程式狀態變更等。strace作為一種動態跟蹤工具，能夠高效地定位程式和服務故障、分析程式hang住或者程式崩潰的原因，其跟蹤程式執行過程中產生的系統呼叫及接收到的訊號，幫助我們分析程式或命令執行中遇到的異常情況，使用strace跟蹤掛死程式，如果最後一行系統呼叫顯示完整，程式在邏輯程式碼處掛死；如果最後一行系統呼叫顯示不完整，程式在該系統呼叫處掛死。
1、檢查資料庫引數配置
檢查kingbase.conf、 kingbase.auto.conf配置檔案tcp開頭的引數，在Linux系統引數預設值都為0，表示使用系統預設值，取值為linux作業系統sysctl -a對應的引數值。在等效的套接字選項可用系統以及 Windows支援，在Linux系統上設定無效。如果在linux系統部署的資料庫伺服器上設定非0值，應用跟資料庫之間存在訪問限制或者防火牆，也會導致應用連線的SocketTimeoutException。
$ cat /home/kingbase/data/kingbase.conf | grep tcp_*
# see "man 7 tcp" for details
#tcp_keepalives_idle = 0 # TCP_KEEPIDLE, in seconds;
#tcp_keepalives_interval = 0 # TCP_KEEPINTVL, in seconds;
#tcp_keepalives_count = 0 # TCP_KEEPCNT;
#tcp_user_timeout = 0 # TCP_USER_TIMEOUT, in milliseconds;
$ cat /home/kingbase/data/kingbase.auto.conf | grep tcp_*
經檢查資料庫配置檔案均使用預設值0.
2、在jdbc連線串新增socketTimeout/connectTimeout/loggerLevel/loggerFile引數
一般情況下，SocketTimeoutException異常在jdbc url只需新增socketTimeout引數就可以解決此問題。
# 在jdbc連線串新增以下引數
socketTimeout=120
connectTimeout=120
loggerLevel=trace
loggerFile=/opt/jdbc.log
# 完整的jdbc url連線串例子
jdbc:kingbase8://10.10.10.36:54321/test?currentSchema=public&socketTimeout=120&connectTimeout=120&loggerLevel=trace&loggerFile=/opt/jdbc.log
透過給jdbc url連線串新增引數，列印jdbc連線日誌，應用訪問依然是提示同樣的錯誤資訊。引數無效？
Caused By: java.net.SocketTimeoutException: Read timed out
at java.base/java.net.SocketInputStream.socketRead0(Native Method)
at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:168)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140)
...
Com.kingbase8.util.KSQLException: An I/O error occurred while sending to this backend.
at com.kingbase8.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:345)
at com.kingbase8.jdbc.KbStatement.executeInternal(KbStatement.java:472)
at com.kingbase8.jdbc.KbStatement.execute(KbStatement.java:392)
at com.kingbase8.jdbc.KbPreparedStatement.executeWithFlags(KbPreparedStatement.java:191)
at com.kingbase8.jdbc.KbPreparedStatement.execute(KbPreparedStatement.java:180)
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_executeQuery(FilterChainImpl.java:3446)
at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_executeQuery(FilterEventAdapter.java:434)
at com.alibaba.druid.filter.FilterChainImpl.peparedStatement_executeQuery(FilterChainImpl.java:3444)
at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_executeQuery(FilterAdapter.java:434)
3、使用tcpdump排除網路原因：
# host 填寫需要監聽的ip地址，
# port 填寫需要艦艇的埠
# enp0s17 ip地址對應的網路卡名稱
# tcpdump.out 使用tcpdump抓包生成的檔案
tcpdump -nv -i enp0s17: '((ip[1:1] - ((ip[0]&0xf)<<2)) - ((tcp[12]&0xf0)>>2)) != 0' and host 10.10.10.36 and port 54321 -XX > tcpdump.out 2>&1
使用tcpdump抓取應用對應模組訪問資料庫直到發生Read timed out異常期間的資料包。
# 由於日誌有點多，只篩選出發生異常連線的tcpdump資訊
# TCP三次握手的過程：
# 第一次握手10.10.10.16.58209 > 10.10.10.36.54321: 請求來自10.10.10.16埠是58209，目標的IP地址是10.10.10.36埠是54321。Flags [SEW] 這裡SEW看作是S就行，表示客戶端的SYN請求，seq為614136864
# 第二次握手10.10.10.36.54321 > 10.10.10.16.58209: 10.10.10.36回覆來自10.10.10.16的請求，Flags [S.] S表示SYN回覆，.表示ack，seq 614136865 = 客戶端seq + 1。
# 第三次握手10.10.10.16.58209 > 10.10.10.36.54321: 客戶端到目標端 Flags為[.]，表示ack確認，此時TCP三次握手建立成功。
10:26:18.832836 IP (tos 0x2,ECT(0), ttl 128, id 21814, offset 0, flags [DF], proto TCP (6), length 52)
10.10.10.16.58209 > 10.10.10.36.54321: Flags [SEW], cksum 0x2c80 (correct), seq 614136864, win 8192, options [mss 1460,nop,wscale 8,nop,nop,sackOK], length 0
0x0000: fa16 3ecc 3d29 fa16 3e6f ab70 0800 4502 ..>.=)..>o.p..E.
0x0010: 0034 5536 4000 8006 5c0a 11a7 1310 11a7 .4U6@...\.......
0x0020: 1324 e361 d431 249a fc20 0000 0000 80c2 .$.a.1$.........
0x0030: 2000 2c80 0000 0204 05b4 0103 0308 0101 ..,.............
0x0040: 0402 ..
10:26:18.832851 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6), length 52)
10.10.10.36.54321 > 10.10.10.16.58209: Flags [S.], cksum 0x49a8 (incorrect -> 0x97b3), seq 1234893263, ack 614136865, win 29200, options [mss 1460,nop,nop,sackOK,nop,wscale 9], length 0
0x0000: fa16 3e6f ab70 fa16 3ecc 3d29 0800 4500 ..>o.p..>.=)..E.
0x0010: 0034 0000 4000 4006 f142 11a7 1324 11a7 .4..@.@..B...$..
0x0020: 1310 d431 e361 499a f9cf 249a fc21 8012 ...1.aI...$..!..
0x0030: 7210 49a8 0000 0204 05b4 0101 0402 0103 r.I.............
0x0040: 0309 ..
10:26:18.833060 IP (tos 0x0, ttl 128, id 21815, offset 0, flags [DF], proto TCP (6), length 40)
10.10.10.16.58209 > 10.10.10.36.54321: Flags [.], cksum 0x4897 (correct), ack 1, win 513, length 0
0x0000: fa16 3ecc 3d29 fa16 3e6f ab70 0800 4500 ..>.=)..>o.p..E.
0x0010: 0028 5537 4000 8006 5c17 11a7 1310 11a7 .(U7@...\.......
0x0020: 1324 e361 d431 249a fc21 499a f9d0 5010 .$.a.1$..!I...P.
0x0030: 0201 4897 0000 0000 0000 0000 ..H.........
# 以下就是實際資料傳輸過程，可以看到tcp的分段傳輸，客戶端到目標短的資料seq 1:9,目標短響應ack 9。依此類推。透過分析tcpdump日誌，沒有發現異常情況，排除資料庫伺服器網路原因。
10:26:18.833386 IP (tos 0x0, ttl 128, id 21816, offset 0, flags [DF], proto TCP (6), length 48)
10.10.10.16.58209 > 10.10.10.36.54321: Flags [P.], cksum 0x2d7e (correct), seq 1:9, ack 1, win 513, length 8
0x0000: fa16 3ecc 3d29 fa16 3e6f ab70 0800 4500 ..>.=)..>o.p..E.
0x0010: 0030 5538 4000 8006 5c0e 11a7 1310 11a7 .0U8@...\.......
0x0020: 1324 e361 d431 249a fc21 499a f9d0 5018 .$.a.1$..!I...P.
0x0030: 0201 2d7e 0000 0000 0008 04d2 162f ..-~........./
10:26:18.833386 IP (tos 0x0, ttl 128, id 21816, offset 0, flags [DF], proto TCP (6), length 48)
10.10.10.16.58209 > 10.10.10.36.54321: Flags [P.], cksum 0x2d7e (correct), seq 1:9, ack 1, win 513, length 8
0x0000: fa16 3ecc 3d29 fa16 3e6f ab70 0800 4500 ..>.=)..>o.p..E.
0x0010: 0030 5538 4000 8006 5c0e 11a7 1310 11a7 .0U8@...\.......
0x0020: 1324 e361 d431 249a fc21 499a f9d0 5018 .$.a.1$..!I...P.
0x0030: 0201 2d7e 0000 0000 0008 04d2 162f ..-~........./
10:26:22.723238 IP (tos 0x0, ttl 128, id 21983, offset 0, flags [DF], proto TCP (6), length 428)
10.10.10.16.58209 > 10.10.10.36.54321: Flags [P.], cksum 0xbfcf (correct), seq 3358:3746, ack 1919, win 511, length 388
0x0000: fa16 3ecc 3d29 fa16 3e6f ab70 0800 4500 ..>.=)..>o.p..E.
0x0010: 01ac 55df 4000 8006 59eb 11a7 1310 11a7 ..U.@...Y.......
0x0020: 1324 e361 d431 249b 093e 499b 014e 5018 .$.a.1$..>I..NP.
0x0030: 01ff bfcf 0000 5000 0001 2c00 7365 6c65 ......P...,.sele
0x0040: 6374 2063 6f75 6e74 282a 2920 746f 7461 ct.count(*).tota
0x0050: 6c0a 2020 2020 2020 2020 6672 6f6d 2070 l.........from.p
0x0060: 6572 6d69 7373 696f 6e5f 696e 666f 0a20 ermission_info..
0x0070: 2020 2020 2020 2077 6865 7265 2064 656c .......where.del
0x0080: 6574 655f 666c 6167 203d 2027 3027 0a20 ete_flag.=.'0'..
0x0090: 2020 2020 2020 2020 0a20 2020 2020 2020 ................
0x00a0: 2020 0a20 2020 2020 2020 2020 0a20 2020 ................
0x00b0: 2020 2020 2020 0a20 2020 2020 2020 2020 ................
0x00c0: 2020 2061 6e64 2064 6f75 6274 5f73 7461 ...and.doubt_sta
0x00d0: 7465 203d 2024 310a 2020 2020 2020 2020 te.=.$1.........
0x00e0: 200a 2020 2020 2020 2020 200a 2020 2020 ................
0x00f0: 2020 2020 2020 2020 616e 6420 6572 726f ........and.erro
0x0100: 725f 7374 6174 6520 3d20 2432 0a20 2020 r_state.=.$2....
0x0110: 2020 2020 2020 0a20 2020 2020 2020 2020 ................
0x0120: 0a20 2020 2020 2020 2020 0a20 2020 2020 ................
0x0130: 2020 2020 2020 2061 6e64 2073 6f75 7263 .......and.sourc
0x0140: 655f 6465 7061 7274 6d65 6e74 5f69 6420 e_department_id.
0x0150: 3d20 2433 0000 0320 0004 1320 0004 1320 =.$3............
0x0160: 0004 1342 0000 0040 0000 0003 0000 0000 ...B...@........
0x0170: 0000 0003 0000 0001 3000 0000 0130 0000 ........0....0..
0x0180: 0020 6639 6434 3831 6364 3037 6336 3465 ..f9d481cd07c64e
0x0190: 3939 6164 3435 3038 3665 6237 6538 6130 99ad45086eb7e8a0
0x01a0: 3038 0000 4400 0000 0650 0045 0000 0009 08..D....P.E....
0x01b0: 0000 0000 0053 0000 0004 .....S....
10:26:22.723272 IP (tos 0x0, ttl 64, id 5340, offset 0, flags [DF], proto TCP (6), length 40)
10.10.10.36.54321 > 10.10.10.16.58209: Flags [.], cksum 0x499c (incorrect -> 0x3431), ack 3746, win 72, length 0
0x0000: fa16 3e6f ab70 fa16 3ecc 3d29 0800 4500 ..>o.p..>.=)..E.
0x0010: 0028 14dc 4000 4006 dc72 11a7 1324 11a7 .(..@.@..r...$..
0x0020: 1310 d431 e361 499b 014e 249b 0ac2 5010 ...1.aI..N$...P.
0x0030: 0048 499c 0000 .HI...
10:26:22.941670 IP (tos 0x0, ttl 64, id 5341, offset 0, flags [DF], proto TCP (6), length 118)
10.10.10.36.54321 > 10.10.10.16.58209: Flags [P.], cksum 0x49ea (incorrect -> 0x3e06), seq 1919:1997, ack 3746, win 72, length 78
0x0000: fa16 3e6f ab70 fa16 3ecc 3d29 0800 4500 ..>o.p..>.=)..E.
0x0010: 0076 14dd 4000 4006 dc23 11a7 1324 11a7 .v..@.@..#...$..
0x0020: 1310 d431 e361 499b 014e 249b 0ac2 5018 ...1.aI..N$...P.
0x0030: 0048 49ea 0000 3100 0000 0432 0000 0004 .HI...1....2....
0x0040: 5400 0000 1e00 0174 6f74 616c 0000 0000 T......total....
0x0050: 0000 0000 0000 1400 08ff ffff ff00 0044 ...............D
0x0060: 0000 0010 0001 0000 0006 3134 3634 3939 ..........146499
0x0070: 4300 0000 0d53 454c 4543 5420 3100 5a00 C....SELECT.1.Z.
0x0080: 0000 0549 ...I
10:26:22.950436 IP (tos 0x0, ttl 128, id 22267, offset 0, flags [DF], proto TCP (6), length 428)
10.10.10.16.58209 > 10.10.10.36.54321: Flags [P.], cksum 0xbafe (correct), seq 3746:4134, ack 1997, win 511, length 388
0x0000: fa16 3ecc 3d29 fa16 3e6f ab70 0800 4500 ..>.=)..>o.p..E.
0x0010: 01ac 56fb 4000 8006 58cf 11a7 1310 11a7 ..V.@...X.......
0x0020: 1324 e361 d431 249b 0ac2 499b 019c 5018 .$.a.1$...I...P.
0x0030: 01ff bafe 0000 5000 0001 2c00 7365 6c65 ......P...,.sele
0x0040: 6374 2063 6f75 6e74 282a 2920 746f 7461 ct.count(*).tota
0x0050: 6c0a 2020 2020 2020 2020 6672 6f6d 2070 l.........from.p
0x0060: 756e 6973 686d 656e 745f 696e 666f 0a20 unishment_info..
0x0070: 2020 2020 2020 2077 6865 7265 2064 656c .......where.del
0x0080: 6574 655f 666c 6167 203d 2027 3027 0a20 ete_flag.=.'0'..
0x0090: 2020 2020 2020 2020 0a20 2020 2020 2020 ................
0x00a0: 2020 0a20 2020 2020 2020 2020 0a20 2020 ................
0x00b0: 2020 2020 2020 0a20 2020 2020 2020 2020 ................
0x00c0: 2020 2061 6e64 2064 6f75 6274 5f73 7461 ...and.doubt_sta
0x00d0: 7465 203d 2024 310a 2020 2020 2020 2020 te.=.$1.........
0x00e0: 200a 2020 2020 2020 2020 200a 2020 2020 ................
0x00f0: 2020 2020 2020 2020 616e 6420 6572 726f ........and.erro
0x0100: 725f 7374 6174 6520 3d20 2432 0a20 2020 r_state.=.$2....
0x0110: 2020 2020 2020 0a20 2020 2020 2020 2020 ................
0x0120: 0a20 2020 2020 2020 2020 0a20 2020 2020 ................
0x0130: 2020 2020 2020 2061 6e64 2073 6f75 7263 .......and.sourc
0x0140: 655f 6465 7061 7274 6d65 6e74 5f69 6420 e_department_id.
0x0150: 3d20 2433 0000 0320 0004 1320 0004 1320 =.$3............
0x0160: 0004 1342 0000 0040 0000 0003 0000 0000 ...B...@........
0x0170: 0000 0003 0000 0001 3000 0000 0130 0000 ........0....0..
0x0180: 0020 6639 6434 3831 6364 3037 6336 3465 ..f9d481cd07c64e
0x0190: 3939 6164 3435 3038 3665 6237 6538 6130 99ad45086eb7e8a0
0x01a0: 3038 0000 4400 0000 0650 0045 0000 0009 08..D....P.E....
0x01b0: 0000 0000 0053 0000 0004 .....S....
10:26:22.950471 IP (tos 0x0, ttl 64, id 5342, offset 0, flags [DF], proto TCP (6), length 40)
10.10.10.36.54321 > 10.10.10.16.58209: Flags [.], cksum 0x499c (incorrect -> 0x325d), ack 4134, win 74, length 0
0x0000: fa16 3e6f ab70 fa16 3ecc 3d29 0800 4500 ..>o.p..>.=)..E.
0x0010: 0028 14de 4000 4006 dc70 11a7 1324 11a7 .(..@.@..p...$..
0x0020: 1310 d431 e361 499b 019c 249b 0c46 5010 ...1.aI...$..FP.
0x0030: 004a 499c 0000 .JI...
10:26:23.550825 IP (tos 0x0, ttl 64, id 5343, offset 0, flags [DF], proto TCP (6), length 118)
10.10.10.36.54321 > 10.10.10.16.58209: Flags [P.], cksum 0x49ea (incorrect -> 0x4538), seq 1997:2075, ack 4134, win 74, length 78
0x0000: fa16 3e6f ab70 fa16 3ecc 3d29 0800 4500 ..>o.p..>.=)..E.
0x0010: 0076 14df 4000 4006 dc21 11a7 1324 11a7 .v..@.@..!...$..
0x0020: 1310 d431 e361 499b 019c 249b 0c46 5018 ...1.aI...$..FP.
0x0030: 004a 49ea 0000 3100 0000 0432 0000 0004 .JI...1....2....
0x0040: 5400 0000 1e00 0174 6f74 616c 0000 0000 T......total....
0x0050: 0000 0000 0000 1400 08ff ffff ff00 0044 ...............D
0x0060: 0000 0010 0001 0000 0006 3236 3031 3534 ..........260154
0x0070: 4300 0000 0d53 454c 4543 5420 3100 5a00 C....SELECT.1.Z.
0x0080: 0000 0549 ...I
關於tcpdump Flags 標誌位
[S] 表示seq:
在建立連線時使用，用來同步序號。當 SYN=1，ACK=0 時，表示這是一個請求建立連線的報文段；當 SYN=1，ACK=1 時，表示對方同意建立連線。SYN=1 時，說明這是一個請求建立連線或同意建立連線的報文。
[S.] 表示seq和ack:
[.] 表示ack:
確認序號標誌，為1時表示確認號有效，為0表示報文中不含確認資訊，忽略確認號欄位。我們稱攜帶ACK標識的TCP報文段為確認報文段。TCP 規定，連線建立後，ACK 必須為 1。
[F] 表示FIN:
標記資料是否傳送完畢。如果 FIN=1，表示資料已經傳送完成，可以釋放連線,我們稱攜帶FIN標誌的TCP報文段為結束報文段。
[P] 表示有DATA資料傳輸:
Push為1表示是帶有push標誌的資料，指示接收方在接收到該報文段以後，應優先將這個報文段交給應用程式，而不是在tcp核心緩衝區排隊。
[R] 表示連線重置:
表示是否重置連線。如果 RST=1，說明 TCP 連線出現了嚴重錯誤（如主機崩潰），必須釋放連線，然後再重新建立連線。
[E] 表示ECN-Echo:
用來在 TCP 三次握手時表明一個 TCP 端是具備 ECN 功能的。在資料傳輸過程中，它也用來表明接收到的 TCP 包的 IP 頭部的 ECN 被設定為 11，即網路線路擁堵。
[W] 表示ECN CWR:
（Congestion Window Reduce）擁塞視窗減少標誌，用來表明它接收到了設定 ECE 標誌的 TCP 包。並且，傳送方收到訊息之後，透過減小傳送視窗的大小來降低傳送速率。
4、使用strace分析程式在系統呼叫遇到的異常情況：
# strace輸出資訊，無異常資訊，應用訪問資料返回正常，程式也正常退出
strace: Process 176337 attached
10:28:50 epoll_wait(3, [{EPOLLIN, {u32=18386056, u64=18386056}}], 1, -1) = 1
10:28:50 recvfrom(10, "Q\0\0\0\26select * from tb;\0", 8192, 0, NULL, NULL) = 23
10:28:50 lseek(89, 0, SEEK_END) = 450560
10:28:50 lseek(89, 0, SEEK_END) = 450560
10:28:50 sendto(10, "T\0\0\0002\0\2id\0\0\0@a\0\1\0\0\0\27\0\4\377\377\377\377\0\0name"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\2\0\0\0\003349\0\0\0\6Tes349D\0\0\0\27\0\2\0\0\0\00335"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "0\0\0\0\6Tes690D\0\0\0\27\0\2\0\0\0\003691\0\0\0\6Tes"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "1029\0\0\0\7Tes1029D\0\0\0\31\0\2\0\0\0\0041030\0\0"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "44\0\0\0\7Tes1344D\0\0\0\31\0\2\0\0\0\0041345\0\0\0\7"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\0\0\7Tes1659D\0\0\0\31\0\2\0\0\0\0041660\0\0\0\7Te"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\7Tes1974D\0\0\0\31\0\2\0\0\0\0041975\0\0\0\7Tes1"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "Tes2289D\0\0\0\31\0\2\0\0\0\0042290\0\0\0\7Tes229"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "s2604D\0\0\0\31\0\2\0\0\0\0042605\0\0\0\7Tes2605D"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "919D\0\0\0\31\0\2\0\0\0\0042920\0\0\0\7Tes2920D\0\0"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "4D\0\0\0\31\0\2\0\0\0\0043235\0\0\0\7Tes3235D\0\0\0\31"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\0\0\31\0\2\0\0\0\0043550\0\0\0\7Tes3550D\0\0\0\31\0\2"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\31\0\2\0\0\0\0043865\0\0\0\7Tes3865D\0\0\0\31\0\2\0\0"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\2\0\0\0\0044180\0\0\0\7Tes4180D\0\0\0\31\0\2\0\0\0\4"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\0\0\0044495\0\0\0\7Tes4495D\0\0\0\31\0\2\0\0\0\00444"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\0044810\0\0\0\7Tes4810D\0\0\0\31\0\2\0\0\0\0044811"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "5125\0\0\0\7Tes5125D\0\0\0\31\0\2\0\0\0\0045126\0\0"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "40\0\0\0\7Tes5440D\0\0\0\31\0\2\0\0\0\0045441\0\0\0\7"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\0\0\7Tes5755D\0\0\0\31\0\2\0\0\0\0045756\0\0\0\7Te"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\7Tes6070D\0\0\0\31\0\2\0\0\0\0046071\0\0\0\7Tes6"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "Tes6385D\0\0\0\31\0\2\0\0\0\0046386\0\0\0\7Tes638"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "s6700D\0\0\0\31\0\2\0\0\0\0046701\0\0\0\7Tes6701D"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "015D\0\0\0\31\0\2\0\0\0\0047016\0\0\0\7Tes7016D\0\0"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "0D\0\0\0\31\0\2\0\0\0\0047331\0\0\0\7Tes7331D\0\0\0\31"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\0\0\31\0\2\0\0\0\0047646\0\0\0\7Tes7646D\0\0\0\31\0\2"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\31\0\2\0\0\0\0047961\0\0\0\7Tes7961D\0\0\0\31\0\2\0\0"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\2\0\0\0\48276\0\0\0\7Tes8276D\0\0\0\31\0\2\0\0\0\4"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\0\0\48591\0\0\0\7Tes8591D\0\0\0\31\0\2\0\0\0\485"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "\0\48906\0\0\0\7Tes8906D\0\0\0\31\0\2\0\0\0\48907"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "9221\0\0\0\7Tes9221D\0\0\0\31\0\2\0\0\0\49222\0\0"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(10, "36\0\0\0\7Tes9536D\0\0\0\31\0\2\0\0\0\49537\0\0\0\7"..., 8192, 0, NULL, 0) = 8192
10:28:50 sendto(8, "\2\0\0\0\230\0\0\0\3102\0\0\1\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 152, 0, NULL, 0) = 152
10:28:50 sendto(8, "\20\0\0\0\200\0\0\0\2\0\0\0\0\0\0\0\n\0\0\0\3102\0\0\t\0\0\0\0\0\0\0"..., 128, 0, NULL, 0) = 128
10:28:50 sendto(8, "\21\0\0\0H\0\0\0\1\0\0\0\0\0\0\0\0\0\0\6\n\0\0\0\3102\0\0\0\0\0\0"..., 72, 0, NULL, 0) = 72
10:28:50 sendto(8, "\22\0\0\0\260\0\0\0\1\0\0\0\0\0\0\0\n\0\0\0\3102\0\0g\276\262&\243.\36\336"..., 176, 0, NULL, 0) = 176
10:28:50 sendto(10, "\0\0\0\7Tes9851D\0\0\0\31\0\2\0\0\0\49852\0\0\0\7Te"..., 3963, 0, NULL, 0) = 3963
10:28:50 recvfrom(10, 0xf26060, 8192, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
10:28:50 epoll_wait(3, [{EPOLLIN|EPOLLHUP, {u32=18386056, u64=18386056}}], 1, -1) = 1
10:28:50 recvfrom(10, "X\0\0\0\4", 8192, 0, NULL, NULL) = 5
10:28:50 sendto(8, "\20\0\0\0H\0\0\0\1\0\0\0\0\0\0\0\n\0\0\0\3102\0\0\t\0\0\0\0\0\0\0"..., 72, 0, NULL, 0) = 72
10:28:50 sendto(8, "\21\0\0\0H\0\0\0\1\0\0\0\0\0\0\0\0\0\0\6\n\0\0\0\3102\0\0\0\0\0\0"..., 72, 0, NULL, 0) = 72
10:28:50 epoll_ctl(3, EPOLL_CTL_MOD, 11, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=18386080, u64=18386080}}) = 0
10:28:50 exit_group(0) = ?
10:28:50 +++ exited with 0 +++
透過strace跟蹤應用訪問資料庫執行查詢過程中程式的所有系統呼叫以及程式所接收到的所有的訊號值，發現資料庫返回正常，未發現異常資訊。應用如果在資料庫訪問出現異常，那麼在strace跟蹤日誌會顯示發生的異常資訊。
程式在執行過程中有異常發生strace跟蹤程式日誌的資訊輸出：
# 可以看到有Connection timed out異常資訊輸出
[pid 23164] 10:37:47 close(39) = 0
[pid 23164] 10:37:47 epoll_wait(25, <unfinished ...>
[pid 23128] 10:37:48 mprotect(0x7f872bd70000, 4096, PROT_READ) = 0
[pid 23128] 10:37:48 mprotect(0x7f872bd70000, 4096, PROT_READ|PROT_WRITE) = 0
[pid 23128] 10:37:48 mprotect(0x7f872bd71000, 4096, PROT_NONE) = 0
[pid 23128] 10:37:48 mprotect(0x7f872bd71000, 4096, PROT_READ) = 0
[pid 80913] 10:38:21 <... restart_syscall resumed>) = -1 ETIMEDOUT (Connection timed out)
[pid 80914] 10:38:21 <... restart_syscall resumed>) = -1 ETIMEDOUT (Connection timed out)
5、系統跟網路相關核心引數檢查
# 客戶機認為連線斷開並通知應用層之前傳送並未獲確認的探測器數
net.ipv4.tcp_keepalive_probes=3
# 傳送的最後一個資料包與第一個保持活動探測器之間的時間間隔
net.ipv4.tcp_keepalive_time=1200
# 傳送後續保持活動探測器的時間間隔
net.ipv4.tcp_keepalive_intvl=30
6、Druid連線池
既然Druid連線池是阿里巴巴開源的資料庫連線池專案，在GitHub看看是否有相同的問題。
專案地址：https://github.com/alibaba/druid
經過一番搜尋終於發現問題所在，具體資訊請參考：
https://github.com/alibaba/druid/releases
Druid 1.2.12版本釋出，連線池預設指定socketTimeout，增強SQL Parser
Druid 1.2.13版本釋出，修復連線池預設指定socketTimeout導致的問題
https://github.com/alibaba/druid/issues/4946
驅動引數中loginTimeout和socketTimeout傳入了Integer型別導致失效或NPE
四、問題原因：
1.專案現場使用的Druid版本是1.2.15，屬於是已經fix4946 bug之後的版本，在druid資料來源url連線串新增socketTimeout=120，但是實際情況跟驅動引數中socketTimeout傳入了Integer型別導致失效相同。
2.根據Druid 1.2.12版本說明：連線池DruidDataSource支援新的配置connectTimeout和socketTimeout，分別都是10秒。這個預設值會減少因為網路丟包時導致的連線池無法建立連結。但是如果應用執行的sql超過socketTimeout預設值會發生異常（建議根據實際情況設定合理的值，避免應用執行sql時長超過預設值發生SocketTimeoutException）。
3.根據Druid 1.2.12版本說明問題原因應該是：在使用Druid資料來源的場景且Druid版本>=1.2.12，Druid資料來源socketTimeout預設值會覆蓋url連線串裡面的socketTimeout。這樣就可以解釋第1條在druid資料來源url連線串新增socketTimeout無效的情況。
解決過程：
第一次報錯：druid資料來源 url 未新增 sockettimeout=120，druid 資料來源未新增 socket-timeout=300000
第二次報錯：druid資料來源 url 新增 sockettimeout=120，druid 資料來源未新增 socket-timeout=300000
第三次：druid 資料來源新增 socket-timeout=300000 connect-timeout=300000問題解決。
五、解決方法：
在druid資料來源配置新增 socket-timeout、connect-timeout引數
druid:
datasource:
username: root
password: 123456
url: jdbc:mysql://10.10.10.36:54321/test?characterEncoding=utf-8
driver-class-name: com.kingbase8.Driver
#druid 資料來源專有配置
initialSize: 5
minIdle: 5
maxActive: 20
maxWait: 60000
timeBetweenEvictionRunsMillis: 60000
minEvictableIdleTimeMillis: 300000
validationQuery: SELECT 1 FROM DUAL
testWhileIdle: true
testOnBorrow: false
testOnReturn: false
poolPreparedStatements: true
#配置監控統計攔截的filters，stat:監控統計、log4j：日誌記錄、wall：防禦sql注入
#如果允許時報錯 java.lang.ClassNotFoundException: org.apache.log4j.Priority
filters: stat,wall,log4j
stat-view-servlet:
login-username: admin
login-password: admin
enabled: true
url-pattern: /druid/*
socket-timeout: 300000
connect-timeout: 300000
再次進行訪問測試，問題解決。
解決java.net.SocketTimeoutException: Read timed out異常問題後，An I/O error occurred while sending to this backend.問題隨之消失。
六、關於Read timed out、Connect timed out:
- “connect timed out” 是在指定時間內TCP連線未建立成功時jdk丟擲的異常
- “Read timed out”是在呼叫socketread後，指定時間內未收到響應時 jdk丟擲的異常， 假如一個http響應10k, 每次socket read 4k, 那麼就需要發起3次read的請求，假如timeout設定3秒，那麼就允許每次read都等待3秒，最差的情況就是大概6秒讀完資料，當然這得是極端的網路情況， 所以大部分情況下都是客戶端發起請求後，在指定時間內收到的伺服器的回包響應。