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.

Author: davidtaylorhq

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}`;

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);
     }
   }
 

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 {

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;

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<T>(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 (<ConsoleWithCreateTask>console).createTask(
+        `runloop ${queueName} | ${method?.name || "<anonymous>"}`
+      );
+    }
+  }
 }

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();
+  });
+});

tests/index.ts

@@ -1,3 +1,4 @@
+import './async-stack-test';
 import './autorun-test';
 import './bb-has-timers-test';
 import './build-next-test';