Unexpectedly triggers report when `new vm.Script` fails during compilation

[davidgwking]

It appears that node-report is unexpectedly trigger uncaught exception reports when vm.Script fails during script compilation.

In the example found below the caller clearly catches the exception. I would expect node-report not to automatically trigger a report in this situation.

Reproduction Example

var vm = require('vm');
var nodereport = require('node-report');
var nodereportConfig = require('node-report/api');

nodereportConfig.setFileName('stderr');

try {
  new vm.Script("[", {});
} catch (err) {
  console.log('this appears to be a caught exception');
}

Output Produced

➜ node repro.js >out 2> errout
➜ cat out
this appears to be a caught exception
➜ cat errout
================================================================================
==== Node Report ===============================================================

Event: exception, location: "OnUncaughtException"
Filename: stderr
Dump event time:  2017/02/14 15:07:38
Module load time: 2017/02/14 15:07:38
Process ID: 51793
Command line: node repro.js

Node.js version: v6.9.1
(ares: 1.10.1-DEV, http_parser: 2.7.0, icu: 57.1, modules: 48, openssl: 1.0.2j,
 uv: 1.9.1, v8: 5.1.281.84, zlib: 1.2.8)

node-report version: 2.1.0 (built against Node.js v6.9.1)

OS version: Darwin 16.4.0 Darwin Kernel Version 16.4.0: Thu Dec 22 22:53:21 PST 2016; root:xnu-3789.41.3~3/RELEASE_X86_64

Machine: neptune x86_64

================================================================================
==== JavaScript Stack Trace ====================================================

Object.<anonymous> (/Users/davidgwking/Desktop/repro.js:8:3)
Module._compile (module.js:570:32)
Object.Module._extensions..js (module.js:579:10)
Module.load (module.js:487:32)
tryModuleLoad (module.js:446:12)
Function.Module._load (module.js:438:3)
Module.runMain (module.js:604:10)
run (bootstrap_node.js:394:7)
startup (bootstrap_node.js:149:9)
bootstrap_node.js:509:3

================================================================================
==== Native Stack Trace ========================================================

 0: [pc=0x101db9e2a] nodereport::OnUncaughtException(v8::Isolate*) [/Users/davidgwking/Desktop/node_modules/node-report/api.node]
 1: [pc=0x10057c0a2] v8::internal::Isolate::Throw(v8::internal::Object*, v8::internal::MessageLocation*) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
 2: [pc=0x10066c7e7] v8::internal::PendingCompilationErrorHandler::ThrowPendingError(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Script>) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
 3: [pc=0x10062b373] v8::internal::Parser::Internalize(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Script>, bool) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
 4: [pc=0x10062b649] v8::internal::Parser::Parse(v8::internal::ParseInfo*) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
 5: [pc=0x10062b47e] v8::internal::Parser::ParseStatic(v8::internal::ParseInfo*) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
 6: [pc=0x10033c41f] v8::internal::(anonymous namespace)::CompileToplevel(v8::internal::CompilationInfo*) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
 7: [pc=0x10033d149] v8::internal::Compiler::GetSharedFunctionInfoForScript(v8::internal::Handle<v8::internal::String>, v8::internal::Handle<v8::internal::Object>, int, int, v8::ScriptOriginOptions, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Context>, v8::Extension*, v8::internal::ScriptData**, v8::ScriptCompiler::CompileOptions, v8::internal::NativesFlag, bool) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
 8: [pc=0x10014eed9] v8::ScriptCompiler::CompileUnboundInternal(v8::Isolate*, v8::ScriptCompiler::Source*, v8::ScriptCompiler::CompileOptions, bool) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
 9: [pc=0x1008e2e6e] node::ContextifyScript::New(v8::FunctionCallbackInfo<v8::Value> const&) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
