一次 Node.js http 连接无法复用的问题排查原创
一次压测中阿里云 SLB 的并发连接数被打满了,导致服务之间的 HTTP 调用延迟很大。当时 SLB 的并发连接数情况如下图所示。
登录容器终端查看,发现某个前端 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 代码,得到的抓包结果如下
可用看到这次实验中的包,间隔 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
跟踪其中一个包,它的包交互过程如下。
这个连接保持了 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 跟踪一个包的结果如下。
可以看到连接终于被复用起来了。
小结
这个问题本来比较简单,只是因为对封装过很多层以后的 Node.js 不太熟悉,导致排查花了一些时间。这个问题在 Java 中很早也犯过错,使用 OkHttp 发起连接时,如果 OkHttpClient 实例没有被单例,每次调用都 new 一个的话,那就是一个灾难。因为 OkHttpClient 内部也是维护了一个连接池。
public class OkHttpClient implements Cloneable, Call.Factory, WebSocket.Factory {
final ConnectionPool connectionPool;
}
教训告诉我们,连接池使用需谨慎,连接池需要共享。