NVIDIA 初创加速计划,免费加速您的创业启动 了解详情
写点什么

携程一次 Dubbo 连接超时问题的排查

  • 2020-02-19
  • 本文字数:4238 字

    阅读完需:约 14 分钟

携程一次Dubbo连接超时问题的排查

工作中,常常会遇到连接超时的问题,一般都是先检查端口状态,然后再检查 CPU、Memory、GC、Connection 等机器指标是否正常。如果都在合理范围内就会怀疑到网络或者容器上,甩手丢给网络组同事去排查。


今天,我们想分享一个高并发场景导致的 connect timeout,对原因以及过程的分析或许可以帮助大家从容地面对类似问题。

一、问题背景

携程度假事业部的某个核心服务在两个机房一共有 80 台机器,每台机器都是 4C8G 的 docker 容器。这个服务的调用方比较多,几十个调用方的机器加起来大概有 1300 多台。


SOA over CDubbo 是将现有 SOA 框架的 HTTP 传输协议切换到 TCP 协议,能够解决长尾问题以及提供更好的稳定性。大概实现原理是,服务端通过 CDubbo 启动代理服务,客户端在服务发现后与服务端同步建立 TCP 长连接,请求也会在 TCP 通道传输。


但是,度假事业部的这个服务每次发布总是会有部分客户端报 connect timeout,触发大面积的应用报警。


