Large memory leak caused by context.js's domains

[STRML]

This regression was introduced in ca0208d.

I am documenting as I go - this was causing large memory usage in my application that would eventually cause it to crash.

An example of its memory usage (I updated from loopback 2.8.4 to latest on Feb 1):

To replicate this, clone loopback-example-app and run:

ab -n 1000 -c 10 "http://127.0.0.1:3000/api/cars"

Simple as that. It appears that the domain is not properly being torn down after the request has ended.

Here's a few snapshots of some heapdumps:

Here's the retainers (coming back to currentDomain). Note that this is a comparison between Snapshot 5 and Snapshot 6, so the listed items are those retained between the snapshots. All I did was run a thousand hits via ab.

[STRML]

Using the following memwatch code in the example app:

memwatch.on('leak', function(info) { 
  console.log('leak');
  console.dir(info);
});

I ran the server and hit it with ab. Results after 10000 hits:

10 Feb 08:15:55 - [nodemon] starting `node --debug server/server.js`
debugger listening on port 5858
Using the memory connector.
To specify another connector:
  `DB=oracle node .` or `DB=oracle slc run .`
  `DB=mongodb node .` or `DB=mongodb slc run .`
  `DB=mysql node .` or `DB=mysql slc run .`
Started the import of sample data.
Browse your REST API at http://localhost:3000/explorer
Web server listening at: http://localhost:3000/
Sample data was imported.
leak
{ start: Tue Feb 10 2015 08:15:57 GMT+0700 (ICT),
  end: Tue Feb 10 2015 08:16:15 GMT+0700 (ICT),
  growth: 12421744,
  reason: 'heap growth over 5 consecutive GCs (18s) - -2147483648 bytes/hr' }
leak
{ start: Tue Feb 10 2015 08:16:17 GMT+0700 (ICT),
  end: Tue Feb 10 2015 08:16:26 GMT+0700 (ICT),
  growth: 5742344,
  reason: 'heap growth over 5 consecutive GCs (9s) - -2147483648 bytes/hr' }
leak
{ start: Tue Feb 10 2015 08:16:29 GMT+0700 (ICT),
  end: Tue Feb 10 2015 08:16:41 GMT+0700 (ICT),
  growth: 6717752,
  reason: 'heap growth over 5 consecutive GCs (12s) - 1921.96 mb/hr' }
leak
{ start: Tue Feb 10 2015 08:16:45 GMT+0700 (ICT),
  end: Tue Feb 10 2015 08:17:04 GMT+0700 (ICT),
  growth: 10054544,
  reason: 'heap growth over 5 consecutive GCs (19s) - 1816.82 mb/hr' }
leak
{ start: Tue Feb 10 2015 08:17:09 GMT+0700 (ICT),
  end: Tue Feb 10 2015 08:17:30 GMT+0700 (ICT),
  growth: 11983664,
  reason: 'heap growth over 5 consecutive GCs (21s) - 1959.17 mb/hr' }
leak
{ start: Tue Feb 10 2015 08:17:36 GMT+0700 (ICT),
  end: Tue Feb 10 2015 08:18:01 GMT+0700 (ICT),
  growth: 15221160,
  reason: 'heap growth over 5 consecutive GCs (25s) - -2147483648 bytes/hr' }
leak
{ start: Tue Feb 10 2015 08:18:08 GMT+0700 (ICT),
  end: Tue Feb 10 2015 08:18:41 GMT+0700 (ICT),
  growth: 18587128,
  reason: 'heap growth over 5 consecutive GCs (33s) - 1933.75 mb/hr' }
leak
{ start: Tue Feb 10 2015 08:18:50 GMT+0700 (ICT),
  end: Tue Feb 10 2015 08:19:31 GMT+0700 (ICT),
  growth: 24078992,
  reason: 'heap growth over 5 consecutive GCs (41s) - 2016.31 mb/hr' }
leak
{ start: Tue Feb 10 2015 08:19:43 GMT+0700 (ICT),
  end: Tue Feb 10 2015 08:20:34 GMT+0700 (ICT),
  growth: 29199392,
  reason: 'heap growth over 5 consecutive GCs (51s) - 1965.65 mb/hr' }

Stats from ab:

~/g/f/l/server (master|✚1) $ ab -n 10000 -c 10 "http://127.0.0.1:3000/api/cars"
This is ApacheBench, Version 2.3 <$Revision: 1554214 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 1000 requests
Completed 2000 requests
Completed 3000 requests
Completed 4000 requests
Completed 5000 requests
Completed 6000 requests
Completed 7000 requests
Completed 8000 requests
Completed 9000 requests
Completed 10000 requests
Finished 10000 requests


Server Software:
Server Hostname:        127.0.0.1
Server Port:            3000

Document Path:          /api/cars
Document Length:        204962 bytes

Concurrency Level:      10
Time taken for tests:   299.940 seconds
Complete requests:      10000
Failed requests:        0
Total transferred:      2052380000 bytes
HTML transferred:       2049620000 bytes
Requests per second:    33.34 [#/sec] (mean)
Time per request:       299.940 [ms] (mean)
Time per request:       29.994 [ms] (mean, across all concurrent requests)
Transfer rate:          6682.27 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       1
Processing:    66  299  26.2    295     494
Waiting:       65  299  26.2    295     494
Total:         67  300  26.2    295     494

Percentage of the requests served within a certain time (ms)
  50%    295
  66%    300
  75%    304
  80%    307
  90%    319
  95%    347
  98%    397
  99%    421
 100%    494 (longest request)

Funnily enough, heap growth is actually so fast that it overflows in memwatch's calculations.