René's URL Explorer Experiment

{"@context":"https://schema.org","@type":"DiscussionForumPosting","headline":"async_hooks.triggerAsyncId() don't return the expected value in context of the connection callback of net.Server","articleBody":"\u003c!--\r\nThank you for reporting an issue.\r\n\r\nThis issue tracker is for bugs and issues found within Node.js core.\r\nIf you require more general support please file an issue on our help\r\nrepo. https://github.com/nodejs/help\r\n\r\n\r\nPlease fill in as much of the template below as you're able.\r\n\r\nVersion: output of `node -v`\r\nPlatform: output of `uname -a` (UNIX), or version and 32 or 64-bit (Windows)\r\nSubsystem: if known, please specify affected core module name\r\n\r\nIf possible, please provide code that demonstrates the problem, keeping it as\r\nsimple and free of external dependencies as you are able.\r\n-->\r\n\r\n* **Version**: 8.x and 10.x\r\n* **Platform**: all supported\r\n* **Subsystem**:\r\n\r\n\u003c!-- Enter your issue details below this comment. -->\r\nasync_hooks.triggerAsyncId() is expected to return the async id of the connection in the `onconnection` callback of server. This was specifically declared in the example of the async_hooks documentation which can be found [here](https://nodejs.org/dist/latest-v10.x/docs/api/async_hooks.html#async_hooks_async_hooks_triggerasyncid). \r\n\r\nHowever, after testing the example using both node 10.3.0 and 8.11.2, I found the result was different. Below is the code and output of my test.\r\nmy code:\r\n```\r\nlet net = require('net');\r\nlet async_hooks = require('async_hooks');\r\nlet fs = require('fs');\r\n\r\nasync_hooks.createHook({\r\n  init(asyncId, type, triggerAsyncId) {\r\n  \tfs.writeSync(1, `init hook: ${type}, asyncID: ${asyncId}, triggerID: ${triggerAsyncId}\\n`);\r\n  },\r\n  before(asyncId) {\r\n    fs.writeSync(1, `before hook: asyncID: ${asyncId}\\n`);\r\n  },\r\n  after(asyncId) {\r\n    fs.writeSync(1, `after hook: asyncId: ${asyncId}\\n`);\r\n  },\r\n}).enable();\r\nconst server = net.createServer((conn) => {\r\n  // The resource that caused (or triggered) this callback to be called\r\n  // was that of the new connection. Thus the return value of triggerAsyncId()\r\n  // is the asyncId of \"conn\".\r\n  // fs.wriateSync(1, '-- conn callback, triggerAsyncId:', async_hooks.triggerAsyncId());\r\n  let tid = async_hooks.triggerAsyncId();\r\n  let eid = async_hooks.executionAsyncId();\r\n  fs.writeSync(1, `-- conn callback, triggerAsyncId: ${tid}, executionAsyncId: ${eid}\\n`);\r\n}).listen(8000, () => {\r\n  // Even though all callbacks passed to .listen() are wrapped in a nextTick()\r\n  // the callback itself exists because the call to the server's .listen()\r\n  // was made. So the return value would be the ID of the server.\r\n  let tid = async_hooks.triggerAsyncId();\r\n  let eid = async_hooks.executionAsyncId();\r\n  fs.writeSync(1, `-- listen callback, triggerAsyncId: ${tid}, executionAsyncId: ${eid}\\n`);\r\n});\r\n```\r\n\r\nif I connect the server with another terminal by `connect localhost 8000`, then the output is:\r\n```\r\ninit hook: TCPSERVERWRAP, asyncID: 5, triggerID: 1\r\ninit hook: TickObject, asyncID: 6, triggerID: 5\r\nbefore hook: asyncID: 6\r\n-- listen callback, triggerAsyncId: 5, executionAsyncId: 6\r\nafter hook: asyncId: 6\r\ninit hook: TCPWRAP, asyncID: 7, triggerID: 5\r\nbefore hook: asyncID: 5\r\n-- conn callback, triggerAsyncId: 1, executionAsyncId: 5\r\nafter hook: asyncId: 5\r\nbefore hook: asyncID: 7\r\ninit hook: TickObject, asyncID: 8, triggerID: 7\r\nafter hook: asyncId: 7\r\nbefore hook: asyncID: 8\r\ninit hook: TickObject, asyncID: 9, triggerID: 8\r\ninit hook: TickObject, asyncID: 10, triggerID: 8\r\nafter hook: asyncId: 8\r\nbefore hook: asyncID: 9\r\nafter hook: asyncId: 9\r\nbefore hook: asyncID: 10\r\nafter hook: asyncId: 10\r\nbefore hook: asyncID: 7\r\nafter hook: asyncId: 7\r\n\r\n```\r\n\r\nPlease note the line `-- conn callback, triggerAsyncId: 1, executionAsyncId: 5`. It means in the connection callback, the triggerAsyncId is 1 instead of 7 which is expected.\r\n\r\nI investigated the code, and found the root cause is:\r\nWhen the callback is made, it was made on the TCPWrap instance of the server, and the server's triggerId (1) and asyncId (5) were pushed into the stack, thus lead to this result. While It seems that this mechanism is ok most of the time for normal callbacks, but for this new connection callback, I think we should add some logic to pass the triggerId of the new connection (actually a new TCPWrap instance) to push into the stack. I made a change based on that and verified the result, it could work.\r\n\r\nSo, I doubt is the issue due to document obsoleted or the code should be changed?\r\nI'd like to make a PR if it is confirmed, thanks.","author":{"url":"https://github.com/tingshao","@type":"Person","name":"tingshao"},"datePublished":"2018-06-01T08:20:21Z","url":"https://github.com/nodejs/node/issues/21078"}