Improve stack traces for async functions

This patch tracks the stack of async functions differently from other
Promise async stack tracking. With this patch, the stack trace of a
callstack of async functions should look similarly to the call stack
if all of the functions were synchronous. An example can be found in
the updated test expectations: https://codereview.chromium.org/2362923002 .

The new stack traces are implemented using existing mechanisms in the
inspector. The inspector has two ways to save async stack traces: recurring
and non-recurring stacks. An example of a non-recurring stack is setTimeout,
and a recurring one is saved for setInterval. Recurring stacks are deleted
only when a special "cancel" function is called, rather than being deleted
after being used the first time. Previous Promise async stack tracking always
used non-recurring stacks.

For async functions, this patch saves a recurring stack. The top frame of
the stack is duplicated, as the resuming function contains a similar frame;
the devtools frontend is responsible for removing or marking this frame,
which it can do based on seeing the [async function] line which follows it.
The second frame will instead be provided by the resuming execution
context. The recurring stack is saved when the async function is entered, and
it is deleted from a finally block. The id of the stack is saved in the outer
Promise being constructed by the async function. When an intermediate
throwaway Promise will be triggered as a reaction, it will be identified as
such based on its debugging metadata, and the corresponding async function's
recurring stack will be used.

BUG=v8:4483

Review-Url: https://codereview.chromium.org/2357423002
Cr-Commit-Position: refs/heads/master@{#39695}
This commit is contained in:
littledan 2016-09-23 15:23:50 -07:00 committed by Commit bot
parent 72b01e4a41
commit f296dad962
9 changed files with 116 additions and 70 deletions

View File

@ -72,6 +72,10 @@ enum ContextLookupFlags {
async_function_await_caught) \
V(ASYNC_FUNCTION_AWAIT_UNCAUGHT_INDEX, JSFunction, \
async_function_await_uncaught) \
V(ASYNC_FUNCTION_PROMISE_CREATE_INDEX, JSFunction, \
async_function_promise_create) \
V(ASYNC_FUNCTION_PROMISE_RELEASE_INDEX, JSFunction, \
async_function_promise_release) \
V(DERIVED_GET_TRAP_INDEX, JSFunction, derived_get_trap) \
V(ERROR_FUNCTION_INDEX, JSFunction, error_function) \
V(ERROR_TO_STRING, JSFunction, error_to_string) \

View File

@ -199,6 +199,7 @@
V(normal_ic_symbol) \
V(not_mapped_symbol) \
V(premonomorphic_symbol) \
V(promise_async_stack_id_symbol) \
V(promise_debug_marker_symbol) \
V(promise_deferred_reactions_symbol) \
V(promise_forwarding_handler_symbol) \

View File

@ -20,8 +20,10 @@ namespace {
const char stepIntoV8MethodName[] = "stepIntoStatement";
const char stepOutV8MethodName[] = "stepOutOfFunction";
static const char v8AsyncTaskEventEnqueue[] = "enqueue";
static const char v8AsyncTaskEventEnqueueRecurring[] = "enqueueRecurring";
static const char v8AsyncTaskEventWillHandle[] = "willHandle";
static const char v8AsyncTaskEventDidHandle[] = "didHandle";
static const char v8AsyncTaskEventCancel[] = "cancel";
inline v8::Local<v8::Boolean> v8Boolean(bool value, v8::Isolate* isolate) {
return value ? v8::True(isolate) : v8::False(isolate);
@ -653,10 +655,14 @@ void V8Debugger::handleV8AsyncTaskEvent(v8::Local<v8::Context> context,
void* ptr = reinterpret_cast<void*>(id * 2 + 1);
if (type == v8AsyncTaskEventEnqueue)
asyncTaskScheduled(name, ptr, false);
else if (type == v8AsyncTaskEventEnqueueRecurring)
asyncTaskScheduled(name, ptr, true);
else if (type == v8AsyncTaskEventWillHandle)
asyncTaskStarted(ptr);
else if (type == v8AsyncTaskEventDidHandle)
asyncTaskFinished(ptr);
else if (type == v8AsyncTaskEventCancel)
asyncTaskCanceled(ptr);
else
UNREACHABLE();
}

View File

@ -153,6 +153,7 @@ std::unique_ptr<V8StackTraceImpl> V8StackTraceImpl::create(
return result;
}
// static
std::unique_ptr<V8StackTraceImpl> V8StackTraceImpl::capture(
V8Debugger* debugger, int contextGroupId, size_t maxStackSize,
const String16& description) {

View File

@ -18,21 +18,25 @@ var IsPromise;
var NewPromiseCapability;
var PerformPromiseThen;
var PromiseCreate;
var PromiseNextMicrotaskID;
var RejectPromise;
var ResolvePromise;
utils.Import(function(from) {
AsyncFunctionNext = from.AsyncFunctionNext;
AsyncFunctionThrow = from.AsyncFunctionThrow;
IsPromise = from.IsPromise;
GlobalPromise = from.GlobalPromise;
IsPromise = from.IsPromise;
NewPromiseCapability = from.NewPromiseCapability;
PromiseCreate = from.PromiseCreate;
PerformPromiseThen = from.PerformPromiseThen;
PromiseCreate = from.PromiseCreate;
PromiseNextMicrotaskID = from.PromiseNextMicrotaskID;
RejectPromise = from.RejectPromise;
ResolvePromise = from.ResolvePromise;
});
var promiseAsyncStackIDSymbol =
utils.ImportNow("promise_async_stack_id_symbol");
var promiseHandledBySymbol =
utils.ImportNow("promise_handled_by_symbol");
var promiseForwardingHandlerSymbol =
@ -94,9 +98,7 @@ function AsyncFunctionAwait(generator, awaited, outerPromise) {
// unhandled reject events as its work is done
SET_PRIVATE(throwawayCapability.promise, promiseHasHandlerSymbol, true);
PerformPromiseThen(promise, onFulfilled, onRejected, throwawayCapability);
if (DEBUG_IS_ACTIVE && !IS_UNDEFINED(outerPromise)) {
if (DEBUG_IS_ACTIVE) {
if (IsPromise(awaited)) {
// Mark the reject handler callback to be a forwarding edge, rather
// than a meaningful catch handler
@ -108,6 +110,8 @@ function AsyncFunctionAwait(generator, awaited, outerPromise) {
SET_PRIVATE(throwawayCapability.promise, promiseHandledBySymbol,
outerPromise);
}
PerformPromiseThen(promise, onFulfilled, onRejected, throwawayCapability);
}
// Called by the parser from the desugaring of 'await' when catch
@ -122,10 +126,7 @@ function AsyncFunctionAwaitCaught(generator, awaited, outerPromise) {
if (DEBUG_IS_ACTIVE && IsPromise(awaited)) {
SET_PRIVATE(awaited, promiseHandledHintSymbol, true);
}
// Pass undefined for the outer Promise to not waste time setting up
// or following the dependency chain when this Promise is already marked
// as handled
AsyncFunctionAwait(generator, awaited, UNDEFINED);
AsyncFunctionAwait(generator, awaited, outerPromise);
}
// How the parser rejects promises from async/await desugaring
@ -133,10 +134,47 @@ function RejectPromiseNoDebugEvent(promise, reason) {
return RejectPromise(promise, reason, false);
}
function AsyncFunctionPromiseCreate() {
var promise = PromiseCreate();
if (DEBUG_IS_ACTIVE) {
// Push the Promise under construction in an async function on
// the catch prediction stack to handle exceptions thrown before
// the first await.
%DebugPushPromise(promise);
// Assign ID and create a recurring task to save stack for future
// resumptions from await.
var id = PromiseNextMicrotaskID();
SET_PRIVATE(promise, promiseAsyncStackIDSymbol, id);
%DebugAsyncTaskEvent({
type: "enqueueRecurring",
id: id,
name: "async function",
});
}
return promise;
}
function AsyncFunctionPromiseRelease(promise) {
if (DEBUG_IS_ACTIVE) {
// Cancel
var id = GET_PRIVATE(promise, promiseAsyncStackIDSymbol);
%DebugAsyncTaskEvent({
type: "cancel",
id: id,
name: "async function",
});
// Pop the Promise under construction in an async function on
// from catch prediction stack.
%DebugPopPromise();
}
}
%InstallToContext([
"async_function_await_caught", AsyncFunctionAwaitCaught,
"async_function_await_uncaught", AsyncFunctionAwaitUncaught,
"reject_promise_no_debug_event", RejectPromiseNoDebugEvent,
"async_function_promise_create", AsyncFunctionPromiseCreate,
"async_function_promise_release", AsyncFunctionPromiseRelease,
]);
})

View File

@ -198,6 +198,7 @@ function PostNatives(utils) {
"PerformPromiseThen",
"PromiseThen",
"PromiseCreate",
"PromiseNextMicrotaskID",
"RegExpSubclassExecJS",
"RegExpSubclassMatch",
"RegExpSubclassReplace",
@ -217,6 +218,7 @@ function PostNatives(utils) {
// From runtime:
"is_concat_spreadable_symbol",
"iterator_symbol",
"promise_async_stack_id_symbol",
"promise_result_symbol",
"promise_state_symbol",
"promise_forwarding_handler_symbol",

View File

@ -12,6 +12,8 @@
// Imports
var InternalArray = utils.InternalArray;
var promiseAsyncStackIDSymbol =
utils.ImportNow("promise_async_stack_id_symbol");
var promiseHandledBySymbol =
utils.ImportNow("promise_handled_by_symbol");
var promiseForwardingHandlerSymbol =
@ -32,8 +34,10 @@ var promiseResultSymbol = utils.ImportNow("promise_result_symbol");
var SpeciesConstructor;
var speciesSymbol = utils.ImportNow("species_symbol");
var toStringTagSymbol = utils.ImportNow("to_string_tag_symbol");
var ObjectHasOwnProperty;
utils.Import(function(from) {
ObjectHasOwnProperty = from.ObjectHasOwnProperty;
SpeciesConstructor = from.SpeciesConstructor;
});
@ -46,6 +50,10 @@ const kRejected = -1;
var lastMicrotaskId = 0;
function PromiseNextMicrotaskID() {
return ++lastMicrotaskId;
}
// ES#sec-createresolvingfunctions
// CreateResolvingFunctions ( promise )
function CreateResolvingFunctions(promise, debugEvent) {
@ -187,9 +195,24 @@ function PromiseEnqueue(value, tasks, deferreds, status) {
}
});
if (instrumenting) {
id = ++lastMicrotaskId;
name = status === kFulfilled ? "Promise.resolve" : "Promise.reject";
%DebugAsyncTaskEvent({ type: "enqueue", id: id, name: name });
// In an async function, reuse the existing stack related to the outer
// Promise. Otherwise, e.g. in a direct call to then, save a new stack.
// Promises with multiple reactions with one or more of them being async
// functions will not get a good stack trace, as async functions require
// different stacks from direct Promise use, but we save and restore a
// stack once for all reactions. TODO(littledan): Improve this case.
if (!IS_UNDEFINED(deferreds) &&
HAS_PRIVATE(deferreds.promise, promiseHandledBySymbol) &&
HAS_PRIVATE(GET_PRIVATE(deferreds.promise, promiseHandledBySymbol),
promiseAsyncStackIDSymbol)) {
id = GET_PRIVATE(GET_PRIVATE(deferreds.promise, promiseHandledBySymbol),
promiseAsyncStackIDSymbol);
name = "async function";
} else {
id = PromiseNextMicrotaskID();
name = status === kFulfilled ? "Promise.resolve" : "Promise.reject";
%DebugAsyncTaskEvent({ type: "enqueue", id: id, name: name });
}
}
}
@ -214,6 +237,7 @@ function PromiseAttachCallbacks(promise, deferred, onResolve, onReject) {
SET_PRIVATE(promise, promiseFulfillReactionsSymbol, resolveCallbacks);
SET_PRIVATE(promise, promiseRejectReactionsSymbol, rejectCallbacks);
SET_PRIVATE(promise, promiseDeferredReactionsSymbol, UNDEFINED);
} else {
maybeResolveCallbacks.push(onResolve, deferred);
GET_PRIVATE(promise, promiseRejectReactionsSymbol).push(onReject, deferred);
@ -292,7 +316,7 @@ function ResolvePromise(promise, resolution) {
// Mark the dependency of the new promise on the resolution
SET_PRIVATE(resolution, promiseHandledBySymbol, promise);
}
id = ++lastMicrotaskId;
id = PromiseNextMicrotaskID();
before_debug_event = {
type: "willHandle",
id: id,
@ -671,6 +695,7 @@ utils.Export(function(to) {
to.IsPromise = IsPromise;
to.PromiseCreate = PromiseCreate;
to.PromiseThen = PromiseThen;
to.PromiseNextMicrotaskID = PromiseNextMicrotaskID;
to.GlobalPromise = GlobalPromise;
to.NewPromiseCapability = NewPromiseCapability;

View File

@ -3130,24 +3130,22 @@ Block* Parser::BuildParameterInitializationBlock(
}
Block* Parser::BuildRejectPromiseOnException(Block* inner_block, bool* ok) {
// .promise = %CreatePromise();
// .debug_is_active = %_DebugIsActive();
// if (.debug_is_active) %DebugPushPromise(.promise);
// .promise = %AsyncFunctionPromiseCreate();
// try {
// <inner_block>
// } catch (.catch) {
// %RejectPromise(.promise, .catch);
// return .promise;
// } finally {
// if (.debug_is_active) %DebugPopPromise();
// %AsyncFunctionPromiseRelease(.promise);
// }
Block* result = factory()->NewBlock(nullptr, 4, true, kNoSourcePosition);
Block* result = factory()->NewBlock(nullptr, 2, true, kNoSourcePosition);
// .promise = %CreatePromise();
// .promise = %AsyncFunctionPromiseCreate();
Statement* set_promise;
{
Expression* create_promise = factory()->NewCallRuntime(
Context::PROMISE_CREATE_INDEX,
Context::ASYNC_FUNCTION_PROMISE_CREATE_INDEX,
new (zone()) ZoneList<Expression*>(0, zone()), kNoSourcePosition);
Assignment* assign_promise = factory()->NewAssignment(
Token::INIT, factory()->NewVariableProxy(PromiseVariable()),
@ -3157,37 +3155,6 @@ Block* Parser::BuildRejectPromiseOnException(Block* inner_block, bool* ok) {
}
result->statements()->Add(set_promise, zone());
Variable* debug_is_active =
scope()->NewTemporary(ast_value_factory()->empty_string());
// .debug_is_active = %_DebugIsActive();
Statement* set_debug_is_active;
{
Expression* call_debug_is_active = factory()->NewCallRuntime(
Runtime::kInlineDebugIsActive,
new (zone()) ZoneList<Expression*>(0, zone()), kNoSourcePosition);
Assignment* assign_debug_is_active = factory()->NewAssignment(
Token::INIT, factory()->NewVariableProxy(debug_is_active),
call_debug_is_active, kNoSourcePosition);
set_debug_is_active = factory()->NewExpressionStatement(
assign_debug_is_active, kNoSourcePosition);
}
result->statements()->Add(set_debug_is_active, zone());
// if (.debug_is_active) %DebugPushPromise(.promise);
Statement* conditionally_debug_push_promise;
{
ZoneList<Expression*>* args = new (zone()) ZoneList<Expression*>(1, zone());
args->Add(factory()->NewVariableProxy(PromiseVariable()), zone());
Expression* call_push_promise = factory()->NewCallRuntime(
Runtime::kDebugPushPromise, args, kNoSourcePosition);
Statement* debug_push_promise =
factory()->NewExpressionStatement(call_push_promise, kNoSourcePosition);
conditionally_debug_push_promise = factory()->NewIfStatement(
factory()->NewVariableProxy(debug_is_active), debug_push_promise,
factory()->NewEmptyStatement(kNoSourcePosition), kNoSourcePosition);
}
result->statements()->Add(conditionally_debug_push_promise, zone());
// catch (.catch) { return %RejectPromise(.promise, .catch), .promise }
Scope* catch_scope = NewScope(CATCH_SCOPE);
catch_scope->set_is_hidden();
@ -3212,19 +3179,17 @@ Block* Parser::BuildRejectPromiseOnException(Block* inner_block, bool* ok) {
factory()->NewBlock(nullptr, 1, true, kNoSourcePosition);
outer_try_block->statements()->Add(try_catch_statement, zone());
// finally { if (.debug_is_active) %DebugPopPromise(); }
// finally { %AsyncFunctionPromiseRelease(.promise) }
Block* finally_block =
factory()->NewBlock(nullptr, 1, true, kNoSourcePosition);
{
ZoneList<Expression*>* args = new (zone()) ZoneList<Expression*>(0, zone());
Expression* call_pop_promise = factory()->NewCallRuntime(
Runtime::kDebugPopPromise, args, kNoSourcePosition);
Statement* debug_pop_promise =
factory()->NewExpressionStatement(call_pop_promise, kNoSourcePosition);
Statement* conditionally_debug_pop_promise = factory()->NewIfStatement(
factory()->NewVariableProxy(debug_is_active), debug_pop_promise,
factory()->NewEmptyStatement(kNoSourcePosition), kNoSourcePosition);
finally_block->statements()->Add(conditionally_debug_pop_promise, zone());
ZoneList<Expression*>* args = new (zone()) ZoneList<Expression*>(1, zone());
args->Add(factory()->NewVariableProxy(PromiseVariable()), zone());
Expression* call_promise_release = factory()->NewCallRuntime(
Context::ASYNC_FUNCTION_PROMISE_RELEASE_INDEX, args, kNoSourcePosition);
Statement* promise_release = factory()->NewExpressionStatement(
call_promise_release, kNoSourcePosition);
finally_block->statements()->Add(promise_release, zone());
}
Statement* try_finally_statement = factory()->NewTryFinallyStatement(

View File

@ -5,9 +5,14 @@
// Flags: --harmony-async-await --expose-debug-as debug --allow-natives-syntax
// The test observes the callbacks that async/await makes to the inspector
// to make accurate stack traces. The limited number of events is an
// indirect indication that we are not doing extra Promise processing that
// could be associated with memory leaks (v8:5380).
// to make accurate stack traces. The pattern is based on saving a stack once
// with enqueueRecurring and restoring it multiple times.
// Additionally, the limited number of events is an indirect indication that
// we are not doing extra Promise processing that could be associated with memory
// leaks (v8:5380). In particular, no stacks are saved and restored for extra
// Promise handling on throwaway Promises.
// TODO(littledan): Write a test that demonstrates that the memory leak in
// the exception case is fixed.
@ -16,14 +21,14 @@ Debug = debug.Debug;
var base_id = -1;
var exception = null;
var expected = [
'enqueue #1',
'enqueueRecurring #1',
'willHandle #1',
'then #1',
'enqueue #2',
'didHandle #1',
'willHandle #2',
'willHandle #1',
'then #2',
'didHandle #2',
'cancel #1',
'didHandle #1',
];
function assertLog(msg) {
@ -41,8 +46,7 @@ function listener(event, exec_state, event_data, data) {
if (base_id < 0)
base_id = event_data.id();
var id = event_data.id() - base_id + 1;
assertTrue("Promise.resolve" == event_data.name() ||
"PromiseResolveThenableJob" == event_data.name());
assertTrue("async function" == event_data.name());
assertLog(event_data.type() + " #" + id);
} catch (e) {
print(e + e.stack)