在 AWS 上进行负载测试时，Node.js 网络性能大幅下降

Question

我将以下 Node.js 代码编写为非常基本的 HTTP 服务器。它的目的是摄取大量包含 base64 数据的请求，并将该数据作为图像写入 S3。 S3 编写方面运行良好，没有任何问题。但是，初始请求在负载下似乎花费了异常长的时间。

server.js

http.createServer(function(req, res){
    if (url.parse(req.url).pathname == '/processimage' && req.method.toLowerCase() == 'post') {
        var startTime = new Date();
        var rawBody = '';
        req.on('data', function(chunk) { 
            rawBody += chunk;
        });

        req.on('end', function() {
            console.log('REQUEST FINISHED: ' + (new Date() - startTime) + ' ms');
            // Process image, upload to S3
            res.writeHead(200);
            res.end('data');
        }
        return;
    } else {
        // Other requests
    }
}).listen(1347);

我也在计时图像处理部分，但它的表现很好，与这个问题无关。

为了对此进行测试，我编写了一个 POST 测试数据的脚本，其中包含大约 500k 个字符的 base64（2-3mb 原始图像）。在本地测试时，一切正常。我的输出是：

REQUEST FINISHED: 9ms
REQUEST FINISHED: 23ms
REQUEST FINISHED: 18ms

等等

但是，在 x-large 实例上将代码部署到 AWS 后，我看到以下内容：

REQUEST FINISHED: 499ms
REQUEST FINISHED: 2493ms
REQUEST FINISHED: 1784ms
REQUEST FINISHED: 3440ms
REQUEST FINISHED: 994ms
REQUEST FINISHED: 36043ms

基本上，在对此进行压力测试时，每 30 个请求中大约有 1 个请求似乎需要 10 多秒（在某些情况下甚至 30 多秒）才能通过请求管道。正如您在我的代码中看到的那样，在计算时间之前对数据进行了零处理，因此这意味着介于“req.on('data')”和“req.on('end')”之间，有很大的延迟。

我的问题是：在 req.on('data') 和 req.on('end') 之间是否发生某种处理会导致此 POST 花费这么长时间？主机是否可能由于某种原因（Ubuntu 12.04、x-large 实例、14GB 内存、4x CPU）阻塞了这些请求？

Answer 1

这可能需要大量的日志记录才能看到发生了什么。您有多个请求，每个请求都包含大量数据，这些数据将在多个块中进行处理。我想说的第一件事是准确记录每个请求的每个块的处理时间，然后您可以了解事情发生的顺序并查看其结果。这是记录的第一个想法：

// helper function
logDelta(id, start, msg) {
    var delta = new Date() - start;
    console.log(id + ": (" + delta + ") - " + msg);
}

var reqCntr = 0;
http.createServer(function(req, res){
    if (url.parse(req.url).pathname == '/processimage' && req.method.toLowerCase() == 'post') {
        // place an id on the request for logging purposes
        req.trackerID = reqCntr++;
        console.log(req.trackerID + ": Begin Request");

        var startTime = new Date();
        var rawBody = '';
        var chunkCntr = 0;
        req.on('data', function(chunk) { 
            logDelta(req.trackerID, startTime, "chunk(" + chunkCntr + "), length = " + chunk.length);
            ++chunkCntr;
            rawBody += chunk;
        });

        req.on('end', function() {
            logDelta(req.trackerID, startTime, "Request Finished");
            // Process image, upload to S3
            res.writeHead(200);
            res.end('data');
        }
        return;
    } else {
        // Other requests
    }
}).listen(1347);

然后，您可能需要对日志数据进行一些处理，以便能够跟踪每个请求中每个事件的时间，尤其是长时间运行的请求。这很可能会为您提供下一步寻找方向的线索。

---

仅供参考，堆栈中有很多不同的地方可能会遇到瓶颈。例如，如果您在服务器上触发数据的速度超过了数据的处理速度（无论是在操作系统级别还是在节点级别），那么 TCP 缓冲区将在某个时候填满，并且传入的数据包将被丢弃，或者套接字将被放入某种流控制中。

如果您在共享服务器上运行，您也可能无法访问整个 TCP 缓冲区。

---

这是一个方案，它会收集每个连接的所有历史记录，然后立即将其输出到日志中（使单个连接的剖析更容易，但会掩盖不同连接之间的事件顺序）。

var reqCntr = 0;
http.createServer(function(req, res){
    var log = [];
    var id;
    var startTime = new Date();

    // helper function
    logDelta(msg) {
        var delta = new Date() - startTime;
        log.push(id + ": (" + delta + ") - " + msg);
    }

    if (url.parse(req.url).pathname == '/processimage' && req.method.toLowerCase() == 'post') {
        // place an id on the request for logging purposes
        id = reqCntr++;
        log.push(id + ": Begin Request");

        var rawBody = '';
        var chunkCntr = 0;
        req.on('data', function(chunk) { 
            logDelta("chunk(" + chunkCntr + "), length = " + chunk.length);
            ++chunkCntr;
            rawBody += chunk;
        });

        req.on('end', function() {
            // dump connection history to console.log()
            logDelta("Request Finished");
            console.log(log.join("/n"));
            // Process image, upload to S3
            res.writeHead(200);
            res.end('data');
        }
        return;
    } else {
        // Other requests
    }
}).listen(1347);