nodejs / node

Node.js JavaScript runtime ✨🐢🚀✨
https://nodejs.org
Other
108.02k stars 29.81k forks source link

HTTP2 download of parallel requests is slower than HTTP1.1 #54874

Open stanislav-halyn opened 2 months ago

stanislav-halyn commented 2 months ago

Version

v20.17.0

Platform

MacOS Sonoma 14.5, 2,3 GHz Quad-Core Intel Core i7

Subsystem

No response

What steps will reproduce the bug?

Define an http2 and http1.1 clients and fetch some data in parallel.

You can use the script below. If you run it using the following command, it will send 25 parallel requests using HTTP1.1

node client.js

or you can run this command and it will send 25 parallel requests using HTTP2:

node client.js http2
client.js

```javascript import http2 from 'node:http2'; import https from 'node:https'; const isHttp2 = process.argv[2] === 'http2'; const MB = 1024 * 1024; const WINDOW_SIZE = 32 * MB; const url = new URL('https://nodejs.org/dist/v17.1.0/node-v17.1.0-x64.msi'); const client = http2.connect(url, { settings: { initialWindowSize: WINDOW_SIZE, }, }); client.on('connect', () => { client.setLocalWindowSize(WINDOW_SIZE); }); const fetchHttp1 = (id) => { return new Promise((resolve) => { const req = https.request({ host: url.host, path: url.pathname, headers: { connection: 'keep-alive', }, }, (res) => { res.on('data', () => {}); res.on('end', () => { console.log(`Complete request with id: ${id}`); resolve(); }); }, ); req.end(); }); }; const fetchHttp2 = (id) => { return new Promise((resolve) => { const req = client.request({ ':path': url.pathname, }); req.on('data', () => {}); req.on('end', () => { console.log(`Complete request with id: ${id}`); resolve(); }); req.end(); }); }; const main = async () => { console.log(`Starting requests using HTTP${isHttp2 ? '2' : '1.1'} protocol.`); const startTime = Date.now(); await Promise.all( Array.from({ length: 25 }) .fill(null) .map((_, index) => isHttp2 ? fetchHttp2(index) : fetchHttp1(index)), ); console.log(`Requests complete. Completion time: ${(Date.now() - startTime) / 1000}s`); }; main(); ```

How often does it reproduce? Is there a required condition?

It's not quite stable, because sometimes http2 has the same performance or even better performance.

What is the expected behavior? Why is that the expected behavior?

I expect http2 to be faster or at least have the same performance as http1.1.

What do you see instead?

Instead, I often see that http1.1 requests are faster. Most of the times http2 took 25s to complete while http1.1 took 20s.

There's a problem, though, because those results are not consistent when using the URL I provided in the example.

But, the results are consistent with some internal APIs I'm working with. First, I thought there might be a problem with our internal APIs, but making 25 parallel requests to our internal APIs using curl has consistently the same performance on both http 1.1 and http2.

I ran curl with the following command:

curl --config ./config.txt --parallel --parallel-max 25 --http2

where config.txt looked like this:

url = "our-internal-api"
output = "/dev/null"
// repeated 25 times

Additional information

I was thinking the reason for such slowness would be TCP stall because http2 uses only 1 tcp connection, so I checked in wireshark how many tcp connections creates node vs curl when using http2, and both created only 1 tcp connection.

Also, I noticed node receives first 10 http2 requests randomly, but then sequentially, while http1 requests are all received randomly.

http2:

image

http1:

image
RedYetiDev commented 2 months ago

It's not quite stable, because sometimes http2 has the same performance or even better performance.

Are you sure it's not the server that is being requested? Have you tried to reproduce with another http2 client?

But, the results are consistent with some internal APIs I'm working with. First, I thought there might be a problem with our internal APIs, but making 25 parallel requests to our internal APIs using curl has consistently the same performance on both http 1.1 and http2.

How different were the speeds compared?

CC @nodejs/http2

stanislav-halyn commented 2 months ago

@RedYetiDev

Are you sure it's not the server that is being requested? Have you tried to reproduce with another http2 client?

Yeah, I'm sure it's not the server that is being requested. I have tried curl and a rust server to make the same requests, and only on nodejs the results for http1.1 and http2 were inconsistent

How different were the speeds compared?

Here's the results of the runs I just completed on our internal APIs (25 parallel requests at the same time using the script I provided for node and for curl)

Agent http2 time(s) http1.1 time(s)
node 5.37 1.45
curl 1.5 1.37

Also, I was able to get different results even when fetching https://nodejs.org/dist/v17.1.0/node-v17.1.0-x64.msi, but it's not alway consistent.

stanislav-halyn commented 2 months ago

I just ran node profiler for the script I provided fetching our internal API, and the results are weird...

Here's the summary for http2

 [Summary]:
   ticks  total  nonlib   name
     22    4.3%    4.3%  JavaScript
      0    0.0%    0.0%  C++
      5    1.0%    1.0%  GC
      0    0.0%          Shared libraries
    484   95.5%          Unaccounted

and for http1.1

 [Summary]:
   ticks  total  nonlib   name
     29    4.7%    4.7%  JavaScript
      0    0.0%    0.0%  C++
      1    0.2%    0.2%  GC
      0    0.0%          Shared libraries
    588   95.3%          Unaccounted

http2 has less total ticks, but more GC ticks. I wonder if it could be somehow related to GC

mcollina commented 2 months ago

