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

test_runner: cleanup test timeout abort listener #48915

Conversation

rluvaton
Copy link
Member

@rluvaton rluvaton commented Jul 25, 2023

fix #48475

@nodejs-github-bot
Copy link
Collaborator

Review requested:

  • @nodejs/test_runner

@nodejs-github-bot nodejs-github-bot added needs-ci PRs that need a full CI run. test_runner Issues and PRs related to the test runner subsystem. labels Jul 25, 2023
@rluvaton rluvaton marked this pull request as ready for review July 25, 2023 09:44
Comment on lines 104 to 115
deferred.promise = PromisePrototypeThen(deferred.promise, () => {
throw new ERR_TEST_FAILURE(
`test timed out after ${timeout}ms`,
kTestTimeoutFailure,
);
});
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wanted to put this in the setTimeout but for some reason, the test-runner-output.mjs test failed for the describe_it file with some missing stack trace

Comment on lines 92 to 108
function throwOnAbort() {
deferred.reject(new AbortError(undefined, { cause: signal.reason }));
clearTimeout(timer);
}
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done this to match the current behavior:

reject(new AbortError(undefined, { cause: signal?.reason }));

but we should align it with just using an abort signal with no timeout - no error being thrown or throw an abort error

Comment on lines 87 to 93
const cleanAbort = addAbortListener(signal, throwOnAbort)[SymbolDispose];
const timer = setTimeout(() => {
deferred.resolve();
cleanAbort();
}, timeout);

timer.unref();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could/Should this be an AbortSignal.any([signal, AbortSignal.timeout(timeout)]) etc?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think it would change anything as the timer won't get cleaned...

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What do you mean about the timer not getting clean?
The AbortSignal.any uses weak refs, so once this is GCed it would clear the timeout...

I think this suggestion could potentially reduce the complexity here, and also make it easier to land on v18, which doesn't have dispose & addAbortListener at the moment

WDYT?

Copy link
Member Author

@rluvaton rluvaton Jul 25, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

thank you! this is a much cleaner solution! the only problem here is that we create 2 new AbortSignal (AbortSignal.any and AbortSignal.timeout) for every describe/test/hook run, which can be bad for performance...

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@MoLow what do you think? should we remove the addAbortListener and dispose in order to support v18 and v16?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think this actually simplifies 😬

Copy link
Member

@atlowChemi atlowChemi Jul 26, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@rluvaton I had something like this in mind:

function stopTest(timeout, signal) {
  const timeoutSignal = timeout !== kDefaultTimeout && AbortSignal.timeout(timeout);
  const composedSignal = AbortSignal.any([signal, timeoutSignal].filter(Boolean));
  return PromisePrototypeThen(once(composedSignal, 'abort'), (e) => {
    if (e.target.reason !== timeoutSignal.reason) {
      return;
    }
    throw new ERR_TEST_FAILURE(
      `test timed out after ${timeout}ms`,
      kTestTimeoutFailure,
    );
  })
};

But current solution works for me 🙂

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we accept the extra creation of an abort signal I highly prefer that

Copy link
Member

@atlowChemi atlowChemi Jul 26, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I assume we would want to profile both and decide based on that?
@MoLow @benjamingr what is your opinion here?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've created a benchmark PR and after it is merged we can check different solutions:

lib/internal/test_runner/test.js Show resolved Hide resolved
Comment on lines 87 to 93
const cleanAbort = addAbortListener(signal, throwOnAbort)[SymbolDispose];
const timer = setTimeout(() => {
deferred.resolve();
cleanAbort();
}, timeout);

timer.unref();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What do you mean about the timer not getting clean?
The AbortSignal.any uses weak refs, so once this is GCed it would clear the timeout...

I think this suggestion could potentially reduce the complexity here, and also make it easier to land on v18, which doesn't have dispose & addAbortListener at the moment

WDYT?

lib/internal/test_runner/test.js Outdated Show resolved Hide resolved
lib/internal/test_runner/test.js Outdated Show resolved Hide resolved
@MoLow
Copy link
Member

MoLow commented Jul 25, 2023

@rluvaton see this implementation, I think a little cleaner and performant - WDYT? fa48543

@rluvaton
Copy link
Member Author

@MoLow updated with your changes and modified to use ObjectDefineProperty

