Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

async_hooks: destroy emitted more than once for an asyncId #26961

Closed
Trott opened this issue Mar 28, 2019 · 8 comments
Closed

async_hooks: destroy emitted more than once for an asyncId #26961

Trott opened this issue Mar 28, 2019 · 8 comments
Labels
async_hooks Issues and PRs related to the async hooks subsystem. confirmed-bug Issues with confirmed bugs. http Issues or PRs related to the http subsystem.

Comments

@Trott
Copy link
Member

Trott commented Mar 28, 2019

  • Version: 12.0.0-pre (current master)
  • Platform: Darwin LIB-0F7FVH8-LT 18.2.0 Darwin Kernel Version 18.2.0: Thu Dec 20 20:46:53 PST 2018; root:xnu-4903.241.1~1/RELEASE_X86_64 x86_64
  • Subsystem: async_hooks

This code shows destroy emitting twice for a single asyncId. (You may need to run it more than once to see the error and/or increase the value of N in the code, but it repros most of the time for me.)

'use strict';

const assert = require('assert');
const async_hooks = require('async_hooks');
const http = require('http');

const N = 50;
const KEEP_ALIVE = 100;

const destroyedIds = [];
async_hooks.createHook({
  destroy: (asyncId) => {
    assert(!destroyedIds.includes(asyncId), `${asyncId} already in ${destroyedIds.sort()}`);
    destroyedIds.push(asyncId);
  }
}).enable();

const server = http.createServer(function(req, res) {
  res.end('Hello');
});

const keepAliveAgent = new http.Agent({
  keepAlive: true,
  keepAliveMsecs: KEEP_ALIVE,
});

let M = 0;
server.listen(0, function() {
  for (let i = 0; i < N; ++i) {
    (function makeRequest() {
      http.get({
        port: server.address().port,
        agent: keepAliveAgent
      }, function(res) {
        res.resume();
        M++;
        if (M === N)
          server.close();
        assert.ok(M <= N);
      });
    })();
  }
});
@Trott Trott added the async_hooks Issues and PRs related to the async hooks subsystem. label Mar 28, 2019
@Trott
Copy link
Member Author

Trott commented Mar 28, 2019

@nodejs/async_hooks

@addaleax addaleax added the http Issues or PRs related to the http subsystem. label Mar 28, 2019
@BridgeAR BridgeAR added the confirmed-bug Issues with confirmed bugs. label Apr 21, 2019
@BridgeAR
Copy link
Member

I am able to reproduce the error and it seems this always fails with the identical asyncId which is a bit surprising. Init is definitely only called once for the id.

@Flarna
Copy link
Member

Flarna commented Apr 21, 2019

I expect this is related to reusing HTTPPARSER instances; so maybe #25094 fixes this as side effect.

By increasing N I can reproduce this also with 8, 10 and 11.

@Flarna
Copy link
Member

Flarna commented Apr 21, 2019

I think destroy gets once triggered via Parser::Free() and once again in Parser::Reinitialize() which calls AsyncWrap::AsyncReset().

@Flarna
Copy link
Member

Flarna commented Apr 22, 2019

Seems #25094 didn't fix this but the behaviour is different. I think the problem now is that destroy is called only once during Parser::Free() but init is missing once a Parser gets reused.

targos pushed a commit that referenced this issue May 4, 2019
Fix some issues introduced/not fixed via
#25094:
* Init hook is not emitted for a reused HTTPParser
* HTTPParser was still used as resource in init hook
* type used in init hook was always HTTPINCOMINGMESSAGE even for client
requests
* some tests have not been adapted to new resource names

With this change the async hooks init event is emitted during a call
to Initialize() as the type and resource object is available at this
time. As a result Initialize() must be called now which could be seen
as breaking change even HTTPParser is not part of documented API.

It was needed to put the ClientRequest instance into a wrapper object
instead passing it directly as async resource otherwise
test-domain-multi fails. I think this is because adding an EventEmitter
to a Domain adds a property 'domain' and the presence of this changes
the context propagation in domains.

Besides that tests still refering to resource HTTPParser have been
updated/improved.

Fixes: #27467
Fixes: #26961
Refs: #25094

PR-URL: #27477
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Reviewed-By: Rich Trott <rtrott@gmail.com>
@Flarna
Copy link
Member

Flarna commented May 10, 2019

This issue happens also on Node 10 and 8.
Fix #27477 depends on #25094 which is labeled with dont-land-on-v10.x therefore the fix can't be backported as is to v10.
Should I create a dedicated PR to fix this on v10 and v8?

@Trott
Copy link
Member Author

Trott commented May 10, 2019

This issue happens also on Node 10 and 8.
Fix #27477 depends on #25094 which is labeled with dont-land-on-v10.x therefore the fix can't be backported as is to v10.
Should I create a dedicated PR to fix this on v10 and v8?

@mcollina is the person who thought #25094 should not land on v10.x. Pinging them to make sure that's still their view. If you can find a way to fix it that avoids whatever their concerns about landing that PR on v10.x were, then yes!

@Trott
Copy link
Member Author

Trott commented May 10, 2019

(Also, thanks for being on top of this stuff!)

Flarna added a commit to dynatrace-oss-contrib/node that referenced this issue May 30, 2019
Avoid that destroy hook is invoked twice - once via `Parser::Free()`
and once again via `Parser::Reinitialize()` by clearing the async_id
in `EmitDestroy()`.

Partial backport of nodejs#27477, a full
backport would require also nodejs#25094
which has a dont-land-on-v10.x label on it.

Fixes: nodejs#26961
BethGriggs pushed a commit that referenced this issue Jun 28, 2019
Avoid that destroy hook is invoked twice - once via `Parser::Free()`
and once again via `Parser::Reinitialize()` by clearing the async_id
in `EmitDestroy()`.

Partial backport of #27477, a full
backport would require also #25094
which has a dont-land-on-v10.x label on it.

Fixes: #26961

Backport-PR-URL: #27986
PR-URL: #27477
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Reviewed-By: Rich Trott <rtrott@gmail.com>
BethGriggs pushed a commit that referenced this issue Jul 17, 2019
Avoid that destroy hook is invoked twice - once via `Parser::Free()`
and once again via `Parser::Reinitialize()` by clearing the async_id
in `EmitDestroy()`.

Partial backport of #27477, a full
backport would require also #25094
which has a dont-land-on-v10.x label on it.

Fixes: #26961

Backport-PR-URL: #27986
PR-URL: #27477
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Reviewed-By: Rich Trott <rtrott@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
async_hooks Issues and PRs related to the async hooks subsystem. confirmed-bug Issues with confirmed bugs. http Issues or PRs related to the http subsystem.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants