AsyncLocalStorage does not work with http.Agent

[indutny]

• Version: 14.5.0
• Platform: macos
• Subsystem: async_hooks

What steps will reproduce the bug?

'use strict';

const http = require('http');
const { AsyncLocalStorage } = require('async_hooks');

const session = new AsyncLocalStorage();

const agent = new http.Agent({
  maxSockets: 1
});

const get = (path, callback) => {
  http.request({
    agent,
    host: 'example.com',

    method: 'GET',
    path,
  }, callback).end();
};

let id = 0;
const server = http.createServer((req, res) => {
  session.run(id++, () => {
    console.error('new req', session.getStore());
    get('/', (remote) => {
      console.error('remote response', session.getStore());
      remote.pipe(res);
    });
  });
}).listen(0, () => {
  const { port } = server.address();
  http.request({ port }).end();
  http.request({ port }).end();
});

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

Always. No conditions.

What is the expected behavior?

I expect this code to print:

new req 0
new req 1
remote response 0
remote response 1

What do you see instead?

new req 0
new req 1
remote response 0
remote response 0

Additional information

This is very much expected behavior of CLS storage. Any sort of pooling would result in similar issues. What's concerning is that it can happen with use of an existing core primitive (http.Agent). In fact, use of any agent with maxSockets !== Infinity or keepAlive set to true would result in similar behavior.

This behavior can be documented, but I'd imagine that such documentation would look like an incompatibility within Node.js core. Given that whole async_hooks module experimental - should we consider removing AsyncLocalStorage instead?

cc @nodejs/collaborators

[Flarna]

I think removing AsyncLocalStorage doesn't solve any problem. If there is no AsyncLocalStorage in core people implement it using async_hooks in userland and end up with the same problem.
We have several areas in core where resources are reused (e.g. HTTPParser) but create a new resource (and async id) everytime it's reused to avoid issues. Looks like there is a reuse where this wrapping is missing.

[indutny]

@Flarna even if we create a patch for this particular issue - similar problems would still be caused by other core or user-land modules. Whenever there is a pooling involved - there is a potential for a thread-local storage to get out of sync. From my experience, it is hard to impossible to debug and leads to security issues. I've personally seen developers using CLS as a storage for security data and application users performing activities for other random users as a result.

The issue with having it in the core is that core API comes with a promise both in the form of the documentation and provided by the fact that it is a part of the core and thus is can be trusted. Should we make a promise for something as frail and susceptible to issues as thread-local storage?

[indutny]

Perhaps, instead of shipping its version of CLS implementation - Node.js core should be more vocal about why CLS should not be used in user code at all?

[Flarna]

I understand your point that we removing AsyncLocalStorage from core would remove the corresponding problems from core.
My feeling is that AsyncLocalStorage is as good/bad as async_hooks are. Do you think we should remove also async hooks?

The problem with not using CLS is that it disallows some usecases - concrete any APM tool I know uses CLS and I'm quite sure there is more then these.

[indutny]

I think removal of async_hooks should be discussed separately if discussed at all.

APM and any form of tracing/monitoring does not have an effect on the logic of the application so it is indeed safer. However, imagine a different scenario: thread-local storage is used for logging and the support team uses logs when the ground-truth is unavailable. What would happen if the logs of one request will get mixed with the logs of another? One can't argue that this is an incorrect use of the thread-local storage, because, well, it is what it was advertised for. However, evidently there are still possible ways in which this could go wrong even if this doesn't change the behavior of the server in general.

FWIW, I know plenty of tools that use CLS and contributed to removal of CLS at least in some of them. The fact that there exists software that uses faulty API/module doesn't mean that this functionality has to be present in broken form.

[rjharmon]

I have some exposure to CLS impl & integrations, and I'm coming at this from a high-level/black-box point of view. CLS is high value in my estimation.

It seems pretty clear that things that do pooling need to take steps to ensure reasonable CLS semantics for their callers. In the use-case mentioned, the Agent instance should have a CLS (if needed) branched from its point of creation; the http.request() should have CLS branched from its point of creation, with any Agent interactions passing the request's CLS through so they can be used in alignment with expected semantics.

Choosing one of these contexts accurately inside the Agent would depend on the situation, though. For instance, a) pool activity isn't request-specific, so logging cleanup of idle connections would use the Agent's CLS logger if that were a thing. Again with a hypothetical, b) logging "yay, this connection is still active, we'll hang onto it longer" might ALSO use the Agent's CLS logger even though an in-scope request having its own CLS context was the causation for it. ...but then c) it would use that request's CLS/async context explicitly, for a callback such as the one mentioned in this issue.

Maybe the issue title should be centered on http.request() and/or http.Agent not playing their expected cooperative role with CLS?

[indutny]

@rjharmon what are you are saying is that we have a leaky abstraction that requires a full-stack support. Yet most Node.js apps are built around public npm modules that do not yet provide (and many won't for a long time) such support. Sure, it is possible to "fix" http.Agent to make it play better with this particular CLS and even introduce an API for doing so, but until whole ecosystem catches up - there are still going to be incompatibilities in the 3rd party modules and these modules may not even be in the direct dependencies of the application (as it was in my case some time ago).

[chrisdickinson]

Chiming in on this as a former user of CLS for sensitive data: this is a tough issue to thread. There's a legitimate desire for CLS for operations like logging, APM, or associating resources with requests (like postgres connections, for example.) Doing this requires a lot of care, as @indutny notes -- if a dependency anywhere in your tree does any sort of connection pooling & doesn't use the AsyncResource API to correctly re-associate asyncwrap ids, context might be lost or swapped incorrectly. It's very hard to debug when this happens.

However.

Authors have been doing this with Node for a very long time – even before AsyncLocalStorage, through monkeypatching or via domains. There's a real desire for this feature; in my experience Node has not had much success in telling authors not to do something that they want to do. Providing a blessed API for doing this work gives Node an place to document the potential pitfalls, and maybe some amount of leverage over the situation (could Node provide an AsyncResourcePool API that issued AsyncWrap IDs in a CLS-compatible fashion? You could imagine this making the rounds to popular packages, like pg-pool, much in the same way domain support did.)

I'm in complete agreement that the feature, as it is now, is dangerous. However, it's a feature that authors continue to try to implement themselves. By acknowledging that authors want this functionality, we can better educate them on the pitfalls. Hopefully, eventually, we can work with the community to make the feature less dangerous. Backing out the feature would be doing node's users a disservice by continuing to let them fend for themselves.

[rjharmon]

Fair points, for sure. I'd agree that the http module has a leaky abstraction. Possibly that's true more generally of AsyncLocalStorage too; that's not really how I'm seeing it, though I recognize I may be seeing wrongly. The facts of this issue's existence, and that both modules are included with nodejs, makes these distinctions pretty much boring, though.

With some clear guidelines, maybe we can help those 3rd-party module providers shorten "a long time" somewhat (perhaps in a way like @chrisdickinson elaborates) - the API seems straightforward enough, once one gets their head around it. Helping them to identify how/whether they're impacted, and to add not-v14 and not->v13.whatever clauses to their package.json might also be in order.

Shipping broken bundled modules in a v14-LTS in October would be a real bummer.

[indutny]

@chrisdickinson beautiful take on it!

I can see the motivation behind having it in core. What I disagree with is that 3rd party modules will catch up and provide support for this. As you said single 3rd party module in indirect dependencies may mix up the async contexts for whole app and result in very unpredictable and dangerous behavior.

Having this API means that the ecosystem is going to fracture into modules that were modified to support this and the modules without the support. If we are to assume full cooperation from all module authors - there are still pure JavaScript code that is no longer (or lightly) maintained, but does not depend on Node.js core specifically and thus is perfectly usable.

It is okay to have a breaking an API change and we do it from time to time. What's unfortunate in the case of CLS is that the fact that the module does not support it is completely invisible to the module user up to the moment when it blows up in production.

[indutny]

@rjharmon unfortunately I can't agree with you. http module implementation has its pitfalls, but in the context of this particular issue it suffers from the same symptoms that the rest of JavaScript modules might. There is nothing specifically incorrect about how it is written.

[Qard]

There's already many modules which properly use AsyncResource to bind the context and that's with async_hooks being marked as experimental. With AsyncLocalStorage we have a simpler API surface area than async_hooks and so it has a better chance of leaving experimental and thus a better chance of convincing module authors that they should use AsyncResource to support it properly.

Removing AsyncLocalStorage from core doesn't fix the issues, it just drops them all on the users to fix in userland where it can't be fixed safely or in a way that benefits everyone. The cost of fixing context propagation issues is large and so individuals tend to just leave them broken which has resulted in an ecosystem full of APM vendors that are likely to crash your app, which is obviously undesirable. By having it in core, we're committing to a goal of reaching greater stability and are thus making more fixes to do that, which is evidenced by the creation of executionAsyncResource, the thenables fix I made to V8, the promise hook fast path when not using the destroy hook in async_hooks--yes, it's not perfect, but in core we can work toward something more solid than the horribly broken and fragmented solutions the ecosystem has had for the last decade. We've made more progress on async_hooks performance, usability and stability in the last six months than in the entire lifetime of Node.js leading up to that, because we finally were able to get some of this stuff in core.