相较于 MySQL 这样的单机数据库，OceanBase 数据库的访问链路会稍长一些，当出现连接异常的情况，排查起来会多一些思考步骤，下面通过一个案例来分享如何抓包分析应用连接超时的问题。
问题描述
这是一个生产环境，访问链路大概是这样的：应用-->VIP-->3 节点OBProxy-->3 节点OBServer，其中还需要说明的是VIP 是用 keepalived 来进行漂移的，所用版本为OBServer4.2.1.1、OBProxy 4.2.2.0。应用偶尔会出现连接数据库超时的报错：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 节点上，所以所有应用访问 xx.xx.xx.9:3306 时实际上都是访问的 xx.xx.xx.12，因此先分析 xx.xx.xx.12 节点上的 obproxy.log 即可。
思路 2：分析 obproxy日志的目的是什么？
- 是看应用到 obproxy 的前端连接处理是不是异常了
- 如果应用到 obproxy 连接正常，继续看 obproxy 到 observer 的后端连接是不是建成功了
由于日志回收，只保留了 03-11 08:14 这个时间段的日志。按照上述思路通过以下几个维度搜索日志：
- 过滤VC_EVENT_EOS关键字，看有没有异常断开的前端连接。结果返回空，说明没有
grep VC_EVENT_EOS obproxy.log.* |egrep -i 'tenant_name=[a-z].*'
- 继续看obproxy 到 observer 的后端连接状况，这里需要用一点统计方法，先过滤 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事件，这个事件说明连接建立成功，输出内容与上一步完全一致，说明所有连接都正常
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'
- 继续输出创建连接成功后 server_sessid，输出结果全部不为 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}'
小结：obproxy 日志正常，大概率 obproxy 没有收到应用端的请求，这个连接超时问题可能和网络有关。下一步的建议：在应用服务器上抓包
2. 抓包分析
由于这是一个偶发问题，无法预期故障时间，因此只能长时间抓包，需要注意两个两点：
- 每个包文件不能太大，因此需要自动切换结果文件
- 抓的包不宜过多，降低可能对系统的影响，因此需要尽可能过滤包
本案例的抓包命令如下：
tcpdump -X -s 0 -C 50 -W 500 -Z root -i lo -w /tmp/cap/obproxy.cap host xx.xx.xx.9
##参数解释
1. 应用与 obproxy 在同一台服务器上，抓包时需要指定回环接口 -i lo
2. -w /tmp/cap/obproxy.cap 指定结果文件路径
3. -C 50 表示结果文件满 50M 就自动切换新的文件
4. -W 500 表示一共 500 个结果文件，当写满 500 个会循环到第 1 个继续写
5. host xx.xx.xx.9 过滤访问 VIP 的网络包，减少抓宝数量
既然抓到包了，现在面对的一个问题是怎么分析这些网络包，并找到我们需要的信息？
思路 3：利用 wireshark 的专家信息（入口：分析->专家信息）快速找到可能异常的包。
由于客户端、服务端在一台服务器上，所以上面展示的包有来有回，实际从客户端的角度来看过程应该是：
- 15:52:47 向 xx.xx.xx.9:3306 发起 TCP 连接请求（三次握手的 SYN），即 8359 号包
- 15:52:48 向 xx.xx.xx.9:3306 重发8517号 SYN 包，TCP Retransmission 表示重传，TCP Port numbers reused 表示端口重用（net.ipv4.tcp_tw_reuse=1），这是 wireshark 打的标记，因为和第一个 SYN 包的四元组一样
- 15:52:50 继续重发 SYN 包，9075
- 15:52:54 继续重发 SYN 包，10140
服务端角度：
- 15:52:47 向 xx.xx.xx.12:4232 发 SYN+ACK 包，即 8360 号包
- 15:52:48 重发 SYN、ACK 包，即 8517 号包
- ...
这里面还有ICMP 协议的包，信息是 Destination unreachable(Port unreachable)，从前面的信息来看是服务端到客户端的4232端口发 SYN+ACK 包时报的，因此客户端没收到服务端的 ACK 包一直重发 SYN 包。
应用报错是在15:52:57，也就是客户端发起 TCP 连接的 10秒后，Connector/Python 默认的 connection_timeout 就是 10秒，这个是吻合的。应用报错 timeout 就是丢包重传导致的，但是为什么会丢包？
查到这里僵住了，直接原因有了，但是根因还差一步。好在随着下一次报错，问题迎来了转机。
3. 第二次抓包分析
时隔 13 天后在 3 月 22 日，我们再次抓到一个故障时间点的包。再次祭出 wireshark 三板斧，问题包如下：
这个异常包简直和 3 月 9 日的一模一样，最重要的是连客户端使用的随机端口一样都是 4232。这还有啥好说的，直接拿着这个证据问了下网络部门，这回终于得到证实：
结论
网络禁止了 4232 端口外部访问，因此当客户端连接 OBProxy、或者 OBProxy 连接 OBServer 时使用了 4232 随机端口，服务端回包到 4232 端口将导致丢包无法建立连接。
解决方案
设置内核参数 ip_local_port_range，限制服务器本地随机端口的范围，防止使用到被禁止的端口：
sysctl -w net.ipv4.ip_local_port_range="10000 60999"
tips：在部署OB 集群时，observer服务器初始化时会自动设置 net.ipv4.ip_local_port_range = 3500 65535，需要格外注意网络策略是否会有影响。