10: [pc=0x1001799a4] v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
11: [pc=0x1001e80c9] v8::internal::Builtin_Impl_HandleApiCallConstruct(v8::internal::(anonymous namespace)::BuiltinArguments<(v8::internal::BuiltinExtraArguments)1>, v8::internal::Isolate*) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
12: [pc=0x1001ce1d3] v8::internal::Builtin_HandleApiCallConstruct(int, v8::internal::Object**, v8::internal::Isolate*) [/Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node]
13: [pc=0x15698f9092a7]

================================================================================
==== JavaScript Heap and Garbage Collector =====================================

Heap space name: new_space
    Memory size: 2,097,152 bytes, committed memory: 2,097,152 bytes
    Capacity: 1,031,680 bytes, used: 1,023,368 bytes, available: 8,312 bytes
Heap space name: old_space
    Memory size: 3,100,672 bytes, committed memory: 3,100,672 bytes
    Capacity: 2,425,512 bytes, used: 2,425,400 bytes, available: 112 bytes
Heap space name: code_space
    Memory size: 2,097,152 bytes, committed memory: 2,097,152 bytes
    Capacity: 585,408 bytes, used: 585,312 bytes, available: 96 bytes
Heap space name: map_space
    Memory size: 1,130,496 bytes, committed memory: 1,130,496 bytes
    Capacity: 173,624 bytes, used: 173,624 bytes, available: 0 bytes
Heap space name: large_object_space
    Memory size: 0 bytes, committed memory: 0 bytes
    Capacity: 1,488,924,160 bytes, used: 0 bytes, available: 1,488,924,160 bytes

Total heap memory size: 8,425,472 bytes
Total heap committed memory: 8,425,472 bytes
Total used heap memory: 4,207,704 bytes
Total available heap memory: 1,488,932,680 bytes

Heap memory limit: 1,501,560,832

================================================================================
==== Resource Usage ============================================================

Process total resource usage:
  User mode CPU: 0.078303 secs
  Kernel mode CPU: 0.014141 secs
  Maximum resident set size: 20,828,913,664 bytes
  Page faults: 0 (I/O required) 5264 (no I/O required)
  Filesystem activity: 0 reads 0 writes

================================================================================
==== Node.js libuv Handle Summary ==============================================

(Flags: R=Ref, A=Active)

Flags  Type      Address
[-A]   async     0x0x10127c0d8
[-A]   async     0x0x101f09470
[--]   check     0x0x10280ce10
[R-]   idle      0x0x10280ce88
[--]   prepare   0x0x10280cf00
[--]   check     0x0x10280cf78
[-A]   async     0x0x101dbdb58

================================================================================
==== System Information ========================================================

Environment variables
  [REDACTED FOR BREVITY]

Resource limits                        soft limit      hard limit
  core file size (blocks)               unlimited       unlimited
  data seg size (kbytes)                unlimited       unlimited
  file size (blocks)                    unlimited       unlimited
  max locked memory (bytes)             unlimited       unlimited
  max memory size (kbytes)              unlimited       unlimited
  open files                                10240       unlimited
  stack size (bytes)                      8388608        67104768
  cpu time (seconds)                    unlimited       unlimited
  max user processes                          709            1064
  virtual memory (kbytes)               unlimited       unlimited

