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.

Sign up for GitHub

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

src: fix MakeCallback error handling #4507

Merged
merged 6 commits into from
Feb 12, 2016
Merged

src: fix MakeCallback error handling #4507

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
575b84e
src: fix MakeCallback error handling
trevnorris Feb 11, 2016
e919224
src: add AsyncCallbackScope
trevnorris Jan 5, 2016
f86a3a2
src: remove unused of TickInfo::last_threw()
trevnorris Feb 11, 2016
5e30478
src: remove unused TickInfo::in_tick()
trevnorris Feb 10, 2016
95afe28
src: remove TryCatch in MakeCallback
trevnorris Feb 11, 2016
ab6fe59
test: add addons test for MakeCallback
trevnorris Jan 6, 2016
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
52 changes: 20 additions & 32 deletions src/async-wrap.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -173,8 +173,8 @@ void LoadAsyncWrapperInfo(Environment* env) {


Local<Value> AsyncWrap::MakeCallback(const Local<Function> cb,
int argc,
Local<Value>* argv) {
int argc,
Local<Value>* argv) {
CHECK(env()->context() == env()->isolate()->GetCurrentContext());

Local<Function> pre_fn = env()->async_hooks_pre_function();
Expand All @@ -184,6 +184,8 @@ Local<Value> AsyncWrap::MakeCallback(const Local<Function> cb,
Local<Object> domain;
bool has_domain = false;

Environment::AsyncCallbackScope callback_scope(env());

if (env()->using_domains()) {
Local<Value> domain_v = context->Get(env()->domain_string());
has_domain = domain_v->IsObject();
Expand All @@ -194,52 +196,45 @@ Local<Value> AsyncWrap::MakeCallback(const Local<Function> cb,
}
}

TryCatch try_catch(env()->isolate());
try_catch.SetVerbose(true);

if (has_domain) {
Local<Value> enter_v = domain->Get(env()->enter_string());
if (enter_v->IsFunction()) {
enter_v.As<Function>()->Call(domain, 0, nullptr);
if (try_catch.HasCaught())
return Undefined(env()->isolate());
if (enter_v.As<Function>()->Call(domain, 0, nullptr).IsEmpty()) {
FatalError("node::AsyncWrap::MakeCallback",
"domain enter callback threw, please report this");
}
}
}

if (ran_init_callback() && !pre_fn.IsEmpty()) {
try_catch.SetVerbose(false);
pre_fn->Call(context, 0, nullptr);
if (try_catch.HasCaught())
if (pre_fn->Call(context, 0, nullptr).IsEmpty())
Copy link

Choose a reason for hiding this comment

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

I think not setting verbose to false here means that errors thrown from with async pre-hooks would be forwarded to the active domain's error handler. Do you have time to verify that theory? If that's the case, I'm not sure that makes sense, and what the right thing to do is.

Setting verbose to false also means that the debugger wouldn't catch any exception in async pre-hooks, so it might not be ideal too.

Copy link

Choose a reason for hiding this comment

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

Confirmed:

➜  node git:(master) ✗ cat /tmp/test-asyncwrap-throw.js 
const asyncHooks = process.binding('async_wrap');
const domain = require('domain');
const fs = require('fs');

asyncHooks.setupHooks(_ => _, function () {
  throw new Error('throw in async pre hook');
}, function () {
  throw new Error('throw in async post hook');
});
asyncHooks.enable();

const d = domain.create();

d.on('error', function onError(err) {
    console.log('in domain error handler:', err);
});

d.run(function() {
    fs.stat(__filename, function() {
        throw new Error('throw from fs.stat callback');
    });
});
➜  node git:(master) ✗ ./node /tmp/test-asyncwrap-throw.js
in domain error handler: { [Error: throw in async pre hook]
  domain: 
   Domain {
     domain: null,
     _events: { error: [Function: onError] },
     _eventsCount: 1,
     _maxListeners: undefined,
     members: [] },
  domainThrown: true }
FATAL ERROR: node::AsyncWrap::MakeCallback pre hook threw
[1]    97516 abort      ./node /tmp/test-asyncwrap-throw.js
➜  node git:(master) ✗

Copy link

Choose a reason for hiding this comment

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

Also trying to reproduce that for node::MakeCallback with the following code:

const asyncHooks = process.binding('async_wrap');
const domain = require('domain');
const fs = require('fs');

asyncHooks.setupHooks(_ => _, function () {
  throw new Error('throw in async pre hook');
}, function () {
  throw new Error('throw in async post hook');
});
asyncHooks.enable();

const d = domain.create();

d.on('error', function onError(err) {
    console.log('in domain error handler:', err);
});

d.run(function() {
    setImmediate(function() {
        throw new Error('throw from setImmediate callback');
    });
});

doesn't seem to trigger async hooks (note the change from calling fs.stat to setImmediate). Am I missing something?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

In the init callback you have to put this._asyncQueue = {}. Since it doesn't tap into the AsyncWrap class used that long ago to trigger the remaining callbacks. Not a good solution, but haven't had a chance to rethink it.

As for the setImmediate(). timers don't currently work ATM. Will require hacking the JS and have been putting that off hoping I'd find a better solution.

FatalError("node::AsyncWrap::MakeCallback", "pre hook threw");
try_catch.SetVerbose(true);
}

Local<Value> ret = cb->Call(context, argc, argv);

if (try_catch.HasCaught()) {
return Undefined(env()->isolate());
}

if (ran_init_callback() && !post_fn.IsEmpty()) {
try_catch.SetVerbose(false);
post_fn->Call(context, 0, nullptr);
if (try_catch.HasCaught())
if (post_fn->Call(context, 0, nullptr).IsEmpty())
FatalError("node::AsyncWrap::MakeCallback", "post hook threw");
try_catch.SetVerbose(true);
}

if (ret.IsEmpty()) {
Copy link

Choose a reason for hiding this comment

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

It may be worth mentioning in a comment that this early return is very important because of the way node::FatalException is called when no TryCatch instance is present in this stack frame.

Without a TryCatch instance, node::FatalException will be called after this function returns, and thus exiting the current active domain if an error is thrown from the JavaScript function cb would exit the active domain before its error handler had a chance to run.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Good call. I'll add it to both locations.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@misterdjules actually I'm a little confused. without the TryCatch node::FatalException is run immediately after "cb". Even before the AsyncWrap post callback has a chance to run. Meaning the domain stack will have already been cleared before we get to domain.exit(). I'm just returning early to save us a call to JS.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Verified this by placing the early return after the domain exit call and tested with the following:

'use strict';

const domain = require('domain');
const d = domain.create();
const async_wrap = process.binding('async_wrap');

async_wrap.setupHooks(function() {
}, function() {
  process._rawDebug('before');
}, function() {
  process._rawDebug('after');
});
async_wrap.enable();

d.on('error', function() {
  process._rawDebug('d errored');
});

d.run(function() {
  require('crypto').randomBytes(1024, function() {
    throw new Error('crap');
  });
});

return Undefined(env()->isolate());
}

if (has_domain) {
Local<Value> exit_v = domain->Get(env()->exit_string());
if (exit_v->IsFunction()) {
exit_v.As<Function>()->Call(domain, 0, nullptr);
if (try_catch.HasCaught())
return Undefined(env()->isolate());
if (exit_v.As<Function>()->Call(domain, 0, nullptr).IsEmpty()) {
FatalError("node::AsyncWrap::MakeCallback",
"domain exit callback threw, please report this");
}
}
}

Environment::TickInfo* tick_info = env()->tick_info();

if (tick_info->in_tick()) {
if (callback_scope.in_makecallback()) {
return ret;
}

Expand All @@ -252,14 +247,7 @@ Local<Value> AsyncWrap::MakeCallback(const Local<Function> cb,
return ret;
}

tick_info->set_in_tick(true);

env()->tick_callback_function()->Call(process, 0, nullptr);

tick_info->set_in_tick(false);

if (try_catch.HasCaught()) {
tick_info->set_last_threw(true);
if (env()->tick_callback_function()->Call(process, 0, nullptr).IsEmpty()) {
return Undefined(env()->isolate());
}

Expand Down
33 changes: 16 additions & 17 deletions src/env-inl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -101,6 +101,20 @@ inline void Environment::AsyncHooks::set_enable_callbacks(uint32_t flag) {
fields_[kEnableCallbacks] = flag;
}

inline Environment::AsyncCallbackScope::AsyncCallbackScope(Environment* env)
: env_(env) {
env_->makecallback_cntr_++;
}

inline Environment::AsyncCallbackScope::~AsyncCallbackScope() {
env_->makecallback_cntr_--;
CHECK_GE(env_->makecallback_cntr_, 0);
}

inline bool Environment::AsyncCallbackScope::in_makecallback() {
return env_->makecallback_cntr_ > 1;
}

inline Environment::DomainFlag::DomainFlag() {
for (int i = 0; i < kFieldsCount; ++i) fields_[i] = 0;
}
Expand All @@ -117,7 +131,7 @@ inline uint32_t Environment::DomainFlag::count() const {
return fields_[kCount];
}

inline Environment::TickInfo::TickInfo() : in_tick_(false), last_threw_(false) {
inline Environment::TickInfo::TickInfo() {
for (int i = 0; i < kFieldsCount; ++i)
fields_[i] = 0;
}
Expand All @@ -130,34 +144,18 @@ inline int Environment::TickInfo::fields_count() const {
return kFieldsCount;
}

inline bool Environment::TickInfo::in_tick() const {
return in_tick_;
}

inline uint32_t Environment::TickInfo::index() const {
return fields_[kIndex];
}

inline bool Environment::TickInfo::last_threw() const {
return last_threw_;
}

inline uint32_t Environment::TickInfo::length() const {
return fields_[kLength];
}

inline void Environment::TickInfo::set_in_tick(bool value) {
in_tick_ = value;
}

inline void Environment::TickInfo::set_index(uint32_t value) {
fields_[kIndex] = value;
}

inline void Environment::TickInfo::set_last_threw(bool value) {
last_threw_ = value;
}

inline Environment::ArrayBufferAllocatorInfo::ArrayBufferAllocatorInfo() {
for (int i = 0; i < kFieldsCount; ++i)
fields_[i] = 0;
Expand Down Expand Up @@ -223,6 +221,7 @@ inline Environment::Environment(v8::Local<v8::Context> context,
using_domains_(false),
printed_error_(false),
trace_sync_io_(false),
makecallback_cntr_(0),
async_wrap_uid_(0),
debugger_agent_(this),
http_parser_buffer_(nullptr),
Expand Down
22 changes: 6 additions & 16 deletions src/env.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ using v8::Message;
using v8::StackFrame;
using v8::StackTrace;
using v8::TryCatch;
using v8::Value;

void Environment::PrintSyncTrace() const {
if (!trace_sync_io_)
Expand Down Expand Up @@ -64,10 +65,10 @@ void Environment::PrintSyncTrace() const {
}


bool Environment::KickNextTick() {
bool Environment::KickNextTick(Environment::AsyncCallbackScope* scope) {
TickInfo* info = tick_info();

if (info->in_tick()) {
if (scope->in_makecallback()) {
return true;
}

Expand All @@ -80,21 +81,10 @@ bool Environment::KickNextTick() {
return true;
}

info->set_in_tick(true);
Local<Value> ret =
tick_callback_function()->Call(process_object(), 0, nullptr);

// process nextTicks after call
TryCatch try_catch;
try_catch.SetVerbose(true);
tick_callback_function()->Call(process_object(), 0, nullptr);

info->set_in_tick(false);

if (try_catch.HasCaught()) {
info->set_last_threw(true);
return false;
}

return true;
return !ret.IsEmpty();
}

} // namespace node
22 changes: 15 additions & 7 deletions src/env.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -314,6 +314,19 @@ class Environment {
DISALLOW_COPY_AND_ASSIGN(AsyncHooks);
};

class AsyncCallbackScope {
public:
explicit AsyncCallbackScope(Environment* env);
~AsyncCallbackScope();

inline bool in_makecallback();

private:
Environment* env_;

DISALLOW_COPY_AND_ASSIGN(AsyncCallbackScope);
};

class DomainFlag {
public:
inline uint32_t* fields();
Expand All @@ -338,13 +351,9 @@ class Environment {
public:
inline uint32_t* fields();
inline int fields_count() const;
inline bool in_tick() const;
inline bool last_threw() const;
inline uint32_t index() const;
inline uint32_t length() const;
inline void set_in_tick(bool value);
inline void set_index(uint32_t value);
inline void set_last_threw(bool value);

private:
friend class Environment; // So we can call the constructor.
Expand All @@ -357,8 +366,6 @@ class Environment {
};

uint32_t fields_[kFieldsCount];
bool in_tick_;
bool last_threw_;

DISALLOW_COPY_AND_ASSIGN(TickInfo);
};
Expand Down Expand Up @@ -466,7 +473,7 @@ class Environment {

inline int64_t get_async_wrap_uid();

bool KickNextTick();
bool KickNextTick(AsyncCallbackScope* scope);

inline uint32_t* heap_statistics_buffer() const;
inline void set_heap_statistics_buffer(uint32_t* pointer);
Expand Down Expand Up @@ -569,6 +576,7 @@ class Environment {
bool using_domains_;
bool printed_error_;
bool trace_sync_io_;
size_t makecallback_cntr_;
int64_t async_wrap_uid_;
debugger::Agent debugger_agent_;

Expand Down
51 changes: 25 additions & 26 deletions src/node.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1127,10 +1127,10 @@ void SetupPromises(const FunctionCallbackInfo<Value>& args) {


Local<Value> MakeCallback(Environment* env,
Local<Value> recv,
const Local<Function> callback,
int argc,
Local<Value> argv[]) {
Local<Value> recv,
const Local<Function> callback,
int argc,
Local<Value> argv[]) {
// If you hit this assertion, you forgot to enter the v8::Context first.
CHECK_EQ(env->context(), env->isolate()->GetCurrentContext());

Expand All @@ -1140,6 +1140,8 @@ Local<Value> MakeCallback(Environment* env,
bool ran_init_callback = false;
bool has_domain = false;

Environment::AsyncCallbackScope callback_scope(env);

// TODO(trevnorris): Adding "_asyncQueue" to the "this" in the init callback
// is a horrible way to detect usage. Rethink how detection should happen.
if (recv->IsObject()) {
Expand All @@ -1160,52 +1162,46 @@ Local<Value> MakeCallback(Environment* env,
}
}

TryCatch try_catch;
try_catch.SetVerbose(true);

if (has_domain) {
Local<Value> enter_v = domain->Get(env->enter_string());
if (enter_v->IsFunction()) {
enter_v.As<Function>()->Call(domain, 0, nullptr);
if (try_catch.HasCaught())
return Undefined(env->isolate());
if (enter_v.As<Function>()->Call(domain, 0, nullptr).IsEmpty()) {
FatalError("node::MakeCallback",
"domain enter callback threw, please report this");
}
}
}

if (ran_init_callback && !pre_fn.IsEmpty()) {
try_catch.SetVerbose(false);
pre_fn->Call(object, 0, nullptr);
if (try_catch.HasCaught())
if (pre_fn->Call(object, 0, nullptr).IsEmpty())
FatalError("node::MakeCallback", "pre hook threw");
try_catch.SetVerbose(true);
}

Local<Value> ret = callback->Call(recv, argc, argv);

if (ran_init_callback && !post_fn.IsEmpty()) {
try_catch.SetVerbose(false);
post_fn->Call(object, 0, nullptr);
if (try_catch.HasCaught())
if (post_fn->Call(object, 0, nullptr).IsEmpty())
FatalError("node::MakeCallback", "post hook threw");
try_catch.SetVerbose(true);
}

if (ret.IsEmpty()) {
return Undefined(env->isolate());
}

if (has_domain) {
Local<Value> exit_v = domain->Get(env->exit_string());
if (exit_v->IsFunction()) {
exit_v.As<Function>()->Call(domain, 0, nullptr);
if (try_catch.HasCaught())
return Undefined(env->isolate());
if (exit_v.As<Function>()->Call(domain, 0, nullptr).IsEmpty()) {
FatalError("node::MakeCallback",
"domain exit callback threw, please report this");
}
}
}

if (try_catch.HasCaught()) {
if (!env->KickNextTick(&callback_scope)) {
return Undefined(env->isolate());
}

if (!env->KickNextTick())
return Undefined(env->isolate());

return ret;
}

Expand Down Expand Up @@ -4154,7 +4150,10 @@ static void StartNodeInstance(void* arg) {
if (instance_data->use_debug_agent())
StartDebug(env, debug_wait_connect);

LoadEnvironment(env);
{
Environment::AsyncCallbackScope callback_scope(env);
LoadEnvironment(env);
}

env->set_trace_sync_io(trace_sync_io);

Expand Down
Loading