vm: memory leak in vm.runInNewContext #6552
Comments
|
Your code never yeilds - it's an infinite blocking busy loop. The garbage collector can never run. Whatever you were doing, you would run out of memory. |
|
Thanks for letting me know. I apologize for submitting code with that problem and not knowing that. I've verified that if we run node with the --expose-gc flag and do a manual global.gc() in the reproduction code it doesn't increase in memory, and the same is true if we do a global.gc() on every request in our service. However, in our service, if we don't do a global.gc(), then the memory is constantly increasing from this vm.runInNewContext call. If I comment it out, I don't get the memory increase. It's possible that our service is also not yielding. I don't actually know how to make node js yield without manually calling the garbage collector. Is there a way to change my reproduction code to make sure it will yield without manually invoking global.gc()? Note: I am seeing the processes occasionally try to garbage collect in our service from the --trace-gc flag after x number of requests, but if I'm not calling global.gc() manually it doesn't seem to reduce the memory that the process is using at all. |
Do something asynchronous (
How high does it go? V8 won't start aggressively collecting garbage unless it's running out of memory or past the high water mark. |
|
Thanks for the quick and I tried putting some async callbacks in there and you are correct that the memory does eventually stabilize, in the case of the sample code at about 400Mb-600Mb. So maybe this problem simply results from my lack of understanding about V8 garbage collection. In the case of our service, we are running one parent process with many child processes. At some point it stops working when garbage collection happens and I've blamed this on a memory leak. If I used only 2 worker processes for the service and let it run, it does garbage collect periodically and the service never stops working completely, but it does take up almost the entire memory of the box. Here is the result of a top command near the end of that testing. You can see that each of the two node workers takes up about 1.3G in memory, and overall they only leave a few Mb of memory free on the box. Then they scavenge it a bit at a time so that they each always have just enough memory to continue. Is this normal behavior?: If it is, then this probably results from something about doing garbage collection with many node processes at once. Perhaps it gets in a similar state to this, with little memory left on the machine, and then several processes try to allocate space and fail, and then something goes wrong with memory collisions or cleanup. I'll continue to try to pinpoint exactly what is going on there. Do you know of anything that might go wrong with garbage collection with many node processes taking load? Mem: 3844596k total, 3774756k used, 69840k free, 124224k buffers PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND Here is one of their garbage collections: Map space, used: 34349 KB, available: 12135 KB, committed: 46484 KB |
|
I now believe this may be an issue with the garbage collector change is Node v10. I ran the code below using node v0.8.5 and node v0.10.22. In v0.8.5 the memory starts at about 35Mb and never increases significantly. Running with --trace-gc shows that it is doing Mark-sweep collections very frequently and successfully collection garbage. Running with v0.10.22 shows the process increasing in memory usage by about 30Mb per second until it the box runs out of memory. Looking at the memory collections, it is doing them much loss frequently and it is mostly doing Scavenge, rarely Mark-sweep. Even when it is doing these it is not collecting much of the memory. This may have been a desired change between these node versions. Is Node now meant to basically take up all the memory on the box until it needs to scavenge some? If not, then this appears to be a garbage collection bug. At least for our use case this causes all the node processes to go into a state that they recover from very slowly when they finally do start scavenging garbage. var vm = require('vm'); var i = 0; setInterval( function() { function createNewVM() { setInterval(function() { |
Not all - the default upper limit on most systems is around 1.6 GB. You can limit it further with --old_max_space_size=n where n is in MB. I see you've already figured it out but to confirm, yes, the garbage collector in v0.10 allocates memory more aggressively. A common complaint about the GC in v0.8 is that it's slow (and it is), that's why the GC in v0.10 trades space for time. |
|
Thanks for clarifying that. Sorry to keep bothering you with this but I have one more test case I ran that I think invalidates that the new garbage collection performance is better specifically if vm.runInNewContext is run. Please take a look at this once more. I wrote the code at the end of this post to try to call vm.runInNewContext 100 times every 5 milliseconds. Then every second I outputted how many of these requests had actually processed and the total execution time, as well as how many requests I had made for this that had not yet been processed. When run with Node v0.10.10, I get the output below. You can see that it is only managing to request 100 of these per interval that it outputs. When you run with --trace-gc the rest seems to go to ineffective garbage collection. requested: 100. stillWaiting: 100. Execution time: 2062 When run with Node v0.8.5, I get the output below. Despite garbage collecting a lot more often, it manages to make many more of these requests. Next, I wanted to make sure this only happened with vm.runInNewContext and not other memory intensive objects. I replace vm.runInNewContext with "theThing" commented out in the code below. When I did this, the new version of node collected garbage more effectively and the two versions run comparably. Finally, I wanted to look at the while(true) loop once more from my original posting for an even simpler test case, to verify that it had been an issue of not releasing to the garbage collector. When I replace vm.runInNewContext in the while true loop with "theThing", as in the code below, garbage collection does happen and works, as in: |
|
Thanks for reopening. If anyone on the Node team could take a look that would be appreciated. |
|
any new info on this? |
|
+1 |
There is a bug in node with vm.runInNewContext: nodejs/node-v0.x-archive#6552 This was used for every script call by deployd, and for example GET scripts are being run for every record returned -> so if you need to return 1000 records, the scripts would run 1000 times resulting in big memory leaks. With this change, even 15000 executions of a script take now just 300 ms on my machine and use virtually no extra memory, compared to huge memory leaks and over several minutes with the old code.
|
+1 Note that this also occurs with
Some code exhibiting the problem: https://gist.github.com/billywhizz/813257 (tested on node 0.10.26) |
There is a bug in node with vm.runInNewContext: nodejs/node-v0.x-archive#6552 This was used for every script call by deployd, and for example GET scripts are being run for every record returned -> so if you need to return 1000 records, the scripts would run 1000 times resulting in big memory leaks. With this change, even 15000 executions of a script take now just 300 ms on my machine and use virtually no extra memory, compared to huge memory leaks and over several minutes with the old code. Minor refactoring Remove unneceesary try/catch and add another test. Refactor to remove dependency on 'vm'.
There is a bug in node with vm.runInNewContext: nodejs/node-v0.x-archive#6552 This was used for every script call by deployd, and for example GET scripts are being run for every record returned -> so if you need to return 1000 records, the scripts would run 1000 times resulting in big memory leaks. With this change, even 15000 executions of a script take now just 300 ms on my machine and use virtually no extra memory, compared to huge memory leaks and over several minutes with the old code. Minor refactoring Remove unneceesary try/catch and add another test. Refactor to remove dependency on 'vm'.
|
+1 for the issue. The solution for deployd does not work for me because I am executing a script that is assigning a global variable and then is not using this to reference it: this.newValue = 'value';
// fails with newValue is not defined
console.log(newValue); |
|
My problem is that I am executing a client-side JavaScript code using runInContext which is leaking about 1 MB every time i call runInContext. I am creating browser variables like window and document in the context. I am not aware of another solution which could run the code in a context where window and document could be available in the global context and in the same time the Node.js global scope to not be accessible. function executeCode(browserEnv, html, code) {
var context = vm.createContext(browserEnv.getObject());
var script = vm.createScript(code);
extend(context, {
server: {
html: html,
data: {},
rendered: '',
applications: []
}
});
script.runInContext(context);
return context.server.rendered;
}Tell me if you need more information on the problem. |
|
@astoilkov Sorry, I got confused about what issue this project is in. :) If this is a blocking bug for you and you can use io.js instead of node, it should have this fixed, see here: https://github.com/iojs/io.js/blob/v1.x/CHANGELOG.md#vm |
|
@joyent/node-coreteam ... looks like a fix may have gone into io.js. We may want to investigate further and backport |
|
This is still a problem with Node 4 and 5. Any updates? |
|
Here is a test script: var vm = require("vm");
function run(index) {
var context = vm.createContext();
vm.runInContext("1+1", context);
console.log("run " + index + ":", process.memoryUsage().heapTotal);
}
for (var i = 0; i < 20; i++) {
run(i);
} |
|
Sorry, just realized this project was archived. I'll look in the new project. |
|
Is this issue the same as nodejs/node#3113 + nodejs/node#1741? |
Notable changes * buffer: safeguard against accidental kNoZeroFill (Сковорода Никита Андреевич) [nodejs/node-private#35](https://github.com/nodejs/node-private/pull/35) * deps: upgrade openssl sources to 1.0.2h (Shigeki Ohtsu) [nodejs#6552](nodejs/node#6552)
Notable changes * buffer: safeguard against accidental kNoZeroFill (Сковорода Никита Андреевич) [nodejs/node-private#35](https://github.com/nodejs/node-private/pull/35) * deps: upgrade openssl sources to 1.0.2h (Shigeki Ohtsu) [nodejs#6552](nodejs/node#6552)
There is a memory leak in vm.runInNewContext. If you call it in a loop your machine will quickly run out of memory. It can be reproduced with the code below. Run with "node --trace-gc"--trace-gc-verbose to see garbage collection start to have problems. Running a few processes with the code below will likely cause your box to stop working when it runs out of memory. Use "top" in another console to see the memory usage quickly go up.
We have a use case where we want to use vm.runInNewContext on each request to a web service, so we quickly run out of memory and the service stops working under load.
We are running node v0.10.18.
The text was updated successfully, but these errors were encountered: