Performance issue when sending large responses for concurrent requests #37680

Activity

1. mscdex commented on Mar 9, 2021

   

   mscdex

   on Mar 9, 2021

   Contributor

   More actions

   FWIW 0df581c introduced this change in behavior.
2. jasnell

   added

   questionIssues asking questions about Node.js.Issues asking questions about Node.js.

   on Mar 9, 2021
3. xue-cai commented on Mar 10, 2021

   

   xue-cai

   on Mar 10, 2021

   Author

   More actions

   Thanks @mscdex for replying! So is this behavior intended? If so, is there a recommendation on how to achieve the expected behavior?
4. mscdex commented on Mar 10, 2021

   

   mscdex

   on Mar 10, 2021

   Contributor

   More actions

   It seems that @lpinca mentioned potential issues like this in his comment here in the original PR from that commit. Perhaps he has some ideas on how we can avoid this extra latency?
5. lpinca commented on Mar 10, 2021

   

   lpinca

   on Mar 10, 2021

   Member

   More actions

   There might be some unneeded writes for empty chunks introduced by 0df581c as per #27709 (comment) but the issue here is different.

   Before 0df581c the 'finish' event was emitted before the actual data was written. The finish callback was called before the write_() callback.

   After 0df581c the 'finish' event is emitted after all data is written (after all previous socket.write() callbacks are called). I think this is the correct and expected behavior and is consistent with other writable streams.
6. xue-cai commented on Mar 10, 2021

   

   xue-cai

   on Mar 10, 2021

   Last edited by xue-cai

   Author

   More actions

   Just to clarify, so is that true that we haven't seen this issue reported before?

   This issue happened in our production servers, and then got reproduced on our dev mac laptops.

   If it helps to investigate, we kind of solved this issue by doing both of the following:

   • only process one request at a time using async.queue(), however, flushing request 1's response (res.send(serializedBigObject)) still overlaps with request 2's processing
   • introduce more async gaps (like await 1ms 100 times in a loop) in the beginning of request 2's processing to let request 1's response to flush

   With these two workarounds, we were able to achieve the "expected behavior" pasted above.

   It seems to us that event loop getting blocked is a problem here, and it has something to do with large response flushing.
7. lpinca commented on Mar 11, 2021

   

   lpinca

   on Mar 11, 2021

   Last edited by lpinca

   Member

   More actions

   Are you using keep-alive connections? If so it makes sense. Because the client socket is the same so the second response has to wait for the data of the first response to be flushed.

   Some blocking is expected because you are synchronously serializing and sending 55 MiB of data for every request.
8. xue-cai commented on Mar 11, 2021

   

   xue-cai

   on Mar 11, 2021

   Author

   More actions

   They are different file descriptors according to Node.js Diagnostic report (https://nodejs.org/api/report.html) so I don't think second response needs to wait for first response to finish flushing.
   Also you can see in "What do you see instead?", the requests finished out of order:

   [2536] -- Took 773ms to flush response for request 4 --
   [2538] -- Took 309ms to flush response for request 5 --
   [2539] -- Took 1719ms to flush response for request 2 --
   [2540] -- Took 2206ms to flush response for request 1 --
   [2540] -- Took 1248ms to flush response for request 3 --
   
9. lpinca commented on Mar 12, 2021

   

   lpinca

   on Mar 12, 2021

   Last edited by lpinca

   Member

   More actions

   It is more or less consistent with

   const net = require('net');
   
   function makeBigObject(leaves, depth) {
     if (depth === 0) {
       return 'howdy';
     } else {
       const ret = {};
       for (let i = 0; i < leaves; ++i) {
         ret[i] = makeBigObject(leaves, depth - 1);
       }
       return ret;
     }
   }
   
   const bigObject = makeBigObject(2000, 2);
   let connectionCount = 0;
   let firstConnectionStartTime;
   
   function getTimeMs() {
     return Date.now() - firstConnectionStartTime;
   }
   
   function handleConnection({ connectionIndex, socket }) {
     socket.resume();
   
     if (connectionIndex === 1) {
       firstConnectionStartTime = Date.now();
     }
   
     console.log(
       `[${getTimeMs()}] Serializing data for connection ${connectionIndex}...`
     );
     const serializedBigObject = JSON.stringify(bigObject);
   
     const flushStartTimeMs = Date.now();
     socket.on('finish', function () {
       const flushDurationMs = Date.now() - flushStartTimeMs;
       console.log(
         `[${getTimeMs()}] -- Took ${flushDurationMs}ms to flush data for connection ${connectionIndex} --`
       );
     });
   
     console.log(
       `[${getTimeMs()}] Sending ${Math.round(
         serializedBigObject.length / 1024 / 1024
       )}MB data for connection ${connectionIndex}...`
     );
     socket.end(serializedBigObject);
   
     console.log(
       `[${getTimeMs()}] - Handler done for connection ${connectionIndex} -`
     );
   }
   
   const server = net.createServer(function (socket) {
     handleConnection({ connectionIndex: ++connectionCount, socket})
   });
   
   server.listen(function () {
     const port = server.address().port;
   
     for (let i = 0; i < 5; i++) {
       net.createConnection({ port }).resume();
     }
   });

   so, if anything, it is not an HTTP issue.
10. github-actions commented on Jun 27, 2026

    

    github-actionsbot

    on Jun 27, 2026 – with GitHub Actions

    Contributor

    More actions

    This issue has been marked as stale due to 210 days of inactivity.
    It will be automatically closed in 30 days if no further activity occurs. If this is still relevant, please leave a comment or update it to keep it open.
11. github-actions

    added

    staleIssues and PRs marked stale due to inactivity and scheduled for automatic closure.Issues and PRs marked stale due to inactivity and scheduled for automatic closure.

    on Jun 27, 2026
12. github-actions commented on Jul 28, 2026

    

    github-actionsbot

    on Jul 28, 2026 – with GitHub Actions

    Contributor

    More actions

    This issue has been automatically closed after 30 days of inactivity following its stale status (no activity for a total of 120 days).
    If this is still relevant, feel free to reopen it or leave a comment with additional details so we can continue the discussion.
13. github-actions

    closed this as not plannedon Jul 28, 2026