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

Jump to bottom

async_hooks,async_wrap: fixups and fewer aborts #14722

Closed
wants to merge 4 commits into from
Closed

async_hooks,async_wrap: fixups and fewer aborts #14722

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
f5ef678
async_wrap: return undefined if domain is disposed
trevnorris Aug 9, 2017
0f863d0
async_hooks: improve comments and function names
trevnorris Aug 2, 2017
f2c1638
async_wrap: unroll unnecessarily DRY code
trevnorris Aug 3, 2017
14c3a5e
async_hooks: don't abort unnecessarily
trevnorris Aug 3, 2017
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
258 changes: 146 additions & 112 deletions lib/async_hooks.js
View file
Open in desktop

Large diffs are not rendered by default.

3 changes: 3 additions & 0 deletions lib/internal/errors.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -101,6 +101,8 @@ module.exports = exports = {
// Note: Please try to keep these in alphabetical order
E('ERR_ARG_NOT_ITERABLE', '%s must be iterable');
E('ERR_ASSERTION', '%s');
E('ERR_ASYNC_CALLBACK', (name) => `${name} must be a function`);
Copy link
Contributor

Choose a reason for hiding this comment

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

Could you add perfunctory tests in test/parallel/test-internal-errors.js as per https://github.com/nodejs/node/blob/master/doc/guides/using-internal-errors.md#testing-new-errors

Copy link
Contributor Author

Choose a reason for hiding this comment

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

done

E('ERR_ASYNC_TYPE', (s) => `Invalid name for async "type": ${s}`);
E('ERR_BUFFER_OUT_OF_BOUNDS', bufferOutOfBounds);
E('ERR_CHILD_CLOSED_BEFORE_REPLY', 'Child closed before reply received');
E('ERR_CONSOLE_WRITABLE_STREAM',
Expand Down Expand Up @@ -188,6 +190,7 @@ E('ERR_INVALID_ARRAY_LENGTH',
assert.strictEqual(typeof actual, 'number');
return `The array "${name}" (length ${actual}) must be of length ${len}.`;
});
E('ERR_INVALID_ASYNC_ID', (type, id) => `Invalid ${type} value: ${id}`);
E('ERR_INVALID_BUFFER_SIZE', 'Buffer size must be a multiple of %s');
E('ERR_INVALID_CALLBACK', 'Callback must be a function');
E('ERR_INVALID_CHAR', 'Invalid character in %s');
Expand Down
107 changes: 46 additions & 61 deletions src/async-wrap.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -54,6 +54,7 @@ using v8::String;
using v8::Symbol;
using v8::TryCatch;
using v8::Uint32Array;
using v8::Undefined;
using v8::Value;

using AsyncHooks = node::Environment::AsyncHooks;
Expand Down Expand Up @@ -164,6 +165,7 @@ static void DestroyIdsCb(uv_timer_t* handle) {
if (ret.IsEmpty()) {
ClearFatalExceptionHandlers(env);
FatalException(env->isolate(), try_catch);
UNREACHABLE();
}
}
} while (!env->destroy_ids_list()->empty());
Expand Down Expand Up @@ -217,69 +219,43 @@ bool DomainExit(Environment* env, v8::Local<v8::Object> object) {
}


static bool PreCallbackExecution(AsyncWrap* wrap, bool run_domain_cbs) {
if (wrap->env()->using_domains() && run_domain_cbs) {
bool is_disposed = DomainEnter(wrap->env(), wrap->object());
if (is_disposed)
return false;
}

return AsyncWrap::EmitBefore(wrap->env(), wrap->get_id());
}


