性能文章>一次 Node.js http 连接无法复用的问题排查>

一次 Node.js http 连接无法复用的问题排查原创

9036110

一次压测中阿里云 SLB 的并发连接数被打满了,导致服务之间的 HTTP 调用延迟很大。当时 SLB 的并发连接数情况如下图所示。

image.png

登录容器终端查看,发现某个前端 Node.js 服务中的单个容器的 ESTABLISH 状态的连接数达到 2 万多个,几十个容器直接把连接数占满了。

通过 tcpdump 抓包发现了如下的情况:

  • http 连接请求头都有带上 Connection: Keep-Alive
  • 连接全部都没有复用,一个连接三次握手完,隔了 65s 才会被 nginx 超时发送 fin 包断开

因此连接既有 Keep-Alive,不会在 http 请求处理完以后关闭,又没有被复用,因此压测请求一上来,连接蹭蹭蹭的往上涨,马上就达到了 SLB 的瓶颈。

一开始我们以为是 Node.js 的 http.Agent 的参数设置有错误,Node.js 通过http.Agent 来管理可复用的连接,创建 http.Agent 实例的方法如下:

var agent = new http.Agent();

请求头 Connection: Keep-Alive 就是在 http.Agent 中指定的,如下所示。

var agent = new http.Agent({keepAlive: true})

我们来写一个最简单的例子,代码如下所示。

let http = require('http');

const agent = new http.Agent({keepAlive: true,});

function sendHttp() {
    http.get({
        hostname: 'ya.test.me',
        port: 80,
        path: '/',
        agent: agent
    }, (res) => {
        console.log('STATUS: ' + res.statusCode);
        res.on('data', chunk => {
            console.log('BODY: ' + chunk);
        });
    });
}

sendHttp();

setTimeout(function () {
    console.log("start sleep");
    sendHttp();
}, 10 * 1000);

setTimeout(function () {
}, 100000);

执行上面的 Node.js 代码,得到的抓包结果如下

image.png

可用看到这次实验中的包,间隔 10s 的两次 HTTP 请求复用了 TCP 连接,这个连接在空闲 65s 左右以后被 Nginx 断开。

排查到这里,貌似思路就断了。Node.js 明明有复用连接的能力,为什么这里没有生效。只能去阅读 Node.js 的 Agent 的源码,发现它在底层维护了requests、freeSockets 等数据结构,如下所示。

function Agent(options) {
  this.requests = {};
  this.sockets = {};
  /**
  *  freeSockets 是一个 map,结构如下:
  *  test.ye.me:80 -> [socket1, socket2, socket3...]
  *  xxx.com:8080 -> [socket1, socket2, socket3...]
  **/
  this.freeSockets = {};
  this.keepAliveMsecs = this.options.keepAliveMsecs || 1000;
  this.keepAlive = this.options.keepAlive || false;
  // 允许对单个 host:port 最大的连接数
  this.maxSockets = this.options.maxSockets || Agent.defaultMaxSockets;
  // 允许对单个 host:port 最大的空闲连接数
  this.maxFreeSockets = this.options.maxFreeSockets || 256;
}

当连接空闲时,会回调 free 事件,核心代码注释如下所示。

 this.on('free', (socket, options) => {
    // name 是域名和端口的拼接字符串 test.ya.me:80:
    var name = this.getName(options);
        // 得到当前的域名端口对应的 freeSockets 数组
        var freeSockets = this.freeSockets[name];
        var freeLen = freeSockets ? freeSockets.length : 0;
        var count = freeLen;
        // 如果当前空闲连接大于配置的 maxSockets 或 maxFreeSockets 值,直接关闭当前这个 socket
        if (count > this.maxSockets || freeLen >= this.maxFreeSockets) {
          socket.destroy(); // 关闭 socket
        } else if (this.keepSocketAlive(socket)) {
          如果是 Keep-Alive 的 socket,将它加入到 freeSockets 数组中
          freeSockets = freeSockets || [];
          this.freeSockets[name] = freeSockets;
          socket[async_id_symbol] = -1;
          socket._httpMessage = null;
          this.removeSocket(socket, options);
          freeSockets.push(socket);
        } else {
          前面都不满足要它何用,关掉
          // Implementation doesn't want to keep socket alive
          socket.destroy();
        }
    }
  });
}

通过调试,发现线上服务的代码,确实有回调到 free 事件,但是没有调用过 reuseSocket 方法。后来前端大佬去看代码发现了一点蛛丝马迹,每次请求时,都新建了一个 http.Agent 对象,这样就相当于每次 http 调用都新建了一个连接池,每次 HTTP 请求完以后这个连接池的空闲连接数都是 1。下面来进行实验,代码如下。

let express = require("express");
let app = express();
let http = require('http');

app.get("/", function (req, res) {
    http.get({
        hostname: 'ya.test.me',
        port: 80,
        path: '/',
        agent: new http.Agent({keepAlive: true,})
    }, (result) => {
        console.log('STATUS: ' + result.statusCode);
        result.on('data', chunk => {
            console.log('BODY: ' + chunk);
        });
        res.send("hello");
    });
});
app.listen(3000);

启动这个 Node.js 服务,同时开始抓取 80 端口的包,使用 ab 工具(其它能批量发起 http 调用工具也行)调用这个 node 服务,

ab -n 5000 -c 10  'http://10.211.55.10:3000/'

短短时间内 ESTABLISH 的连接就达到了几千个,这些连接全部没有复用。与线上的现象一样。

netstat -lnpa | grep :80 | grep -v 8080  | awk '{print $6}' | sort | uniq -c | sort -rn

   2038 ESTABLISHED
      1 LISTEN

跟踪其中一个包,它的包交互过程如下。

image.png

这个连接保持了 65s 才被 Nginx 超时断开,既占了连接,又没有复用,比短连接危害更大。

接下来我们把 http.Agent 对象改为了全局公用,重新来一遍实验,使用 netstat 的结果如下所示。

netstat -lnpa | grep :80 | grep -v 8080  | awk '{print $6}' | sort | uniq -c | sort -rn

     10 ESTABLISHED
      1 LISTEN

可以看到全程最多只创建了 10 个连接,相比于之前的 2000 多个,降了几个数量级。wireshark 跟踪一个包的结果如下。

image.png

可以看到连接终于被复用起来了。

小结

这个问题本来比较简单,只是因为对封装过很多层以后的 Node.js 不太熟悉,导致排查花了一些时间。这个问题在 Java 中很早也犯过错,使用 OkHttp 发起连接时,如果 OkHttpClient 实例没有被单例,每次调用都 new 一个的话,那就是一个灾难。因为 OkHttpClient 内部也是维护了一个连接池。

public class OkHttpClient implements Cloneable, Call.Factory, WebSocket.Factory {
  final ConnectionPool connectionPool;
}

教训告诉我们,连接池使用需谨慎,连接池需要共享。

点赞收藏
分类:标签:
挖坑的张师傅

机械工业出版社《深入理解 JVM 字节码》作者,掘金小册作者《JVM 字节码从入门到精通》、《深入理解TCP 协议》作者,Vim 死忠粉、Kotlin&Go 爱好者、能抓一手好包、喜欢底层技术和分享。微信公众号:张师傅的博客(shifuzhang01)

请先登录,查看1条精彩评论吧
快去登录吧,你将获得
  • 浏览更多精彩评论
  • 和开发者讨论交流,共同进步

为你推荐

日常Bug排查-集群逐步失去响应

日常Bug排查-集群逐步失去响应

浅析AbstractQueuedSynchronizer

浅析AbstractQueuedSynchronizer

10
1