前言:本次追踪没保存截图。因此只能文字描述下了。

运维通过内部沟通软件发来消息,有个消费挤压太厉害已经超过1000w。收到消息后打开监控,发现消费能力于之前下降了50%。

由于是春节期间,考虑量上来的可能性大。所以认为只是偶尔消费挤压之后便会恢复,但第二天依然是这种问题。于是登上其中一台机器。发现1,5,15分钟load均在82,观察一小时左右仍居高不下。于是下定决心排查问题。

首先我们用top命令,把正在跑的进程动态列出来,-c一下看看cpu的使用情况。这时发现一个问题。cpu使用率很高,并且sys的cpu使用率已经到了75%,而user的才占14.1%,这说明系统在做剧烈运动。

于是,抓出来一个pid如 10728 使用strace -c -p 10728,发现90%的时间在进行connect,由此知道程序中应该是用了短连接导致频繁的创建连接。再使用strace -Ff -p 10728追踪他的详细调用发现总是报can't assign requested address,意思就是没有端口了无法创建链接,那也就是说现在可能有大量的time_wait再等待释放,因此使用netstat -anp|grep TIME_WAIT 发现有大量的连接等待释放。

一般的解决办法:

sysctl -w net.ipv4.tcp_timestamps=1  开启对于TCP时间戳的支持,若该项设置为0,则下面一项设置不起作用
sysctl -w net.ipv4.tcp_tw_recycle=1  表示开启TCP连接中TIME-WAIT sockets的快速回收

查看服务器的配置也打开这个了。到现在已经无路可走了。

既然连接数这么多,是那些比较多呢?重新strace -Ff -p 10728抓取调用,发现有一个ip一直被大量的调用。通过这个ip对应业务去查。发现是curl_init()导致的。仔细看了下逻辑,是因为每次调用都初始化、发送、关闭。于是把初始化这种短链接改成了长链接。上线后系统的load直接就降下来了。