Sails: Memory leak

[berge616]

Sails version:1.0.0-12
Node version:8.9.3
NPM version:5.5.1
DB adapter name: sails-mysql
DB adapter version: 1.0.0-15
Operating system:na

---

https://github.com/node-machine/machine/issues/46

--Copied below:

There is a memory leak in this module when called through sails-mysql. The above image shows the memory leak on a system with 768mb ram. The ECS container gets kicked when it reaches its max so that's why the sawtooth. This is a low use system so this memory leak is quite significant. Reproduced locally with a fresh sails project and took heap snapshots before any calls and then after running many calls through the api. Compared these heaps in chromes profiling and found an alarming number of debug closures being left in memory(both snapshots were taken immediately after forcing a garbage collection)

This is easily reproducible by installing sails v1 and connecting it to a mysql db with some basic routes to add a record to the db.

Here is the code i used to get heap size and generate the snapshots:
```
npm install heapdump
const heapdump = require('heapdump');

generateHeapDumpAndStats: function(req, res){
//1. Force garbage collection every time this function is called
try {
global.gc();
} catch (e) {
console.log("You must run program with 'node --expose-gc index.js' or 'npm start'");
process.exit();
}

//2. Output Heap stats
var heapUsed = process.memoryUsage().heapUsed;
console.log("Program is using " + heapUsed + " bytes of Heap.")
res.status(200).json({heapUsed:heapUsed/1042/1024});

//3. Get Heap dump
//process.kill(process.pid, 'SIGUSR2');
heapdump.writeSnapshot();
}

These lines seem to be the culprit:

https://github.com/node-machine/machine/blob/13.0/lib/private/intercept-exit-callbacks.js#L260-L261
https://github.com/node-machine/machine/blob/13.0/lib/private/help-exec-machine-instance.js#L108-L110

I'm using the following versions:

"sails": "^1.0.0-42",
"sails-disk": "^1.0.0-12",
"sails-hook-custom-blueprints": "^1.0.0",
"sails-hook-grunt": "^3.0.0",
"sails-hook-orm": "^2.0.0-22",
"sails-mysql": "^1.0.0-15",

```

[sailsbot]

Hi @berge616! It looks like you missed a step or two when you created your issue. Please edit your comment (use the pencil icon at the top-right corner of the comment box) and fix the following:

• Provide your Sails version
• Provide your Node version
• Provide your NPM version
• Provide your Operating system

As soon as those items are rectified, post a new comment (e.g. “Ok, fixed!”) below and we'll take a look. Thanks!

*If you feel this message is in error, or you want to debate the merits of my existence (sniffle), please contact [email protected]

[berge616]

fixed

[sailsbot]

@berge616 Thanks for posting, we'll take a look as soon as possible.

---

For help with questions about Sails, click here. If you’re interested in hiring @sailsbot and her minions in Austin, click here.

[sgress454]

Original thread from Gitter: https://gitter.im/balderdashy/sails?at=5a32e1a1a2be466828a140c6

Kyle will try commenting out those debugs and seeing if it fixes the issue...

[berge616]

Commented out those debug lines along with similiar ones in identically named files from machinepack-mysql and the leak is fixed. Confirmed by observing dumps after removal of Debug lines

[sgress454]

Thanks @berge616!

[sgress454]

@mikermcneil posted to Trello as https://trello.com/c/IzkNTeO7/404-machine-runner-memory-leak

[mikermcneil]

@berge616 @sgress454 thanks! And @sgress454 that plan in Trello sounds good, though in the latest runner, we're not actually using the debug package, so it won't affect us there.

@berge616 For the mp-mysql stuff, assuming this is about the query logs, just to make sure: Were you using NODE_ENV=production when you tested this? I took a look at potential issues from debug but didn't find anything particularly telling. We definitely want to keep query logging though, so worst case we can just add an if (process.env.DEBUG) {…} check around the relevant calls to debug(). That should isolate the problem so that it only temporarily affects apps while native query logging is enabled. (That said, if we've isolated it to that point, we might as well try updating debug and, if this hasn't been fixed there yet, try to do a patch in that package)

[sgress454]

@mikermcneil These are debug calls inside of machine runner (see line numbers in original post), and they're made regardless of environment (they just don't actually output anything if you don't set the DEBUG env var). So the issue seems to be that a new debug instance is made on every run, where typically we just create a single instance when we first require debug. I think it's done that way so that the debugs can be namespaced to the specific machine that's running. They should get cleaned up anyway, but at least in @berge616's test they seem to linger indefinitely. If he comments out those lines, the memory issue goes away.

[sgress454]

