Output logs for tests that remain pending when AVA exits #3125

kevo1ution · 2022-10-25T01:28:49Z

What
This PR plumbs test logs to be printed when tests timeout due to the global timeout set by ava --timeout <timeout> command.

Why
t.log is a very useful utility for debugging what happens when a test fails. When a test times out, these logs are useful for figuring out why the tests timed out.

unecessary dif temp add logs for pending tests fix linting issues undo unecessary change

kevo1ution · 2022-10-25T04:06:17Z

@novemberborn

This is the output with the same code snippet on #3122 . Before I attempt writing test cases for this, do you think this looks good implementation-wise and output-wise?

 % npm run test

> ava-logging-timeout-bug@1.0.0 test
> npx ava --timeout=1s --verbose


start promise that never resolves...
  
  ✘ Timed out while running tests

  1 tests were pending in test/example.js

  ◌ example where logs are not provided by ava when test time out
    ℹ {
        message: 'Very important debug statement, that developer would love to see in output after test run',
      }

  ─

  1 test remained pending after a timeout

kevo1ution · 2022-10-25T04:07:31Z

lib/run-status.js

@@ -9,6 +9,7 @@ export default class RunStatus extends Emittery {
 		super();

 		this.pendingTests = new Map();
+		this.pendingTestsLogReference = new Map();


separate map from this.pendingTests because they are modified and initialized in different events with different objects.

Why Reference?

oops, I think pendingTestsLogs sounds better

novemberborn · 2022-11-01T09:29:30Z

@kevo1ution this is on my list to look at more closely, but at first glance it seems reasonable.

kevo1ution · 2022-11-01T16:46:40Z

@kevo1ution this is on my list to look at more closely, but at first glance it seems reasonable.

thanks I'll start adding several tests to confirm that the output works, and mark this ready for review when it's ready to be looked at

kevo1ution · 2022-11-01T18:52:40Z

@novemberborn This is ready for review. It took some time to figure out how testing the testing framework works (lol), so hopefully, I did it up to your standards. Let me know if there is anything I missed

kevo1ution · 2022-11-04T21:01:29Z

@novemberborn bumping on this, let me know if there's anything else I need to do, thanks!

novemberborn

Nice! Left some comments and suggestions around optional chaining.

novemberborn · 2022-11-07T16:06:47Z

lib/reporters/default.js

@@ -370,8 +370,11 @@ export default class Reporter {
 			}

 			this.lineWriter.writeLine(`${testsInFile.size} tests were pending in ${this.relativeFile(file)}\n`);
+			const testTitleToLogs = evt.pendingTestsLogReference.get(file) ?? new Map();


Suggested change

const testTitleToLogs = evt.pendingTestsLogReference.get(file) ?? new Map();

const testTitleToLogs = evt.pendingTestsLogReference.get(file);

novemberborn · 2022-11-07T16:09:43Z

lib/reporters/default.js

 			for (const title of testsInFile) {
+				const logs = testTitleToLogs.get(title) ?? [];


writeLogs() can handle falsey logs values. So with optional chaining and the above we can do:

Suggested change

const logs = testTitleToLogs.get(title) ?? [];

const logs = testTitleToLogs?.get(title);

novemberborn · 2022-11-07T16:10:25Z

lib/run-status.js

@@ -9,6 +9,7 @@ export default class RunStatus extends Emittery {
 		super();

 		this.pendingTests = new Map();
+		this.pendingTestsLogReference = new Map();


Why Reference?

novemberborn · 2022-11-07T16:11:50Z

lib/run-status.js

+		if (this.pendingTestsLogReference.has(event.testFile)) {
+			this.pendingTestsLogReference.get(event.testFile).set(event.title, event.logs);
+		}


Suggested change

if (this.pendingTestsLogReference.has(event.testFile)) {

this.pendingTestsLogReference.get(event.testFile).set(event.title, event.logs);

}

this.pendingTestsLogReference.get(event.testFile)?.set(event.title, event.logs);

novemberborn

Lovely!

kevo1ution · 2022-11-13T22:02:44Z

Lovely!

Thank you for the helpful reviews and insight on fixing the issue! Looking forward to using this fix in my repos

[![Mend Renovate](https://app.renovatebot.com/images/banner.svg)](https://renovatebot.com) This PR contains the following updates: | Package | Change | Age | Adoption | Passing | Confidence | |---|---|---|---|---|---| | [ava](https://avajs.dev) ([source](https://togithub.com/avajs/ava)) | [`^5.0.0` -> `^6.0.0`](https://renovatebot.com/diffs/npm/ava/5.0.1/6.0.0) | [![age](https://developer.mend.io/api/mc/badges/age/npm/ava/6.0.0?slim=true)](https://docs.renovatebot.com/merge-confidence/) | [![adoption](https://developer.mend.io/api/mc/badges/adoption/npm/ava/6.0.0?slim=true)](https://docs.renovatebot.com/merge-confidence/) | [![passing](https://developer.mend.io/api/mc/badges/compatibility/npm/ava/5.0.1/6.0.0?slim=true)](https://docs.renovatebot.com/merge-confidence/) | [![confidence](https://developer.mend.io/api/mc/badges/confidence/npm/ava/5.0.1/6.0.0?slim=true)](https://docs.renovatebot.com/merge-confidence/) | --- ### Release Notes <details> <summary>avajs/ava (ava)</summary> ### [`v6.0.0`](https://togithub.com/avajs/ava/releases/tag/v6.0.0) [Compare Source](https://togithub.com/avajs/ava/compare/v5.3.1...v6.0.0) #### Breaking Changes - AVA now requires Node.js versions 18.18, 20.8 or 21. Versions 14 and 16 are no longer supported. [#3251](https://togithub.com/avajs/ava/issues/3251) [#3216](https://togithub.com/avajs/ava/issues/3216) - When tests finish, worker threads or child processes are no longer exited through `proces.exit()`. If your test file does not exit on its own, the test run will time out. [#3260](https://togithub.com/avajs/ava/issues/3260) - Changes to watch mode [#3218](https://togithub.com/avajs/ava/issues/3218): - Watch mode can no longer be started via the `ava.config.*` or `package.json` configuration. - The `ignoredByWatcher` configuration has moved to the `watchMode` object, under the `ignoreChanges` key. - Watch mode now uses the built-in [`fs.watch()`](https://nodejs.org/api/fs.html#fswatchfilename-options-listener) in recursive mode. This is supported on Linux in Node.js 20 or newer, and MacOS and Windows in Node.js 18 as well. There are [caveats](https://nodejs.org/api/fs.html#caveats) to keep in mind. - Failed assertions now throw, meaning that any subsequent code is not executed. This also impacts the type definitions. [#3246](https://togithub.com/avajs/ava/issues/3246) - [Only native errors](https://nodejs.org/api/util.html#utiltypesisnativeerrorvalue) are now considered errors by the `t.throws()` and `t.throwsAsync()` assertions. [`Object.create(Error.prototype)` is **not** a native error](Object.create\(Error.prototype\)). [#3229](https://togithub.com/avajs/ava/issues/3229) - Changes to modules loaded through the `require` configuration [#3184](https://togithub.com/avajs/ava/issues/3184): - If such modules export a default function, this function is now invoked. - Local files are loaded through `@ava/typescript` if necessary. #### Improvements ##### Rewritten watcher The watcher has been rewritten. It’s now built on [`fs.watch()`](https://nodejs.org/api/fs.html#fswatchfilename-options-listener) in recursive mode. [`@vercel/nft`](https://togithub.com/vercel/nft) is used to perform static dependency analysis, supporting ESM and CJS imports for JavaScript & TypeScript source files. This is a huge improvement over the previous runtime tracking of CJS imports, which did not support ESM. Integration with [`@ava/typescript`](https://togithub.com/avajs/typescript) has been improved. The watcher can now detect a change to a TypeScript source file, then wait for the corresponding build output to change before re-running tests. The ignoredByWatcher configuration has moved to the watchMode object, under the ignoreChanges key. See [#3218](https://togithub.com/avajs/ava/issues/3218) and [#3257](https://togithub.com/avajs/ava/issues/3257). ##### Failed assertions now throw Assertions now throw a `TestFailure` error when they fail. This error is not exported or documented and should not be used or thrown manually. You cannot catch this error in order to recover from a failure, use `t.try()` instead. All assertions except for `t.throws()` and `t.throwsAsync()` now return `true` when they pass. This is useful for some of the assertions in TypeScript where they can be used as a type guard. Committing a failed `t.try()` result now also throws. See [#3246](https://togithub.com/avajs/ava/issues/3246). ##### `t.throws()` and `t.throwsAsync()` can now expect any error By default, the thrown error (or rejection reason) must be a native error. You can change the assertion to expect any kind of error by setting `any: true` in the expectation object: ```js t.throws(() => { throw 'error' }, {any: true}) ``` See [#3245](https://togithub.com/avajs/ava/issues/3245) by [@adiSuper94](https://togithub.com/adiSuper94). ##### The `require` configuration is now more powerful It now loads ES modules. Local files are loaded through `@ava/typescript` if necessary, so you can also write these in TypeScript. If there is a default export function, it is invoked after loading. The function is awaited so it can do asynchronous setup before further modules are loaded. Arguments from the configuration can be passed to the function (as a \[[structured clone](https://developer.mozilla.org/en-US/docs/Web/API/structuredClone)]\(https://developer.mozilla.org/en-US/docs/Web/API/structuredClone)). See [#3184](https://togithub.com/avajs/ava/issues/3184) by [@sculpt0r](https://togithub.com/sculpt0r). ##### Other changes worth noting - Internal events can now be observed (experimentally). See [#3247](https://togithub.com/avajs/ava/issues/3247) by [@codetheweb](https://togithub.com/codetheweb). It’s experimental and undocumented. - You can now use `t.timeout.clear()` to restore a previous `t.timeout()`. [#3221](https://togithub.com/avajs/ava/issues/3221) - Code coverage is flushed to disk at opportune moments. [#3220](https://togithub.com/avajs/ava/issues/3220) #### New Contributors - [@sculpt0r](https://togithub.com/sculpt0r) made their first contribution in [avajs/ava#3184 - [@ZachHaber](https://togithub.com/ZachHaber) made their first contribution in [avajs/ava#3233 - [@adiSuper94](https://togithub.com/adiSuper94) made their first contribution in [avajs/ava#3245 - [@bricker](https://togithub.com/bricker) made their first contribution in [avajs/ava#3250 **Full Changelog**: avajs/ava@v5.3.1...v6.0.0 ### [`v5.3.1`](https://togithub.com/avajs/ava/releases/tag/v5.3.1) [Compare Source](https://togithub.com/avajs/ava/compare/v5.3.0...v5.3.1) #### What's Changed - Update `t.like()` to support Symbol keys and ignore non-enumerable properties by [@gibson042](https://togithub.com/gibson042) in [avajs/ava#3209 - Fix circular selector detection in `t.like()` by [@novemberborn](https://togithub.com/novemberborn) in [avajs/ava#3212 **Full Changelog**: avajs/ava@v5.3.0...v5.3.1 ### [`v5.3.0`](https://togithub.com/avajs/ava/releases/tag/v5.3.0) [Compare Source](https://togithub.com/avajs/ava/compare/v5.2.0...v5.3.0) #### What's Changed - Support arrays in `t.like()` assertions by [@tommy-mitchell](https://togithub.com/tommy-mitchell) in [avajs/ava#3185 - Recognize typical assertion errors (`expect` and `assert`) and use their formatting by [@Irvenae](https://togithub.com/Irvenae) in [avajs/ava#3187 #### New Contributors - [@MartynasZilinskas](https://togithub.com/MartynasZilinskas) made their first contribution in [avajs/ava#3172 - [@flovogt](https://togithub.com/flovogt) made their first contribution in [avajs/ava#3194 - [@ondreian](https://togithub.com/ondreian) made their first contribution in [avajs/ava#3192 - [@tommy-mitchell](https://togithub.com/tommy-mitchell) made their first contribution in [avajs/ava#3185 - [@craigahobbs](https://togithub.com/craigahobbs) made their first contribution in [avajs/ava#3198 - [@Irvenae](https://togithub.com/Irvenae) made their first contribution in [avajs/ava#3187 **Full Changelog**: avajs/ava@v5.2.0...v5.3.0 ### [`v5.2.0`](https://togithub.com/avajs/ava/releases/tag/v5.2.0) [Compare Source](https://togithub.com/avajs/ava/compare/v5.1.1...v5.2.0) #### What's Changed - Infer thrown error from expectations by [@tao-cumplido](https://togithub.com/tao-cumplido) in [avajs/ava#3156 #### New Contributors - [@tao-cumplido](https://togithub.com/tao-cumplido) made their first contribution in [avajs/ava#3156 **Full Changelog**: avajs/ava@v5.1.1...v5.2.0 ### [`v5.1.1`](https://togithub.com/avajs/ava/releases/tag/v5.1.1) [Compare Source](https://togithub.com/avajs/ava/compare/v5.1.0...v5.1.1) #### What's Changed - Fix de-registration of shared workers to ensure AVA exits correctly, by [@codetheweb](https://togithub.com/codetheweb) in [avajs/ava#3149 & [avajs/ava#3151 **Full Changelog**: avajs/ava@v5.1.0...v5.1.1 ### [`v5.1.0`](https://togithub.com/avajs/ava/releases/tag/v5.1.0) [Compare Source](https://togithub.com/avajs/ava/compare/v5.0.1...v5.1.0) ##### What's Changed - Output logs for tests that remain pending when AVA exits by [@kevo1ution](https://togithub.com/kevo1ution) in [avajs/ava#3125 - Check for --config file extensions after they fail to load, allowing custom loaders by [@panva](https://togithub.com/panva) in [avajs/ava#3135 ##### New Contributors - [@kevo1ution](https://togithub.com/kevo1ution) made their first contribution in [avajs/ava#3125 - [@panva](https://togithub.com/panva) made their first contribution in [avajs/ava#3135 **Full Changelog**: avajs/ava@v5.0.1...v5.1.0 </details> --- ### Configuration 📅 **Schedule**: Branch creation - At any time (no schedule defined), Automerge - At any time (no schedule defined). 🚦 **Automerge**: Disabled by config. Please merge this manually once you are satisfied. ♻ **Rebasing**: Whenever PR becomes conflicted, or you tick the rebase/retry checkbox. 🔕 **Ignore**: Close this PR and you won't be reminded about this update again. --- - [ ] If you want to rebase/retry this PR, check this box --- This PR has been generated by [Mend Renovate](https://www.mend.io/free-developer-tools/renovate/). View repository job log [here](https://developer.mend.io/github/gr2m/github-project).  Co-authored-by: renovate[bot] <29139614+renovate[bot]@users.noreply.github.com>

adding notes before making change

ce2b12e

unecessary dif temp add logs for pending tests fix linting issues undo unecessary change

kevo1ution force-pushed the fix-issue-3222-log-after-timeout branch from 0ff9efc to ce2b12e Compare October 25, 2022 04:03

kevo1ution commented Oct 25, 2022

View reviewed changes

novemberborn marked this pull request as ready for review November 1, 2022 09:28

novemberborn marked this pull request as draft November 1, 2022 09:28

kevo1ution added 2 commits November 1, 2022 11:34

add tests

1937048

add tests for sigint printing pending tests

98bbc25

kevo1ution marked this pull request as ready for review November 1, 2022 18:50

kevo1ution changed the title ~~Output logs for each test after global timeout is triggered~~ Output logs for pending tests after global timeout or SIGINT is triggered Nov 3, 2022

chore: address feedback

29ed720

novemberborn reviewed Nov 7, 2022

View reviewed changes

kevo1ution requested a review from novemberborn November 7, 2022 22:26

novemberborn changed the title ~~Output logs for pending tests after global timeout or SIGINT is triggered~~ Output logs for tests that remain pending when AVA exits Nov 13, 2022

Merge branch 'main' into fix-issue-3222-log-after-timeout

82231fc

novemberborn approved these changes Nov 13, 2022

View reviewed changes

novemberborn merged commit 9206928 into avajs:main Nov 13, 2022

kevo1ution deleted the fix-issue-3222-log-after-timeout branch November 13, 2022 22:02

novemberborn mentioned this pull request Jul 3, 2023

Logs swallowed during test timeout/interrupt #2780

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Output logs for tests that remain pending when AVA exits #3125

Output logs for tests that remain pending when AVA exits #3125

kevo1ution commented Oct 25, 2022 •

edited

kevo1ution commented Oct 25, 2022 •

edited

kevo1ution Oct 25, 2022

novemberborn Nov 7, 2022

kevo1ution Nov 7, 2022

novemberborn commented Nov 1, 2022

kevo1ution commented Nov 1, 2022

kevo1ution commented Nov 1, 2022 •

edited

kevo1ution commented Nov 4, 2022

novemberborn left a comment

novemberborn Nov 7, 2022

novemberborn Nov 7, 2022

novemberborn Nov 7, 2022

novemberborn Nov 7, 2022

novemberborn left a comment

kevo1ution commented Nov 13, 2022 •

edited

	const testTitleToLogs = evt.pendingTestsLogReference.get(file) ?? new Map();
	const testTitleToLogs = evt.pendingTestsLogReference.get(file);

		for (const title of testsInFile) {
		const logs = testTitleToLogs.get(title) ?? [];

	const logs = testTitleToLogs.get(title) ?? [];
	const logs = testTitleToLogs?.get(title);

Output logs for tests that remain pending when AVA exits #3125

Output logs for tests that remain pending when AVA exits #3125

Conversation

kevo1ution commented Oct 25, 2022 • edited

kevo1ution commented Oct 25, 2022 • edited

kevo1ution Oct 25, 2022

Choose a reason for hiding this comment

novemberborn Nov 7, 2022

Choose a reason for hiding this comment

kevo1ution Nov 7, 2022

Choose a reason for hiding this comment

novemberborn commented Nov 1, 2022

kevo1ution commented Nov 1, 2022

kevo1ution commented Nov 1, 2022 • edited

kevo1ution commented Nov 4, 2022

novemberborn left a comment

Choose a reason for hiding this comment

novemberborn Nov 7, 2022

Choose a reason for hiding this comment

novemberborn Nov 7, 2022

Choose a reason for hiding this comment

novemberborn Nov 7, 2022

Choose a reason for hiding this comment

novemberborn Nov 7, 2022

Choose a reason for hiding this comment

novemberborn left a comment

Choose a reason for hiding this comment

kevo1ution commented Nov 13, 2022 • edited

kevo1ution commented Oct 25, 2022 •

edited

kevo1ution commented Oct 25, 2022 •

edited

kevo1ution commented Nov 1, 2022 •

edited

kevo1ution commented Nov 13, 2022 •

edited