I guess something very odd is happening within http/2. I don't think the problem here is GC - it's 100% true that HTTP/2 consumes more resources than HTTP/1.1 but the difference should be lower.

It seems that curl can progress all HTTP/2 streams in parallel, while we can't, and after a bit it becomes sequential. I wonder if @jasnell has some ideas.

stanislav-halyn commented 2 months ago

@mcollina I did some testing today and found some new insights.

This does not happen for our internal endpoints with little data, those are processed faster with http2.

When fetching a heavy endpoint with lots of data(json with lots of text, most of the text is contained in one particular field), http1.1 seems to be much faster. Besides, when fetching heavy endpoint, http1.1 receives smaller chunks on data event whereas http2 larger ones(~1400 bytes vs ~12000 bytes).

What's interesting: in cases when http1.1 is slower than http2, it receives larger chunks on data event whereas http2 smaller ones.

puskin94 commented 2 months ago

@stanislav-halyn I played with your script a bit and I wasn't able to reproduce the http2 slowness (compared to http1) not even once. Do you have any more updates on the issue? Did you find anything else?

stanislav-halyn commented 2 months ago

@puskin94 I just re-run the tests on our internal APIs, and to my surprise the results are the same now. The results for a 25 parallel requests to a heavy API endpoint used to be: ~1.5s for http1 and ~4-5s for http2. Now the results are: ~4s for both http1 and http2.

I also re-run test for the https://nodejs.org/dist/index.json endpoint, but the results were not consistent, and sometimes http2 was faster, sometimes it was slower.

Here's the script I used:

test.js

```javascript /* eslint-disable */ import http2 from 'node:http2'; import https from 'node:https'; const isHttp2 = process.argv.includes('http2'); const isSilent = process.argv.includes('silent'); const MB = 1024 * 1024; const WINDOW_SIZE = 32 * MB; // let url = new URL('https://nodejs.org/dist/v17.1.0/node-v17.1.0-x64.msi'); let url = new URL('https://nodejs.org/dist/index.json'); const client = http2.connect(url.protocol + url.host, { settings: { initialWindowSize: WINDOW_SIZE, }, rejectUnauthorized: false, }); client.on('connect', () => { client.setLocalWindowSize(WINDOW_SIZE); }); const logger = isSilent ? { log: () => {}, info: console.info, } : { log: console.log, info: console.info, }; const headers = {}; function fetchHttp1(id) { return new Promise((resolve) => { const req = https.request( { rejectUnauthorized: false, host: url.hostname, path: url.pathname + url.search, port: url.port, headers: { connection: 'keep-alive', ...headers, }, }, (res) => { let counter = 0; let bytes = 0; res.on('data', (chunk) => { counter += 1; bytes += Buffer.byteLength(chunk); }); res.on('end', () => { logger.log( `Complete request with id: ${id}, bytes download: ${Math.floor(bytes / counter)} bytes/chunk`, ); resolve(); }); }, ); req.end(); }); } function fetchHttp2(id) { return new Promise((resolve) => { const req = client.request({ ':path': url.pathname + url.search, ...headers, }); let counter = 0; let bytes = 0; req.on('data', (chunk) => { counter += 1; bytes += Buffer.byteLength(chunk); }); req.on('end', () => { logger.log( `Complete request with id: ${id}, bytes download: ${Math.floor(bytes / counter)} bytes/chunk`, ); resolve(); }); req.end(); }); } async function main() { console.log(`process id: ${process.pid}`); console.log(`Starting requests using HTTP${isHttp2 ? '2' : '1.1'} protocol. URL: ${url}`); const startTime = Date.now(); const responses = await Promise.all( Array.from({ length: 25 }) .fill(null) .map((_, index) => { return isHttp2 ? fetchHttp2(index) : fetchHttp1(index); }), ); console.log( `Requests complete. Completion time: ${(Date.now() - startTime) / 1000}s.`, ); process.exit(0); } main(); ```

puskin94 commented 2 months ago

@stanislav-halyn for me http2 it is consistently faster (by a tiny bit ofc, given the test file), and I believe because the bytes/chunk in http2 is 1.5x / 2x the size in http1.

I believe your network was playing a big role when you submitted the issue the first time 😄

stanislav-halyn commented 2 months ago

@puskin94 yeah, you might be right 😄 I just re-run the tests for the https://nodejs.org/dist/index.json endpoint on a different machine with two different network configurations: my home network(~600mbps) and mobile network(~30mbps), and on slower network http2 was consistently faster, whilst on the fast network the results were inconsistent

I do wonder if there can be some kind of TCP packets clogging on http2 in the fast network? Meaning, the packets can come only though one TCP connection and they come so fast, that they are not processed fast enough and get sent to some kind of queue

Maybe that would be the explanation🤔

stanislav-halyn commented 2 months ago

@puskin94 It's really weird because I still can reproduce the issue on one of our internal API endpoints which is quite JSON-heavy with lots of text (384803 bytes).

Here're the results: Agent http2 time(s) http1.1 time(s)
node ~10s ~5s
curl ~5s ~5s
stanislav-halyn commented 2 months ago

@puskin94 but why curl has the same performance on both http1.1 and http2 and only node suffers from bad performance on http2?

I also ran the same test using an http client on Rust and the results where consistent

stanislav-halyn commented 2 months ago

@mcollina @jasnell maybe you could point where I could look into to try to debug poor performance on node http2 client?