VM.runInThisContext filename param not in stack trace, docs say it should be

[itaylor]

From the vm docs:

vm.runInThisContext() compiles code, runs it and returns the result. Running code does not have access to local scope.
filename is optional, it's used only in stack traces.

but when you run a script that has invalid js that causes a syntax error...

var myFileName = "/path/to/some/file.js";
require("vm").runInThisContext('invalidJsHere ?= 1;', myFileName);

The output has no filename in it.
Here's sample output:

/Users/itaylor/temp/test.js:2
usingscript = vm.runInThisContext('localVar ?= 1;',
                 ^
SyntaxError: Unexpected token =
    at Object.<anonymous> (/Users/itaylor/temp/test.js:2:18)
    at Module._compile (module.js:446:26)
    at Object..js (module.js:464:10)
    at Module.load (module.js:353:31)
    at Function._load (module.js:311:12)
    at Array.0 (module.js:484:10)
    at EventEmitter._tickCallback (node.js:190:38)

Notice that the file name appears nowhere in the stack trace or the message. This makes it very difficult to track down errors in scripts that you are trying to run with vm, as the stack trace points you to the wrong place. Ideally, there'd be another element atop the stack trace with the line numbers of the script evaluated by vm.

Here's the output that would be ideal:

/path/to/some/file.js:2
localVar ?= 1;
          ^
SyntaxError: Unexpected token =
    at <anonymous> (/path/to/some/file.js:2:9)
    at vm.runInThisContext (vm.js:line:col)
    at Object.<anonymous> (/Users/itaylor/temp/test.js:5:18)
    at Module._compile (module.js:446:26)
    at Object..js (module.js:464:10)
    at Module.load (module.js:353:31)
    at Function._load (module.js:311:12)
    at Array.0 (module.js:484:10)
    at EventEmitter._tickCallback (node.js:190:38)

[itaylor]

This same symptom occurs with vm.runInContext vm.runInNewContext and vm.createScript as well.

[isaacs]

Confirmed.

It's interesting that we get the correct output from syntax errors in modules, though, since that's exactly what we do in node to load them. Very curious indeed.

[isaacs]

Note: if something in the parsed module throws, then I'm seeing the correct output. It looks like only SyntaxErrors that are handled improperly.

[itaylor]

So, I started looking through node_script.cc a there's an undocumented boolean parameter display_errors that you can pass to these methods that will cause it to attempt to print more info about the syntax error to stderr. However, it doesn't work right either, in that it assumes the script is a wrapped script and it needs to back out the 62 character function preamble that wraps module scripts (but not these) so the line/col numbers are all screwed up. It does get you the file name printed to stderr though.

Script with added display_error set to true

var myFileName = "/path/to/some/file";
require("vm").createScript('invalidJsHere ?= 1;', myFileName, true);

Output:

/path/to/some/file:1

^

vm.js:26
  return new exports.Script(code, ctx, name);
         ^
SyntaxError: Unexpected token =
    at Object.createScript (vm.js:26:10)
    at Object.<anonymous> (/Users/itaylor/temp/test.js:2:15)
    at Module._compile (module.js:446:26)
    at Object..js (module.js:464:10)
    at Module.load (module.js:353:31)
    at Function._load (module.js:311:12)
    at Array.0 (module.js:484:10)
    at EventEmitter._tickCallback (node.js:190:38)

Really, I think the approach taken in node_script.cc probably just needs to be revisited, it appears it's author thought so as well based on the comments.

if (input_flag == compileCode) {
    // well, here WrappedScript::New would suffice in all cases, but maybe
    // Compile has a little better performance where possible
    script = output_flag == returnResult ? Script::Compile(code, filename)
                                         : Script::New(code, filename);
    if (script.IsEmpty()) {
      // FIXME UGLY HACK TO DISPLAY SYNTAX ERRORS.
      if (display_error) DisplayExceptionLine(try_catch);

      // Hack because I can't get a proper stacktrace on SyntaxError
      return try_catch.ReThrow();
    }
  }

I'm not much of a C++ developer, but maybe I'll take a whack at making a patch for fixing this error handling, if you're amenable to it.

[eldargab]

+1 for this to be fixed

[apaprocki]

I've submitted a patch for the V8 folks which fixes the TryCatch.ReThrow() bug which is causing #1310 and this bug. I've verified that with the patch these Node bugs are fixed and the whole display_error hack can be removed. I will follow up there and if/once accepted, I'll submit a PR to remove display_error.

https://codereview.chromium.org/15669003/

[apaprocki]

I published an integration branch containing the V8 fix and removing the display_error hack if anyone else would like to play with it pending the V8 code review:

https://github.com/apaprocki/node/tree/issue-3452

With the fix, this test:

var vm = require('vm');
var context = {
    run: function() {
        vm.runInNewContext('invalid ?= 1', context, 'bar');
    }
};
vm.runInNewContext('run()', context, 'foo');

produces the correct exception and stack:

bar:1
invalid ?= 1
         ^
SyntaxError: Unexpected token =
    at context.run (test.js:4:12)
    at foo:1:1
    at Object.<anonymous> (test.js:7:4)
    at Module._compile (module.js:449:26)
    at Object.Module._extensions..js (module.js:467:10)
    at Module.load (module.js:349:32)
    at Function.Module._load (module.js:305:12)
    at Function.Module.runMain (module.js:490:10)
    at startup (node.js:119:16)
    at node.js:828:3

[glasser]

@apaprocki I've tried out your branch. If I understand correctly, it allows you to remove the hacky call to DisplayExceptionLine in node_script.cc... but it doesn't actually make the syntax error's real location available to JS code that is calling vm.runInWhateverContext, right?

ie, there's still no way to do:

try {
  vm.runInThisContext(someCode, filename);
} catch (e) {
  // extract the syntax error location from e somehow and do something other than
  // let node catch it at the top level and print it to stderr
}

right?

(Not to say that your patch isn't a definite improvement, just wondering if the above is possible.)

[apaprocki]

@glasser Do you have an example that isn't working the way you expect? In my example in the update before yours, if I modify the second vm call to have a try/catch wrapper, the caught exception is correct (SyntaxError) and the stack correctly points to the inner vm call.

[glasser]

@apaprocki I agree that if you do

var vm = require('vm');
var context = {
    run: function() {
        try {
          vm.runInNewContext('invalid ?= 1', context, 'bar');
        } catch (e) {
          console.log("MESSAGE", e.message);
          console.log("STACK", e.stack);
        }
    }
};
vm.runInNewContext('run()', context, 'foo');

then the stack correctly points to the inner vm call. But is there any way to get bar:1 out of the caught e object? The bar:1 is printed to stderr if that error makes it all the way up to the top level, but I'm not sure if it's anywhere on e...

(Again, this is in no way an objection to a patch which improves the situation. Just wondering if we could improve it further while we're at it :) )

[apaprocki]

V8 does not set the filename and line number as properties on the Error object. (Mozilla does this, but the fileName and lineNumber properties are non-standard (https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Error))

The V8 team has indicated that they are only exposing the stack property, and that the stack property should contain the filename and line number where the error occured, but it does not appear that this works in all situations currently.

These two bugs are requesting that it be fixed:
https://code.google.com/p/v8/issues/detail?id=1914
https://code.google.com/p/v8/issues/detail?id=1281

As soon as some solution is found there at the V8 level, I think you will get what you're looking for.

[agsha]

+1 Would love to have this fixed

[bnoordhuis]

Closing, works in master:

$ cat tmp/issue3452.js
require('vm').runInThisContext('invalidJsHere ?= 1;', 'foobar.js');

$ out/Release/node tmp/issue3452.js

foobar.js:1
invalidJsHere ?= 1;
               ^
SyntaxError: Unexpected token =
    at Object.exports.runInThisContext (vm.js:69:16)
    at Object.<anonymous> (/home/bnoordhuis/src/master/tmp/issue3452.js:1:77)
    at Module._compile (module.js:449:26)
    at Object.Module._extensions..js (module.js:467:10)
    at Module.load (module.js:349:32)
    at Function.Module._load (module.js:305:12)
    at Function.Module.runMain (module.js:490:10)
    at startup (node.js:121:16)
    at node.js:764:3

That's about as good as it gets.

[glasser]

@bnoordhuis That's not actually what is being asked for. The problem is that if you catch that error instead of letting it get to the built-in top level, there's nothing in e.stack to find foobar.js:1. The print of foobar.js:1 is a special-cased thing in the Node C++ code that JS doesn't have access to.

As far as I can tell this is a V8 issue. See eg https://code.google.com/p/v8/issues/detail?id=1281 and https://code.google.com/p/v8/issues/detail?id=1914

[bnoordhuis]

That's what I mean with 'as good as it gets'. Node reports the proper file name at the top. The stack trace is V8 territory, not something we can fix in node.