@MoLow MoLow requested a review from benjamingr July 25, 2023 18:56
Copy link
Member

@benjamingr benjamingr left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't like the promise+disposer in one object code pattern here + I don't like the explicit promise construction here.

We're core, we can "cheat", we can add the listener with [kWeakHandler]: test and it will cleanup the listener when the test is done.

@rluvaton
Copy link
Member Author

We're core, we can "cheat", we can add the listener with [kWeakHandler]: test and it will cleanup the listener when the test is done.

to which listener? the abort listener? because using the aborted function from internal/abort_controller and passing the test as the resource did not work to clean up the abort listener

@benjamingr
Copy link
Member

The issue is the listener won't be removed right? kWeakListener means "remove the listener when that resource is gcd"

@rluvaton
Copy link
Member Author

rluvaton commented Jul 26, 2023

(I removed the timeout support so I try to make it work for the simple case)

I understand, but when I tried changing the stopTest function to using aborted (which under the hood use the kWeakHandler):

const { aborted } = require('internal/abort_controller');

function stopTest(timeout, signal) {
  return aborted(signal, {});
}

The test I wrote:

const { beforeEach, afterEach, test} = require("node:test");
beforeEach(() => {
  global.gc();
});
afterEach(() => {
  global.gc();
});

for (let i = 1; i <= 11; ++i) {
  test(`${i}`, () => {
  global.gc();
  });
}

it still log that:

(node:60047) MaxListenersExceededWarning: Possible EventTarget memory leak detected. 11 abort listeners added to [AbortSignal]. Use events.setMaxListeners() to increase limit
    at [kNewListener] (node:internal/event_target:542:17)
    at [kNewListener] (node:internal/abort_controller:239:24)
    at EventTarget.addEventListener (node:internal/event_target:655:23)
    at node:internal/test_runner/test:85:12
    at new Promise (<anonymous>)
    at stopTest (node:internal/test_runner/test:84:10)
    at TestHook.run (node:internal/test_runner/test:563:21)
    at TestHook.run (node:internal/test_runner/test:772:18)
    at node:internal/test_runner/test:519:20
    at async Test.runHook (node:internal/test_runner/test:517:7)

also when doing this it had the same effect:

function stopTest(timeout, signal) {
  return new Promise((resolve) => {
    signal.addEventListener('abort', resolve, { [kWeakHandler]: {} });
    setImmediate(() => {
      global.gc()
    }).unref()
  });
}

Maybe I'm missing something?

@atlowChemi
Copy link
Member

Maybe I'm missing something?

@rluvaton if we want to keep using the original signal we could keep updating kMaxEventTargetListeners, and since this AFAIK this signal is created internally we can probably safely assume we know how many listeners are being added...

@rluvaton
Copy link
Member Author

The problem is that we are not cleaning up the abort listener (see that it still happening even when we GC manually)

@rluvaton
Copy link
Member Author

rluvaton commented Jul 28, 2023

The reason why the warning still printed was because of #48951

rluvaton added a commit to rluvaton/node that referenced this pull request Aug 15, 2023
no longer needed after nodejs#48915 fix

PR-URL: nodejs#48989
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
@RafaelGSS
Copy link
Member

Due to fact, #48877 didn't land cleanly on v20.x-staging. This PR somehow, depends on it. So we'll need a manual backport.

Reference: https://github.com/nodejs/node/blob/main/doc/contributing/backporting-to-release-lines.md

@RafaelGSS RafaelGSS added the backport-requested-v20.x PRs awaiting manual backport to the v20.x-staging branch. label Aug 17, 2023
rluvaton added a commit to rluvaton/node that referenced this pull request Aug 18, 2023
fix nodejs#48475

PR-URL: nodejs#48915
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
rluvaton added a commit to rluvaton/node that referenced this pull request Aug 18, 2023
no longer needed after nodejs#48915 fix

PR-URL: nodejs#48989
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
@rluvaton
Copy link
Member Author

@rluvaton rluvaton added backport-open-v20.x Indicate that the PR has an open backport and removed backport-requested-v20.x PRs awaiting manual backport to the v20.x-staging branch. labels Aug 18, 2023
rluvaton added a commit to rluvaton/node that referenced this pull request Sep 4, 2023
fix nodejs#48475

