追踪将服务器CPU耗光的凶手!

前面我们讨论系统调用的时候结论是耗时200ns-15us不等。不过我今天说的我的这个遭遇可能会让你进一步认识系统调用的真正开销。在本节里你会看到一个耗时2.5ms的connect系统调用,注意是毫秒,相当于2500us!

问题描述

当时是我的一个线上云控接口,是nginx+lua写的。正常情况下,单虚机8核8G可以抗每秒2000左右的QPS,负载还比较健康。但是该服务近期开始出现一些500状态的请求了,监控时不时会出现报警。通过sar -u查看峰值时cpu余量只剩下了20-30%。

图3.jpg

第一步、迅速锁定嫌疑人

top命令查看cpu使用,通过top命令发现峰值的时候cpu确实消耗的比较多,idle只有20-30%左右。在使用的cpu里,软中断的占比也比较高,1/3左右。
再通过cat /proc/softirqs查看到软中断是都是网络IO产生的NET_TX,NET_RX,和时钟TIMER。
既然软中断这个贼人吃掉了我这么多的CPU时间,所以案件的嫌疑人就这么初步被我锁定了。

处理,那既然是NET_TX,NET_RX和TIMER都高,那咱就挑可以削减的功能砍一砍呗。

  • 1.砍掉多余的gettimeofday系统调用
  • 2.每个请求砍掉一次非必须Redis访问,只留了必要的。

结果:峰值的cpu余量从确实多出来一些了。报警频率确实下来了,但是还是偶尔会有零星的报警。可见该嫌疑人并非主犯。。

第二步、干掉一大片,真凶在其中

接着查看网络连接的情况ss -n -t -a发现,ESTABLISH状态的链接不是很多,但是TIME-WAIT有11W多。继续研究发现针对..*.122:6390的TIME-WAIT已经超过了3W。所以端口有限。原来呀,上一步执行时只干掉了连接上的数据请求,但是tcp握手请求仍然存在。

处理:彻底干掉了针对..*.122:6390的网络连接请求,只保留了必须保留的逻辑。
结果:问题彻底解决。sar -u查看cpu的idle余量竟然达到了90%多。

Tips:单台机器如果作为TCP的客户端,有如下限制

  1. ESTABLISH状态的连接只能有ip_local_port_range范围内的个数。
  2. 只有针对特定ip,特定port的TIME-WAIT过多,超过或接近ip_local_port_range,再新建立连接可能会出现无端口可用的情况。( 总的TIME-WAIT过多并不一定有问题 )

没想到一个简单砍掉一个对redis server的tcp连接,能把cpu优化到这么多。大大出乎意料,而且也想不明白。 根据我之前的性能测试经验,每个tcp连接的建立大约只需要消耗36usec的cpu时间。我们来估算一下:

当时server的qps大约在2000左右,假设是均匀分布的,则8个核每个核每秒只需要处理250个请求。也就是说每秒一条tcp连接需要消耗的cpu时间为:250*36usec = 9ms.

也就是说,正常来讲砍掉这些握手开销只能节约1%左右的cpu,不至于有这么大的提升。(即使我上面的估算只考虑了建立连接,没有统计释放连接的cpu开销,但是连接释放cpu开销也和建立连接差不多。)

总之,这一步确实解决了问题,但是代价是牺牲了一个业务逻辑。

最终、审出真凶,真相大白于天下

我在某一台机器上把老的有问题的代码回滚了回来,恢复问题现场。然后只修改一下ip_local_port_range。 然后请出了strace这个命令。
通过strace -c 统计到对于所有系统调用的开销汇总。 结果我们发现了connect系统调用这个二货,在正常的机器上只需要22us左右,在有问题的机器上竟然花掉来 2500us,上涨了100倍。我们用strace -c $PID查看一下出问题时和正常时的connect系统调用耗时对比:

图1.png

<centor>图1:正常情况下</centor>

图2.png

<centor>图2:出问题时</centor>

然后回想起了..*.122:6390的TIME-WAIT已经超过了3W,会不会TIME_WAIT占用了太多端口导致端口不足呢。因此查看端口内核参数配置:

