Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

High memory usage for upgraded http requests #11868

Closed
lpinca opened this issue Mar 15, 2017 · 9 comments

Comments

@lpinca
Copy link
Member

commented Mar 15, 2017

  • Version:
    v7.7.3
  • Platform:
    macOS/Linux
  • Subsystem:
    net/http

I noticed that n socket connections obtained with the HTTP upgrade mechanism use a lot more memory than n socket connections obtained with a plain net server. Consider for example the following test.

net server
'use strict';

const net = require('net');

const headers = [
  'HTTP/1.1 101 Switching Protocols',
  'Connection: Upgrade',
  'Upgrade: foo',
  '',
  ''
].join('\r\n');

let count = 0;
const handler = (socket) => {
  socket.resume();
  socket.write(headers);

  if (++count === 150000) {
    gc();
    const rss = process.memoryUsage().rss;
    console.log(rss / 1024 / 1024);
  }
};

const server = net.createServer({ allowHalfOpen: true });

server.on('connection', handler);
server.listen(3000, () => console.log('listening on *:3000'));
net client
'use strict';

const net = require('net');

const headers = [
  'GET / HTTP/1.1',
  'Connection: Upgrade',
  'Upgrade: foo',
  'Host: localhost:3000',
  '',
  ''
].join('\r\n');

let i = 0;
(function createClient() {
  const socket = net.connect({
    localAddress: `127.0.0.${i % 100 + 1}`,
    port: 3000
  });

  socket.on('connect', () => {
    socket.resume();
    socket.write(headers);

    if (++i === 150000) return;

    createClient();
  });
})();
http server
'use strict';

const http = require('http');

const headers = [
  'HTTP/1.1 101 Switching Protocols',
  'Connection: Upgrade',
  'Upgrade: foo',
  '',
  ''
].join('\r\n');

let count = 0;
const handler = (req, socket, head) => {
  socket.resume();
  socket.write(headers);

  if (++count === 150000) {
    gc();
    const rss = process.memoryUsage().rss;
    console.log(rss / 1024 / 1024);
  }
};

const server = http.createServer();

server.setTimeout(0);
server.on('upgrade', handler);
server.listen(3000, () => console.log('listening on *:3000'));
http client
'use strict';

const http = require('http');

let i = 0;
(function createClient() {
  const req = http.get({
    localAddress: `127.0.0.${i % 100 + 1}`,
    port: 3000,
    headers: {
      'Connection': 'Upgrade',
      'Upgrade': 'foo'
    }
  });

  req.on('upgrade', (res, socket, head) => {
    socket.resume();

    if (++i === 150000) return;

    createClient();
  });
})();

The first (net) server uses ~295 MiB of memory while the second (http) ~525 MiB. Shouldn't they use more or less the same amount of memory?

It seems that, in part, the difference is caused by the additional event listeners. If I add

socket.removeAllListeners('drain');
socket.removeAllListeners('error');
socket.removeAllListeners('timeout');

in the upgrade event handler, memory usage drops to ~420 MiB.

@lpinca lpinca added the http label Mar 15, 2017
@lpinca

This comment has been minimized.

Copy link
Member Author

commented Mar 19, 2017

After digging a little more, I noticed that memory usage drops to ~275 MiB if all listeners are removed from the socket.

This made me think that it must be something to do with the default net.Socket event listeners:

I tried to remove and readd them to the socket in the upgrade listener.

const end = socket.listeners('end')[0];
const _socketEnd = socket.listeners('_socketEnd')[0];
const finish = socket.listeners('finish')[0];

socket.removeAllListeners('end');
socket.removeAllListeners('_socketEnd');
socket.removeAllListeners('finish');

socket.once('end', end);
socket.on('_socketEnd', _socketEnd);
socket.on('finish', finish);

and with my big surprise memory usage is now ~300 MiB (the same amount used by the plain net server).

To summarize, in order to make the n socket connections obtained with the HTTP upgrade mechanism use a the same memory of n socket connections obtained with a plain net server, I have to:

  1. Remove the additional event listeners added in the HTTP server (timeout, error, drain). This makes sense.
  2. Backup, remove and readd the default net.Socket event listeners. This doesn't make sense to me.

