From c212e3ef5698d516922f05be99f91b59a87997fd 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. --- 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 cff49cea35a8d1..670dbfbc871365 100644 --- a/lib/repl.js +++ b/lib/repl.js @@ -231,7 +231,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 970455bb25cb2e..f69352d8e81ad3 100644 --- a/src/node_contextify.cc +++ b/src/node_contextify.cc @@ -736,8 +736,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(), @@ -984,6 +986,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. @@ -996,15 +1001,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 a7a49bba27750f..8a40a03a03962a 100644 --- a/test/message/vm_display_runtime_error.js +++ b/test/message/vm_display_runtime_error.js @@ -25,6 +25,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 9035c1783c389a..7e116ee8964525 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 Function.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 Function.Module.runMain (module.js:*) From c6b07f29f1f7ad4098603d1b5003da0a09916434 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. --- src/node_contextify.cc | 24 ++++++++--------- src/node_watchdog.cc | 53 ++++++++---------------------------- src/node_watchdog.h | 28 +++++++------------ test/pummel/test-vm-race.js | 54 +++++++++++++++++++++++++++++++++++++ 4 files changed, 86 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 f69352d8e81ad3..ef69d35431e237 100644 --- a/src/node_contextify.cc +++ b/src/node_contextify.cc @@ -958,27 +958,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. @@ -986,7 +979,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 3065343ddefa6e..f4020e56f7fb61 100644 --- a/src/node_watchdog.cc +++ b/src/node_watchdog.cc @@ -27,9 +27,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_); @@ -54,20 +54,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_); @@ -80,8 +66,6 @@ void Watchdog::Destroy() { CHECK_EQ(0, rc); delete loop_; loop_ = nullptr; - - destroyed_ = true; } @@ -93,7 +77,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); } @@ -106,24 +90,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. @@ -131,20 +106,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 9dd5a03f816bd5..ae562c9537e6af 100644 --- a/src/node_watchdog.h +++ b/src/node_watchdog.h @@ -37,16 +37,14 @@ namespace node { class Watchdog { public: - explicit Watchdog(v8::Isolate* isolate, uint64_t ms); + explicit Watchdog( + v8::Isolate* isolate, + uint64_t ms, + bool* timed_out = NULL); ~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); @@ -56,27 +54,21 @@ 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 = NULL); ~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..6c33d008e19cda --- /dev/null +++ b/test/pummel/test-vm-race.js @@ -0,0 +1,54 @@ +// Copyright Joyent, Inc. and other Node contributors. +// +// Permission is hereby granted, free of charge, to any person obtaining a +// copy of this software and associated documentation files (the +// "Software"), to deal in the Software without restriction, including +// without limitation the rights to use, copy, modify, merge, publish, +// distribute, sublicense, and/or sell copies of the Software, and to permit +// persons to whom the Software is furnished to do so, subject to the +// following conditions: +// +// The above copyright notice and this permission notice shall be included +// in all copies or substantial portions of the Software. +// +// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS +// OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF +// MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN +// NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, +// DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR +// OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE +// USE OR OTHER DEALINGS IN THE SOFTWARE. + +'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);