com.alibaba.dubbo.rpc.RpcException: Fail to create remoting client for service(dubbo://ip:port/bridgeService)  failed to connect to server /ip:port, error message is:connection timed out:  /ip:portat  com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol.initClient(DubboProtocol.java:364)at  com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol.getSharedClient(DubboProtocol.java:329)at  com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol.getClients(DubboProtocol.java:306)at  com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol.refer(DubboProtocol.java:288)
复制代码


从日志分析,是 CDubbo 代理服务 TCP 连接失败,还好当初设计的时候考虑到降级机制,没有影响到用户流量。有同事提到既然没有影响,是否可以考虑把日志降级。这么诡异的问题,不知道是否会有其他层面的问题需要去优化的呢,作为执着的技术人员,我们决定排查到底。

二、服务的端口是否异步打开

调用方的每台机器都要跟 160 个服务端实例建立连接,但是客户端看到的报错量只有几个。所以,最开始怀疑客户端的连接发到服务端,但是端口没有来得及打开,导致少量的连接失败了。


翻了下 SOA 框架在处理实例注册的代码,启动 CDubbo 代理是在注册之前,而且是同步启动的,这样的话就否定了端口没打开的可能。


三、怀疑注册中心推送出现了问题

正常情况下的注册发现机制是在服务端健康检查通过后,再把实例推送到客户端。是否注册中心推送出了问题,服务没注册完就把实例推送到客户端了?或者,客户端实例缓存出现问题导致的呢?


这类问题还是要从日志入手,翻了下 Dubbo 的代码,如果 Netty 打开端口之后,是会记录端口打开时间的。



从日志系统可以看到端口是在 16:57:19 就已经被打开了。



客户端在 16:57:51 发起的连接居然失败了,这个时候端口肯定是已经被打开了。从这个层面推断注册中心或者缓存机制应该是没有问题的。



那么,是否端口打开后又被莫名其妙的关闭了呢?

四、怀疑端口打开后又被莫名其妙的关闭

不确定是否服务启动后,会有某些未知的场景触发端口被莫名其妙的关闭。于是,在本地模拟服务启动,启动过程中通过 shell 脚本不停的打印端口的状态。


通过以下这段脚本,每 1s 就会打印一次 20xxx 端口的状态。


for i in {1..1000}dolsof -nPi | grep 20xxxsleep 1done
复制代码


从结果中,可以看到 20xxx 端口一直处于 listen 状态,也就是正常情况下并不会被莫名其妙的关闭。


TCP *:20xxx (LISTEN)
复制代码

五、增加连接被 accept 的日志

Dubbo 已经打印了前面看到的端口打开的日志,如果再能够看到服务端连接被 accept 的情况就好了。


继续翻了 Dubbo 的代码,对 Netty3 的版本来说,连接被 accept 之后会执行 channelConnected 的。那么,只要在这里加点日志,就可以知道端口什么时候被打开,以及连接什么时候进来的了。


以下是基于 Dubbo 2.5.10 版本增加的日志。



业务同事帮忙升级了版本之后,服务端在 16:57:51:394 已经有连接被 accept 了,连接报错时间是 16:57:51:527,也就是 accept 连接过程中只有一部分被拒绝了。



那么,是没有收到这个连接的 syn,还是把 syn 给丢弃了呢,必须要抓包看看了。

六、服务端的 TCP 抓包

正常情况下,需要服务端和客户端同时抓包才有意义。但是,客户端数量实在太多,也不知道哪台机器会报超时,两端一起抓的难度有点打,所以决定先只抓服务端试试。


首先摘掉服务的流量,然后在 Tomcat 重启的过程中抓 TCPdump。从 TCP dump 的结果中可以看到,服务端有一阵子收到了 TCP 的 syn,但是全部没有回 ack。可是 HTTP 的 syn 却正常的回复了 syn+ack,难道是应用层把 syn 包给丢了?



没有回 syn+ack 是谁的问题呢,Netty 丢掉的吗?还是操作系统呢?为此,我们做了个小实验。


小实验


如果是应用层丢掉的,那么肯定要从 Netty 的入口处就调试代码。Netty3 的 NioServerBoss 收到请求,会在以下箭头 2 处对连接进行 accept,所以计划在 1 处打上断点。


启动服务端后,再启动客户端,连接进来的时候的确会被箭头 1 处 block 住。



通过 TCP 抓包发现在 accept 之前就已经回复 syn+ack 给客户端了。



这个时候,顺便看了下本机的 20xxx 端口情况,只有一个 listen 状态,没有任何客户端跟它连接。


$ lsof -nPi | grep 20xxxjava  24715  Tim  217u  TCP  *:20xxx (LISTEN)
复制代码


之后,继续执行代码,Netty 在 socket 的 accept 执行之后,就可以看到连接已经 ESTABLISHED 成功了。Netty 在 accept 连接之后会注册到 worker 线程进行 IO 处理。


$ lsof -nPi | grep 20xxxjava   24715  Tim  0t0  TCP  10.xx.xx.1:20xxx->10.xx.xx.139:12918 (ESTABLISHED)java   24715  Tim  0t0  TCP  *:20xxx (LISTEN)
复制代码


这就证明连接失败不是应用层丢掉的,肯定是操作系统层面的问题了,那么容器内的连接是否会成功呢?

七、从容器内发起的连接是否能成功

通过重启服务的时候,脚本不停的对服务端端口发起连接,看看是否会有失败的情况。


#!/bin/bashfor i in`seq 1 3600`dot=`timeout0.1 telnet localhost 20xxx  </dev/null 2>&1|grep -c 'Escapecharacter is'`echo$(date) "20xxx check result:" $tsleep0.005done
复制代码


从脚本的执行结果看到,容器内发起的连接有时也是会失败的,以下黄色高亮的 0 就是失败的连接。



同时,从服务端的抓包结果看到,也会有 syn 被丢弃的情况。


八、全连接队列满导致的 SYN 丢包

syn 包被操作系统丢弃,初步猜测是 syn queue 满了,通过 netstat -s 查看队列的情况。


$ netstat -s3220 times the listen queue of a socket  overflowed 3220 SYNs to LISTEN sockets dropped
复制代码


问题的原因基本找到了,可是导致 syn 被丢弃的原因还是不知道,这里我们先复习下三次握手的整个过程。



上图结合三次握手来说:


1、客户端使用 connect()向服务端发起连接请求(发送 syn 包),此时客户端的 TCP 的状态为 SYN_SENT;


2、服务端在收到 syn 包后,将 TCP 相关信息放到 syn queue 中,同时向客户端发送 syn+ack,服务端 TCP 的状态为 SYN_RCVD;


3、客户端收到服务端的 syn+ack 后,向服务端发送 ack,此时客户端的 TCP 的状态为 ESTABLISHED。服务端收到 ack 确认后,从 synqueue 里将 TCP 信息取出,并放到 accept queue 中,此时服务端的 TCP 的状态为 ESTABLISHED。


我们大概了解了 syn queue 和 accept queue 的过程,那再看上面的问题,overflowed 代表 accept queue 溢出,dropped 代表 syn queue 溢出,那么 3220 SYNs to LISTEN socketsdropped,这个就是代表 syn queue 溢出吗?


其实并不是,我们翻看了源码:



可以看到 overflow 的时候 TCP dropped 也会增加,也就是 dropped 一定大于等于 overflowed。但是结果显示 overflowed 和 dropped 是一样的(都是 3220),只能说明 accept queue 溢出了,而 syn queue 溢出为 0(3220-3220=0)。


从上图的 syn queue 和 accept queue 的设计,accept queue 满了应该不影响 syn 响应,即不影响三次握手。


带着这个疑问我们再次翻看了内核源码:



可以看到建连接的时候,会判断 accept queue,如果 acceptqueue 满了,就会 drop,即把这个 syn 包丢掉了。

九、全连接队列怎么调整?

我们再看下服务器的实际情况,通过 ss -lnt 查看当前 20xxx 端口的 accept queue 只有 50 个,这个 50 是哪里来的呢?


$ ss -lnt State Recv-Q Send-Q Local  Address:Port Peer Address:Port LISTEN 0 50 *:20xxx *:*
复制代码


然后看了下机器内核的 somaxconn 也远远超过 50,难道 50 是应用层设置的?


$ cat  /proc/sys/net/core/somaxconn 128
复制代码


Accept queue 的大小取决于:min(backlog, somaxconn),backlog 是在 socket 创建的时候传入的,somaxconn 是一个内核级别的系统参数。


Syn queue 的大小取决于:max(64,tcp_max_syn_backlog),不同版本的 os 会有些差异。


再研究下 Netty 的默认值,可以发现 Netty3 初始化的时候 backlog 只有 50 个,Netty4 已经默认升到 1024 了。



业务换了新的包,重新发布后发现 accept queue 变成了 128,服务端 syn 被丢弃的问题已经没有了,客户端连接也不再报错。


在应用启动时间,通过 shell 脚本打印队列大小,从图片中可以看到,最大 queue 已经到了 101,所以之前默认的 50 个肯定是要超了。



从这个截图,也可以知道为啥前面提到的 HTTP 请求没有 syn 丢包了。因为 Tomcat 已经设置了 backlog 为 128,而且 HTTP 的连接是 lazy 的。但是,我们对 TCP 连接的初始化并不是 lazy 的,所以在高并发的场景下会出现 accept queue 满的情况。

十、调整 backlog 到底有多大效果?

针对这个问题,我们还专门做了个试验了下,从实验结果看调整带来的效果还是比较明显的。


服务端:1 台 8C 的物理机器


客户端:10 台 4C 的 docker


Backlog每秒并发建连数SYN包被丢?
1283000
1285000少量丢包
10245000
102410000


可以看到,对 8C 的机器 backlog 为 128 的情况下,在每秒 5000 建连的时候就会出现 syn 丢包。在调整到 1024 之后,即使 10000 也没有任何问题。当然,这里提醒下,不要盲目的调整到很高的值,是否可以调整到这么高,还要结合各自服务器的配置以及业务场景。


作者介绍


顾海洋,携程框架架构研发部技术专家,负责携程分布式服务化领域的工作。目前主要负责 Dubbo 在携程的二次开发和推广工作。


李伟,携程云平台技术专家,2012 年加入携程,目前专注于云原生方向技术的研究和落地,先后参与负责过携程部署架构改造、接入层架构升级等项目的设计和推广。


本文转载自公众号携程技术(ID:ctriptech)。


原文链接


https://mp.weixin.qq.com/s/oKtu3AA9D3y--xMDQ8EARw


2020-02-19 20:311024

评论

发布
暂无评论
发现更多内容

沈抚示范区·“华为云杯”2021全国AI大赛圆满落幕

华为云开发者联盟

人工智能 华为云 modelarts AppCube AI大赛

智慧火电扭转传统运作模式,3D可视化助力双碳政策疾行

一只数据鲸鱼

数据可视化 智慧能源 火力发电 智慧火电 火电厂

为了减少代码复杂度,我将if-else升级为面向状态编程

华为云开发者联盟

编程 复杂度 面向状态编程 if-else

VSCode设置Python的unittest测试

陈磊@Criss

disruptor在数据同步场景下的应用实战

编程 架构 面试 后端

8. 这篇博客,把python从数值到模块、到字典、到元组,真python入门复习教程通览

梦想橡皮擦

10月月更

「IM开源推荐」前微信技术专家打造,golang实现,一键部署,客户端SDK全平台支持,轻松替代IM云服务

OpenIM

【Python自动化测试网站推荐】免费资源网址,帮你找到所有想要的资源!!

程序员阿沐

【LeetCode】重复的DNA序列Java题解

Albert

算法 LeetCode 10月月更

业界首个机密计算容器运行时—Inclavare Containers正式进入CNCF!

阿里巴巴云原生

阿里云 容器 云原生

Form Schema 定义详解

全象云低代码

大前端 低代码平台 JSON Schema

Interrupted Exception异常可能没你想的那么简单!

华为云开发者联盟

线程 JVM 高并发 并发 java

OpenKruise 如何实现应用的可用性防护?

阿里巴巴云原生

阿里云 开源 云原生 OpenKruise

🐬【MySQL技术专题】该换换你的数据库版本了,让我们一同迎接8.0的到来哦!(初探篇)

洛神灬殇

MySQL 运维 MySQL8.0 MySQL 数据库 10月月更

ERP对你有帮助吗?ERP是什么时候开始出现的?

低代码小观

管理 企业 企业管理 运营管理 企业管理系统

带你读Paper丨分析ViT尚存问题和相对应的解决方案

华为云开发者联盟

论文阅读 华为云 Vision Transformer 卷积核

netty系列之:使用netty搭建websocket客户端

程序那些事

Java Netty websocket 程序那些事

源码 | 为金融场景而生的数据类型:Numeric

RadonDB

数据库 postgresql

何时适合进行自动化测试?(上)

禅道项目管理

自动化测试

010云原生之可观测架构模式

穿过生命散发芬芳

云原生 10月月更

mysql cpu占用超过100%

hasWhere

第 12 章 -《Linux 一学就会》-重定向和文件的查找

学神来啦

云计算 Linux 运维 linux学习

kubernetes pod访问不了外网但是宿主机可以

ilinux

Android性能优化之Android 10+ dex2oat实践

字节跳动终端技术

字节跳动 移动开发 Android; 火山引擎

Groovy入门常用语法

FunTester

Java 语法 测试开发 Groovy FunTester

北京博睿宏远数据科技股份有限公司声明

博睿数据

ERP系统能帮你做些什么?ERP系统的部署类型哪个更适合你?

低代码小观

企业 企业管理 信息化管理 流程管理

腾讯云原生数据库 TDSQL-C荣获“云原生卓越技术提供商”奖项

腾讯云数据库

数据库 tdsql

定制个机器人帮你和Ta聊天

万俊峰Kevin

golang chatbot 聊天机器人 微信聊天

Vue进阶(幺贰柒):插槽详解

No Silver Bullet

Vue 插槽 10月月更

一文说清楚css3具有颠覆意义的2D转换效果

你好bk

CSS html css3 大前端 html/css

携程一次Dubbo连接超时问题的排查_文化 & 方法_顾海洋_InfoQ精选文章