耗时两天排查问题的小结

最近在线上遇到了一个比较棘手的 ops 问题,我花了两个工作日加上中间的一个晚上时段才最终发现了问题的根源,下面分享下我排查问题的思路以及步骤,先介绍下背景。
三个 IDC,BTC, DG, DL,其中 BTC, DG 是通过光纤直连,内网互通,DL 通过与 BTC 之间建立 OpenVPN tunnel 实现了三个 IDC 内网的打通。这三个 IDC 部分的 VLAN 网段信息分别如下:
BTC: 172.18.10.0/24,BTC 这台机器的 OpenVPN client IP 为 172.18.10.254
DG: 172.20.0.0/24, 172.20.100.0/24, 172.20.200.0/24 等等
DL: 192.168.1.0/24,192.168.1.24 这台 OpenVPN 作为 server 跟 BTC 的 172.18.10.254 建立起 tunnel
由于涉及到公司的商业信息,以上是我简化后的模型,实际的情况、涉及到的因素要比这个复杂的多。

某日下午我做完一个常规性的变更之后,收到反馈说从 DG 172.20.100.0/24 的机器无法访问位于 DL 192.168.1.26/24 的这台机器。
很自然的,我从 172.20.100.0/24 上挑选了 172.20.100.1 这台机器,登录上去,确认了下面的几件事:
1. 基本的网络连同性,ping 192.168.1.26,发现无法 ping 通。

2. 看 route 信息,通过 mtr 看路由信息:
$ sudo mtr 192.168.1.26 -n -r
HOST: host-1.umops.us             Loss%   Snt   Last   Avg  Best  Wrst StDev
  1. 172.20.100.249                 0.0%    10    0.5   2.0   0.5  10.4   3.3
  2. 172.16.1.254                  0.0%    10    3.8   2.1   0.7   7.4   2.3
  3. 172.18.10.254                  0.0%    10    0.3   0.4   0.3   0.4   0.0
  4. ???
可以很清楚的看到,到了 BTC 的 OpenVPN client 之后就断了,也就是没有路由指向了。

2. 基本的 networking,从 ifconfig 以及 /etc/sysconfig/network-scripts/ 来看,没有问题

3. 基本的 route:
[email protected]:~$ route  -n
Kernel IP routing table
Destination     Gateway         Genmask         Flags Metric Ref    Use Iface
172.20.100.0     0.0.0.0         255.255.255.0   U     0      0        0 bond0
0.0.0.0         172.20.100.254   0.0.0.0         UG    0      0        0 bond0
没有问题,默认 GW 直接上我们 Nexus 7000 的 HSRP VIP(172.20.100.254),上面看到的 172.20.100.249 是 RIP。

接着我把 172.20.100.0/24 的其他几台机器挨个试了一遍,发现现象跟上面一样。

接着,我登录到 DG 的其他网段比如 172.20.0.0/24 的机器上做同样的测试,可以发现完全没有问题:
$ sudo mtr 192.168.1.26 -n -r
HOST: host-2.umops.us               Loss%   Snt   Last   Avg  Best  Wrst StDev
  1. 172.20.0.248                  0.0%    10    0.7   0.5   0.4   0.7   0.1
  2. 172.16.1.254                  0.0%    10    5.7   2.3   0.6   8.6   2.8
  3. 172.18.10.254                  0.0%    10    0.3   0.3   0.3   0.4   0.0
  4. 192.168.4.1                   0.0%    10    6.9   5.6   2.6  24.5   6.8
  5. 192.168.1.26                  0.0%    10   17.6  10.2   2.9  36.2  10.5

当时第一想法是,是不是 DG 的 SW 配置有问题,是不是把 172.20.100.0/24 这个网段在某些关键的点上漏掉了,于是让我们的 ne 上去确认,反馈说没有问题。事后总结起来,其实从 mtr 上就能看到应该不是 SW 的问题,mtr 可以看到到了 hop 4 才中断,否则第一或者第二 hop 就断了。

并且诡异的是,DG 的其他网段的机器都没有问题,唯独 172.20.100.0/24 的有问题,我依然认为是整个从端到端的某个设备或者服务对 172.20.100.0/24 这个网段少做或者多做了一些变更,但是从端到端,期间涉及众多的机器,众多的不同同层的因素,从服务器到交换机再加上 VPN,确实需要考虑进去的因素比较多,暂时还没有很好的缩小问题的方式。