Does anyone know and care to explain why this happens?

@lpinca lpinca referenced this issue Mar 20, 2017
2 of 2 tasks complete
lpinca added a commit to lpinca/node that referenced this issue Mar 22, 2017
Prevent the events listeners of the sockets obtained with the HTTP
upgrade mechanism from retaining unneeded memory.

Refs: nodejs#11868
jasnell added a commit that referenced this issue Mar 22, 2017
Prevent the events listeners of the sockets obtained with the HTTP
upgrade mechanism from retaining unneeded memory.

Ref: #11868
PR-URL: #11926
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
@lpinca lpinca added the memory label Mar 25, 2017
@lpinca

This comment has been minimized.

Copy link
Member Author

commented Mar 25, 2017

A small update here after #11926 which partially fixed this.

It seems that the additional, remaining, memory is retained by instances of EventHandlers.
Consider the following example which only uses instances of EventEmitter.

'use strict';

const EE = require('events');

const _socketEnd = () => {};
const end = () => {};
const finish = () => {};

const ondrain = () => {};
const socketOnClose = () => {};
const socketOnData = () => {};
const socketOnDrain = () => {};
const socketOnEnd = () => {};
const socketOnError = () => {};
const socketOnPause = () => {};
const socketOnResume = () => {};
const socketOnTimeout = () => {};

const arr = [];
for (var i = 0; i < 1000000; i ++) {
  const ee = new EE();

  ee.on('_socketEnd', _socketEnd);
  ee.on('finish', finish);
  ee.once('end', end);
  ee.on('error', socketOnError);
  ee.on('timeout', socketOnTimeout);

  arr.push(ee);
}

setInterval(() => {
  const l = arr.length;
  gc();
  console.log(process.memoryUsage().rss / 1024 / 2014);
}, 30000);

It produces the following results.

$ node -v
v7.7.4
$ node --expose-gc a.js 
127.63455809334657
127.82125124131082
127.89076464746772
127.90863952333665

If I add and remove the additional listeners like it is done in _http_server.js:

$ diff -u a.js b.js 
--- a.js	2017-03-25 16:01:39.000000000 +0100
+++ b.js	2017-03-25 15:34:34.000000000 +0100
@@ -20,12 +20,32 @@
 for (var i = 0; i < 1000000; i ++) {
   const ee = new EE();
 
+  // Default socket events listeners.
   ee.on('_socketEnd', _socketEnd);
   ee.on('finish', finish);
   ee.once('end', end);
+
+  // Listeners added in _http_server.js
   ee.on('error', socketOnError);
   ee.on('timeout', socketOnTimeout);
 
+  // Listeners added and removed in _http_server.js
+  ee.on('close', socketOnClose);
+  ee.on('data', socketOnData);
+  ee.on('drain', ondrain);
+  ee.on('drain', socketOnDrain);
+  ee.on('end', socketOnEnd);
+  ee.on('pause', socketOnPause);
+  ee.on('resume', socketOnResume);
+
+  ee.removeListener('close', socketOnClose);
+  ee.removeListener('data', socketOnData);
+  ee.removeListener('drain', ondrain);
+  ee.removeListener('drain', socketOnDrain);
+  ee.removeListener('end', socketOnEnd);
+  ee.removeListener('pause', socketOnPause);
+  ee.removeListener('resume', socketOnResume);
+
   arr.push(ee);
 }

I get

$ node -v
v7.7.4
$ node --expose-gc b.js 
561.4955312810328
561.9324726911618
562.0238331678253
562.051638530288

With #11930 results are more in line with the expected behavior.

$ node -v
v8.0.0-pre
$ node --expose-gc a.js 
355.98808341608736
346.6454816285998
345.3028798411122
345.2154915590864
^C
$ node -v
v8.0.0-pre
$ node --expose-gc b.js 
387.759682224429
389.708043694141
379.2850049652433
378.1708043694141
@lpinca lpinca referenced this issue Mar 26, 2017
2 of 2 tasks complete
@mscdex

This comment has been minimized.

Copy link
Contributor

commented Mar 26, 2017

