From b98dd0af92656df4889350e63081552aced61ad7 Mon Sep 17 00:00:00 2001 From: kozyatinskiy Date: Thu, 26 Jan 2017 01:32:37 -0800 Subject: [PATCH] [inspector] added creation frame for async call chains for promises With creation frame we can show additional information with description of each async stack trace, which could help user to understand where promises were chained. At least in case of Promise.resolve().then(foo1).then(foo2) we would be able to show following stack trace for break in foo2 callback: foo2 (test.js:14:2) -- Promise.resolve (test.js:29:14)-- -- Promise.resolve (test.js:28:14)-- promiseThen (test.js:30:2) More details: https://docs.google.com/document/d/1u19N45f1gSF7M39mGsycJEK3IPyJgIXCBnWyiPeuJFE BUG=v8:5738 R=dgozman@chromium.org,gsathya@chromium.org Review-Url: https://codereview.chromium.org/2648873002 Cr-Commit-Position: refs/heads/master@{#42682} --- src/inspector/js_protocol.json | 3 +- src/inspector/v8-debugger.cc | 37 +++- src/inspector/v8-debugger.h | 2 + src/inspector/v8-stack-trace-impl.cc | 30 ++- src/inspector/v8-stack-trace-impl.h | 3 + .../debugger/async-stack-await-expected.txt | 13 +- test/inspector/debugger/async-stack-await.js | 7 +- .../async-stack-created-frame-expected.txt | 100 ++++++++++ .../debugger/async-stack-created-frame.js | 178 ++++++++++++++++++ .../async-stack-for-promise-expected.txt | 79 +++++--- .../debugger/async-stack-for-promise.js | 7 +- .../debugger/async-stacks-limit-expected.txt | 35 ++-- test/inspector/debugger/async-stacks-limit.js | 60 +++--- test/inspector/protocol-test.js | 15 ++ 14 files changed, 467 insertions(+), 102 deletions(-) create mode 100644 test/inspector/debugger/async-stack-created-frame-expected.txt create mode 100644 test/inspector/debugger/async-stack-created-frame.js diff --git a/src/inspector/js_protocol.json b/src/inspector/js_protocol.json index f8feb6c1e2..7627b5b7f5 100644 --- a/src/inspector/js_protocol.json +++ b/src/inspector/js_protocol.json @@ -201,7 +201,8 @@ "properties": [ { "name": "description", "type": "string", "optional": true, "description": "String label of this stack trace. For async traces this may be a name of the function that initiated the async call." }, { "name": "callFrames", "type": "array", "items": { "$ref": "CallFrame" }, "description": "JavaScript function name." }, - { "name": "parent", "$ref": "StackTrace", "optional": true, "description": "Asynchronous JavaScript stack trace that preceded this stack, if available." } + { "name": "parent", "$ref": "StackTrace", "optional": true, "description": "Asynchronous JavaScript stack trace that preceded this stack, if available." }, + { "name": "promiseCreationFrame", "$ref": "CallFrame", "optional": true, "experimental": true, "description": "Creation frame of the Promise which produced the next synchronous trace when resolved, if available." } ] } ], diff --git a/src/inspector/v8-debugger.cc b/src/inspector/v8-debugger.cc index a5076f9121..f4980e2f87 100644 --- a/src/inspector/v8-debugger.cc +++ b/src/inspector/v8-debugger.cc @@ -862,9 +862,32 @@ void V8Debugger::setAsyncCallStackDepth(V8DebuggerAgentImpl* agent, int depth) { if (!maxAsyncCallStackDepth) allAsyncTasksCanceled(); } +void V8Debugger::registerAsyncTaskIfNeeded(void* task) { + if (m_taskToId.find(task) != m_taskToId.end()) return; + + int id = ++m_lastTaskId; + m_taskToId[task] = id; + m_idToTask[id] = task; + if (static_cast(m_idToTask.size()) > m_maxAsyncCallStacks) { + void* taskToRemove = m_idToTask.begin()->second; + asyncTaskCanceled(taskToRemove); + } +} + void V8Debugger::asyncTaskCreated(void* task, void* parentTask) { if (!m_maxAsyncCallStackDepth) return; if (parentTask) m_parentTask[task] = parentTask; + v8::HandleScope scope(m_isolate); + // We don't need to pass context group id here because we gets this callback + // from V8 for promise events only. + // Passing one as maxStackSize forces no async chain for the new stack and + // allows us to not grow exponentially. + std::unique_ptr creationStack = + V8StackTraceImpl::capture(this, 0, 1, String16()); + if (creationStack && !creationStack->isEmpty()) { + m_asyncTaskCreationStacks[task] = std::move(creationStack); + registerAsyncTaskIfNeeded(task); + } } void V8Debugger::asyncTaskScheduled(const StringView& taskName, void* task, @@ -887,13 +910,7 @@ void V8Debugger::asyncTaskScheduled(const String16& taskName, void* task, if (chain) { m_asyncTaskStacks[task] = std::move(chain); if (recurring) m_recurringTasks.insert(task); - int id = ++m_lastTaskId; - m_taskToId[task] = id; - m_idToTask[id] = task; - if (static_cast(m_idToTask.size()) > m_maxAsyncCallStacks) { - void* taskToRemove = m_idToTask.begin()->second; - asyncTaskCanceled(taskToRemove); - } + registerAsyncTaskIfNeeded(task); } } @@ -902,6 +919,7 @@ void V8Debugger::asyncTaskCanceled(void* task) { m_asyncTaskStacks.erase(task); m_recurringTasks.erase(task); m_parentTask.erase(task); + m_asyncTaskCreationStacks.erase(task); auto it = m_taskToId.find(task); if (it == m_taskToId.end()) return; m_idToTask.erase(it->second); @@ -924,6 +942,10 @@ void V8Debugger::asyncTaskStarted(void* task) { std::unique_ptr stack; if (stackIt != m_asyncTaskStacks.end() && stackIt->second) stack = stackIt->second->cloneImpl(); + auto itCreation = m_asyncTaskCreationStacks.find(task); + if (stack && itCreation != m_asyncTaskCreationStacks.end()) { + stack->setCreation(itCreation->second->cloneImpl()); + } m_currentStacks.push_back(std::move(stack)); } @@ -947,6 +969,7 @@ void V8Debugger::allAsyncTasksCanceled() { m_currentStacks.clear(); m_currentTasks.clear(); m_parentTask.clear(); + m_asyncTaskCreationStacks.clear(); m_idToTask.clear(); m_taskToId.clear(); m_lastTaskId = 0; diff --git a/src/inspector/v8-debugger.h b/src/inspector/v8-debugger.h index 7bbb51f080..5859c1d5ab 100644 --- a/src/inspector/v8-debugger.h +++ b/src/inspector/v8-debugger.h @@ -134,6 +134,7 @@ class V8Debugger : public v8::debug::DebugDelegate { v8::Local); void asyncTaskCreated(void* task, void* parentTask); + void registerAsyncTaskIfNeeded(void* task); // v8::debug::DebugEventListener implementation. void PromiseEventOccurred(v8::debug::PromiseDebugActionType type, int id, @@ -166,6 +167,7 @@ class V8Debugger : public v8::debug::DebugDelegate { using AsyncTaskToStackTrace = protocol::HashMap>; AsyncTaskToStackTrace m_asyncTaskStacks; + AsyncTaskToStackTrace m_asyncTaskCreationStacks; int m_maxAsyncCallStacks; std::map m_idToTask; std::unordered_map m_taskToId; diff --git a/src/inspector/v8-stack-trace-impl.cc b/src/inspector/v8-stack-trace-impl.cc index 962a00a773..07172a4619 100644 --- a/src/inspector/v8-stack-trace-impl.cc +++ b/src/inspector/v8-stack-trace-impl.cc @@ -141,10 +141,13 @@ std::unique_ptr V8StackTraceImpl::create( maxAsyncCallChainDepth = 1; } - // Only the top stack in the chain may be empty, so ensure that second stack - // is non-empty (it's the top of appended chain). - if (asyncCallChain && asyncCallChain->isEmpty()) + // Only the top stack in the chain may be empty and doesn't contain creation + // stack , so ensure that second stack is non-empty (it's the top of appended + // chain). + if (asyncCallChain && asyncCallChain->isEmpty() && + !asyncCallChain->m_creation) { asyncCallChain = asyncCallChain->m_parent.get(); + } if (stackTrace.IsEmpty() && !asyncCallChain) return nullptr; @@ -180,9 +183,11 @@ std::unique_ptr V8StackTraceImpl::capture( std::unique_ptr V8StackTraceImpl::cloneImpl() { std::vector framesCopy(m_frames); - return std::unique_ptr( + std::unique_ptr copy( new V8StackTraceImpl(m_contextGroupId, m_description, framesCopy, m_parent ? m_parent->cloneImpl() : nullptr)); + if (m_creation) copy->setCreation(m_creation->cloneImpl()); + return copy; } std::unique_ptr V8StackTraceImpl::clone() { @@ -205,6 +210,19 @@ V8StackTraceImpl::V8StackTraceImpl(int contextGroupId, V8StackTraceImpl::~V8StackTraceImpl() {} +void V8StackTraceImpl::setCreation(std::unique_ptr creation) { + m_creation = std::move(creation); + // When async call chain is empty but doesn't contain useful schedule stack + // and parent async call chain contains creationg stack but doesn't + // synchronous we can merge them together. + // e.g. Promise ThenableJob. + if (m_parent && isEmpty() && m_description == m_parent->m_description && + !m_parent->m_creation) { + m_frames.swap(m_parent->m_frames); + m_parent = std::move(m_parent->m_parent); + } +} + StringView V8StackTraceImpl::topSourceURL() const { DCHECK(m_frames.size()); return toStringView(m_frames[0].m_scriptName); @@ -243,6 +261,10 @@ V8StackTraceImpl::buildInspectorObjectImpl() const { .build(); if (!m_description.isEmpty()) stackTrace->setDescription(m_description); if (m_parent) stackTrace->setParent(m_parent->buildInspectorObjectImpl()); + if (m_creation && m_creation->m_frames.size()) { + stackTrace->setPromiseCreationFrame( + m_creation->m_frames[0].buildInspectorObject()); + } return stackTrace; } diff --git a/src/inspector/v8-stack-trace-impl.h b/src/inspector/v8-stack-trace-impl.h index f0a452e939..f8b53d0a65 100644 --- a/src/inspector/v8-stack-trace-impl.h +++ b/src/inspector/v8-stack-trace-impl.h @@ -81,6 +81,8 @@ class V8StackTraceImpl final : public V8StackTrace { const override; std::unique_ptr toString() const override; + void setCreation(std::unique_ptr creation); + private: V8StackTraceImpl(int contextGroupId, const String16& description, std::vector& frames, @@ -90,6 +92,7 @@ class V8StackTraceImpl final : public V8StackTrace { String16 m_description; std::vector m_frames; std::unique_ptr m_parent; + std::unique_ptr m_creation; DISALLOW_COPY_AND_ASSIGN(V8StackTraceImpl); }; diff --git a/test/inspector/debugger/async-stack-await-expected.txt b/test/inspector/debugger/async-stack-await-expected.txt index 1fda6b0d4b..506b9a268a 100644 --- a/test/inspector/debugger/async-stack-await-expected.txt +++ b/test/inspector/debugger/async-stack-await-expected.txt @@ -1,33 +1,34 @@ Checks that async stacks works for async/await foo2 (test.js:15:2) --- async function -- +-- async function (test.js:13:19)-- foo2 (test.js:13:19) test (test.js:24:8) (anonymous) (expr.js:0:0) foo2 (test.js:17:2) --- async function -- +-- async function (test.js:13:19)-- foo2 (test.js:13:19) test (test.js:24:8) (anonymous) (expr.js:0:0) foo1 (test.js:9:2) foo2 (test.js:18:8) --- async function -- +-- async function (test.js:13:19)-- foo2 (test.js:13:19) test (test.js:24:8) (anonymous) (expr.js:0:0) foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:19:43)-- +-- Promise.resolve (test.js:19:16)-- foo2 (test.js:19:30) --- async function -- +-- async function (test.js:13:19)-- foo2 (test.js:13:19) test (test.js:24:8) (anonymous) (expr.js:0:0) foo2 (test.js:20:2) --- async function -- +-- async function (test.js:13:19)-- foo2 (test.js:13:19) test (test.js:24:8) (anonymous) (expr.js:0:0) diff --git a/test/inspector/debugger/async-stack-await.js b/test/inspector/debugger/async-stack-await.js index a7eb741904..50f423d044 100644 --- a/test/inspector/debugger/async-stack-await.js +++ b/test/inspector/debugger/async-stack-await.js @@ -28,12 +28,7 @@ async function test() { InspectorTest.setupScriptMap(); Protocol.Debugger.onPaused(message => { InspectorTest.logCallFrames(message.params.callFrames); - var asyncStackTrace = message.params.asyncStackTrace; - while (asyncStackTrace) { - InspectorTest.log(`-- ${asyncStackTrace.description} --`); - InspectorTest.logCallFrames(asyncStackTrace.callFrames); - asyncStackTrace = asyncStackTrace.parent; - } + InspectorTest.logAsyncStackTrace(message.params.asyncStackTrace); InspectorTest.log(''); Protocol.Debugger.resume(); }); diff --git a/test/inspector/debugger/async-stack-created-frame-expected.txt b/test/inspector/debugger/async-stack-created-frame-expected.txt new file mode 100644 index 0000000000..6e61d1aca4 --- /dev/null +++ b/test/inspector/debugger/async-stack-created-frame-expected.txt @@ -0,0 +1,100 @@ +Checks created frame for async call chain + +Running test: testPromise +foo1 (test.js:10:2) +-- Promise.resolve (test.js:20:14)-- +promise (test.js:21:2) +(anonymous) (expr.js:0:0) + + +Running test: testPromiseThen +foo1 (test.js:10:2) +-- Promise.resolve (test.js:28:14)-- +promiseThen (test.js:30:2) +(anonymous) (expr.js:0:0) + +foo2 (test.js:14:2) +-- Promise.resolve (test.js:29:14)-- +-- Promise.resolve (test.js:28:14)-- +promiseThen (test.js:30:2) +(anonymous) (expr.js:0:0) + + +Running test: testPromiseThenThen +foo1 (test.js:10:2) +-- Promise.resolve (test.js:37:14)-- +promiseThenThen (test.js:39:2) +(anonymous) (expr.js:0:0) + +foo1 (test.js:10:2) +-- Promise.resolve (test.js:38:14)-- +promiseThenThen (test.js:39:2) +(anonymous) (expr.js:0:0) + +foo2 (test.js:14:2) +-- Promise.resolve (test.js:37:25)-- +-- Promise.resolve (test.js:37:14)-- +promiseThenThen (test.js:39:2) +(anonymous) (expr.js:0:0) + + +Running test: testPromiseResolve +foo1 (test.js:10:2) +-- Promise.resolve (test.js:44:27)-- +promiseResolve (test.js:44:17) +(anonymous) (expr.js:0:0) + + +Running test: testPromiseReject +foo1 (test.js:10:2) +-- Promise.reject (test.js:48:31)-- +promiseReject (test.js:48:17) +(anonymous) (expr.js:0:0) + + +Running test: testPromiseAll +foo1 (test.js:10:2) +-- Promise.resolve (test.js:52:44)-- +-- Promise.resolve (test.js:52:17)-- +promiseAll (test.js:52:31) +(anonymous) (expr.js:0:0) + + +Running test: testPromiseRace +foo1 (test.js:10:2) +-- Promise.resolve (test.js:56:45)-- +-- Promise.resolve (test.js:56:17)-- +promiseRace (test.js:56:32) +(anonymous) (expr.js:0:0) + + +Running test: testThenableJob1 +foo1 (test.js:10:2) +-- Promise.resolve (test.js:60:72)-- +-- Promise.resolve (test.js:60:56)-- +Promise.resolve.then (test.js:60:46) +-- Promise.resolve (test.js:60:27)-- +thenableJob1 (test.js:60:17) +(anonymous) (expr.js:0:0) + + +Running test: testThenableJob2 +foo1 (test.js:10:2) +-- Promise.resolve (test.js:64:57)-- +Promise.resolve.then (test.js:64:46) +-- Promise.resolve (test.js:64:27)-- +thenableJob2 (test.js:64:17) +(anonymous) (expr.js:0:0) + + +Running test: testSetTimeouts +foo1 (test.js:10:2) +setTimeout (test.js:72:25) +-- setTimeout -- +setTimeout (test.js:72:6) +-- setTimeout -- +setTimeout (test.js:71:4) +-- setTimeout -- +setTimeouts (test.js:70:2) +(anonymous) (expr.js:0:0) + diff --git a/test/inspector/debugger/async-stack-created-frame.js b/test/inspector/debugger/async-stack-created-frame.js new file mode 100644 index 0000000000..e7430d7cfd --- /dev/null +++ b/test/inspector/debugger/async-stack-created-frame.js @@ -0,0 +1,178 @@ +// Copyright 2017 the V8 project authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +print('Checks created frame for async call chain'); + +InspectorTest.addScript( + ` +function foo1() { + debugger; +} + +function foo2() { + debugger; +} + +function promise() { + var resolve; + var p1 = new Promise(r => resolve = r); + var p2 = p1.then(foo1); + resolve(); + return p2; +} + +function promiseThen() { + var resolve; + var p1 = new Promise(r => resolve = r); + var p2 = p1.then(foo1); + var p3 = p2.then(foo2); + resolve(); + return p3; +} + +function promiseThenThen() { + var resolve; + var p1 = new Promise(r => resolve = r); + var p2 = p1.then(foo1).then(foo2); + var p3 = p1.then(foo1); + resolve(); + return p2; +} + +function promiseResolve() { + return Promise.resolve().then(foo1); +} + +function promiseReject() { + return Promise.reject().catch(foo1); +} + +function promiseAll() { + return Promise.all([ Promise.resolve() ]).then(foo1); +} + +function promiseRace() { + return Promise.race([ Promise.resolve() ]).then(foo1); +} + +function thenableJob1() { + return Promise.resolve().then(() => Promise.resolve().then(() => 42)).then(foo1); +} + +function thenableJob2() { + return Promise.resolve().then(() => Promise.resolve()).then(foo1); +} + +function setTimeouts() { + var resolve; + var p = new Promise(r => resolve = r); + setTimeout(() => + setTimeout(() => + setTimeout(() => { foo1(); resolve(); }, 0), 0), 0); + return p; +} + +//# sourceURL=test.js`, + 8, 4); + +InspectorTest.setupScriptMap(); +Protocol.Debugger.onPaused(message => { + InspectorTest.logCallFrames(message.params.callFrames); + InspectorTest.logAsyncStackTrace(message.params.asyncStackTrace); + InspectorTest.log(''); + Protocol.Debugger.resume(); +}); + +Protocol.Debugger.enable(); +Protocol.Debugger.setAsyncCallStackDepth({maxDepth: 128}); + +InspectorTest.runTestSuite([ + function testPromise(next) { + Protocol.Runtime + .evaluate( + {expression: 'promise()//# sourceURL=expr.js', awaitPromise: true}) + .then(next); + }, + + function testPromiseThen(next) { + Protocol.Runtime + .evaluate({ + expression: 'promiseThen()//# sourceURL=expr.js', + awaitPromise: true + }) + .then(next); + }, + + function testPromiseThenThen(next) { + Protocol.Runtime + .evaluate({ + expression: 'promiseThenThen()//# sourceURL=expr.js', + awaitPromise: true + }) + .then(next); + }, + + function testPromiseResolve(next) { + Protocol.Runtime + .evaluate({ + expression: 'promiseResolve()//# sourceURL=expr.js', + awaitPromise: true + }) + .then(next); + }, + + function testPromiseReject(next) { + Protocol.Runtime + .evaluate({ + expression: 'promiseReject()//# sourceURL=expr.js', + awaitPromise: true + }) + .then(next); + }, + + function testPromiseAll(next) { + Protocol.Runtime + .evaluate({ + expression: 'promiseAll()//# sourceURL=expr.js', + awaitPromise: true + }) + .then(next); + }, + + function testPromiseRace(next) { + Protocol.Runtime + .evaluate({ + expression: 'promiseRace()//# sourceURL=expr.js', + awaitPromise: true + }) + .then(next); + }, + + function testThenableJob1(next) { + Protocol.Runtime + .evaluate({ + expression: 'thenableJob1()//# sourceURL=expr.js', + awaitPromise: true + }) + .then(next); + }, + + function testThenableJob2(next) { + Protocol.Runtime + .evaluate({ + expression: 'thenableJob2()//# sourceURL=expr.js', + awaitPromise: true + }) + .then(next); + }, + + function testSetTimeouts(next) { + Protocol.Runtime + .evaluate({ + expression: 'setTimeouts()//# sourceURL=expr.js', + awaitPromise: true + }) + .then(next); + } +]); diff --git a/test/inspector/debugger/async-stack-for-promise-expected.txt b/test/inspector/debugger/async-stack-for-promise-expected.txt index dfa5951909..a948803f28 100644 --- a/test/inspector/debugger/async-stack-for-promise-expected.txt +++ b/test/inspector/debugger/async-stack-for-promise-expected.txt @@ -2,13 +2,14 @@ Checks that async chains for promises are correct. Running test: testPromise foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:19:14)-- promise (test.js:20:2) (anonymous) (testPromise.js:0:0) Running test: testPromiseResolvedBySetTimeout foo1 (test.js:9:2) +-- Promise.resolve (test.js:27:14)-- -- setTimeout -- promiseResolvedBySetTimeout (test.js:28:2) (anonymous) (testPromiseResolvedBySetTimeout.js:0:0) @@ -16,96 +17,103 @@ promiseResolvedBySetTimeout (test.js:28:2) Running test: testPromiseAll foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:37:35)-- +-- Promise.resolve (test.js:37:19)-- promiseAll (test.js:39:2) (anonymous) (testPromiseAll.js:0:0) Running test: testPromiseAllReverseOrder foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:48:35)-- +-- Promise.resolve (test.js:48:19)-- promiseAllReverseOrder (test.js:50:2) (anonymous) (testPromiseAllReverseOrder.js:0:0) Running test: testPromiseRace foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:59:36)-- +-- Promise.resolve (test.js:59:19)-- promiseRace (test.js:60:2) (anonymous) (testPromiseRace.js:0:0) Running test: testTwoChainedCallbacks foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:68:14)-- twoChainedCallbacks (test.js:69:2) (anonymous) (testTwoChainedCallbacks.js:0:0) foo2 (test.js:13:2) --- Promise.resolve -- +-- Promise.resolve (test.js:68:25)-- +-- Promise.resolve (test.js:68:14)-- twoChainedCallbacks (test.js:69:2) (anonymous) (testTwoChainedCallbacks.js:0:0) Running test: testPromiseResolve foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:74:27)-- promiseResolve (test.js:74:17) (anonymous) (testPromiseResolve.js:0:0) foo2 (test.js:13:2) --- Promise.resolve -- +-- Promise.resolve (test.js:74:38)-- +-- Promise.resolve (test.js:74:27)-- promiseResolve (test.js:74:17) (anonymous) (testPromiseResolve.js:0:0) Running test: testThenableJobResolvedInSetTimeout foo1 (test.js:9:2) +-- Promise.resolve (test.js:86:40)-- -- setTimeout -- thenableJob (test.js:81:4) p1.then (test.js:86:25) --- Promise.resolve -- +-- Promise.resolve (test.js:86:14)-- thenableJobResolvedInSetTimeout (test.js:87:2) (anonymous) (testThenableJobResolvedInSetTimeout.js:0:0) Running test: testThenableJobResolvedInSetTimeoutWithStack foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:104:40)-- inner (test.js:94:6) -- setTimeout -- thenableJob (test.js:99:4) p1.then (test.js:104:25) --- Promise.resolve -- +-- Promise.resolve (test.js:104:14)-- thenableJobResolvedInSetTimeoutWithStack (test.js:105:2) (anonymous) (testThenableJobResolvedInSetTimeoutWithStack.js:0:0) Running test: testThenableJobResolvedByPromise foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:118:40)-- +-- Promise.resolve (test.js:113:22)-- thenableJob (test.js:113:12) p1.then (test.js:118:25) --- Promise.resolve -- +-- Promise.resolve (test.js:118:14)-- thenableJobResolvedByPromise (test.js:119:2) (anonymous) (testThenableJobResolvedByPromise.js:0:0) Running test: testThenableJobResolvedByPromiseWithStack foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:136:40)-- inner (test.js:126:6) --- Promise.resolve -- +-- Promise.resolve (test.js:131:22)-- thenableJob (test.js:131:12) p1.then (test.js:136:25) --- Promise.resolve -- +-- Promise.resolve (test.js:136:14)-- thenableJobResolvedByPromiseWithStack (test.js:137:2) (anonymous) (testThenableJobResolvedByPromiseWithStack.js:0:0) Running test: testLateThenCallback foo1 (test.js:9:2) --- Promise.resolve -- +-- Promise.resolve (test.js:145:12)-- lateThenCallback (test.js:144:2) (anonymous) (testLateThenCallback.js:0:0) @@ -113,43 +121,54 @@ lateThenCallback (test.js:144:2) Running test: testComplex inner1 (test.js:154:6) foo1 (test.js:156:4) --- Promise.resolve -- +-- Promise.resolve (test.js:202:5)-- inner2 (test.js:162:6) --- Promise.resolve -- +-- Promise.resolve (test.js:165:22)-- foo2 (test.js:165:12) --- Promise.resolve -- +-- Promise.resolve (test.js:201:5)-- inner3 (test.js:172:6) -- setTimeout -- foo3 (test.js:175:4) --- Promise.resolve -- +-- Promise.resolve (test.js:200:5)-- +-- Promise.resolve (test.js:199:5)-- +-- Promise.resolve (test.js:188:7)-- +-- Promise.resolve (test.js:187:19)-- foo5 (test.js:187:52) --- Promise.resolve -- +-- Promise.resolve (test.js:198:5)-- +-- Promise.resolve (test.js:193:7)-- +-- Promise.resolve (test.js:192:19)-- foo6 (test.js:192:34) --- Promise.resolve -- +-- Promise.resolve (test.js:197:5)-- complex (test.js:196:18) (anonymous) (testComplex.js:0:0) p.then (test.js:207:8) --- Promise.resolve -- +-- Promise.resolve (test.js:206:8)-- +-- Promise.resolve (test.js:202:5)-- inner2 (test.js:162:6) --- Promise.resolve -- +-- Promise.resolve (test.js:165:22)-- foo2 (test.js:165:12) --- Promise.resolve -- +-- Promise.resolve (test.js:201:5)-- inner3 (test.js:172:6) -- setTimeout -- foo3 (test.js:175:4) --- Promise.resolve -- +-- Promise.resolve (test.js:200:5)-- +-- Promise.resolve (test.js:199:5)-- +-- Promise.resolve (test.js:188:7)-- +-- Promise.resolve (test.js:187:19)-- foo5 (test.js:187:52) --- Promise.resolve -- +-- Promise.resolve (test.js:198:5)-- +-- Promise.resolve (test.js:193:7)-- +-- Promise.resolve (test.js:192:19)-- foo6 (test.js:192:34) --- Promise.resolve -- +-- Promise.resolve (test.js:197:5)-- complex (test.js:196:18) (anonymous) (testComplex.js:0:0) Running test: testReject foo1 (test.js:9:2) --- Promise.reject -- +-- Promise.reject (test.js:217:31)-- reject (test.js:217:17) (anonymous) (testReject.js:0:0) diff --git a/test/inspector/debugger/async-stack-for-promise.js b/test/inspector/debugger/async-stack-for-promise.js index 705bb19086..a627747a55 100644 --- a/test/inspector/debugger/async-stack-for-promise.js +++ b/test/inspector/debugger/async-stack-for-promise.js @@ -222,12 +222,7 @@ function reject() { InspectorTest.setupScriptMap(); Protocol.Debugger.onPaused(message => { InspectorTest.logCallFrames(message.params.callFrames); - var asyncStackTrace = message.params.asyncStackTrace; - while (asyncStackTrace) { - InspectorTest.log(`-- ${asyncStackTrace.description} --`); - InspectorTest.logCallFrames(asyncStackTrace.callFrames); - asyncStackTrace = asyncStackTrace.parent; - } + InspectorTest.logAsyncStackTrace(message.params.asyncStackTrace); InspectorTest.log(''); Protocol.Debugger.resume(); }); diff --git a/test/inspector/debugger/async-stacks-limit-expected.txt b/test/inspector/debugger/async-stacks-limit-expected.txt index 16270656c6..8dd1456990 100644 --- a/test/inspector/debugger/async-stacks-limit-expected.txt +++ b/test/inspector/debugger/async-stacks-limit-expected.txt @@ -4,7 +4,7 @@ Running test: testZeroLimit foo1 (test.js:11:2) -Running test: testOneLimit +Running test: testTwoLimit foo1 (test.js:11:2) -- Promise.resolve -- promise (test.js:23:2) @@ -17,11 +17,14 @@ foo1 (test.js:11:2) foo2 (test.js:15:2) -Running test: testTwoLimitTwoPromises +Running test: testFourLimitTwoPromises +foo1 (test.js:11:2) + +foo2 (test.js:15:2) + + +Running test: testSixLimitTwoPromises foo1 (test.js:11:2) --- Promise.resolve -- -twoPromises (test.js:34:2) -(anonymous) (expr.js:0:0) foo2 (test.js:15:2) -- Promise.resolve -- @@ -29,7 +32,7 @@ twoPromises (test.js:35:2) (anonymous) (expr.js:0:0) -Running test: testOneLimitTwoSetTimeouts +Running test: testTwoLimitTwoSetTimeouts foo1 (test.js:11:2) foo2 (test.js:15:2) @@ -38,7 +41,7 @@ twoSetTimeout (test.js:41:2) (anonymous) (expr.js:0:0) -Running test: testTwoLimitTwoSetTimeouts +Running test: testThreeLimitTwoSetTimeouts foo1 (test.js:11:2) -- setTimeout -- twoSetTimeout (test.js:40:2) @@ -84,54 +87,54 @@ foo10 (:0:18) foo11 (:0:18) (anonymous) (:0:29) -- setTimeout -- -twentySetTimeout (test.js:55:4) +twentySetTimeout (test.js:49:4) (anonymous) (expr.js:0:0) foo12 (:0:18) (anonymous) (:0:29) -- setTimeout -- -twentySetTimeout (test.js:55:4) +twentySetTimeout (test.js:49:4) (anonymous) (expr.js:0:0) foo13 (:0:18) (anonymous) (:0:29) -- setTimeout -- -twentySetTimeout (test.js:55:4) +twentySetTimeout (test.js:49:4) (anonymous) (expr.js:0:0) foo14 (:0:18) (anonymous) (:0:29) -- setTimeout -- -twentySetTimeout (test.js:55:4) +twentySetTimeout (test.js:49:4) (anonymous) (expr.js:0:0) foo15 (:0:18) (anonymous) (:0:29) -- setTimeout -- -twentySetTimeout (test.js:55:4) +twentySetTimeout (test.js:49:4) (anonymous) (expr.js:0:0) foo16 (:0:18) (anonymous) (:0:29) -- setTimeout -- -twentySetTimeout (test.js:55:4) +twentySetTimeout (test.js:49:4) (anonymous) (expr.js:0:0) foo17 (:0:18) (anonymous) (:0:29) -- setTimeout -- -twentySetTimeout (test.js:55:4) +twentySetTimeout (test.js:49:4) (anonymous) (expr.js:0:0) foo18 (:0:18) (anonymous) (:0:29) -- setTimeout -- -twentySetTimeout (test.js:55:4) +twentySetTimeout (test.js:49:4) (anonymous) (expr.js:0:0) foo19 (:0:18) (anonymous) (:0:29) -- setTimeout -- -twentySetTimeout (test.js:55:4) +twentySetTimeout (test.js:49:4) (anonymous) (expr.js:0:0) diff --git a/test/inspector/debugger/async-stacks-limit.js b/test/inspector/debugger/async-stacks-limit.js index b028b74aae..d3c47dbfd4 100644 --- a/test/inspector/debugger/async-stacks-limit.js +++ b/test/inspector/debugger/async-stacks-limit.js @@ -42,12 +42,6 @@ function twoSetTimeout() { return new Promise(resolve => resolveTest = resolve); } -function threeSetTimeout() { - setTimeout(foo1, 0); - setTimeout(foo2, 0); - return new Promise(resolve => resolveTest = resolve); -} - function twentySetTimeout() { var resolve1; var p1 = new Promise(resolve => resolve1 = resolve); @@ -85,14 +79,16 @@ InspectorTest.runTestSuite([ .then(next); }, - function testOneLimit(next) { - Protocol.Runtime.evaluate({ - expression: 'setMaxAsyncTaskStacks(1)//# sourceURL=expr.js'}) - .then(() => Protocol.Runtime.evaluate({ - expression: 'promise()//# sourceURL=expr.js', awaitPromise: true - })) - .then(() => cancelAllAsyncTasks()) - .then(next); + function testTwoLimit(next) { + // we need one stack for parent task and one for next task. + Protocol.Runtime + .evaluate({expression: 'setMaxAsyncTaskStacks(2)//# sourceURL=expr.js'}) + .then(() => Protocol.Runtime.evaluate({ + expression: 'promise()//# sourceURL=expr.js', + awaitPromise: true + })) + .then(() => cancelAllAsyncTasks()) + .then(next); }, function testOneLimitTwoPromises(next) { @@ -108,19 +104,31 @@ InspectorTest.runTestSuite([ .then(next); }, - function testTwoLimitTwoPromises(next) { - Protocol.Runtime.evaluate({ - expression: 'setMaxAsyncTaskStacks(2)//# sourceURL=expr.js'}) - .then(() => Protocol.Runtime.evaluate({ - expression: 'twoPromises()//# sourceURL=expr.js', awaitPromise: true - })) - .then(() => cancelAllAsyncTasks()) - .then(next); + function testFourLimitTwoPromises(next) { + Protocol.Runtime + .evaluate({expression: 'setMaxAsyncTaskStacks(4)//# sourceURL=expr.js'}) + .then(() => Protocol.Runtime.evaluate({ + expression: 'twoPromises()//# sourceURL=expr.js', + awaitPromise: true + })) + .then(() => cancelAllAsyncTasks()) + .then(next); }, - function testOneLimitTwoSetTimeouts(next) { + function testSixLimitTwoPromises(next) { + Protocol.Runtime + .evaluate({expression: 'setMaxAsyncTaskStacks(6)//# sourceURL=expr.js'}) + .then(() => Protocol.Runtime.evaluate({ + expression: 'twoPromises()//# sourceURL=expr.js', + awaitPromise: true + })) + .then(() => cancelAllAsyncTasks()) + .then(next); + }, + + function testTwoLimitTwoSetTimeouts(next) { Protocol.Runtime.evaluate({ - expression: 'setMaxAsyncTaskStacks(1)//# sourceURL=expr.js'}) + expression: 'setMaxAsyncTaskStacks(2)//# sourceURL=expr.js'}) .then(() => Protocol.Runtime.evaluate({ expression: 'twoSetTimeout()//# sourceURL=expr.js', awaitPromise: true })) @@ -128,9 +136,9 @@ InspectorTest.runTestSuite([ .then(next); }, - function testTwoLimitTwoSetTimeouts(next) { + function testThreeLimitTwoSetTimeouts(next) { Protocol.Runtime.evaluate({ - expression: 'setMaxAsyncTaskStacks(2)//# sourceURL=expr.js'}) + expression: 'setMaxAsyncTaskStacks(3)//# sourceURL=expr.js'}) .then(() => Protocol.Runtime.evaluate({ expression: 'twoSetTimeout()//# sourceURL=expr.js', awaitPromise: true })) diff --git a/test/inspector/protocol-test.js b/test/inspector/protocol-test.js index 37e6447f79..a30068faf7 100644 --- a/test/inspector/protocol-test.js +++ b/test/inspector/protocol-test.js @@ -112,6 +112,21 @@ InspectorTest.logCallFrames = function(callFrames) } } +InspectorTest.logAsyncStackTrace = function(asyncStackTrace) +{ + while (asyncStackTrace) { + if (asyncStackTrace.promiseCreationFrame) { + var frame = asyncStackTrace.promiseCreationFrame; + InspectorTest.log(`-- ${asyncStackTrace.description} (${frame.url + }:${frame.lineNumber}:${frame.columnNumber})--`); + } else { + InspectorTest.log(`-- ${asyncStackTrace.description} --`); + } + InspectorTest.logCallFrames(asyncStackTrace.callFrames); + asyncStackTrace = asyncStackTrace.parent; + } +} + InspectorTest.completeTest = function() { Protocol.Debugger.disable().then(() => quit());