AsyncLocalStorage instance shared between several http requests

Version

v17.5.0

Platform

Linux DESKTOP 5.10.60.1-microsoft-standard-WSL2 #1 SMP Wed Aug 25 23:20:18 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

Subsystem

async_hooks

What steps will reproduce the bug?

Opening localhost:3000/ in Chrome (keep-alive) shows that we have access to the same instance of AsyncLocalStorage when we serve both / and /favicon.ico. I would understand if both of them were coming from the same async resource representing connection and there was no distinction, but log (see below) produced by async hooks shows that there was two separate HTTPINCOMINGMESSAGE but when it comes to request listener suddenly we have same asyncId.

May be it is not a bug, but observed behavior is very confusing. I've read that

import * as http from "node:http";
import * as events from "node:events";
import * as async_hooks from "node:async_hooks";

await events.once(http.createServer(httpHandler).listen(3000), "listening");
console.log("server started");
const currentRequest = new async_hooks.AsyncLocalStorage();

// Create hook to ensure t
async_hooks
  .createHook({
    init(asyncId, type) {
      if (type === "TickObject" || type === "TickTimeout") return;
      console.log(asyncId, type);
    },
  })
  .enable();

function getCurrentRequestExn() {
  const current = currentRequest.getStore();
  if (!current) throw new Error("no current request");
  return current;
}

function setCurrentRequest(req) {
  console.log(
    "setCurrentRequest %s %d",
    req.url,
    async_hooks.executionAsyncId()
  );
  const existing = currentRequest.getStore();
  if (existing !== void 0) throw new Error("current request already set");
  currentRequest.enterWith(req);
}

function httpHandler(req, res) {
  setCurrentRequest(req);
  if (req.url === "/") res.end(route1());
  else if (req.url === "/favicon.ico") res.end(route2());
}

function route1() {
  const req = getCurrentRequestExn();
  return "route1 " + req.url;
}

function route2() {
  const req = getCurrentRequestExn();
  return "route2" + req.url;
}

Log produced:

server started
20 TCPWRAP
22 HTTPINCOMINGMESSAGE
24 TCPWRAP
26 HTTPINCOMINGMESSAGE
setCurrentRequest / 22
29 Timeout
34 Timeout
setCurrentRequest /favicon.ico 22

And, since we accessing same instance of the async local storage - then there is an exception:

file:///home/dolphin/projects/komsomol/server.js:33
  if (existing !== void 0) throw new Error("current request already set");
                           ^

Error: current request already set
    at setCurrentRequest (file:///home/dolphin/projects/komsomol/server.js:33:34)
    at Server.httpHandler (file:///home/dolphin/projects/komsomol/server.js:38:3)
    at Server.emit (node:events:526:28)
    at parserOnIncoming (node:_http_server:951:12)
    at HTTPParser.parserOnHeadersComplete (node:_http_common:128:17)

How often does it reproduce? Is there a required condition?

All the time.

What is the expected behavior?

Separate instances of AsyncLocalStorage for each request, or some explanation in documentation on how to achieve it.

What do you see instead?

Same instances of AsyncLocalStorage shared between http requests contexts when requests made using keep-alive connection.

Additional information

No response

Start by running the reproduction in server.js with a keep-alive browser connection and compare the async_hooks output for both requests. Then trace the request path through parserOnIncoming in node:_http_server and the AsyncLocalStorage behavior described in the issue. Done means the request contexts are correctly distinguished or the supported behavior and required usage are documented.