@lpinca Did you run those scripts with the various versions of V8 in master? It would be interesting to test master with/without #11930 with each V8: 5.5 (same as v7), 5.6, and recently merged 5.7. This might help narrow down if this was due to some other change in node, due to V8 upgrade, or due to Object.create(null) itself.

@lpinca

This comment has been minimized.

Copy link
Member Author

commented Mar 26, 2017

Gonna try with more combinations and post back. It will take some time as compiling takes ages.

@lpinca

This comment has been minimized.

Copy link
Member Author

commented Mar 26, 2017

$ ./node-master@9ac363b_5.7_+11930 --expose-gc a.js
347.6683217477656
347.8391261171797
347.38828202581925
349.48560079443894

$ ./node-master@9ac363b_5.7_+11930 --expose-gc b.js
382.33366434955315
382.90963257199604
379.36444885799403
379.3426017874876

$ ./node-master@9ac363b_5.7_-11930 --expose-gc a.js
121.93843098311817
122.1966236345581
121.74577954319761
121.60476663356505

$ ./node-master@9ac363b_5.7_-11930 --expose-gc b.js
552.5898709036743
552.9513406156901
551.5829195630586
551.5431976166832

$ ./node-master@e0bc5a7_5.6_+11930 --expose-gc a.js
346.8599801390268
347.36246276067527
345.68023833167825
345.6524329692155

$ ./node-master@e0bc5a7_5.6_+11930 --expose-gc b.js
381.4975173783515
382.04170804369414
378.14299900695136
377.97815292949355

$ ./node-master@e0bc5a7_5.6_-11930 --expose-gc a.js
121.15392254220457
121.92055610724925
120.99304865938431
120.95928500496524

$ ./node-master@e0bc5a7_5.6_-11930 --expose-gc b.js
554.5620655412115
555.1062562065541
551.7378351539226
551.578947368421

$ ./node-v7.7.4+11930 --expose-gc a.js
130.5700099304866
131.23733862959284
129.02879841112215
128.95729890764648

$ ./node-v7.7.4+11930 --expose-gc b.js
555.0625620655412
555.6981132075472
552.1966236345581
552.1251241310824

$ ./node-v7.7.4-11930 --expose-gc a.js
119.14597815292949
119.46573982125125
118.95729890764648
118.96921549155908

$ ./node-v7.7.4-11930 --expose-gc b.js
553.811320754717
554.5719960278053
551.9443892750745
551.9602780536246

$ ./node-v7.5.0+11930 --expose-gc a.js
132.76663356504469
133.54319761668322
129.33267130089374
129.2651439920556

$ ./node-v7.5.0+11930 --expose-gc b.js
550.4270109235352
550.6276067527309
550.1767626613704
550.1231380337637

$ ./node-v7.5.0-11930 --expose-gc a.js
122.38927507447865
122.91161866931479
120.1449851042701
120.06752730883814

$ ./node-v7.5.0-11930 --expose-gc b.js
553.837140019861
554.720953326713
550.5124131082423
550.4389275074478

With V8 5.4 and 5.5 there is no difference. Something changed in 5.6.

@mscdex

This comment has been minimized.

Copy link
Contributor

commented Mar 26, 2017

I'm wondering if 5.6 is when the Object.create(null) pattern changed to producing dictionary mode objects.

@lpinca

This comment has been minimized.

Copy link
Member Author

commented Mar 26, 2017

@mscdex

This comment has been minimized.

Copy link
Contributor

commented Mar 26, 2017

@lpinca It appears it was first available in 5.6.144 (see the github mirror).

Additionally, you can check the output of

var obj = Object.create(null);
console.log(%HasFastProperties(obj));

with the --allow-natives-syntax command line flag. It should show 'false' if the commit exists in the V8 release.

lpinca added a commit to lpinca/node that referenced this issue Mar 29, 2017
Prevent the events listeners of the sockets obtained with the HTTP
upgrade mechanism from retaining unneeded memory.

Ref: nodejs#11868
PR-URL: nodejs#11926
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
@lpinca lpinca referenced this issue Apr 4, 2017
3 of 3 tasks complete
@lpinca

This comment has been minimized.

Copy link
Member Author

commented Apr 6, 2017

Closing as everything has been addressed here.

@lpinca lpinca closed this Apr 6, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants
You can’t perform that action at this time.