第一天晚上回去的时候想起来可以反向试试,于是从 192.168.1.26 这台机器 mtr 到 172.20.100.1,hop 如下:
$ mtr 172.20.100.1 -r -n
HOST: github-jaseywang-me            Loss%   Snt   Last   Avg  Best  Wrst StDev
  1.|– 192.168.1.24               0.0%    10    0.5   0.4   0.3   0.5   0.1
  2.|– ???                       100.0    10    0.0   0.0   0.0   0.0   0.0
可以发现,IDGP 包到了 DL 的 OpenVPN server 就中止了。

至此,我基本可以将问题的范围缩小到连接 BTC 跟 DL 的两台对端的 OpenVPN 机器上,并且从 hops 信息来看,应该是 DL 的 OpenVPN server 有问题的概率更大。

晚上回去之后,我一边在 192.168.1.26 这台机器上 mtr 172.20.100.1,一边通过 tcpdump 抓包,可以发现只有 syn,没有任何的 ack。同样的,mtr 172.20.0.1 这类的机器却没有任何的问题,有 request/reply。这更加确定了我之前的想法,一定是这个端到端的跨越了 3 个 IDC 的某个子系统出了点问题,并且这个问题可以归结于,把 172.20.100.0/24 这个段给特殊对待了。

至于是哪台机器的哪个服务出现了问题,这个就是我那天晚上以及第二天上午做的工作。当天晚上,我又确认了下面的几件事:
1. 一一排查了这两台 OpenVPN 机器的 iptables,为了以防万一,我清空了 INPUT 做测试,现象依旧
2. 再三确定 SNAT 对 OpenVPN 影响很大的这个 chain 配置没有问题
3. selinux 关闭了,sysctl 里面也没有特殊的开关
4. 基础的系统配置,包括我最开始提到的 networking、route 等信息
5. 172.20.100.0/24 里面的机器跟其他比如 172.20.0.0/24 机器的差异,由于都是统一定制安装的,在基础的系统层面根本找不出差异
6. OpenVPN 的配置,把 client, server 的两个文件检查了好几遍,没有发现异常

第二天上午继续排查了两个多小时,能想到的可能会涉及到的方面都想到了,依然没有结论。转而向我们的总监求助,跟他描述了下问题的情况,跟我一样,一样觉得很诡异,同样的配置,其他 VLAN 的机器完全没问题,就这一个 VLAN 的有问题。要是整个 DG 的 VLAN 都不通,那还能说明些问题,现在仅仅这一个 VLAN 不通。
下午,我们又从下面几个方面入手逐一排查:
1. 依然怀疑是 route 层面有问题,并且是 DG 那台 OpenVPN server 本机的 route 有问题,于是直接上了 iproute2 来确定 route table 是否正确,我也临时熟悉了 iproute2 的一些基本概念。通过下面几条 cli 判断了几个不同类型的 routing table 的情况:
# ip rule list
# ip route get 172.20.100.1

2. tracapath 继续跟踪了番,现象依然是到了 DG 的 OpenVPN server 就断了

3. 通过 starce 查看系统的调用显示跟上面一样的现象

4. 由于这两台 OpenVPN 的机器都是跑在 Xen 上的 instance,怀疑可能是由于 VM 某些方面的问题导致的,但是考虑到使用的是 bridge 并且要排除 VM 导致可能性的的繁杂程度,暂时放弃深挖。

5. bonding 方面的影响,由于我们对 DG 的所有机器刚做完 10G 的升级,包括 172.20.100.1 这台机器都使用了 bonding,尽管没没有理由怀疑是 bonding 造成的,我们还是把这台机器的 bondin 给拆了,换成了普通的单网卡模式进行测试,结果很明显

6. 抓包,在两端的 OpenVPN 上抓包以及在上联的交换机做 mirror,得到的现象跟上面一样

7. 扩大 OpenVPN server 的 netmask,既然 172.20.100.0/24 这个跟其他的诸如 172.20.0.0/24 等地位一样,将原先的 /24 扩大到 /16 以包含所有的 IP,就没有理由不通了,这个是修改前的 route:
# route  -n

172.20.100.0     0.0.0.0         255.255.255.0   U     0      0        0 tun0
172.20.0.0       0.0.0.0         255.255.255.0   U     0      0        0 tun0

修改后的 route:
# route  -n

172.20..0       0.0.0.0         255.255.0.0   U     0      0        0 tun0

意外的是,依然不通

