当流管道用于缓冲时,节点回送服务器降级10倍

Question

在节点v8.1.4和v6.11.1上

我开始使用以下echo服务器实现,我将其称为pipe.js或pipe.

const http = require('http');

const handler = (req, res) => req.pipe(res);
http.createServer(handler).listen(3001);

我用wrk和下面的lua脚本(为简洁起见缩短了)对它进行了基准测试,它将发送一个小体作为有效载荷.

wrk.method = "POST"
wrk.body   = string.rep("a", 10)

每秒2k请求和44ms的平均延迟,性能不是很好.

所以我编写了另一个使用中间缓冲区的实现,直到请求完成,然后将这些缓冲区写出来.我将其称为 buffer.js或buffer.

const http = require('http');

const handler = (req, res) => {
  let buffs = [];
  req.on('data', (chunk) => {
    buffs.push(chunk);
  });
  req.on('end', () => {
    res.write(Buffer.concat(buffs));
    res.end();
  });
};
http.createServer(handler).listen(3001);

性能发生了巨大变化,buffer.js每秒处理20k次请求,平均延迟为4ms.

在视觉上,下图描绘了超过5次运行和各种延迟百分位数的服务请求的平均数量(p50是中位数).

因此,缓冲区在所有类别中都要好一个数量级.我的问题是为什么？

接下来是我的调查笔记,希望它们至少具有教育意义.

反应行为

这两个实现都是精心设计的,因此它们会给出与返回的完全相同的响应curl -D - --raw.如果给出一个10 d's的主体,两者都将返回完全相同的响应(当然,修改时间):

HTTP/1.1 200 OK
Date: Thu, 20 Jul 2017 18:33:47 GMT
Connection: keep-alive
Transfer-Encoding: chunked

a
dddddddddd
0

两者都输出128个字节(记住这个).

缓冲的唯一事实

从语义上讲,两个实现之间的唯一区别是 pipe.js在请求尚未结束时写入数据.这可能会让人怀疑buffer.js中可能存在多个data事件.这不是真的.

req.on('data', (chunk) => {
  console.log(`chunk length: ${chunk.length}`);
  buffs.push(chunk);
});
req.on('end', () => {
  console.log(`buffs length: ${buffs.length}`);
  res.write(Buffer.concat(buffs));
  res.end();
});

经验:

• 块长度始终为10
• 缓冲区长度始终为1

因为只有一个块,如果我们删除缓冲并实现一个穷人的管道会发生什么:

const http = require('http');

const handler = (req, res) => {
  req.on('data', (chunk) => res.write(chunk));
  req.on('end', () => res.end());
};
http.createServer(handler).listen(3001);

事实证明,这与pipe.js一样糟糕.我觉得这很有趣,因为相同数量的res.write,并res.end呼吁使用相同的参数进行.到目前为止,我最好的猜测是性能差异是由于在请求数据结束后发送响应数据.

剖析

我使用简单的分析指南(--prof)来分析这两个应用程序.

我只包括相关的行:

pipe.js

 [Summary]:
   ticks  total  nonlib   name
   2043   11.3%   14.1%  JavaScript
  11656   64.7%   80.7%  C++
     77    0.4%    0.5%  GC
   3568   19.8%          Shared libraries
    740    4.1%          Unaccounted

 [C++]:
   ticks  total  nonlib   name
   6374   35.4%   44.1%  syscall
   2589   14.4%   17.9%  writev

buffer.js

 [Summary]:
   ticks  total  nonlib   name
   2512    9.0%   16.0%  JavaScript
  11989   42.7%   76.2%  C++
    419    1.5%    2.7%  GC
  12319   43.9%          Shared libraries
   1228    4.4%          Unaccounted

 [C++]:
   ticks  total  nonlib   name
   8293   29.6%   52.7%  writev
    253    0.9%    1.6%  syscall

我们看到,在这两种实现中,C++占主导地位; 然而,主导的功能是交换的.Syscalls占管道时间的近一半 ,但缓冲区仅占1%(原谅我的舍入).下一步,哪个系统调用是罪魁祸首？

我们来到这里

调用strace strace -c node pipe.js就会给我们一个系统调用的摘要.以下是顶级系统调用:

pipe.js

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 43.91    0.014974           2      9492           epoll_wait
 25.57    0.008720           0    405693           clock_gettime
 20.09    0.006851           0     61748           writev
  6.11    0.002082           0     61803       106 write