# sysctl -a | grep ip_local_port_range
net.ipv4.ip_local_port_range = 32768    65000

果然发现该机器上的端口范围只开了3W多个,也就是说端口已经几乎快用满了。那就提高端口可用数量:

# vim /etc/sysctl.conf
net.ipv4.ip_local_port_range = 10000 65000

connect系统调用恢复理性状态,整体服务器的CPU使用率非常健康。

问题的根本原因是建立TCP连接使用的端口数量上(ip_local_port_range)不充裕,导致connect系统调用开销上涨了将近100倍!

后来我们的一位开发同学帮忙翻到了connect系统调用里的一段源码

int inet_hash_connect(struct inet_timewait_death_row *death_row,
               struct sock *sk)
{
    return __inet_hash_connect(death_row, sk, inet_sk_port_offset(sk),
            __inet_check_established, __inet_hash_nolisten);
}

int __inet_hash_connect(struct inet_timewait_death_row *death_row,
                struct sock *sk, u32 port_offset,
                int (*check_established)(struct inet_timewait_death_row *,
                        struct sock *, __u16, struct inet_timewait_sock **),
                int (*hash)(struct sock *sk, struct inet_timewait_sock *twp))
{
        struct inet_hashinfo *hinfo = death_row->hashinfo;
        const unsigned short snum = inet_sk(sk)->inet_num;
        struct inet_bind_hashbucket *head;
        struct inet_bind_bucket *tb;
        int ret;
        struct net *net = sock_net(sk);
        int twrefcnt = 1;

        if (!snum) {
                int i, remaining, low, high, port;
                static u32 hint;
                u32 offset = hint + port_offset;
                struct inet_timewait_sock *tw = NULL;

                inet_get_local_port_range(&low, &high);
                remaining = (high - low) + 1;

                local_bh_disable();
                for (i = 1; i <= remaining; i++) {
                        port = low + (i + offset) % remaining;
                        if (inet_is_reserved_local_port(port))
                                continue;
                        ......
        }
}

static inline u32 inet_sk_port_offset(const struct sock *sk)
{
        const struct inet_sock *inet = inet_sk(sk);  
        return secure_ipv4_port_ephemeral(inet->inet_rcv_saddr,  
                                          inet->inet_daddr,  
                                          inet->inet_dport);  
}

从上面源代码可见,临时端口选择过程是生成一个随机数,利用随机数在ip_local_port_range范围内取值,如果取到的值在ip_local_reserved_ports范围内 ,那就再依次取下一个值,直到不在ip_local_reserved_ports范围内为止。原来临时端口竟然是随机撞。出。来。的。。 也就是说假如就有range里配置了5W个端口可以用,已经使用掉了49999个。那么新建立连接的时候,可能需要调用这个随机函数5W次才能撞到这个没用的端口身上。

所以请记得要保证你可用临时端口的充裕,避免你的connect系统调用进入SB模式。正常端口充足的时候,只需要22usec。但是一旦出现端口紧张,则一次系统调用耗时会上升到2.5ms,整整多出100倍。这个开销比正常tcp连接的建立吃掉的cpu时间(每个30usec左右)的开销要大的多。

解决TIME_WAIT的办法除了放宽端口数量限制外,还可以考虑设置net.ipv4.tcp_tw_recycle和net.ipv4.tcp_tw_reuse这两个参数,避免端口长时间保守地等待2MSL时间。

欢迎关注个人公众号“开发内功修炼”,打通理论与实践的任督二脉

参考文献

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 200,302评论 5 470
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 84,232评论 2 377
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 147,337评论 0 332
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 53,977评论 1 272
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 62,920评论 5 360
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,194评论 1 277
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,638评论 3 390
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,319评论 0 254
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,455评论 1 294
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,379评论 2 317
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,426评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,106评论 3 315
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,696评论 3 303
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,786评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 30,996评论 1 255
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,467评论 2 346
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,043评论 2 341

推荐阅读更多精彩内容