相較于 MySQL 這樣的單機數(shù)據(jù)庫快集，OceanBase 數(shù)據(jù)庫的訪問鏈路會稍長一些近迁，當出現(xiàn)連接異常的情況首懈，排查起來會多一些思考步驟，下面通過一個案例來分享如何抓包分析應(yīng)用連接超時的問題君编。
問題描述
這是一個生產(chǎn)環(huán)境，訪問鏈路大概是這樣的：應(yīng)用-->VIP-->3 節(jié)點OBProxy-->3 節(jié)點OBServer川慌，其中還需要說明的是VIP 是用 keepalived 來進行漂移的吃嘿，所用版本為OBServer4.2.1.1祠乃、OBProxy 4.2.2.0。應(yīng)用偶爾會出現(xiàn)連接數(shù)據(jù)庫超時的報錯：pymysql.err.OperationalError) (2003, "Can't connect to MySQL server on ' xx.xx.xx.9' (timed out)"兑燥，大概每天1-2 次亮瓷，日志如下：
分析過程
1. 分析 obproxy 日志
思路 1：VIP 在 xx.xx.xx.12 綁在這個 obproxy 節(jié)點上，所以所有應(yīng)用訪問 xx.xx.xx.9:3306 時實際上都是訪問的 xx.xx.xx.12降瞳，因此先分析 xx.xx.xx.12 節(jié)點上的 obproxy.log 即可嘱支。
思路 2：分析 obproxy日志的目的是什么？
- 是看應(yīng)用到 obproxy 的前端連接處理是不是異常了
- 如果應(yīng)用到 obproxy 連接正常挣饥，繼續(xù)看 obproxy 到 observer 的后端連接是不是建成功了
由于日志回收除师，只保留了 03-11 08:14 這個時間段的日志。按照上述思路通過以下幾個維度搜索日志：
- 過濾VC_EVENT_EOS關(guān)鍵字亮靴，看有沒有異常斷開的前端連接馍盟。結(jié)果返回空，說明沒有
grep VC_EVENT_EOS obproxy.log.* |egrep -i 'tenant_name=[a-z].*'
- 繼續(xù)看obproxy 到 observer 的后端連接狀況茧吊，這里需要用一點統(tǒng)計方法贞岭，先過濾 03-11 08:14 時間點來自客戶端 xx.xx.xx.12 訪問 xx.xx.xx.9:3306 的請求，將客戶端IP:PORT 輸出出來
grep 'xx.xx.xx.9:3306' obproxy.log.20240311084410 |egrep '2024-03-11 08:14:[0-2].*' | egrep 'caddr=\{xx.xx.xx.12' | awk -F'caddr={' '{print $2}' |awk -F'}' '{print $1}'
- 然后過濾
succ to set proxy_sessid事件搓侄，這個事件說明連接建立成功瞄桨，輸出內(nèi)容與上一步完全一致，說明所有連接都正常
grep 'succ to set proxy_sessid' obproxy.log.20240311084410 | egrep '2024-03-11 08:14:[0-2].*' | awk -F'client_addr=' '{print $2}' |awk -F'"' '{print $2}' |grep 'xx.xx.xx.12'
- 繼續(xù)輸出創(chuàng)建連接成功后 server_sessid讶踪，輸出結(jié)果全部不為 0芯侥，說明所有連接都正常建立了后端連接
grep 'succ to set proxy_sessid' obproxy.log.20240311084410 | egrep '2024-03-11 08:14:[0-2].*' | egrep 'client_addr="xx.xx.xx.12' | awk -F'server_sessid=' '{print $2}' |awk -F',' '{print $1}'
小結(jié)：obproxy 日志正常，大概率 obproxy 沒有收到應(yīng)用端的請求乳讥，這個連接超時問題可能和網(wǎng)絡(luò)有關(guān)柱查。下一步的建議：在應(yīng)用服務(wù)器上抓包
2. 抓包分析
由于這是一個偶發(fā)問題，無法預期故障時間云石，因此只能長時間抓包唉工，需要注意兩個兩點：
- 每個包文件不能太大，因此需要自動切換結(jié)果文件
- 抓的包不宜過多汹忠，降低可能對系統(tǒng)的影響淋硝，因此需要盡可能過濾包
本案例的抓包命令如下：
tcpdump -X -s 0 -C 50 -W 500 -Z root -i lo -w /tmp/cap/obproxy.cap host xx.xx.xx.9
##參數(shù)解釋
1. 應(yīng)用與 obproxy 在同一臺服務(wù)器上，抓包時需要指定回環(huán)接口 -i lo
2. -w /tmp/cap/obproxy.cap 指定結(jié)果文件路徑
3. -C 50 表示結(jié)果文件滿 50M 就自動切換新的文件
4. -W 500 表示一共 500 個結(jié)果文件宽菜，當寫滿 500 個會循環(huán)到第 1 個繼續(xù)寫
5. host xx.xx.xx.9 過濾訪問 VIP 的網(wǎng)絡(luò)包谣膳，減少抓寶數(shù)量
既然抓到包了，現(xiàn)在面對的一個問題是怎么分析這些網(wǎng)絡(luò)包铅乡，并找到我們需要的信息继谚？
思路 3：利用 wireshark 的專家信息（入口：分析->專家信息）快速找到可能異常的包。
由于客戶端臭挽、服務(wù)端在一臺服務(wù)器上捂襟，所以上面展示的包有來有回，實際從客戶端的角度來看過程應(yīng)該是：
- 15:52:47 向 xx.xx.xx.9:3306 發(fā)起 TCP 連接請求（三次握手的 SYN）欢峰，即 8359 號包
- 15:52:48 向 xx.xx.xx.9:3306 重發(fā)8517號 SYN 包葬荷，TCP Retransmission 表示重傳，TCP Port numbers reused 表示端口重用（net.ipv4.tcp_tw_reuse=1）纽帖，這是 wireshark 打的標記宠漩，因為和第一個 SYN 包的四元組一樣
- 15:52:50 繼續(xù)重發(fā) SYN 包，9075
- 15:52:54 繼續(xù)重發(fā) SYN 包懊直，10140
服務(wù)端角度：
- 15:52:47 向 xx.xx.xx.12:4232 發(fā) SYN+ACK 包扒吁，即 8360 號包
- 15:52:48 重發(fā) SYN、ACK 包室囊，即 8517 號包
- ...
這里面還有ICMP 協(xié)議的包雕崩，信息是 Destination unreachable(Port unreachable)，從前面的信息來看是服務(wù)端到客戶端的4232端口發(fā) SYN+ACK 包時報的融撞，因此客戶端沒收到服務(wù)端的 ACK 包一直重發(fā) SYN 包盼铁。
應(yīng)用報錯是在15:52:57，也就是客戶端發(fā)起 TCP 連接的 10秒后尝偎，Connector/Python 默認的 connection_timeout 就是 10秒饶火，這個是吻合的。應(yīng)用報錯 timeout 就是丟包重傳導致的致扯，但是為什么會丟包肤寝？
查到這里僵住了，直接原因有了抖僵，但是根因還差一步醒陆。好在隨著下一次報錯，問題迎來了轉(zhuǎn)機裆针。
3. 第二次抓包分析
時隔 13 天后在 3 月 22 日，我們再次抓到一個故障時間點的包寺晌。再次祭出 wireshark 三板斧世吨，問題包如下：
這個異常包簡直和 3 月 9 日的一模一樣，最重要的是連客戶端使用的隨機端口一樣都是 4232呻征。這還有啥好說的耘婚，直接拿著這個證據(jù)問了下網(wǎng)絡(luò)部門，這回終于得到證實：
結(jié)論
網(wǎng)絡(luò)禁止了 4232 端口外部訪問陆赋，因此當客戶端連接 OBProxy沐祷、或者 OBProxy 連接 OBServer 時使用了 4232 隨機端口嚷闭，服務(wù)端回包到 4232 端口將導致丟包無法建立連接。
解決方案
設(shè)置內(nèi)核參數(shù) ip_local_port_range赖临，限制服務(wù)器本地隨機端口的范圍胞锰，防止使用到被禁止的端口：
sysctl -w net.ipv4.ip_local_port_range="10000 60999"
tips：在部署OB 集群時，observer服務(wù)器初始化時會自動設(shè)置 net.ipv4.ip_local_port_range = 3500 65535兢榨，需要格外注意網(wǎng)絡(luò)策略是否會有影響嗅榕。
