From 53951fbce7645f60b221c6d51c21b47225ff5a0c Mon Sep 17 00:00:00 2001 From: Marcel Laverdet Date: Thu, 18 May 2017 16:53:20 -0500 Subject: [PATCH 1/2] vm: fix displayErrors in runIn.. functions This option has been broken for almost a year when used with any of the vm.runIn.. family of functions, except for syntax errors. PR-URL: https://github.com/nodejs/node/pull/13074 Reviewed-By: Anna Henningsen --- lib/repl.js | 2 +- src/node_contextify.cc | 18 +++++++----------- test/message/vm_display_runtime_error.js | 8 +++++++- test/message/vm_display_runtime_error.out | 15 +++++++++++++++ 4 files changed, 30 insertions(+), 13 deletions(-) diff --git a/lib/repl.js b/lib/repl.js index 52bb1b6b53986c..7ae0f0830f06c3 100644 --- a/lib/repl.js +++ b/lib/repl.js @@ -332,7 +332,7 @@ function REPLServer(prompt, try { try { const scriptOptions = { - displayErrors: true, + displayErrors: false, breakOnSigint: self.breakEvalOnSigint }; diff --git a/src/node_contextify.cc b/src/node_contextify.cc index 741f568259a1a6..d87ae4c592fa2a 100644 --- a/src/node_contextify.cc +++ b/src/node_contextify.cc @@ -670,8 +670,10 @@ class ContextifyScript : public BaseObject { return; } - Local decorated_stack = String::Concat(arrow.As(), - stack.As()); + Local decorated_stack = String::Concat( + String::Concat(arrow.As(), + FIXED_ONE_BYTE_STRING(env->isolate(), "\n")), + stack.As()); err_obj->Set(env->stack_string(), decorated_stack); err_obj->SetPrivate( env->context(), @@ -867,6 +869,9 @@ class ContextifyScript : public BaseObject { env->ThrowError("Script execution timed out."); } else if (received_signal) { env->ThrowError("Script execution interrupted."); + } else if (display_errors) { + // We should decorate non-termination exceptions + DecorateErrorStack(env, *try_catch); } // If there was an exception thrown during script execution, re-throw it. @@ -879,15 +884,6 @@ class ContextifyScript : public BaseObject { return false; } - if (result.IsEmpty()) { - // Error occurred during execution of the script. - if (display_errors) { - DecorateErrorStack(env, *try_catch); - } - try_catch->ReThrow(); - return false; - } - args.GetReturnValue().Set(result); return true; } diff --git a/test/message/vm_display_runtime_error.js b/test/message/vm_display_runtime_error.js index 861e87f2f2bb93..a16afaee3d559b 100644 --- a/test/message/vm_display_runtime_error.js +++ b/test/message/vm_display_runtime_error.js @@ -4,6 +4,12 @@ const vm = require('vm'); console.error('beginning'); -vm.runInThisContext('throw new Error("boo!")', { filename: 'test.vm' }); +try { + vm.runInThisContext('throw new Error("boo!")', { filename: 'test.vm'}); +} catch (err) { + console.error(err.stack); +} + +vm.runInThisContext('throw new Error("spooky!")', { filename: 'test.vm' }); console.error('end'); diff --git a/test/message/vm_display_runtime_error.out b/test/message/vm_display_runtime_error.out index d5cf1d3ee50dbb..789f12733c163f 100644 --- a/test/message/vm_display_runtime_error.out +++ b/test/message/vm_display_runtime_error.out @@ -14,3 +14,18 @@ Error: boo! at tryModuleLoad (module.js:*:*) at Function.Module._load (module.js:*) at Module.runMain (module.js:*) +test.vm:1 +throw new Error("spooky!") +^ + +Error: spooky! + at test.vm:1:7 + at ContextifyScript.Script.runInThisContext (vm.js:*) + at Object.runInThisContext (vm.js:*) + at Object. (*test*message*vm_display_runtime_error.js:*) + at Module._compile (module.js:*) + at Object.Module._extensions..js (module.js:*) + at Module.load (module.js:*) + at tryModuleLoad (module.js:*:*) + at Function.Module._load (module.js:*) + at Module.runMain (module.js:*) From 7a175b04283f8904c826f0c1e0eaea363187817f Mon Sep 17 00:00:00 2001 From: Marcel Laverdet Date: Thu, 18 May 2017 17:12:41 -0500 Subject: [PATCH 2/2] vm: fix race condition with timeout param This fixes a race condition in the watchdog timer used for vm timeouts. The condition would terminate the main stack's execution instead of the code running under the sandbox. PR-URL: https://github.com/nodejs/node/pull/13074 Reviewed-By: Anna Henningsen --- src/node_contextify.cc | 24 ++++++++--------- src/node_watchdog.cc | 53 ++++++++----------------------------- src/node_watchdog.h | 26 ++++++------------ test/pummel/test-vm-race.js | 33 +++++++++++++++++++++++ 4 files changed, 63 insertions(+), 73 deletions(-) create mode 100644 test/pummel/test-vm-race.js diff --git a/src/node_contextify.cc b/src/node_contextify.cc index d87ae4c592fa2a..b6e408146a732d 100644 --- a/src/node_contextify.cc +++ b/src/node_contextify.cc @@ -841,27 +841,20 @@ class ContextifyScript : public BaseObject { bool timed_out = false; bool received_signal = false; if (break_on_sigint && timeout != -1) { - Watchdog wd(env->isolate(), timeout); - SigintWatchdog swd(env->isolate()); + Watchdog wd(env->isolate(), timeout, &timed_out); + SigintWatchdog swd(env->isolate(), &received_signal); result = script->Run(); - timed_out = wd.HasTimedOut(); - received_signal = swd.HasReceivedSignal(); } else if (break_on_sigint) { - SigintWatchdog swd(env->isolate()); + SigintWatchdog swd(env->isolate(), &received_signal); result = script->Run(); - received_signal = swd.HasReceivedSignal(); } else if (timeout != -1) { - Watchdog wd(env->isolate(), timeout); + Watchdog wd(env->isolate(), timeout, &timed_out); result = script->Run(); - timed_out = wd.HasTimedOut(); } else { result = script->Run(); } - if (try_catch->HasCaught()) { - if (try_catch->HasTerminated()) - env->isolate()->CancelTerminateExecution(); - + if (timed_out || received_signal) { // It is possible that execution was terminated by another timeout in // which this timeout is nested, so check whether one of the watchdogs // from this invocation is responsible for termination. @@ -869,7 +862,12 @@ class ContextifyScript : public BaseObject { env->ThrowError("Script execution timed out."); } else if (received_signal) { env->ThrowError("Script execution interrupted."); - } else if (display_errors) { + } + env->isolate()->CancelTerminateExecution(); + } + + if (try_catch->HasCaught()) { + if (!timed_out && !received_signal && display_errors) { // We should decorate non-termination exceptions DecorateErrorStack(env, *try_catch); } diff --git a/src/node_watchdog.cc b/src/node_watchdog.cc index 5d95c4132f1b3f..049cd177ef0a0b 100644 --- a/src/node_watchdog.cc +++ b/src/node_watchdog.cc @@ -6,9 +6,9 @@ namespace node { -Watchdog::Watchdog(v8::Isolate* isolate, uint64_t ms) : isolate_(isolate), - timed_out_(false), - destroyed_(false) { +Watchdog::Watchdog(v8::Isolate* isolate, uint64_t ms, bool* timed_out) + : isolate_(isolate), timed_out_(timed_out) { + int rc; loop_ = new uv_loop_t; CHECK(loop_); @@ -33,20 +33,6 @@ Watchdog::Watchdog(v8::Isolate* isolate, uint64_t ms) : isolate_(isolate), Watchdog::~Watchdog() { - Destroy(); -} - - -void Watchdog::Dispose() { - Destroy(); -} - - -void Watchdog::Destroy() { - if (destroyed_) { - return; - } - uv_async_send(&async_); uv_thread_join(&thread_); @@ -59,8 +45,6 @@ void Watchdog::Destroy() { CHECK_EQ(0, rc); delete loop_; loop_ = nullptr; - - destroyed_ = true; } @@ -72,7 +56,7 @@ void Watchdog::Run(void* arg) { uv_run(wd->loop_, UV_RUN_DEFAULT); // Loop ref count reaches zero when both handles are closed. - // Close the timer handle on this side and let Destroy() close async_ + // Close the timer handle on this side and let ~Watchdog() close async_ uv_close(reinterpret_cast(&wd->timer_), nullptr); } @@ -85,24 +69,15 @@ void Watchdog::Async(uv_async_t* async) { void Watchdog::Timer(uv_timer_t* timer) { Watchdog* w = ContainerOf(&Watchdog::timer_, timer); - w->timed_out_ = true; - uv_stop(w->loop_); + *w->timed_out_ = true; w->isolate()->TerminateExecution(); + uv_stop(w->loop_); } -SigintWatchdog::~SigintWatchdog() { - Destroy(); -} - - -void SigintWatchdog::Dispose() { - Destroy(); -} - - -SigintWatchdog::SigintWatchdog(v8::Isolate* isolate) - : isolate_(isolate), received_signal_(false), destroyed_(false) { +SigintWatchdog::SigintWatchdog( + v8::Isolate* isolate, bool* received_signal) + : isolate_(isolate), received_signal_(received_signal) { // Register this watchdog with the global SIGINT/Ctrl+C listener. SigintWatchdogHelper::GetInstance()->Register(this); // Start the helper thread, if that has not already happened. @@ -110,20 +85,14 @@ SigintWatchdog::SigintWatchdog(v8::Isolate* isolate) } -void SigintWatchdog::Destroy() { - if (destroyed_) { - return; - } - - destroyed_ = true; - +SigintWatchdog::~SigintWatchdog() { SigintWatchdogHelper::GetInstance()->Unregister(this); SigintWatchdogHelper::GetInstance()->Stop(); } void SigintWatchdog::HandleSigint() { - received_signal_ = true; + *received_signal_ = true; isolate_->TerminateExecution(); } diff --git a/src/node_watchdog.h b/src/node_watchdog.h index 2d55d782d0af5d..ec6285af5d0349 100644 --- a/src/node_watchdog.h +++ b/src/node_watchdog.h @@ -16,16 +16,13 @@ namespace node { class Watchdog { public: - explicit Watchdog(v8::Isolate* isolate, uint64_t ms); + explicit Watchdog(v8::Isolate* isolate, + uint64_t ms, + bool* timed_out = nullptr); ~Watchdog(); - - void Dispose(); - v8::Isolate* isolate() { return isolate_; } - bool HasTimedOut() { return timed_out_; } - private: - void Destroy(); + private: static void Run(void* arg); static void Async(uv_async_t* async); static void Timer(uv_timer_t* timer); @@ -35,27 +32,20 @@ class Watchdog { uv_loop_t* loop_; uv_async_t async_; uv_timer_t timer_; - bool timed_out_; - bool destroyed_; + bool* timed_out_; }; class SigintWatchdog { public: - explicit SigintWatchdog(v8::Isolate* isolate); + explicit SigintWatchdog(v8::Isolate* isolate, + bool* received_signal = nullptr); ~SigintWatchdog(); - - void Dispose(); - v8::Isolate* isolate() { return isolate_; } - bool HasReceivedSignal() { return received_signal_; } void HandleSigint(); private: - void Destroy(); - v8::Isolate* isolate_; - bool received_signal_; - bool destroyed_; + bool* received_signal_; }; class SigintWatchdogHelper { diff --git a/test/pummel/test-vm-race.js b/test/pummel/test-vm-race.js new file mode 100644 index 00000000000000..7f9514b04e9e73 --- /dev/null +++ b/test/pummel/test-vm-race.js @@ -0,0 +1,33 @@ +'use strict'; +require('../common'); +const vm = require('vm'); + +// We're testing a race condition so we just have to spin this in a loop +// for a little while and see if it breaks. The condition being tested +// is an `isolate->TerminateExecution()` reaching the main JS stack from +// the timeout watchdog. +const sandbox = { timeout: 5 }; +const context = vm.createContext(sandbox); +const script = new vm.Script( + 'var d = Date.now() + timeout;while (d > Date.now());' +); +const immediate = setImmediate(function() { + throw new Error('Detected vm race condition!'); +}); + +// When this condition was first discovered this test would fail in 50ms +// or so. A better, but still incorrect implementation would fail after +// 100 seconds or so. If you're messing with vm timeouts you might +// consider increasing this timeout to hammer out races. +const giveUp = Date.now() + 5000; +do { + // The loop adjusts the timeout up or down trying to hit the race + try { + script.runInContext(context, { timeout: 5 }); + ++sandbox.timeout; + } catch (err) { + --sandbox.timeout; + } +} while (Date.now() < giveUp); + +clearImmediate(immediate);