Skip to content

test_runner: simplify test time tracking #52182

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.

Sign up for GitHub

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

Closed
cjihrig wants to merge 2 commits into from
Closed

test_runner: simplify test time tracking #52182

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
f2e7bcc
test_runner: simplify test start time tracking
cjihrig Mar 21, 2024
7470065
test_runner: simplify test end time tracking
cjihrig Mar 21, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Next Next commit
test_runner: simplify test start time tracking 
This commit simplifies the logic for tracking test start time.
The start time is now set only when a test/suite begins running.
If the test/suite never runs, a fallback is provided in postRun().
  • Loading branch information
@cjihrig
cjihrig committed Mar 21, 2024
commit f2e7bcc41eb1bf27acaa0addde34210cc9ddbcf7
5 changes: 2 additions & 3 deletions lib/internal/test_runner/test.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -507,7 +507,6 @@ class Test extends AsyncResource {
}

if (preventAddingSubtests) {
test.startTime = test.startTime || hrtime();
test.fail(
new ERR_TEST_FAILURE(
'test could not be started because its parent finished',
Expand Down Expand Up @@ -537,7 +536,6 @@ class Test extends AsyncResource {
kCancelledByParent,
),
);
this.startTime = this.startTime || this.endTime; // If a test was canceled before it was started, e.g inside a hook
this.cancelled = true;
this.abortController.abort();
}
Expand Down Expand Up @@ -763,12 +761,13 @@ class Test extends AsyncResource {
}

postRun(pendingSubtestsError) {
this.startTime ??= hrtime();

// If the test was failed before it even started, then the end time will
// be earlier than the start time. Correct that here.
if (this.endTime < this.startTime) {
this.endTime = hrtime();
}
this.startTime ??= this.endTime;

// The test has run, so recursively cancel any outstanding subtests and
// mark this test as failed if any subtests failed.
Expand Down
12 changes: 6 additions & 6 deletions test/fixtures/test-runner/output/hooks_spec_reporter.snapshot
View file
Open in desktop

@atlowChemi atlowChemi Mar 24, 2024

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Not sure I get why these changed

@cjihrig cjihrig Mar 24, 2024

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

The spec reporter only shows times if they are non-zero. Those values were coming through as zeros before. I have now updated the PR as shown below. That seems to keep the snapshots the same, which can also save a second hrtime() call. Please take another look.

diff --git a/lib/internal/test_runner/test.js b/lib/internal/test_runner/test.js
index f61aada409..9f9c47edae 100644
--- a/lib/internal/test_runner/test.js
+++ b/lib/internal/test_runner/test.js
@@ -754,8 +754,8 @@ class Test extends AsyncResource {
   postRun(pendingSubtestsError) {
     // If the test was cancelled before it started, then the start and end
     // times need to be corrected.
-    this.startTime ??= hrtime();
     this.endTime ??= hrtime();
+    this.startTime ??= this.endTime;
 
     // The test has run, so recursively cancel any outstanding subtests and
     // mark this test as failed if any subtests failed.

Original file line number Diff line number Diff line change
Expand Up @@ -11,10 +11,10 @@

describe hooks - no subtests (*ms)
before throws
1
1 (*ms)
'test did not finish before its parent and was cancelled'

2
2 (*ms)
'test did not finish before its parent and was cancelled'

before throws (*ms)
Expand Down Expand Up @@ -390,7 +390,7 @@

- after() called
run after when before throws
1
1 (*ms)
'test did not finish before its parent and was cancelled'

run after when before throws (*ms)
Expand Down Expand Up @@ -422,11 +422,11 @@
failing tests:

*
1
1 (*ms)
'test did not finish before its parent and was cancelled'

*
2
2 (*ms)
'test did not finish before its parent and was cancelled'

*
Expand Down Expand Up @@ -772,7 +772,7 @@
*

*
1
1 (*ms)
'test did not finish before its parent and was cancelled'

*
Expand Down