8. 在 DG 新启用了一个 172.20.150.0/24 gateway 为 172.20.150.254 的 VIP,在 DL 的 OpenVPN server 上添加到到这个 IP 的路由:
# route  add -net 172.20.150.0  netmask 255.255.255.0 tun0

在 192.168.1.26 的机器上测试,现象依旧:
$ mtr 172.20.150.254 -r -n
HOST: github-jaseywang-me            Loss%   Snt   Last   Avg  Best  Wrst StDev
  1.|– 192.168.1.24               0.0%    10    0.4   0.5   0.4   1.1   0.2
  2.|– ???                       100.0    10    0.0   0.0   0.0   0.0   0.0

把以上所有的现象以及测试结果综合起来看,几乎可以可以确定就是 OpenVPN server 的问题,但是哪里有问题,依然不清楚。 这时我们突然想到还有这台 OpenVPN server 的 log 没仔细检查一边,google 了下,通过 "verb 5" 提高了 debug 级别,这下就能很详细的看到 OpenVPN 打的 log。log 的格式比较奇怪,像下面这样的,但是这不重要,下面这么多的字符,好好看,能发现 "packet dropped" 的关键词:
wrWrWRwRwrWRwrWRwRwrWrWRwRFri Apr 18 17:05:02 2014 us=291047 btc/111.111.111.111:45721 MULTI: bad source address from client [111.111.111.111], packet dropped
RwRwRwrWRwRwRwRwRwRwrWRwrWRwrWrWRwrWRwRwrWRwrWrWRwRwrWrWrWRwrWRwRw
RwRwRwRFri Apr 18 17:05:10 2014 us=132323 btc/111.111.111.111:45721 MULTI: Learn: 10.8.0.38 -> btc/111.111.111.111:45721
RwrWRwRwRwrWrWrWRwRwrWrWRwrWRwRwRwrWrWrWRwRwrWrWRwrWRwRwRwrWrWR
i Apr 18 17:06:07 2014 us=891600 btc/111.111.111.111:45721 MULTI: Learn: 10.8.0.126 -> btc/111.111.111.111:45721
RwrWrWRwrWrWRwrWRwRFri Apr 18 17:06:29 2014 us=146563 btc/111.111.111.111:45721 MULTI: Learn: 10.8.0.26 -> btc/11
1.111.111.111:45721

Google 第一条就告诉了我们答案!原来 172.20.100.0/24 作为我们较新的网段,我忘记把 iroute 写到 ccd 文件里面了:
These errors occur because OpenVPN doesn't have an internal route for
192.168.100.249. Consequently, it doesn't know how to route the packet to this
machine, so it drops the packet.
Use client-config-dir and create a ccd file for your client containing the
iroute option to tell OpenVPN that the 192.168.100.0/24 network is available
behind this client.

"MULTI: bad source address from client [192.168.100.249], packet dropped" or
"GET INST BY VIRT: 192.168.100.249 [failed]"?

下面提几个跟 route 关系较大的指令(1, 2) ,以后 end-to-end, sub-to-sub 出现问题,不妨先考虑是不是这些方面造成的。
1. client end 的 route
;push "route 192.168.10.0 255.255.255.0"

2. client subnet 的 route
;client-config-dir ccd
;route 192.168.40.128 255.255.255.248
;route 10.9.0.0 255.255.255.252

最后总结一下,这是一次刺激的发现问题找到根源解决问题的过程,又一次验证了整个 *nix stack 里面最复杂的是 networking 这个问题,因为牵扯到层面太多。正所谓「山穷水尽疑无路,柳暗花明又一村」。不吹牛逼的说,做了这么多年,还真没有我解决不了的工程问题。

不同业务对网络的要求

前段时间遇到一起比较严重涉及业务也比较广的 outstage。跟大家分享下,我认为比较经典。
由于前端的接 webserver 的交换机(普通的 2960S 1G)在晚高峰阶段撑不住了,导致了大量的丢包。可以看下面这张图。

