async_hooks does not currently provide a way to track causality for a PromiseReactionJob

[hayes]

• Version: v8.0.0
• Platform: All
• Subsystem: async_hooks, promises

Currently, there is no way (using async_hooks) to associate a PromiseReactionJob with the async id that fulfilled that promise. There is also no way to get the timing of the kResolved promise life cycle hook. These may be 2 separate issues, but are closely related.

Currently here is what is available for promises:

• init (Promise creation):
  • currentId: the async_id of the current execution context when the promise is created
  • triggerId: (once async_hooks: use parent promise as triggerId in init hook #13367 lands) The id of the parent promise
  • asyncId: an async id for the new promise
  • async_hooks.currentId(): same as currentId
  • async_hooks.triggerId(): trigger id for the current execution context (not the same as triggerId argument)
• before (start of PromiseReactionJob)
  • asyncId: an async id for the promise
  • async_hooks.currentId(): same as asyncId (once async_hooks.currentId() sometimes reports the wrong id during PromiseReactionJob #13427 is fixed)
  • `async_hooks.triggerId(): currently also affected by async_hooks.currentId() sometimes reports the wrong id during PromiseReactionJob #13427 (either parentPromise id or same as currentId?)
• after (end of PromiseReactionJob)
  • asyncId: an async id for the promise
  • async_hooks.currentId(): same as asyncId (once async_hooks.currentId() sometimes reports the wrong id during PromiseReactionJob #13427 is fixed)
  • async_hooks.triggerId(): currently also affected by async_hooks.currentId() sometimes reports the wrong id during PromiseReactionJob #13427 (either parentPromise id or same as currentId?)

Ideally there would be a way to access the id of the async context active during kResolved from the before/after hooks. Initially I had expected that during a PromiseReactionJob calling async_hooks.triggeredId() would return the contextId of the context responsible for resolving the promise. I am not sure if this is right approach. but having some way to link these 2 contexts is important for the apm use case.

[hayes]

/cc @nodejs/async_hooks

[AndreasMadsen]

Could you clarify what a "PromiseReactionJob" is? I can see that it used elsewhere but I don't know what the definition is.

[matthewloring]

It is a reference to the ES spec. Having access to the resolution context at resolution time is important. I think the best way to handle this would be to add a new async_hooks event that fires when asynchronous work completes even if the associated callback may not yet run. This could be used for promise resolution but I could also imagine other async operations (maybe uses of the embedder api) where the callback is not invoked immediately after the task completes. There was some previous discussion of this here (#13000 (comment)).

[hayes]

Interesting, I like the idea of having another event fire for this case, seems like there are a few other places where it could be useful. I took a quick stab at trying to implement it (hayes/node@4439e99) got something that seems to work well enough for a quick hack/proof of concept.

This would work great to solve the lack of timing for promises, It also makes it possible to track causality, even if it is a bit more complicated than just looking at triggerId.

Here is a quick example using the change I linked above:

const async_hooks = require('async_hooks');
const fs = require('fs')

let indent = 0;
async_hooks.createHook({
  init(asyncId, type, triggerId, obj) {
    const cId = async_hooks.currentId();
    const currentTrigger = async_hooks.triggerId()
    fs.writeSync(1, ' '.repeat(indent) +
                    `${type}(${asyncId}): trigger: ${triggerId} scope: ${cId}\n`);
  },
  before(asyncId) {
    fs.writeSync(1, ' '.repeat(indent) + `before:  ${asyncId}\n`);
    indent += 2;
  },
  after(asyncId) {
    indent -= 2;
    fs.writeSync(1, ' '.repeat(indent) + `after:   ${asyncId}\n`);
  },
  destroy(asyncId) {
    fs.writeSync(1, ' '.repeat(indent) + `destroy: ${asyncId}\n`);
  },
  resolve(asyncId, triggerId) {
    fs.writeSync(1, ' '.repeat(indent) + `resolved: ${asyncId} in context: ${triggerId}\n`);
  },
}).enable();


Promise.resolve().then(() => {
  return new Promise(resolve => setTimeout(resolve));
});

which outputs
(some of the context values are incorrect because of #13427)

PROMISE(2): trigger: 1 scope: 1
resolved: 2 in context: 1
PROMISE(3): trigger: 2 scope: 1
before:  3
  PROMISE(4): trigger: 1 scope: 1
  Timeout(5): trigger: 1 scope: 1
  TIMERWRAP(6): trigger: 1 scope: 1
  resolved: 3 in context: 1
after:   3
PROMISE(7): trigger: 4 scope: 1
before:  6
  before:  5
    resolved: 4 in context: 5
  after:   5
after:   6
before:  7
  resolved: 3 in context: 0
  resolved: 7 in context: 0
after:   7
destroy: 5
destroy: 6

If this seems like a good direction to go, I would be happy to clean things up and turn it into a PR.
The main things I would need to figure out:

1. what should the new hook be called
2. should I remove the second argument for the resolve hook (current it emits the async id of the resolved resource, and the currentId from where the resource was resolved). I think its redundant because you can get it by calling async_hooks.currentId() to get the same value.
3. Is it okay just to implement this hook for promises, or would it need to be added for other resources as well in the initial pass.

[AndreasMadsen]

what should the new hook be called

Not sure, but I don't think resolved is a good choice since it so specific to promises.

should I remove the second argument for the resolve hook (current it emits the async id of the resolved resource, and the currentId from where the resource was resolved). I think its redundant because you can get it by calling async_hooks.currentId() to get the same value.

Yes, remove it.

Is it okay just to implement this hook for promises, or would it need to be added for other resources as well in the initial pass.

Since this is a big addition to async_hooks I definitely don't want to move fast with this idea. I would like to get a clear overview of where else this feature could be useful, so we can make sure it isn't too specific to promises.

[hayes]

Not sure, but I don't think resolved is a good choice since it so specific to promises.

Agreed, it was just a placeholder because I didn't have any good idea about what other types of events might trigger the new hook.

I would like to get a clear overview of where else this feature could be useful, so we can make sure it isn't too specific to promises.

I have been thinking about this a lot, but all of the ideas I had initially for where this might be useful have not held up once I thought a little more about their use cases. Promises are unique in that the scheduling of work is generally a reaction to user code, and not the resource. As far as I can tell there are no other resources that don't either schedule their callbacks as a direct response to creating the resource, or schedule them based on something that happens in native code. I don't really see a good way to create a similar situation using the Embedder api, since any scheduling of callbacks would be done using methods like setTimeout that are represented by their own resources.

[AndreasMadsen]

This is something that would be good to take up on the Diagnostic WG meeting, just to get some other perspectives.

/cc @nodejs/diagnostics

[hayes]

sounds good, I'll put this on hold until after the next diag meeting. I also sent a request to rejoin that group (I removed myself sometime last year because I didn't have the time to keep up with it at the time).