buffer.js

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 42.56    0.007379           0    121374           writev
 32.73    0.005674           0    617056           clock_gettime
 12.26    0.002125           0    121579           epoll_ctl
 11.72    0.002032           0    121492           read
  0.62    0.000108           0      1217           epoll_wait

管道(epoll_wait)的顶级系统调用(44%的时间)仅为缓冲时间的0.6%(增加140 倍).虽然存在很大的时间差异,但是epoll_wait调用的次数与管道调用的次数相比更少, epoll_wait大约是8倍.我们可以从该语句中获得一些有用的信息,例如管道调用epoll_wait 不断和平均值,这些调用比epoll_waitfor 缓冲区重.

对于缓冲区,顶级系统调用是writev,考虑到大部分时间应该用于将数据写入套接字.

从逻辑上讲,下一步是epoll_wait使用常规strace 查看这些语句,其中显示缓冲区始终包含epoll_wait100个事件(表示使用的百个连接wrk),并且管道 在大多数时间内少于100个.像这样:

pipe.js

epoll_wait(5, [.16 snip.], 1024, 0) = 16

buffer.js

epoll_wait(5, [.100 snip.], 1024, 0) = 100

图形:

这就解释了为什么有更多的是epoll_wait在管,如epoll_wait 不服务于一体的事件循环的所有连接.该epoll_wait零个事件,使它看起来像事件循环处于闲置状态!所有这些都无法解释为什么epoll_wait占用更多的管道时间,因为它表示epoll_wait应立即返回的手册页:

指定超时等于零会导致epoll_wait()立即返回,即使没有可用的事件.

手册页说明函数立即返回,我们可以确认一下吗？strace -T救援:

除了支持缓冲区的呼叫次数减少外,我们还可以看到几乎所有呼叫都不到100ns.管道有一个更有趣的分布显示,虽然大多数呼叫需要不到100ns,但不可忽略的数量需要更长的时间并降落到微秒级的土地上.

Strace确实发现了另一个奇怪的事情,那就是writev.返回值是写入的字节数.

pipe.js

writev(11, [{"HTTP/1.1 200 OK\r\nDate: Thu, 20 J"..., 109},
  {"\r\n", 2}, {"dddddddddd", 10}, {"\r\n", 2}], 4) = 123

buffer.js

writev(11, [{"HTTP/1.1 200 OK\r\nDate: Thu, 20 J"..., 109},
  {"\r\n", 2}, {"dddddddddd", 10}, {"\r\n", 2}, {"0\r\n\r\n", 5}], 5) = 128

还记得当我说两个都输出128个字节？好吧,管道writev返回123字节,缓冲区返回128 字节.管道的五个字节差异在随后的每个调用中进行协调.writewritev

write(44, "0\r\n\r\n", 5)

如果我没弄错的话,write系统调用就会阻塞.

结论

如果我必须做出有根据的猜测,我会说在请求未完成时滚动导致write调用.这些阻塞调用通过更频繁的epoll_wait语句部分地显着降低了吞吐量.为什么 write被调用而不是writev在缓冲区中看到的单个超出我.有人可以解释为什么我看到的一切都在发生吗？

踢球者？在官方的Node.js指南中, 您可以看到指南如何从缓冲区实现开始,然后转移到管道!如果管道实施在官方指南中,那么应该没有这样的性能影响,对吗？

除此之外:这个问题的真实世界性能影响应该是最小的,因为问题是非常人为的,特别是在功能和身体方面,尽管这并不意味着这不是一个有用的问题.假设,答案可能看起来像"Node.js write用于在x情况下获得更好的性能(其中x是更真实的世界用例)"

---

^{披露:从我的博客文章中复制并稍加修改的问题,希望这是一个更好的途径来回答这个问题}

---

2017年7月31日编辑

我最初的假设是,在请求流完成之后编写回显的主体增加了性能,@ robertklep用他的可读(或可读)实现反驳了:

const http   = require('http');
const BUFSIZ = 2048;

const handler = (req, res) => {
  req.on('readable', _ => {
    let chunk;
    while (null !== (chunk = req.read(BUFSIZ))) {
      res.write(chunk);
    }
  });
  req.on('end', () => {
    res.end();
  });
};
http.createServer(handler).listen(3001);

