背景
在公司的综合支付系统中负责搭建基础框架的, 主要包括:
- 搭建 RabbitMQ 服务,采用镜像模式以提供稳定可用的服务;
- HAProxy 采用主备的模式,由腾讯云切换;
- 封装 C++ 客户端提供给订单服务/账务服务等服务调用;
- 把客户端写入 RabbitMQ 的数据同步到 ElasticSearch;
数据的大致流程:
在提交测试的时候发现一个问题:有些交易数据在ES查询不到。分析后发现:
- RabbitMQ Client 在发送消息的时候没有报错;
- RabbitMQ Server 里并没有接收到数据;
那么可以认定问题只有两种可能 a) client 在发送给 proxy 的过程中失败;b) proxy 在转发给 server 的过程中失败。
重现问题
1) 会不会是线上的数据量大导致的。于是写了个测试用例在开发环境进行压测,源码:https://github.com/TomeC/cookies/blob/master/mq_test.cpp,发送的json格式的数据,数据里有个seq的键,它的值是递增的,可以用来验证是否丢了消息。用 Python 客户端去拉取 RabbitMQ 数据后解析 json 数据,验证seq是不是递增的来确定有没有丢单,源码:https://github.com/TomeC/cookies/blob/master/mq_id_check.py,发送 2300/s,接收 530/s,并没有出现丢消息的问题。
2) 可能是网络问题。对压测脚本进行修改,只有在收到 SIGUSR1 信号的时候才会发送数据,然后在另外一个终端上执行:kill -SIGUSR1 pid , client 收到信号后发送数据. 测了一段时间后果然重现了问题,然后用 tcpdump 去监控数据流来判断是哪个端出现了问题。
先在 proxy 端监听: tcpdump -AXl tcp port 4672 and host 10.20.20.25
# 10.100.100.103是 proxy ip,SIT-mq-es-01.amqp是server ip
18:55:48.571307 IP 10.100.100.103.59709 > SIT-mq-es-01.amqp: Flags [F.], seq 518, ack 534, win 31, length 0
0x0000: 4500 0028 d4db 4000 3f06 750e 0a64 6467 E..(..@.?.u..ddg
0x0010: 0a64 78b7 e93d 1628 054e 9600 f3ec 5d67 .dx..=.(.N....]g
0x0020: 5011 001f d1c5 0000 0000 0000 0000 P.............
18:55:48.571402 IP 10.100.100.103.59709 > SIT-mq-es-01.amqp: Flags [R.], seq 519, ack 534, win 31, length 0
0x0000: 4500 0028 d4dc 4000 3f06 750d 0a64 6467 E..(..@.?.u..ddg
0x0010: 0a64 78b7 e93d 1628 054e 9601 f3ec 5d67 .dx..=.(.N....]g
0x0020: 5014 001f d1c1 0000 0000 0000 0000 P.............
然后在 server 端监听数据:tcpdump -AXl tcp port 5672 and host 10.100.100.103
18:55:48.571307 IP 10.100.100.103.59709 > SIT-mq-es-01.amqp: Flags [F.], seq 518, ack 534, win 31, length 0
0x0000: 4500 0028 d4db 4000 3f06 750e 0a64 6467 E..(..@.?.u..ddg
0x0010: 0a64 78b7 e93d 1628 054e 9600 f3ec 5d67 .dx..=.(.N....]g
0x0020: 5011 001f d1c5 0000 0000 0000 0000 P.............
18:55:48.571402 IP 10.100.100.103.59709 > SIT-mq-es-01.amqp: Flags [R.], seq 519, ack 534, win 31, length 0
0x0000: 4500 0028 d4dc 4000 3f06 750d 0a64 6467 E..(..@.?.u..ddg
0x0010: 0a64 78b7 e93d 1628 054e 9601 f3ec 5d67 .dx..=.(.N....]g
0x0020: 5014 001f d1c1 0000 0000 0000 0000 P.............
过滤掉其他无效的数据后可以看到 70s 后 proxy 主动断开连接。因为 proxy 设置的 timeout 是 70s,在这段时间内没有数据就会断开连接,解决办法是加上 RabbitMQ 的心跳包。RabbitMQ 官方提供的C++客户端默认心跳时间是0,,也就是禁用心跳,需要在函数 AMQP::login() 的实现里 amqp_rpc_reply_t res = amqp_login(cnn, vhost.c_str(), 0, FRAME_MAX, 0, AMQP_SASL_METHOD_PLAIN, user.c_str(), password.c_str()); 把第 5 个参数 0 改为60,也就是心跳间隔 60s 。
超时时间单位为秒,默认值为60,心跳包每半个超时时间发送一次。 丢失了两个心跳包, 连接被认为不可抵达。
深入分析
问题虽然解决了,但问题是既然 TCP 连接断开了,为什么 Client 调用 send() 的时候返回“成功”?client 的发送“成功”并不是指发送给对方,而是指在 TCP 连接依然可以写(正常连接或半连接)的情况下把要发送的数据写到了发送缓存区。
TCP 的关闭有两种方式:
第一种是四次挥手,消息如下:
10:57:20.439686 IP localhost.61643 > localhost.amqp: Flags [F.], seq 6, ack 4, win 12759, options [nop,nop,TS val 598333924 ecr 598324512], length 0 10:57:20.439724 IP localhost.amqp > localhost.61643: Flags [.], ack 7, win 12759, options [nop,nop,TS val 598333924 ecr 598333924], length 0 10:57:20.439793 IP localhost.amqp > localhost.61643: Flags [F.], seq 4, ack 7, win 12759, options [nop,nop,TS val 598333924 ecr 598333924], length 0 10:57:20.439827 IP localhost.61643 > localhost.amqp: Flags [.], ack 5, win 12759, options [nop,nop,TS val 598333924 ecr 598333924], length 0
解释:[F.] 表示关闭发送连接,[.] 表示确认
第二种是一方直接发送 RST 直接关闭连接
还原现场
问题出在 server 向 HAProxy 发送 RST 后直接断开连接,而 HAProxy 没有直接转发而是与 client 进行四次挥手的步骤,导致 client 和 proxy 依然存在半连接。client 可以向 proxy 发消息,而 proxy 和 server 已经断开连接了,导致步骤4发的消息丢失。