Node echo server degrades 10x when stream pipes are used over buffering

That’s a funny question you have!

In fact, buffered vs piped is not the question here. You have a small chunk; it is processed in one event. To show the issue at hand, you can write your handler like this:

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

or

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

or

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

If write and end are on the same handler, latency is 10 times less.

If you check the write function code, there is around this line

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

cork and uncork connection on next event. This means that you use a cache for the data, then you force the data to be sent on the next event before other events are processed.

To sum up, if you have write and end on different handlers, you will have:

  1. cork connection (+ create a tick to uncork)
  2. create buffer with data
  3. uncork connection from another event (send data)
  4. call end process (that send another packet with the final chunk and close)

If they are on same handler, the end function is called before the uncork event is processed, so the final chunk will be in the cache.

  1. cork connection
  2. create buffer with data
  3. add “end” chunk on buffer
  4. uncork connection to send everything

Also, the end function runs cork / uncork synchronously, which will be a little bit faster.

Now why does this matter? Because on the TCP side, if you send a packet with data, and wish to send more, process will wait for an acknowledge from the client before sending more:

write + end on different handlers:

About 40ms for ack

  • 0.044961s: POST / => it is the request
  • 0.045322s: HTTP/1.1 => 1st chunk : header + “aaaaaaaaa”
  • 0.088522s: acknowledge of packet
  • 0.088567s: Continuation => 2nd chunk (ending part, 0\r\n\r\n)

There is ~40 ms before ack after the 1st buffer is sent.

write + end in the same handler:

No ack needed

The data is complete in a single packet, no ack needed.

Why the 40ms on ACK? This is a built-in feature in the OS to improve performance overall. It is described in section 4.2.3.2 of IETF RFC 1122: When to Send an ACK Segment’.
Red Hat (Fedora/CentOS/RHEL) uses 40ms: it is a parameter and can be modified. On Debian (Ubuntu included), it seems to be hardcoded to 40ms, so it’s not modifiable (except if you create a connection with the TCP_NO_DELAY option).

I hope this is enough detail to understand a little bit more about the process. This answer is already big, so I will stop here, I guess.

Readable

I checked your note about readable. Wild guess: if readable detects an empty input it closes the stream on the same tick.

Edit: I read the code for readable. As I suspected:

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

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

If read finishes an event, end is immediately emitted to be processed next.

So the event processing is:

  1. readable event: reads data
  2. readable detects it has finished => creates end event
  3. You write data so that it creates an event to uncork
  4. end event processed (uncork done)
  5. uncork processed (but do nothing as everything is already done)

If you reduce the buffer:

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

This forces two writes. The process will be:

  1. readable event: reads data. You get five as.
  2. You write data that creates an uncork event
  3. You read data. readable detects it has finished => create end event
  4. You write data and it is added to the buffered data
  5. uncork processed (because it was launched before end); you send data
  6. end event processed (uncork done) => wait for ACK to send final chunk
  7. Process will be slow (it is; I checked)

Leave a Comment

Hata!: SQLSTATE[HY000] [1045] Access denied for user 'divattrend_liink'@'localhost' (using password: YES)