runInNewContext leaks memory in v0.12.0

[alexpenev-s]

Memory allocated in script ran under a new context is not freed properly, even as the process runs out of memory and GC becomes aggressive.

In v0.12.0 the application runs out of memory and is stopped by the OS.
In v0.10.36 memory levels off and the issue cannot be reproduced.

I noticed that in node_contextify.cc the function WeakCallback is only called once with
kind == kSandbox consequently the context is never deleted.

To reproduce - run:
node --expose-gc --trace-gc --max_old_space_size=150 index.js

index.js

var fs = require('fs');
var vm = require('vm');
var exp = require('express');

var app = exp();
var script = new vm.Script(fs.readFileSync("t.js2", 'utf8'));

app.get('/', function(req, res) {
  script.runInNewContext();

  global.gc();
  console.log(process.memoryUsage());
  res.send("Hi");
});

app.listen(4000, function() {
  console.log("Running " + this.address().address + " port " + this.address().port);
})

t.js2

var o = {};
function makeid()
{
  var text = "";
  var possible = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789";

  for( var i=0; i < 100; i++ )
      text += possible.charAt(Math.floor(Math.random() * possible.length));

  return text;
}
for(i=0;i<1000;i++)
{
  o["p_" +i] = makeid();
}

[alexpenev-s]

v0.10.36

v0.12.0

[trevnorris]

I've condensed it down to a single script:

var vm = require('vm');
var src = vmScript.toString().substr(22);
var script = new vm.Script(src.substr(0, src.length - 2));
var iter = 1e3;

(function runThis() {
  script.runInNewContext();
  global.gc();
  if (0 < --iter)
    setImmediate(runThis);
}());


function vmScript() {
  var o = {};
  var pos = 'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789';

  function makeid() {
    var text = '';
    for (var i=0; i < 100; i++)
        text += pos.charAt(Math.floor(Math.random() * pos.length));
    return text;
  }

  for (i = 0; i < 1000; i++)
    o["p_" +i] = makeid();
}

And have confirmed it's an issue. Investigating more.

[trevnorris]

This is working in io.js, and I bisected the fix back to the upgrade to V8 3.31.74.1. So I'm not sure if this is a V8 issue, or a Node issue. Will continue to investigate.

[tjfontaine]

my simplified version looked like:

var vm = require('vm');

var text = "var o = {};";
text += "function makeid() { var text = ''; var possible = 'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789';";
text += "for( var i=0; i < 100; i++ ) text += possible.charAt(Math.floor(Math.random() * possible.length)); return text; }";
//text += " for(i=0;i<1000;i++) o['p_' +i] = makeid();";

var script = new vm.Script(text);

setInterval(function runScript() {
  script.runInNewContext();
  gc();
}, 10);

doing that I watched the ContextifyContext grow, and have a references_ count of 2, as @saperal pointed out, only the sandbox was being cleaned up.

@trevnorris the bisect probably comes down to a Persistents API change, my interpretation of the problem is we're calling ClearWeak instead of Reset and thus not releasing the hidden reference to the context and thus the global.

@saperal could you try applying https://gist.github.com/tjfontaine/5b59ce6c4a0493ed2248 and see if it fixes your problem?

[tjfontaine]

of course this also breaks other things -- so YMMV :)

[trevnorris]

@tjfontaine While I also see that it fixes the memory problem, also consider:

  ~ContextifyContext() {
    context_.Reset();
    proxy_global_.Reset();
    sandbox_.Reset();
  }

[trevnorris]

The real fix, and break, comes at context->sandbox_.Reset(). We need to determine when a sandbox is done being used so it can be reset. This value doesn't match up with context->references_.

[tjfontaine]

Ya, I was going through the same thoughts here at work -- basically it feels like there's an overcomplicated nature of how many references we really need to hold on to -- I feel like we should only have to take care of maintaining a weak reference to the v8 context, and it should be responsible for the references to the sandbox and proxy global. I am working to verify that hypothesis now.

[alexpenev-s]

The patch works for the sample app, but breaks other scenarios. Here is a seg fault trace:

#0  operator* (this=0x7ffff7fb4f00) at ../deps/v8/src/handles-inl.h:44
#1  operator-> (this=<optimized out>) at ../deps/v8/src/handles.h:105
#2  v8::Object::GetRealNamedProperty (this=0x0, key=...) at ../deps/v8/src/api.cc:3597
#3  0x0000000001087442 in node::ContextifyContext::GlobalPropertyGetterCallback (property=..., args=...) at ../src/node_contextify.cc:372
#4  0x0000000000a5b91b in v8::internal::PropertyCallbackArguments::Call (this=0x7ffff7fb51f0, f=0x108732a <node::ContextifyContext::GlobalPropertyGetterCallback(v8::Local<v8::String>, v8::PropertyCallbackInfo<v8::Value> const&)>, arg1=...) at ../deps/v8/src/arguments.cc:87
#5  0x0000000000e2b0a6 in v8::internal::JSObject::GetPropertyWithInterceptor (holder=..., receiver=..., name=...) at ../deps/v8/src/objects.cc:13619
#6  0x0000000000dd610a in v8::internal::Object::GetProperty (it=0x7ffff7fb55b0) at ../deps/v8/src/objects.cc:142
#7  0x0000000000f618ae in __RT_impl_LoadPropertyWithInterceptor (isolate=0x1870190, args=...) at ../deps/v8/src/stub-cache.cc:604
#8  v8::internal::LoadPropertyWithInterceptor (args_length=4, args_object=0x7ffff7fb5760, isolate=0x1870190) at ../deps/v8/src/stub-cache.cc:592


362│   static void GlobalPropertyGetterCallback(
363│       Local<String> property,
364│       const PropertyCallbackInfo<Value>& args) {
365│     Isolate* isolate = args.GetIsolate();
366│     HandleScope scope(isolate);
367│
368│     ContextifyContext* ctx =
369│         Unwrap<ContextifyContext>(args.Data().As<Object>());
370│
371│     Local<Object> sandbox = PersistentToLocal(isolate, ctx->sandbox_);
372├>    Local<Value> rv = sandbox->GetRealNamedProperty(property);


(gdb) p sandbox
$6 = {<v8::Handle<v8::Object>> = {val_ = 0x0}, <No data fields>}

[jasnell]

@trevnorris ... any further thoughts on this one?

[trevnorris]

@jasnell Will have to ask @domenic about this one. He's done a lot of work on the vm module since then, but has been for a later V8 b/c it had the fixes necessary.

[jasnell]

Looks like this may be a duplicate of #6552, which does appear to have been resolved in io.js, we'd just need to decide if it's worth trying to do a backport.