可读在同一水平进行的缓冲,而之前写入数据end的事件.如果有什么事情让我更加困惑,因为可读和我最初的穷人的管道实现之间的唯一区别是data和readable事件之间的差异,但这导致了10倍的性能提升.但我们知道data事件本身并不慢,因为我们在缓冲区代码中使用它.

对于好奇的,可读的报告writev输出,所有128字节输出像缓冲区

这很令人困惑!

Answer 1

这是一个有趣的问题!

事实上,缓冲vs管道不是这里的问题.你有一小块; 它在一个事件中处理.要显示手头的问题,您可以像这样编写处理程序:

let chunk;
req.on('data', (dt) => {
    chunk=dt
});
req.on('end', () => {
    res.write(chunk);
    res.end();
});

要么

let chunk;
req.on('data', (dt) => {
    chunk=dt;
    res.write(chunk);
    res.end();
});
req.on('end', () => {
});

要么

let chunk;
req.on('data', (dt) => {
    chunk=dt
    res.write(chunk);
});
req.on('end', () => {
    res.end();
});

如果write和end是在同一个处理程序上,延迟会减少10倍.

如果检查write功能代码,则该行周围有

msg.connection.cork();
process.nextTick(connectionCorkNT, msg.connection);

cork和uncork下一个事件的连接.这意味着您对数据使用缓存,然后在处理其他事件之前强制在下一个事件上发送数据.

总而言之,如果您拥有write和end使用不同的处理程序,您将拥有:

1. 软木连接(+打开开关)
2. 用数据创建缓冲区
3. 来自另一个事件的uncork连接(发送数据)
4. 呼叫结束进程(用最后一个块发送另一个数据包并关闭)

如果它们位于同一个处理程序中,则在处理事件end之前调用该函数uncork,因此最终的块将位于缓存中.

1. 软木连接
2. 用数据创建缓冲区
3. 在缓冲区上添加"end"块
4. unork连接发送一切

此外,该end功能运行cork/ uncork同步,这将更快一点.

现在为什么这很重要？因为在TCP端,如果您发送带有数据的数据包,并希望发送更多数据,则进程将在发送更多数据之前等待来自客户端的确认:

write+ end在不同的处理程序上:

• 0.044961s:POST/ =>这是请求
• 0.045322s:HTTP/1.1=>第一块:标题+"aaaaaaaaa"
• 0.088522s:确认数据包
• 0.088567s:延续=>第二块(结束部分0\r\n\r\n)

ack发送第一个缓冲区之前约有40毫秒.

write+ end在同一个处理程序中:

数据在单个数据包中完成,ack不需要.

为什么40ms开ACK？这是操作系统中的内置功能,可提高整体性能.它在IETF RFC 1122的第4.2.3.2节中描述:何时发送ACK段'.Red Hat(Fedora/CentOS/RHEL)使用40ms:它是一个参数,可以修改.在Debian(包含Ubuntu)上,它似乎被硬编码为40ms,因此它不可修改(除非您使用该TCP_NO_DELAY选项创建连接).

我希望这是足够的细节,以了解更多关于这个过程.这个答案已经很大了,所以我想,我会停在这里.

可读

我查了一下你的笔记readable.狂野猜测:如果readable检测到空输入,则会在同一个刻度上关闭流.

编辑:我读了可读的代码.我怀疑:

https://github.com/nodejs/node/blob/master/lib/_stream_readable.js#L371

https://github.com/nodejs/node/blob/master/lib/_stream_readable.js#L1036

如果读取完成一个事件,end则立即发出以便接下来处理.

所以事件处理是:

1. readable 事件:读取数据
2. readable检测到它已完成=>创建end事件
3. 您编写数据以便创建一个要开启的事件
4. end 事件处理(完成)
5. 解开处理(但什么都没做,因为一切都已经完成)

如果减少缓冲区:

req.on('readable',()=> {
    let chunk2;
    while (null !== (chunk2 = req.read(5))) {
        res.write(chunk2);
    }
});

这迫使两次写入.这个过程将是:

1. readable事件:读取数据.你得到五秒a.
2. 您编写创建uncork事件的数据
3. 你读了数据.readable检测到它已完成=>创建end事件
4. 您编写数据并将其添加到缓冲数据中
5. 开槽处理(因为之前发布过end); 你发送数据
6. end事件处理(uncork done)=>等待ACK发送最终块
7. 过程会很慢(这是;我检查过)