仔细观察可以发现,在大概 22:00 的时候,只有 outcoming 出现了一个明显的凹陷,而对于 incoming 流量说,几乎没有影响,曲线保持的非常好。
后来通过大量的排查发现,其实这个 imcoming 的主要对应某个单独的业务,而该业务的最明显的特点就是几乎只有进没有出流量,仅仅是一个 POST 请求,而蓝色曲线的则对应其他的几个业务,其同时涉及到进跟出的流量。
再到 SW 上看看就明白情况了:
#show interfaces GigabitEthernet0/48
GigabitEthernet0/48 is up, line protocol is up (connected)
  Hardware is Gigabit Ethernet, address is xxxx.yyyy.zzzz (bia xxxx.yyyy.zzzz)
  MTU 1500 bytes, BW 1000000 Kbit, DLY 10 usec,
     reliability 255/255, txload 85/255, rxload 116/255
  Encapsulation ARPA, loopback not set
  Keepalive not set
  Full-duplex, 1000Mb/s, link type is auto, media type is 10/100/1000BaseTX
  input flow-control is off, output flow-control is unsupported
  ARP type: ARPA, ARP Timeout 04:00:00
  Last input 00:00:52, output 00:00:01, output hang never
  Last clearing of "show interface" counters never
  Input queue: 0/75/0/0 (size/max/drops/flushes); Total output drops: 793838

看到这里是不是就明白问题的原因了。

最初的时候,我发现我们的前端机器上 dmesg 有大量的报错,怀疑是 Nginx 的某个 bug 导致的,后来结合上面的情况就一目了然了。现在推测下来,应该是由于交换机的大量丢包,导致 Nginx 不断的向 upstream 重试,消耗了大量的内存,导致上面现象的出现,对比发现,我们同样负载的机器,只有 16G 的内存,没有出现任何的问题。

所以有时候出现问题,需要综合的思考各种情况,站的高才能看的远,这就是为什么有些问题别人解决不了而你能很快的定位到问题的根源。如果在排查过程中根本不知道或者压根没有想起有这回事,把自己仅仅局限于某个工作流水上的某一个零件,那估计一辈子都发现不了问题的根源了,在这种情况下,之前积累的经验会显的更为重要。

IP 再次冲突

给二层新划分了一个 vlan,在三层上做好对应的关系,测试各网段的连通性就可以了,本来是件简单的工作,却因为一次事故变得复杂起来。
划分完毕后,在该 vlan 下新上几十台的机器。正常情况下是先确保远程卡的连通性,所以先从某台 cobbler ping,确认其是否工作正常。测试下来发现这批远程卡会出现时通时不通的情况,当时没有太在意,多 ping 了几次,也通了。后来再次连接的时候又出现了上面的问题,检查了遍涉及到的交换机的变更,没有发现问题。把目光转向了远程卡,查了下版本之类的信息,g 了下发现了不少跟我们类似的情况,遂以为是 firmware bug 之类的问题,于是升级了其中的一台,问题依然存在。
再后来由于时间关系也就没再追究(后来发现现在解决不了的问题迟早要出事),在该 vlan 下部署了一台 dhcrealy server,奇怪的是,安装完了之后,发现网络死活不同,其症状为:
1. 从本地可以 ping 通任何的的本网段的远程卡、交换机,并且没有任何的丢包
2. 从二层交换机可以 ping 通该 server,但是从三层则完全 ping 不通

第一次遇到这类正向通反向不通的情况,以为是 12.04 的机器默认把 icmp_echo_ignore_all 打开了,确认了一遍依然是 0。后来怀疑可以是三层配置的问题,之前没有发现,于是登陆上去,把 sh run 的结果跟我们另外一个环境类似的 IDC 的三层做 diff,依然没有发现任何的问题。

最后想到了看看三层的 log,这下终于有了头目:
# show logging
Log Buffer (4096 bytes):
 %IP-4-DUPADDR: Duplicate address 191.168.20.254 on Vlan4, sourced by d0c2.8e3e.0fa3
. ..
*Apr 2 06:36:53.443: %IP-4-DUPADDR: Duplicate address 192.168.20.254 on Vlan123, sourced by abcd.823e.0fc3

Continue reading

IP 冲突引起的问题

jw-2 开放的端口会出现间歇性的连接不上,直接 “connection refused”,比如从 jw-1 连接
[email protected]:~$ ssh jw-2
ssh: connect to host 192.168.10.50 port 22: Connection refused

查看 jw-1 上当前的 arp 表:
[email protected]:~$ arp -n
Address                  HWtype  HWaddress           Flags Mask            Iface
192.168.10.50              ether   78:2b:cb:77:d5:3f   C                     eth1

在 jw-2 上查看网络连接:
[email protected]:~$ ifconfig
eth0      Link encap:Ethernet  HWaddr d4:be:d9:ed:64:9d 
          inet addr:192.168.10.50  Bcast:192.168.10.255  Mask:255.255.255.0
          UP BROADCAST MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)
          Interrupt:36 Memory:d2000000-d2012800 

Continue reading