From ea1882f1b5817e6fc2444813280a932eb86e53ee Mon Sep 17 00:00:00 2001 From: David Taylor Date: Sun, 9 Oct 2022 12:18:01 +0100 Subject: [PATCH 1/2] Add support for Chrome's Async Stack Tagging API https://developer.chrome.com/blog/devtools-modern-web-debugging/#linked-stack-traces This enables the Chrome developer tools to link the stack traces of the original event scheduling and the eventual execution on the runloop. This is available in Chrome 106 and above. To protect production performance, this is disabled-by-default, but can be enabled by setting `Backburner.ASYNC_STACKS = true`. Applications/frameworks could choose to enable this by default in development modes. --- bench/benches/schedule-flush.js | 16 +++++ lib/backburner/deferred-action-queues.ts | 6 +- lib/backburner/queue.ts | 31 +++++++--- lib/backburner/utils.ts | 7 ++- lib/index.ts | 37 +++++++++--- tests/async-stack-test.ts | 75 ++++++++++++++++++++++++ tests/index.ts | 1 + 7 files changed, 151 insertions(+), 22 deletions(-) create mode 100644 tests/async-stack-test.ts diff --git a/bench/benches/schedule-flush.js b/bench/benches/schedule-flush.js index f522213e..434e7af1 100644 --- a/bench/benches/schedule-flush.js +++ b/bench/benches/schedule-flush.js @@ -8,6 +8,15 @@ function prodSetup() { }; } +function asyncStackSetup() { + var backburner = new this.Backburner(["sync", "actions", "routerTransitions", "render", "afterRender", "destroy", "rsvpAfter"]); + backburner.ASYNC_STACKS = true; + + var target = { + someMethod: function() { } + }; +} + function debugSetup() { var backburner = new this.Backburner(["sync", "actions", "routerTransitions", "render", "afterRender", "destroy", "rsvpAfter"]); backburner.DEBUG = true; @@ -77,6 +86,13 @@ base.forEach(item => { scenarios.push(prodItem); }); +base.forEach(item => { + let debugItem = Object.assign({}, item); + debugItem.name = `ASYNC_STACKS - ${debugItem.name}`; + debugItem.setup = asyncStackSetup; + scenarios.push(debugItem); +}); + base.forEach(item => { let debugItem = Object.assign({}, item); debugItem.name = `DEBUG - ${debugItem.name}`; diff --git a/lib/backburner/deferred-action-queues.ts b/lib/backburner/deferred-action-queues.ts index bf51f76c..51273d02 100644 --- a/lib/backburner/deferred-action-queues.ts +++ b/lib/backburner/deferred-action-queues.ts @@ -30,7 +30,7 @@ export default class DeferredActionQueues { * @param {Any} stack * @return queue */ - public schedule(queueName: string, target: any, method: any, args: any, onceFlag: boolean, stack: any) { + public schedule(queueName: string, target: any, method: any, args: any, onceFlag: boolean, stack: any, consoleTask: any) { let queues = this.queues; let queue = queues[queueName]; @@ -45,9 +45,9 @@ export default class DeferredActionQueues { this.queueNameIndex = 0; if (onceFlag) { - return queue.pushUnique(target, method, args, stack); + return queue.pushUnique(target, method, args, stack, consoleTask); } else { - return queue.push(target, method, args, stack); + return queue.push(target, method, args, stack, consoleTask); } } diff --git a/lib/backburner/queue.ts b/lib/backburner/queue.ts index 4943a3c5..81d6ecf6 100644 --- a/lib/backburner/queue.ts +++ b/lib/backburner/queue.ts @@ -2,15 +2,14 @@ import { IQueueItem } from './interfaces'; import { findItem, getOnError, - getQueueItems + getQueueItems, + QUEUE_ITEM_LENGTH } from './utils'; export const enum QUEUE_STATE { Pause = 1 } -const QUEUE_ITEM_LENGTH = 4; - export default class Queue { private name: string; private globalOptions: any; @@ -28,7 +27,7 @@ export default class Queue { public stackFor(index) { if (index < this._queue.length) { - let entry = this._queue[index * 3 + QUEUE_ITEM_LENGTH]; + let entry = this._queue[(index * QUEUE_ITEM_LENGTH) + 3]; if (entry) { return entry.stack; } else { @@ -37,12 +36,20 @@ export default class Queue { } } + public consoleTaskFor(index, inQueueBeingFlushed = false) { + let q = inQueueBeingFlushed ? this._queueBeingFlushed : this._queue; + if (index < q.length) { + return q[(index * QUEUE_ITEM_LENGTH) + 4]; + } + } + public flush(sync?: Boolean) { let { before, after } = this.options; let target; let method; let args; let errorRecordedForStack; + let consoleTask; this.targetQueues.clear(); if (this._queueBeingFlushed.length === 0) { @@ -84,7 +91,12 @@ export default class Queue { target = queueItems[i]; args = queueItems[i + 2]; errorRecordedForStack = queueItems[i + 3]; // Debugging assistance - invoke(target, method, args, onError, errorRecordedForStack); + consoleTask = queueItems[i + 4]; + if(consoleTask){ + consoleTask.run(invoke.bind(this, target, method, args, onError, errorRecordedForStack)) + }else{ + invoke(target, method, args, onError, errorRecordedForStack) + } } if (this.index !== this._queueBeingFlushed.length && @@ -138,8 +150,8 @@ export default class Queue { return false; } - public push(target, method, args, stack): { queue: Queue, target, method } { - this._queue.push(target, method, args, stack); + public push(target, method, args, stack, consoleTask): { queue: Queue, target, method } { + this._queue.push(target, method, args, stack, consoleTask); return { queue: this, @@ -148,7 +160,7 @@ export default class Queue { }; } - public pushUnique(target, method, args, stack): { queue: Queue, target, method } { + public pushUnique(target, method, args, stack, consoleTask): { queue: Queue, target, method } { let localQueueMap = this.targetQueues.get(target); if (localQueueMap === undefined) { @@ -158,12 +170,13 @@ export default class Queue { let index = localQueueMap.get(method); if (index === undefined) { - let queueIndex = this._queue.push(target, method, args, stack) - QUEUE_ITEM_LENGTH; + let queueIndex = this._queue.push(target, method, args, stack, consoleTask) - QUEUE_ITEM_LENGTH; localQueueMap.set(method, queueIndex); } else { let queue = this._queue; queue[index + 2] = args; // replace args queue[index + 3] = stack; // replace stack + queue[index + 3] = consoleTask; // replace consoleTask } return { diff --git a/lib/backburner/utils.ts b/lib/backburner/utils.ts index f7171c5e..1d171099 100644 --- a/lib/backburner/utils.ts +++ b/lib/backburner/utils.ts @@ -11,7 +11,8 @@ const enum QueueItemPosition { stack } -export const TIMERS_OFFSET = 6; +export const QUEUE_ITEM_LENGTH = 5; +export const TIMERS_OFFSET = 7; export function isCoercableNumber(suspect) { let type = typeof suspect; @@ -25,7 +26,7 @@ export function getOnError(options) { export function findItem(target, method, collection) { let index = -1; - for (let i = 0, l = collection.length; i < l; i += 4) { + for (let i = 0, l = collection.length; i < l; i += QUEUE_ITEM_LENGTH) { if (collection[i] === target && collection[i + 1] === method) { index = i; break; @@ -38,7 +39,7 @@ export function findItem(target, method, collection) { export function findTimerItem(target, method, collection) { let index = -1; - for (let i = 2, l = collection.length; i < l; i += 6) { + for (let i = 2, l = collection.length; i < l; i += TIMERS_OFFSET) { if (collection[i] === target && collection[i + 1] === method) { index = i - 2; break; diff --git a/lib/index.ts b/lib/index.ts index 982c7bf2..663b8e10 100644 --- a/lib/index.ts +++ b/lib/index.ts @@ -32,6 +32,14 @@ const noop = function() {}; const DISABLE_SCHEDULE = Object.freeze([]); +interface ConsoleWithCreateTask extends Console { + createTask(name: string): ConsoleTask; +} + +interface ConsoleTask { + run(f: () => T): T; +} + function parseArgs(...args: any[]); function parseArgs() { let length = arguments.length; @@ -163,6 +171,7 @@ export default class Backburner { public static buildNext = buildNext; public DEBUG = false; + public ASYNC_STACKS = false; public currentInstance: DeferredActionQueues | null = null; @@ -371,7 +380,8 @@ export default class Backburner { scheduleCount++; let [target, method, args] = parseArgs(..._args); let stack = this.DEBUG ? new Error() : undefined; - return this._ensureInstance().schedule(queueName, target, method, args, false, stack); + let consoleTask = this.createTask(queueName, method); + return this._ensureInstance().schedule(queueName, target, method, args, false, stack, consoleTask); } /* @@ -385,7 +395,8 @@ export default class Backburner { public scheduleIterable(queueName: string, iterable: () => Iterable) { scheduleIterableCount++; let stack = this.DEBUG ? new Error() : undefined; - return this._ensureInstance().schedule(queueName, null, iteratorDrain, [iterable], false, stack); + let consoleTask = this.createTask(queueName, null); + return this._ensureInstance().schedule(queueName, null, iteratorDrain, [iterable], false, stack, consoleTask); } /** @@ -406,7 +417,8 @@ export default class Backburner { scheduleOnceCount++; let [target, method, args] = parseArgs(..._args); let stack = this.DEBUG ? new Error() : undefined; - return this._ensureInstance().schedule(queueName, target, method, args, true, stack); + let consoleTask = this.createTask(queueName, method); + return this._ensureInstance().schedule(queueName, target, method, args, true, stack, consoleTask); } /** @@ -525,7 +537,8 @@ export default class Backburner { _timers[argIndex] = args; } else { let stack = this._timers[index + 5]; - this._timers.splice(i, 0, executeAt, timerId, target, method, args, stack); + let consoleTask = this._timers[index + 6]; + this._timers.splice(i, 0, executeAt, timerId, target, method, args, stack, consoleTask); this._timers.splice(index, TIMERS_OFFSET); } @@ -666,16 +679,17 @@ export default class Backburner { private _later(target, method, args, wait) { let stack = this.DEBUG ? new Error() : undefined; + let consoleTask = this.createTask("(timer)", method); let executeAt = this._platform.now() + wait; let id = UUID++; if (this._timers.length === 0) { - this._timers.push(executeAt, id, target, method, args, stack); + this._timers.push(executeAt, id, target, method, args, stack, consoleTask); this._installTimerTimeout(); } else { // find position to insert let i = searchTimer(executeAt, this._timers); - this._timers.splice(i, 0, executeAt, id, target, method, args, stack); + this._timers.splice(i, 0, executeAt, id, target, method, args, stack, consoleTask); // always reinstall since it could be out of sync this._reinstallTimerTimeout(); @@ -741,7 +755,8 @@ export default class Backburner { let target = timers[i + 2]; let method = timers[i + 3]; let stack = timers[i + 5]; - this.currentInstance!.schedule(defaultQueue, target, method, args, false, stack); + let consoleTask = timers[i + 6]; + this.currentInstance!.schedule(defaultQueue, target, method, args, false, stack, consoleTask); } } @@ -792,4 +807,12 @@ export default class Backburner { this._autorun = true; } + + private createTask(queueName, method){ + if (this.ASYNC_STACKS && console["createTask"]) { + return (console).createTask( + `runloop ${queueName} | ${method?.name || ""}` + ); + } + } } diff --git a/tests/async-stack-test.ts b/tests/async-stack-test.ts new file mode 100644 index 00000000..91dcb4d8 --- /dev/null +++ b/tests/async-stack-test.ts @@ -0,0 +1,75 @@ +import Backburner from 'backburner'; + +const skipIfNotSupported = !!console["createTask"] ? QUnit.test : QUnit.skip; + +QUnit.module('tests/async_stacks'); + +QUnit.test("schedule - does not affect normal behaviour", function(assert) { + let bb = new Backburner(['one']); + let callCount = 0; + + bb.run(() => { + bb.schedule("one", () => callCount += 1) + bb.schedule("one", () => callCount += 1) + }); + assert.strictEqual(callCount, 2, "schedule works correctly with ASYNC_STACKS disabled"); + + bb.ASYNC_STACKS = true; + + bb.run(() => { + bb.schedule("one", () => callCount += 1) + bb.schedule("one", () => callCount += 1) + }); + assert.strictEqual(callCount, 4, "schedule works correctly with ASYNC_STACKS enabled"); +}); + +skipIfNotSupported('schedule - ASYNC_STACKS flag enables async stack tagging', function(assert) { + let bb = new Backburner(['one']); + + bb.schedule('one', () => {}); + + assert.true(bb.currentInstance && (bb.currentInstance.queues.one.consoleTaskFor(0) === undefined), 'No consoleTask is stored'); + + bb.ASYNC_STACKS = true; + + bb.schedule('one', () => {}); + + const task = bb.currentInstance && bb.currentInstance.queues.one.consoleTaskFor(1); + assert.true(!!task?.run, 'consoleTask is stored in queue'); +}); + +QUnit.test("later - ASYNC_STACKS does not affect normal behaviour", function(assert) { + let bb = new Backburner(['one']); + let done = assert.async(); + bb.ASYNC_STACKS = true; + + bb.later(() => { + assert.true(true, "timer called") + done() + }); +}); + + +skipIfNotSupported('later - skips async stack when ASYNC_STACKS is false', function(assert) { + let done = assert.async(); + let bb = new Backburner(['one']); + + bb.later(() => { + const task = bb.currentInstance && bb.currentInstance.queues.one.consoleTaskFor(0, true); + assert.true(bb.currentInstance && (bb.currentInstance.queues.one.consoleTaskFor(0, true) === undefined), 'consoleTask is not stored') + done(); + }); +}); + + +skipIfNotSupported('later - ASYNC_STACKS flag enables async stack tagging', function(assert) { + let done = assert.async(); + let bb = new Backburner(['one']); + bb.ASYNC_STACKS = true; + + bb.later(() => { + const task = bb.currentInstance && bb.currentInstance.queues.one.consoleTaskFor(0, true); + assert.true(!!task?.run, 'consoleTask is stored in timer queue and then passed to runloop queue') + done(); + }); +}); diff --git a/tests/index.ts b/tests/index.ts index 0f6de03d..6da34498 100644 --- a/tests/index.ts +++ b/tests/index.ts @@ -1,3 +1,4 @@ +import './async-stack-test'; import './autorun-test'; import './bb-has-timers-test'; import './build-next-test'; From f3b8b0bd3a7917ee3fe105026d09fe380dc3f36f Mon Sep 17 00:00:00 2001 From: David Taylor Date: Mon, 10 Oct 2022 18:26:19 +0100 Subject: [PATCH 2/2] Fix linting violations --- lib/index.ts | 8 ++++---- tests/async-stack-test.ts | 20 ++++++++++---------- 2 files changed, 14 insertions(+), 14 deletions(-) diff --git a/lib/index.ts b/lib/index.ts index 663b8e10..89b47b71 100644 --- a/lib/index.ts +++ b/lib/index.ts @@ -679,7 +679,7 @@ export default class Backburner { private _later(target, method, args, wait) { let stack = this.DEBUG ? new Error() : undefined; - let consoleTask = this.createTask("(timer)", method); + let consoleTask = this.createTask('(timer)', method); let executeAt = this._platform.now() + wait; let id = UUID++; @@ -809,9 +809,9 @@ export default class Backburner { } private createTask(queueName, method){ - if (this.ASYNC_STACKS && console["createTask"]) { - return (console).createTask( - `runloop ${queueName} | ${method?.name || ""}` + if (this.ASYNC_STACKS && console['createTask']) { + return (console as ConsoleWithCreateTask).createTask( + `runloop ${queueName} | ${method?.name || ''}` ); } } diff --git a/tests/async-stack-test.ts b/tests/async-stack-test.ts index 91dcb4d8..6f32ce57 100644 --- a/tests/async-stack-test.ts +++ b/tests/async-stack-test.ts @@ -1,26 +1,26 @@ import Backburner from 'backburner'; -const skipIfNotSupported = !!console["createTask"] ? QUnit.test : QUnit.skip; +const skipIfNotSupported = !!console['createTask'] ? QUnit.test : QUnit.skip; QUnit.module('tests/async_stacks'); -QUnit.test("schedule - does not affect normal behaviour", function(assert) { +QUnit.test('schedule - does not affect normal behaviour', function(assert) { let bb = new Backburner(['one']); let callCount = 0; bb.run(() => { - bb.schedule("one", () => callCount += 1) - bb.schedule("one", () => callCount += 1) + bb.schedule('one', () => callCount += 1) + bb.schedule('one', () => callCount += 1) }); - assert.strictEqual(callCount, 2, "schedule works correctly with ASYNC_STACKS disabled"); + assert.strictEqual(callCount, 2, 'schedule works correctly with ASYNC_STACKS disabled'); bb.ASYNC_STACKS = true; bb.run(() => { - bb.schedule("one", () => callCount += 1) - bb.schedule("one", () => callCount += 1) + bb.schedule('one', () => callCount += 1) + bb.schedule('one', () => callCount += 1) }); - assert.strictEqual(callCount, 4, "schedule works correctly with ASYNC_STACKS enabled"); + assert.strictEqual(callCount, 4, 'schedule works correctly with ASYNC_STACKS enabled'); }); skipIfNotSupported('schedule - ASYNC_STACKS flag enables async stack tagging', function(assert) { @@ -38,13 +38,13 @@ skipIfNotSupported('schedule - ASYNC_STACKS flag enables async stack tagging', f assert.true(!!task?.run, 'consoleTask is stored in queue'); }); -QUnit.test("later - ASYNC_STACKS does not affect normal behaviour", function(assert) { +QUnit.test('later - ASYNC_STACKS does not affect normal behaviour', function(assert) { let bb = new Backburner(['one']); let done = assert.async(); bb.ASYNC_STACKS = true; bb.later(() => { - assert.true(true, "timer called") + assert.true(true, 'timer called') done() }); });