PR-URL: nodejs#48915
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
rluvaton added a commit to rluvaton/node that referenced this pull request Sep 4, 2023
no longer needed after nodejs#48915 fix

PR-URL: nodejs#48989
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
UlisesGascon pushed a commit that referenced this pull request Sep 10, 2023
fix #48475

PR-URL: #48915
Backport-PR-URL: #49225
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
UlisesGascon pushed a commit that referenced this pull request Sep 10, 2023
no longer needed after #48915 fix

PR-URL: #48989
Backport-PR-URL: #49225
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
@UlisesGascon UlisesGascon mentioned this pull request Sep 10, 2023
cjihrig added a commit to cjihrig/node that referenced this pull request Sep 28, 2023
There is an `if` statement that likely should have been
an `else` in the original PR.

Refs: nodejs#48915
nodejs-github-bot pushed a commit that referenced this pull request Sep 29, 2023
There is an `if` statement that likely should have been
an `else` in the original PR.

Refs: #48915
PR-URL: #49943
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Raz Luvaton <rluvaton@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: LiviaMedeiros <livia@cirno.name>
alexfernandez pushed a commit to alexfernandez/node that referenced this pull request Nov 1, 2023
There is an `if` statement that likely should have been
an `else` in the original PR.

Refs: nodejs#48915
PR-URL: nodejs#49943
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Raz Luvaton <rluvaton@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: LiviaMedeiros <livia@cirno.name>
targos pushed a commit that referenced this pull request Nov 11, 2023
There is an `if` statement that likely should have been
an `else` in the original PR.

Refs: #48915
PR-URL: #49943
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Raz Luvaton <rluvaton@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: LiviaMedeiros <livia@cirno.name>
@targos targos added backported-to-v20.x PRs backported to the v20.x-staging branch. and removed backport-open-v20.x Indicate that the PR has an open backport labels Nov 12, 2023
targos pushed a commit that referenced this pull request Nov 27, 2023
fix #48475

PR-URL: #48915
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
targos pushed a commit that referenced this pull request Nov 27, 2023
no longer needed after #48915 fix

PR-URL: #48989
Backport-PR-URL: #49225
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
targos pushed a commit that referenced this pull request Nov 27, 2023
There is an `if` statement that likely should have been
an `else` in the original PR.

Refs: #48915
PR-URL: #49943
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Raz Luvaton <rluvaton@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: LiviaMedeiros <livia@cirno.name>
debadree25 pushed a commit to debadree25/node that referenced this pull request Apr 15, 2024
There is an `if` statement that likely should have been
an `else` in the original PR.

Refs: nodejs#48915
PR-URL: nodejs#49943
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Raz Luvaton <rluvaton@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: LiviaMedeiros <livia@cirno.name>
sercher added a commit to sercher/graaljs that referenced this pull request Apr 25, 2024
fix #48475

PR-URL: nodejs/node#48915
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
sercher added a commit to sercher/graaljs that referenced this pull request Apr 25, 2024
There is an `if` statement that likely should have been
an `else` in the original PR.

Refs: nodejs/node#48915
PR-URL: nodejs/node#49943
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Raz Luvaton <rluvaton@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: LiviaMedeiros <livia@cirno.name>
sercher added a commit to sercher/graaljs that referenced this pull request Apr 25, 2024
fix #48475

PR-URL: nodejs/node#48915
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
sercher added a commit to sercher/graaljs that referenced this pull request Apr 25, 2024
There is an `if` statement that likely should have been
an `else` in the original PR.

Refs: nodejs/node#48915
PR-URL: nodejs/node#49943
Reviewed-By: Chemi Atlow <chemi@atlow.co.il>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
Reviewed-By: Raz Luvaton <rluvaton@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: LiviaMedeiros <livia@cirno.name>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
author ready PRs that have at least one approval, no pending requests for changes, and a CI started. backported-to-v20.x PRs backported to the v20.x-staging branch. commit-queue-squash Add this label to instruct the Commit Queue to squash all the PR commits into the first one. needs-ci PRs that need a full CI run. test_runner Issues and PRs related to the test runner subsystem.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

node:test beforeEach and afterEach generate MaxListenersExceededWarning
9 participants