async_hooks: Awaited thenables have no async context after first tick

  • Version: 11.9, 10.15
  • Platform: macOS
  • Subsystem: async_hooks

If I do await { then: fn }, then code running in fn will always see an async ID of 1 until after an Immediate (or "lower priority" tick) is made, then it will start seeing 0 instead. I expect it instead to be the same async ID as the resource in which the call was made... see the below repro for expectations vs. actual results.

The culprit here is probably the same as in #22360, but discussion there has stalled. Also, I think the example here is easier to comprehend.

Repro

const asyncHooks = require('async_hooks');

// activate async_hooks
asyncHooks.createHook({
  init: () => {}
}).enable();

// a custom thenable
const thenable = () => ({
  then: (fn) => {
    console.log(asyncHooks.executionAsyncId());
    fn();
  }
});

async function main() {
  // On first tick
  console.log(asyncHooks.executionAsyncId()); // prints 1
  await thenable(); // prints 1 (expected)

  // After first thenable
  console.log(asyncHooks.executionAsyncId()); // prints incremented ID
  await thenable(); // still prints 1 (unexpected)

  // After high-priority tick
  await new Promise(res => process.nextTick(res)); // tick nextTick queue
  console.log(asyncHooks.executionAsyncId()); // prints incremented ID
  await thenable(); // still prints 1 (unexpected)

  // After Immediate
  await new Promise(res => setImmediate(res)); // tick immediate
  console.log(asyncHooks.executionAsyncId()); // prints incremented ID
  await thenable(); // prints 0 (unexpected)

  // A workaround
  console.log(asyncHooks.executionAsyncId()); // prints incremented ID
  await thenable().then(_ => _); // prints same as above (expected)
}

main().catch(console.error);

Real-world use case example

The knex module seems to sometimes make DB queries in a Promise.prototype.then wrapper. If the Promise implementation happens to be userland, like in bluebird, then async context will be unknown at the DB query call site.