For the sake of clarity, contrast the use of debug in https://github.com/node-machine/machine/blob/13.0/lib/private/intercept-exit-callbacks.js#L260-L261 with how it's used in Skipper, here: https://github.com/balderdashy/skipper/blob/bcf5451ca9d6f1f8763425ac5962531b719116b7/standalone/Upstream/prototype._read.js

[berge616]

@mikermcneil yes this is with the env set to production. They for sure linger forever. Spin up a new sails project with mysql db and hit it with a load test. You'll see the memory grow indefinitely even with GC running. Each debug stmt takes up ~300 bytes and with each api call calling the db a handful of times, this adds up pretty quick.

[mikermcneil]

@berge616 @sgress454 just pushed up experimental upgrades to mp-mysql and sails-mysql in https://github.com/balderdashy/sails-mysql/commit/075d7590dfb5fc51ee7c3084df87261b46ea5356 and https://github.com/sailshq/machinepack-mysql/commit/d9d31aa1bec80d83e9b5b2383376740e68f9bc5e

To test:

• from inside mp-mysql, run git pull && rm -rf node_modules && rm package-lock.json && npm install && npm link
• from inside sails-mysql, run git pull && rm -rf node_modules && rm package-lock.json && npm install && npm link && npm link machinepack-mysql
• from inside a test Sails app, run rm -rf node_modules && rm package-lock.json && npm link sails-mysql
• then try it out (should be no leaks)

[berge616]

@mikermcneil are there any breaking changes for this newer version? I'm getting this error when I try it out:

{ UsageError: Sorry, `.exec()` doesn't know how to handle {...} callbacks.
Please provide a callback function when calling .exec().
|  If you passed in {...} on purpose as a "switchback" (dictionary of callbacks),
|  then try calling .switch() intead of .exec().
 [?] See https://sailsjs.com/support for more help.

[mikermcneil]

@berge616 there are! Thanks for pointing that out-- I should have caught it. Pushed https://github.com/sailshq/machinepack-mysql/commit/8660bf049fb40b8b3dc88ae05461102cbcccfc46 and https://github.com/balderdashy/sails-mysql/commit/5e8ed7e295385c25fb7ed5c23314e25313a3248b

Caveat: I thought I'd nabbed them all the first time when I took care of example->outputExample, etc, but I haven't had time to go much past quickly running a couple of tests yet, so it'd be great to hear if you see any other compatibility issues trying it out in practice with the repos linked

[berge616]

@mikermcneil Thanks for fixing that. The debug() memory leak is gone! I ran through all my tests and everything looks good. Any timeline for getting this released?

[mikermcneil]

@berge616 awesome! Thanks for checking. It'll technically be a breaking change to mp-mysql, so I went ahead and published 3.0.0 of that. I'll try pointing sails-mysql at it to make sure all the tests pass. Assuming that looks good, ready whenever

[mikermcneil]

https://travis-ci.org/balderdashy/sails-mysql/builds/319325186

[mikermcneil]

LGTM - published [email protected] (please give that a shot and let me know if you run into any issues!)

[berge616]

Everything looks good to me!

[itomas]

After 1.0.0-16 sendNativeQuery is not working. https://next.sailsjs.com/documentation/reference/waterline-orm/datastores/send-native-query

Promise never resolves.

[max918]

Hi, i am also focusing on this memory leak issue.
After update to [email protected], the transaction method not work.
I just created empty template sails and testing controller endpoint like this:

transaction: function(req, res) {
sails.log.debug('start');
sails.getDatastore().transaction(function(db, proceed) {
return proceed();
}).exec(function(err) {
sails.log.debug('end');
return res.ok();
})
}

on [email protected], it print "start" and "end" correctly.
but on [email protected], it only print "start"

[wulfsolter]

FWIW, this is affecting sails-postgresql as well, commenting out
https://github.com/node-machine/machine/blob/13.0/lib/private/intercept-exit-callbacks.js#L260-L261
https://github.com/node-machine/machine/blob/13.0/lib/private/help-exec-machine-instance.js#L108-L110

is working for me :) Thanks @berge616 !

[bartbar]

I can confirm that .sendNativeQuery does not work anymore with [email protected].

[billyshena]

@wulfsolter Is this fixed with sails-postgresql ?

[wulfsolter]

I'm running

"sails": "^1.0.0-42", "sails-hook-grunt": "^3.0.2", "sails-hook-orm": "^2.0.0-22", "sails-postgresql": "^1.0.0-12",

in production, and the problem of loose instances of Debug not getting garbage collected is fixed.

[mikermcneil]

@bartbar this should be fixed as of https://github.com/balderdashy/sails-mysql/releases/tag/v1.0.0-17

[sgress454]

🎉 Closing now that v1.0 is officially released.