bool AsyncWrap::EmitBefore(Environment* env, double async_id) {
void AsyncWrap::EmitBefore(Environment* env, double async_id) {
AsyncHooks* async_hooks = env->async_hooks();

if (async_hooks->fields()[AsyncHooks::kBefore] > 0) {
Local<Value> uid = Number::New(env->isolate(), async_id);
Local<Function> fn = env->async_hooks_before_function();
TryCatch try_catch(env->isolate());
MaybeLocal<Value> ar = fn->Call(
env->context(), Undefined(env->isolate()), 1, &uid);
if (ar.IsEmpty()) {
ClearFatalExceptionHandlers(env);
FatalException(env->isolate(), try_catch);
return false;
}
}

return true;
}


static bool PostCallbackExecution(AsyncWrap* wrap, bool run_domain_cbs) {
if (!AsyncWrap::EmitAfter(wrap->env(), wrap->get_id()))
return false;
if (async_hooks->fields()[AsyncHooks::kBefore] == 0)
return;

if (wrap->env()->using_domains() && run_domain_cbs) {
bool is_disposed = DomainExit(wrap->env(), wrap->object());
if (is_disposed)
return false;
Local<Value> uid = Number::New(env->isolate(), async_id);
Local<Function> fn = env->async_hooks_before_function();
TryCatch try_catch(env->isolate());
MaybeLocal<Value> ar = fn->Call(
env->context(), Undefined(env->isolate()), 1, &uid);
if (ar.IsEmpty()) {
ClearFatalExceptionHandlers(env);
FatalException(env->isolate(), try_catch);
UNREACHABLE();
}

return true;
}

bool AsyncWrap::EmitAfter(Environment* env, double async_id) {

void AsyncWrap::EmitAfter(Environment* env, double async_id) {
AsyncHooks* async_hooks = env->async_hooks();

// If the callback failed then the after() hooks will be called at the end
// of _fatalException().
if (async_hooks->fields()[AsyncHooks::kAfter] > 0) {
Local<Value> uid = Number::New(env->isolate(), async_id);
Local<Function> fn = env->async_hooks_after_function();
TryCatch try_catch(env->isolate());
MaybeLocal<Value> ar = fn->Call(
env->context(), Undefined(env->isolate()), 1, &uid);
if (ar.IsEmpty()) {
ClearFatalExceptionHandlers(env);
FatalException(env->isolate(), try_catch);
return false;
}
}
if (async_hooks->fields()[AsyncHooks::kAfter] == 0)
return;

return true;
// If the user's callback failed then the after() hooks will be called at the
// end of _fatalException().
Local<Value> uid = Number::New(env->isolate(), async_id);
Local<Function> fn = env->async_hooks_after_function();
TryCatch try_catch(env->isolate());
MaybeLocal<Value> ar = fn->Call(
env->context(), Undefined(env->isolate()), 1, &uid);
if (ar.IsEmpty()) {
ClearFatalExceptionHandlers(env);
FatalException(env->isolate(), try_catch);
UNREACHABLE();
}
}

class PromiseWrap : public AsyncWrap {
Expand Down Expand Up @@ -372,9 +348,9 @@ static void PromiseHook(PromiseHookType type, Local<Promise> promise,
CHECK_NE(wrap, nullptr);
if (type == PromiseHookType::kBefore) {
env->async_hooks()->push_ids(wrap->get_id(), wrap->get_trigger_id());
PreCallbackExecution(wrap, false);
AsyncWrap::EmitBefore(wrap->env(), wrap->get_id());
} else if (type == PromiseHookType::kAfter) {
PostCallbackExecution(wrap, false);
AsyncWrap::EmitAfter(wrap->env(), wrap->get_id());
if (env->current_async_id() == wrap->get_id()) {
// This condition might not be true if async_hooks was enabled during
// the promise callback execution.
Expand Down Expand Up @@ -686,19 +662,28 @@ MaybeLocal<Value> AsyncWrap::MakeCallback(const Local<Function> cb,
get_id(),
get_trigger_id());

if (!PreCallbackExecution(this, true)) {
return MaybeLocal<Value>();
// Return v8::Undefined() because returning an empty handle will cause
// ToLocalChecked() to abort.
if (env()->using_domains() && DomainEnter(env(), object())) {
return Undefined(env()->isolate());
}

// Finally... Get to running the user's callback.
// No need to check a return value because the application will exit if an
// exception occurs.
AsyncWrap::EmitBefore(env(), get_id());

MaybeLocal<Value> ret = cb->Call(env()->context(), object(), argc, argv);

if (ret.IsEmpty()) {
return ret;
}

if (!PostCallbackExecution(this, true)) {
return Local<Value>();
AsyncWrap::EmitAfter(env(), get_id());

// Return v8::Undefined() because returning an empty handle will cause
// ToLocalChecked() to abort.
if (env()->using_domains() && DomainExit(env(), object())) {
return Undefined(env()->isolate());
}

exec_scope.Dispose();
Expand Down
5 changes: 3 additions & 2 deletions src/async-wrap.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -111,8 +111,8 @@ class AsyncWrap : public BaseObject {
double id,
double trigger_id);

static bool EmitBefore(Environment* env, double id);
static bool EmitAfter(Environment* env, double id);
static void EmitBefore(Environment* env, double id);
static void EmitAfter(Environment* env, double id);

inline ProviderType provider_type() const;

Expand Down Expand Up @@ -146,6 +146,7 @@ class AsyncWrap : public BaseObject {

void LoadAsyncWrapperInfo(Environment* env);

// Return value is an indicator whether the domain was disposed.
bool DomainEnter(Environment* env, v8::Local<v8::Object> object);
bool DomainExit(Environment* env, v8::Local<v8::Object> object);

Expand Down
13 changes: 8 additions & 5 deletions src/env-inl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -127,8 +127,8 @@ inline v8::Local<v8::String> Environment::AsyncHooks::provider_string(int idx) {

inline void Environment::AsyncHooks::push_ids(double async_id,
double trigger_id) {
CHECK_GE(async_id, 0);
CHECK_GE(trigger_id, 0);
CHECK_GE(async_id, -1);
Copy link
Member

Choose a reason for hiding this comment

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

Why is -1 now a special allowed value?

Copy link
Contributor

Choose a reason for hiding this comment

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

AFAIK -1 is now used to represent a recoverable error in the graph.
https://github.com/trevnorris/node/blob/d21e3d9e7875ec8dfe478b587a932f7f3c56221c/lib/async_hooks.js#L381-L384
See the last comment in the OP Note: Still reasoning about automatically coercing undefined values in a way that won't corrupt the stack. the idea is to coerce all the places that exploded till now, because the asyncIDs where undefined, to -1 and treat those as "graph-opaque" bad actors instead of aborting.

Copy link
Member

Choose a reason for hiding this comment

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

I see. My personal opinion is that those checks should simply be skipped when AsyncHooks isn't used. Relaxing the check when AsyncHooks is used, isn't a good solution. I know that is an unpopular opinion, so I won't block it now, but I really feel we are on a steap slope to some very difficult to debug errors. In the future I want a more detailed discussion about this, unfortunately I don't have time these days.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

from commit message body:

  • id values of -1 are allowed. They indicate that the id was never
    correctly assigned to the async resource. These will appear in any
    call graph, and will only be apparent to those using the async_hooks
    module, then reported in an issue.

we can't guarantee the async id is always assigned properly, and was one reason applications were aborting. history has taught me that it's impossible to make sure the async id is always properly defined because of how much node internals can be abused. so -1 is to indicate that the async/trigger id wasn't properly set.

i'm working on one more commit to translate nan values to -1, but there are some edge case when tracking the stack that can leave the application in a bad state. if i can't figure those out soon will push it up regardless and look for feedback.

Copy link
Contributor

Choose a reason for hiding this comment

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

Ack.
I tend to agree, but the -1 trick currently isn't public API, so we could change it if we agree on a better solution.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@AndreasMadsen

My personal opinion is that those checks should simply be skipped when AsyncHooks isn't used.

It's not explicitly documented, but one goal of the API was to allow async_hooks.executionAsyncId() and async_hooks.triggerAsyncId() to be used regardless whether a hook has been enabled or not. We could possibly do the same trick that we do with domains and enable the checks if async_hooks is required, but domains is for performance reasons. Always performing these checks should be possible without ever causing the application to crash, and the additional cost probably isn't measurable.

Relaxing the check when AsyncHooks is used, isn't a good solution.

I fully agree'd with this until I realized how badly node core can be abused by allowing users to pass in arbitrary objects instead of ones created by core constructors (e.g. timers). So it is necessary to coerce, at minimum, async ids of undefined.

I really feel we are on a steap slope to some very difficult to debug errors.

Again, I fully agree'd with this until I came to terms with the reason pointed out above.

@refack

I tend to agree, but the -1 trick currently isn't public API, so we could change it if we agree on a better solution.

I was thinking about doing something more complex, like

  • -1 - indicates the async_id_symbol was undefined
  • -2 - indicates async_id_symbol was set but not a positive integer

etc. But figured that's too much to anticipate, and wouldn't be worth the time.

Copy link
Member

Choose a reason for hiding this comment

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

Please don't document it. I'm on vacation and of all the things I disagree with, our general approach to being robust against implementation errors is what I disagree the most about.

Copy link
Contributor

Choose a reason for hiding this comment

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

👍 on keeping this an "internal implementation" detail for now.

CHECK_GE(trigger_id, -1);

ids_stack_.push({ uid_fields_[kCurrentAsyncId],
uid_fields_[kCurrentTriggerId] });
Expand Down Expand Up @@ -176,20 +176,23 @@ inline void Environment::AsyncHooks::clear_id_stack() {
inline Environment::AsyncHooks::InitScope::InitScope(
Environment* env, double init_trigger_id)
: env_(env),
uid_fields_(env->async_hooks()->uid_fields()) {
env->async_hooks()->push_ids(uid_fields_[AsyncHooks::kCurrentAsyncId],
uid_fields_ref_(env->async_hooks()->uid_fields()) {
CHECK_GE(init_trigger_id, -1);
env->async_hooks()->push_ids(uid_fields_ref_[AsyncHooks::kCurrentAsyncId],
init_trigger_id);
}

inline Environment::AsyncHooks::InitScope::~InitScope() {
env_->async_hooks()->pop_ids(uid_fields_[AsyncHooks::kCurrentAsyncId]);
env_->async_hooks()->pop_ids(uid_fields_ref_[AsyncHooks::kCurrentAsyncId]);
}

inline Environment::AsyncHooks::ExecScope::ExecScope(
Environment* env, double async_id, double trigger_id)
: env_(env),
async_id_(async_id),
disposed_(false) {
CHECK_GE(async_id, -1);
CHECK_GE(trigger_id, -1);
env->async_hooks()->push_ids(async_id, trigger_id);
}

Expand Down
10 changes: 4 additions & 6 deletions src/env.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -401,7 +401,7 @@ class Environment {

private:
Environment* env_;
double* uid_fields_;
double* uid_fields_ref_;

DISALLOW_COPY_AND_ASSIGN(InitScope);
};
Expand Down Expand Up @@ -434,12 +434,10 @@ class Environment {
v8::Isolate* isolate_;
// Stores the ids of the current execution context stack.
std::stack<struct node_async_ids> ids_stack_;
// Used to communicate state between C++ and JS cheaply. Is placed in an
// Uint32Array() and attached to the async_wrap object.
// Attached to a Uint32Array that tracks the number of active hooks for
// each type.
uint32_t fields_[kFieldsCount];
// Used to communicate ids between C++ and JS cheaply. Placed in a
// Float64Array and attached to the async_wrap object. Using a double only
// gives us 2^53-1 unique ids, but that should be sufficient.
// Attached to a Float64Array that tracks the state of async resources.
double uid_fields_[kUidFieldsCount];

DISALLOW_COPY_AND_ASSIGN(AsyncHooks);
Expand Down
8 changes: 4 additions & 4 deletions src/node.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1328,8 +1328,9 @@ MaybeLocal<Value> MakeCallback(Environment* env,
asyncContext.trigger_async_id);

if (asyncContext.async_id != 0) {
if (!AsyncWrap::EmitBefore(env, asyncContext.async_id))
return Local<Value>();
// No need to check a return value because the application will exit if
// an exception occurs.
AsyncWrap::EmitBefore(env, asyncContext.async_id);
}

ret = callback->Call(env->context(), recv, argc, argv);
Expand All @@ -1342,8 +1343,7 @@ MaybeLocal<Value> MakeCallback(Environment* env,
}

if (asyncContext.async_id != 0) {
if (!AsyncWrap::EmitAfter(env, asyncContext.async_id))
return Local<Value>();
AsyncWrap::EmitAfter(env, asyncContext.async_id);
}
}

Expand Down
16 changes: 12 additions & 4 deletions test/async-hooks/test-embedder.api.async-resource.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -12,10 +12,18 @@ const { checkInvocations } = require('./hook-checks');
const hooks = initHooks();
hooks.enable();

assert.throws(() => new AsyncResource(),
/^TypeError: type must be a string with length > 0$/);
assert.throws(() => new AsyncResource('invalid_trigger_id', null),
/^RangeError: triggerAsyncId must be an unsigned integer$/);
assert.throws(() => {
new AsyncResource();
}, common.expectsError({
code: 'ERR_ASYNC_TYPE',
type: TypeError,
}));
assert.throws(() => {
new AsyncResource('invalid_trigger_id', null);
}, common.expectsError({
code: 'ERR_INVALID_ASYNC_ID',
type: RangeError,
}));

assert.strictEqual(
new AsyncResource('default_trigger_id').triggerAsyncId(),
Expand Down
16 changes: 8 additions & 8 deletions test/async-hooks/test-emit-before-after.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,25 +8,25 @@ const initHooks = require('./init-hooks');

switch (process.argv[2]) {
case 'test_invalid_async_id':
async_hooks.emitBefore(-1, 1);
async_hooks.emitBefore(-2, 1);
return;
case 'test_invalid_trigger_id':
async_hooks.emitBefore(1, -1);
async_hooks.emitBefore(1, -2);
return;
}
assert.ok(!process.argv[2]);


const c1 = spawnSync(process.execPath, [__filename, 'test_invalid_async_id']);
assert.strictEqual(c1.stderr.toString().split(/[\r\n]+/g)[0],
'Error: before(): asyncId or triggerAsyncId is less than ' +
'zero (asyncId: -1, triggerAsyncId: 1)');
assert.strictEqual(
c1.stderr.toString().split(/[\r\n]+/g)[0],
'RangeError [ERR_INVALID_ASYNC_ID]: Invalid asyncId value: -2');
assert.strictEqual(c1.status, 1);

const c2 = spawnSync(process.execPath, [__filename, 'test_invalid_trigger_id']);
assert.strictEqual(c2.stderr.toString().split(/[\r\n]+/g)[0],
'Error: before(): asyncId or triggerAsyncId is less than ' +
'zero (asyncId: 1, triggerAsyncId: -1)');
assert.strictEqual(
c2.stderr.toString().split(/[\r\n]+/g)[0],
'RangeError [ERR_INVALID_ASYNC_ID]: Invalid triggerAsyncId value: -2');
assert.strictEqual(c2.status, 1);

const expectedId = async_hooks.newUid();
Expand Down
24 changes: 18 additions & 6 deletions test/async-hooks/test-emit-init.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,12 +25,24 @@ const hooks1 = initHooks({

hooks1.enable();

assert.throws(() => async_hooks.emitInit(),
/^RangeError: asyncId must be an unsigned integer$/);
assert.throws(() => async_hooks.emitInit(expectedId),
/^TypeError: type must be a string with length > 0$/);
assert.throws(() => async_hooks.emitInit(expectedId, expectedType, -1),
/^RangeError: triggerAsyncId must be an unsigned integer$/);
assert.throws(() => {
async_hooks.emitInit();
}, common.expectsError({
code: 'ERR_INVALID_ASYNC_ID',
type: RangeError,
}));
assert.throws(() => {
async_hooks.emitInit(expectedId);
}, common.expectsError({
code: 'ERR_INVALID_ASYNC_ID',
type: RangeError,
}));
assert.throws(() => {
async_hooks.emitInit(expectedId, expectedType, -2);
}, common.expectsError({
code: 'ERR_INVALID_ASYNC_ID',
type: RangeError,
}));

async_hooks.emitInit(expectedId, expectedType, expectedTriggerId,
expectedResource);
Expand Down
Loading