Loaded libraries
  /Users/davidgwking/.nvm/versions/node/v6.9.1/bin/node
  /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation
  /usr/lib/libSystem.B.dylib
  /usr/lib/libstdc++.6.dylib
  /usr/lib/libDiagnosticMessagesClient.dylib
  /usr/lib/libicucore.A.dylib
  /usr/lib/libobjc.A.dylib
  /usr/lib/libz.1.dylib
  /usr/lib/system/libcache.dylib
  /usr/lib/system/libcommonCrypto.dylib
  /usr/lib/system/libcompiler_rt.dylib
  /usr/lib/system/libcopyfile.dylib
  /usr/lib/system/libcorecrypto.dylib
  /usr/lib/system/libdispatch.dylib
  /usr/lib/system/libdyld.dylib
  /usr/lib/system/libkeymgr.dylib
  /usr/lib/system/liblaunch.dylib
  /usr/lib/system/libmacho.dylib
  /usr/lib/system/libquarantine.dylib
  /usr/lib/system/libremovefile.dylib
  /usr/lib/system/libsystem_asl.dylib
  /usr/lib/system/libsystem_blocks.dylib
  /usr/lib/system/libsystem_c.dylib
  /usr/lib/system/libsystem_configuration.dylib
  /usr/lib/system/libsystem_coreservices.dylib
  /usr/lib/system/libsystem_coretls.dylib
  /usr/lib/system/libsystem_dnssd.dylib
  /usr/lib/system/libsystem_info.dylib
  /usr/lib/system/libsystem_kernel.dylib
  /usr/lib/system/libsystem_m.dylib
  /usr/lib/system/libsystem_malloc.dylib
  /usr/lib/system/libsystem_network.dylib
  /usr/lib/system/libsystem_networkextension.dylib
  /usr/lib/system/libsystem_notify.dylib
  /usr/lib/system/libsystem_platform.dylib
  /usr/lib/system/libsystem_pthread.dylib
  /usr/lib/system/libsystem_sandbox.dylib
  /usr/lib/system/libsystem_secinit.dylib
  /usr/lib/system/libsystem_symptoms.dylib
  /usr/lib/system/libsystem_trace.dylib
  /usr/lib/system/libunwind.dylib
  /usr/lib/system/libxpc.dylib
  /usr/lib/libauto.dylib
  /usr/lib/libc++abi.dylib
  /usr/lib/libc++.1.dylib
  /Users/davidgwking/Desktop/node_modules/node-report/api.node

================================================================================
Node.js report completed

Uncaught exception at:
Object.<anonymous> (/Users/davidgwking/Desktop/repro.js:8:3)
Module._compile (module.js:570:32)
Object.Module._extensions..js (module.js:579:10)
Module.load (module.js:487:32)
tryModuleLoad (module.js:446:12)
Function.Module._load (module.js:438:3)
Module.runMain (module.js:604:10)
run (bootstrap_node.js:394:7)
startup (bootstrap_node.js:149:9)
bootstrap_node.js:509:3

[rnchamberlain]

That's interesting, it might be because vm.Script runs in a kind of sandbox/context, with some special handling of exceptions. See https://nodejs.org/api/vm.html#vm_executing_javascript

If I comment out node-report from the application, then run with --abort-on-uncaught-exception, I see the same effect:

rchamberlain@ThinkCentre-M57p:~/test$ node --abort-on-uncaught-exception repro1.js 
Uncaught SyntaxError: Unexpected end of input

FROM
Object.<anonymous> (/home/rchamberlain/test/repro1.js:8:3)
Module._compile (module.js:570:32)
Object.Module._extensions..js (module.js:579:10)
Module.load (module.js:487:32)
tryModuleLoad (module.js:446:12)
Function.Module._load (module.js:438:3)
Module.runMain (module.js:604:10)
run (bootstrap_node.js:394:7)
startup (bootstrap_node.js:149:9)
bootstrap_node.js:509:3
Illegal instruction (core dumped)

So it looks like the V8 hook which both node-report and --abort-on-uncaught-exception use is being triggered. In the normal case there may be some extra long-stop that catches the SyntaxError and passes it back to the application.

[rnchamberlain]

Also seeing this in the node repl, likely because that also uses vm.js:

> nr = require('node-report')
{ triggerReport: [Function],
  getReport: [Function],
  setEvents: [Function],
....
> foo

Writing Node.js report to file: node-report.20170216.101524.1852.001.txt
Node.js report completed

Uncaught exception at:
repl:1:1
sigintHandlersWrap (vm.js:22:35)
sigintHandlersWrap (vm.js:96:12)
Script.runInThisContext (vm.js:21:12)
....

[matteofigus]

I see this happening with vm.runInNewContext too with node 6.10.1 and 6.10.0 (linux and mac) - v8 5.1.281.93