async_hooks: not able to preserve continuation local storage inside Promises

[gms1]

• Version: v8.1.0
• Platform: Linux sirius 4.9.9-gms-1 deps: update openssl to 1.0.1j #1 SMP Sun Feb 12 20:43:38 CET 2017 x86_64 GNU/Linux
• Subsystem: async_hooks

Hi,

maybe related to: (#13367),
the init-hook (now?) reports a triggerId of 0 for type 'PROMISE' sometimes

code to reproduce:

const asyncHooks = require('async_hooks');

let beforeId;
asyncHooks
    .createHook({
    init: (id, type, triggerId) => {
        process._rawDebug(`init: id:${id} type:${type} triggerId:${triggerId}`);
    },
    before: (id) => {
        process._rawDebug(`before: id:${id}`);
        beforeId = id;
    }
})
    .enable();

function tracePromise(prefix) {
    process._rawDebug(`promise : ${prefix}: currId:${asyncHooks.currentId()} lastId:${beforeId}`);
}

setImmediate(() => {
    doTrace = true;
    return new Promise((resolve, reject) => {
        tracePromise('P1: EXECUTOR FUNC');
        resolve();
    })
        .then(() => {
        tracePromise('P1: THEN');
        return new Promise((resolve, reject) => {
            tracePromise('P2: EXECUTOR FUNC');
            resolve();
        })
            .then(() => {
            tracePromise('P2: THEN');
            return new Promise((resolve, reject) => {
                tracePromise('P3: EXECUTOR FUNC');
                resolve();
            })
                .then(() => {
                tracePromise('P3: THEN');
            });
        });
    });
});

output from above:

gms@sirius:~/work/HOT/node-async-context/test (master)$ node promise.js 
init: id:2 type:Immediate triggerId:1
before: id:2
init: id:3 type:PROMISE triggerId:2
promise : P1: EXECUTOR FUNC: currId:2 lastId:2
init: id:4 type:PROMISE triggerId:3
before: id:4
promise : P1: THEN: currId:0 lastId:4
init: id:5 type:PROMISE triggerId:0
promise : P2: EXECUTOR FUNC: currId:0 lastId:4
init: id:6 type:PROMISE triggerId:5
before: id:6
promise : P2: THEN: currId:0 lastId:6
init: id:7 type:PROMISE triggerId:0
promise : P3: EXECUTOR FUNC: currId:0 lastId:6
init: id:8 type:PROMISE triggerId:7
init: id:9 type:PROMISE triggerId:6
before: id:8
promise : P3: THEN: currId:0 lastId:8
init: id:10 type:PROMISE triggerId:8
before: id:10
before: id:9

Guenter

[gms1]

for comparison the output using nodejs 8.0 showing similar behaviour:

gms@sirius:~/work/HOT/node-async-context/test (master)$ node -v
v8.0.0
gms@sirius:~/work/HOT/node-async-context/test (master)$ node promise.js 
init: id:2 type:Immediate triggerId:1
before: id:2
init: id:3 type:PROMISE triggerId:2
promise : P1: EXECUTOR FUNC: currId:2 lastId:2
init: id:4 type:PROMISE triggerId:2
before: id:4
promise : P1: THEN: currId:0 lastId:4
init: id:5 type:PROMISE triggerId:0
promise : P2: EXECUTOR FUNC: currId:0 lastId:4
init: id:6 type:PROMISE triggerId:0
before: id:6
promise : P2: THEN: currId:0 lastId:6
init: id:7 type:PROMISE triggerId:0
promise : P3: EXECUTOR FUNC: currId:0 lastId:6
init: id:8 type:PROMISE triggerId:0
init: id:9 type:PROMISE triggerId:0
before: id:8
promise : P3: THEN: currId:0 lastId:8
init: id:10 type:PROMISE triggerId:0
before: id:10
before: id:9

[addaleax]

Can you check that #13427 does what you want it to do?

[gms1]

Thank you for your fast response!
After checking out your 'async-hooks-promise-pushpop' branch and generating node, I am getting this output:

gms@sirius:~/work/HOT/node-async-context/test (master)$ node -v
v9.0.0-pre
gms@sirius:~/work/HOT/node-async-context/test (master)$ /usr/local/node/bin/node promise-then-promise.js 
init: id:2 type:Immediate triggerId:1
before: id:2
init: id:3 type:PROMISE triggerId:2
promise : P1: EXECUTOR FUNC: currId:2 lastId:2
init: id:4 type:PROMISE triggerId:3
before: id:4
promise : P1: THEN: currId:4 lastId:4
init: id:5 type:PROMISE triggerId:4
promise : P2: EXECUTOR FUNC: currId:4 lastId:4
init: id:6 type:PROMISE triggerId:5
before: id:6
promise : P2: THEN: currId:6 lastId:6
init: id:7 type:PROMISE triggerId:6
promise : P3: EXECUTOR FUNC: currId:6 lastId:6
init: id:8 type:PROMISE triggerId:7
init: id:9 type:PROMISE triggerId:6
before: id:8
promise : P3: THEN: currId:8 lastId:8
init: id:10 type:PROMISE triggerId:8
before: id:10
before: id:9

So the currentId() and the last id reported by the before-hook are now always the same
and using the triggerId it should be possible to preserve the continuation local storage:

P1: EXECUTOR FUNC: currId:2
P1: THEN: currId:4 => id:4 type:PROMISE triggerId:3 => id:3 type:PROMISE triggerId:2
P2: EXECUTOR FUNC: currId:4 lastId:4 => ...
P2: THEN: currId:6 => id:6 type:PROMISE triggerId:5 => id:5 type:PROMISE triggerId:4 ...
P3: EXECUTOR FUNC: currId:6 => ...
P3: THEN: currId:8 => id:8 type:PROMISE triggerId:7 => id:7 type:PROMISE triggerId:6 ...

Many Thanks!
Guenter