Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

vm: fix race condition with timeout param #13074

Closed
wants to merge 2 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion lib/repl.js
Original file line number Diff line number Diff line change
Expand Up @@ -231,7 +231,7 @@ function REPLServer(prompt,
try {
try {
const scriptOptions = {
displayErrors: true,
displayErrors: false,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Any chance you could split the displayErrors changes out into a separate commit?

breakOnSigint: self.breakEvalOnSigint
};

Expand Down
40 changes: 17 additions & 23 deletions src/node_contextify.cc
Original file line number Diff line number Diff line change
Expand Up @@ -736,8 +736,10 @@ class ContextifyScript : public BaseObject {
return;
}

Local<String> decorated_stack = String::Concat(arrow.As<String>(),
stack.As<String>());
Local<String> decorated_stack = String::Concat(
String::Concat(arrow.As<String>(),
FIXED_ONE_BYTE_STRING(env->isolate(), "\n")),
stack.As<String>());
Copy link
Member

@addaleax addaleax May 19, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just a tiny style nit, but we prefer 4 spaces of indentation for statement continuations – that can be fixed while merging, though

err_obj->Set(env->stack_string(), decorated_stack);
err_obj->SetPrivate(
env->context(),
Expand Down Expand Up @@ -956,27 +958,20 @@ class ContextifyScript : public BaseObject {
bool timed_out = false;
bool received_signal = false;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think in a previous version of this PR these were volatile… any reason why that changed?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah sorry I meant to leave a note about that. The volatile ended up being unnecessary. The watchdogs take a non-const reference so that's good enough to ensure the optimizer doesn't do anything fishy. Then in the dtor uv_thread_join is called which will synchronize the watchdog thread back up with the main thread.

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.
Expand All @@ -985,6 +980,14 @@ class ContextifyScript : public BaseObject {
} else if (received_signal) {
env->ThrowError("Script execution interrupted.");
}
env->isolate()->CancelTerminateExecution();
}

if (try_catch->HasCaught()) {
if (!timed_out && !received_signal && display_errors) {
// We should decorate non-termination exceptions
DecorateErrorStack(env, *try_catch);
}

// If there was an exception thrown during script execution, re-throw it.
// If one of the above checks threw, re-throw the exception instead of
Expand All @@ -996,15 +999,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;
}
Expand Down
53 changes: 11 additions & 42 deletions src/node_watchdog.cc
Original file line number Diff line number Diff line change
Expand Up @@ -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_);
Expand All @@ -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_);

Expand All @@ -80,8 +66,6 @@ void Watchdog::Destroy() {
CHECK_EQ(0, rc);
delete loop_;
loop_ = nullptr;

destroyed_ = true;
}


Expand All @@ -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<uv_handle_t*>(&wd->timer_), nullptr);
}

Expand All @@ -106,45 +90,30 @@ 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.
SigintWatchdogHelper::GetInstance()->Start();
}


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();
}

Expand Down
28 changes: 10 additions & 18 deletions src/node_watchdog.h
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ditto for 4-space indents. I think here we’d usually keep the v8::Isolate* isolate bit directly after the ( and align all other parameters vertically below it; but again, this is just a tiny nit and can be fixed up while landing.

~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);
Expand All @@ -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);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

(ditto)

~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 {
Expand Down
8 changes: 7 additions & 1 deletion test/message/vm_display_runtime_error.js
Original file line number Diff line number Diff line change
Expand Up @@ -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');
15 changes: 15 additions & 0 deletions test/message/vm_display_runtime_error.out
Original file line number Diff line number Diff line change
Expand Up @@ -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.<anonymous> (*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:*)
54 changes: 54 additions & 0 deletions test/pummel/test-vm-race.js
Original file line number Diff line number Diff line change
@@ -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.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You can drop the copyright header for newly added files, I think.


'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);