From 1d453e4d31d8a7909e71d78e243d8b6cf83b2a34 Mon Sep 17 00:00:00 2001 From: Moshe Atlow Date: Tue, 4 Apr 2023 07:14:23 +0300 Subject: [PATCH] test_runner: stringify AssertError expected and actual PR-URL: https://github.com/nodejs/node/pull/47088 Fixes: https://github.com/nodejs/node/issues/47075 Reviewed-By: Colin Ihrig --- lib/internal/test_runner/reporter/tap.js | 30 +++++++---- lib/internal/test_runner/yaml_to_js.js | 27 +++++++--- test/message/test_runner_output.js | 14 ++++++ test/message/test_runner_output.out | 39 +++++++++++++-- test/message/test_runner_output_cli.out | 39 +++++++++++++-- .../test_runner_output_dot_reporter.out | 3 +- .../test_runner_output_spec_reporter.out | 50 +++++++++++++++++-- 7 files changed, 173 insertions(+), 29 deletions(-) diff --git a/lib/internal/test_runner/reporter/tap.js b/lib/internal/test_runner/reporter/tap.js index e4061ac93fca42..01c7436c6a6b67 100644 --- a/lib/internal/test_runner/reporter/tap.js +++ b/lib/internal/test_runner/reporter/tap.js @@ -6,6 +6,7 @@ const { ObjectEntries, RegExpPrototypeSymbolReplace, SafeMap, + SafeSet, StringPrototypeReplaceAll, StringPrototypeSplit, StringPrototypeRepeat, @@ -79,7 +80,7 @@ function reportDetails(nesting, data = kEmptyObject) { details += jsToYaml(_indent, 'duration_ms', duration_ms); details += jsToYaml(_indent, 'type', data.type); - details += jsToYaml(_indent, null, error); + details += jsToYaml(_indent, null, error, new SafeSet()); details += `${_indent} ...\n`; return details; } @@ -109,7 +110,7 @@ function tapEscape(input) { return result; } -function jsToYaml(indent, name, value) { +function jsToYaml(indent, name, value, seen) { if (value === null || value === undefined) { return ''; } @@ -136,9 +137,16 @@ function jsToYaml(indent, name, value) { return str; } + seen.add(value); const entries = ObjectEntries(value); const isErrorObj = isError(value); let result = ''; + let propsIndent = indent; + + if (name != null) { + result += `${indent} ${name}:\n`; + propsIndent += ' '; + } for (let i = 0; i < entries.length; i++) { const { 0: key, 1: value } = entries[i]; @@ -146,8 +154,12 @@ function jsToYaml(indent, name, value) { if (isErrorObj && (key === 'cause' || key === 'code')) { continue; } + if (seen.has(value)) { + result += `${propsIndent} ${key}: \n`; + continue; + } - result += jsToYaml(indent, key, value); + result += jsToYaml(propsIndent, key, value, seen); } if (isErrorObj) { @@ -189,20 +201,20 @@ function jsToYaml(indent, name, value) { } } - result += jsToYaml(indent, 'error', errMsg); + result += jsToYaml(indent, 'error', errMsg, seen); if (errCode) { - result += jsToYaml(indent, 'code', errCode); + result += jsToYaml(indent, 'code', errCode, seen); } if (errName && errName !== 'Error') { - result += jsToYaml(indent, 'name', errName); + result += jsToYaml(indent, 'name', errName, seen); } if (errIsAssertion) { - result += jsToYaml(indent, 'expected', errExpected); - result += jsToYaml(indent, 'actual', errActual); + result += jsToYaml(indent, 'expected', errExpected, seen); + result += jsToYaml(indent, 'actual', errActual, seen); if (errOperator) { - result += jsToYaml(indent, 'operator', errOperator); + result += jsToYaml(indent, 'operator', errOperator, seen); } } diff --git a/lib/internal/test_runner/yaml_to_js.js b/lib/internal/test_runner/yaml_to_js.js index 6eb193f4afd36e..724e71baaa67db 100644 --- a/lib/internal/test_runner/yaml_to_js.js +++ b/lib/internal/test_runner/yaml_to_js.js @@ -19,7 +19,7 @@ const { StringPrototypeSubstring, } = primordials; -const kYamlKeyRegex = /^(\s+)?(\w+):(\s)+([>|][-+])?(.*)$/; +const kYamlKeyRegex = /^(\s+)?(\w+):(\s)*([>|][-+])?(.*)$/; const kStackDelimiter = ' at '; function reConstructError(parsedYaml) { @@ -91,28 +91,39 @@ function YAMLToJs(lines) { return undefined; } const result = { __proto__: null }; + let context = { __proto__: null, object: result, indent: 0, currentKey: null }; let isInYamlBlock = false; for (let i = 0; i < lines.length; i++) { const line = lines[i]; if (isInYamlBlock && !StringPrototypeStartsWith(line, StringPrototypeRepeat(' ', isInYamlBlock.indent))) { - result[isInYamlBlock.key] = isInYamlBlock.key === 'stack' ? - result[isInYamlBlock.key] : ArrayPrototypeJoin(result[isInYamlBlock.key], '\n'); + context.object[isInYamlBlock.key] = isInYamlBlock.key === 'stack' ? + context.object[isInYamlBlock.key] : ArrayPrototypeJoin(context.object[isInYamlBlock.key], '\n'); isInYamlBlock = false; } if (isInYamlBlock) { const blockLine = StringPrototypeSubstring(line, isInYamlBlock.indent); - ArrayPrototypePush(result[isInYamlBlock.key], blockLine); + ArrayPrototypePush(context.object[isInYamlBlock.key], blockLine); continue; } const match = RegExpPrototypeExec(kYamlKeyRegex, line); if (match !== null) { const { 1: leadingSpaces, 2: key, 4: block, 5: value } = match; + const indent = leadingSpaces?.length ?? 0; if (block) { - isInYamlBlock = { key, indent: (leadingSpaces?.length ?? 0) + 2 }; - result[key] = []; - } else { - result[key] = getYamlValue(value); + isInYamlBlock = { key, indent: indent + 2 }; + context.object[key] = []; + continue; } + + if (indent > context.indent) { + context.object[context.currentKey] ||= {}; + context = { __proto__: null, parent: context, object: context.object[context.currentKey], indent }; + } else if (indent < context.indent) { + context = context.parent; + } + + context.currentKey = key; + context.object[key] = getYamlValue(value); } } return reConstructError(result); diff --git a/test/message/test_runner_output.js b/test/message/test_runner_output.js index a53ded3dfde3ac..b00e833a212492 100644 --- a/test/message/test_runner_output.js +++ b/test/message/test_runner_output.js @@ -389,3 +389,17 @@ test('unfinished test with unhandledRejection', async () => { setImmediate(() => { throw new Error('uncaught from outside of a test'); }); + +test('assertion errors display actual and expected properly', async () => { + // Make sure the assert module is handled. + const circular = { bar: 2 }; + circular.c = circular; + const tmpLimit = Error.stackTraceLimit; + Error.stackTraceLimit = 1; + try { + assert.deepEqual({ foo: 1, bar: 1 }, circular); // eslint-disable-line no-restricted-properties + } catch (err) { + Error.stackTraceLimit = tmpLimit; + throw err; + } +}); diff --git a/test/message/test_runner_output.out b/test/message/test_runner_output.out index 668676cb6eeda6..c19e2058de7298 100644 --- a/test/message/test_runner_output.out +++ b/test/message/test_runner_output.out @@ -624,8 +624,39 @@ not ok 64 - unfinished test with unhandledRejection * * ... +# Subtest: assertion errors display actual and expected properly +not ok 65 - assertion errors display actual and expected properly + --- + duration_ms: * + failureType: 'testCodeFailure' + error: |- + Expected values to be loosely deep-equal: + + { + bar: 1, + foo: 1 + } + + should loosely deep-equal + + { + bar: 2, + c: [Circular *1] + } + code: 'ERR_ASSERTION' + name: 'AssertionError' + expected: + bar: 2 + c: + actual: + foo: 1 + bar: 1 + operator: 'deepEqual' + stack: |- + * + ... # Subtest: invalid subtest fail -not ok 65 - invalid subtest fail +not ok 66 - invalid subtest fail --- duration_ms: * failureType: 'parentAlreadyFinished' @@ -634,7 +665,7 @@ not ok 65 - invalid subtest fail stack: |- * ... -1..65 +1..66 # Warning: Test "unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: Test "async unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: A resource generated asynchronous activity after the test ended. This activity created the error "Error: uncaught from outside of a test" which triggered an uncaughtException event, caught by the test runner. @@ -642,10 +673,10 @@ not ok 65 - invalid subtest fail # Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. # Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. -# tests 79 +# tests 80 # suites 0 # pass 37 -# fail 24 +# fail 25 # cancelled 3 # skipped 10 # todo 5 diff --git a/test/message/test_runner_output_cli.out b/test/message/test_runner_output_cli.out index e51b6b472ca44f..ba43eabb1940e2 100644 --- a/test/message/test_runner_output_cli.out +++ b/test/message/test_runner_output_cli.out @@ -624,8 +624,39 @@ not ok 64 - unfinished test with unhandledRejection * * ... +# Subtest: assertion errors display actual and expected properly +not ok 65 - assertion errors display actual and expected properly + --- + duration_ms: * + failureType: 'testCodeFailure' + error: |- + Expected values to be loosely deep-equal: + + { + bar: 1, + foo: 1 + } + + should loosely deep-equal + + { + bar: 2, + c: [Circular *1] + } + code: 'ERR_ASSERTION' + name: 'AssertionError' + expected: + bar: 2 + c: '' + actual: + foo: 1 + bar: 1 + operator: 'deepEqual' + stack: |- + * + ... # Subtest: invalid subtest fail -not ok 65 - invalid subtest fail +not ok 66 - invalid subtest fail --- duration_ms: * failureType: 'parentAlreadyFinished' @@ -641,11 +672,11 @@ not ok 65 - invalid subtest fail # Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. # Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. -1..65 -# tests 79 +1..66 +# tests 80 # suites 0 # pass 37 -# fail 24 +# fail 25 # cancelled 3 # skipped 10 # todo 5 diff --git a/test/message/test_runner_output_dot_reporter.out b/test/message/test_runner_output_dot_reporter.out index 823ecfb146b991..5a74119b3887e5 100644 --- a/test/message/test_runner_output_dot_reporter.out +++ b/test/message/test_runner_output_dot_reporter.out @@ -1,4 +1,5 @@ ..XX...X..XXX.X..... XXX.....X..X...X.... .........X...XXX.XX. -.....XXXXXXX...XXXX +.....XXXXXXX...XXXXX + diff --git a/test/message/test_runner_output_spec_reporter.out b/test/message/test_runner_output_spec_reporter.out index b3ca09b0561893..8db20b3195e6f9 100644 --- a/test/message/test_runner_output_spec_reporter.out +++ b/test/message/test_runner_output_spec_reporter.out @@ -184,7 +184,7 @@ callback called twice in different ticks (*ms) callback called twice in future tick (*ms) Error [ERR_TEST_FAILURE]: callback invoked multiple times - * + * { failureType: 'multipleCallbackInvocations', cause: 'callback invoked multiple times', code: 'ERR_TEST_FAILURE' @@ -265,6 +265,28 @@ * * + assertion errors display actual and expected properly (*ms) + AssertionError [ERR_ASSERTION]: Expected values to be loosely deep-equal: + + { + bar: 1, + foo: 1 + } + + should loosely deep-equal + + { + bar: 2, + c: [Circular *1] + } + * { + generatedMessage: true, + code: 'ERR_ASSERTION', + actual: [Object], + expected: [Object], + operator: 'deepEqual' + } + invalid subtest fail (*ms) 'test could not be started because its parent finished' @@ -275,10 +297,10 @@ Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. - tests 79 + tests 80 suites 0 pass 37 - fail 24 + fail 25 cancelled 3 skipped 10 todo 5 @@ -490,5 +512,27 @@ * * + assertion errors display actual and expected properly (*ms) + AssertionError [ERR_ASSERTION]: Expected values to be loosely deep-equal: + + { + bar: 1, + foo: 1 + } + + should loosely deep-equal + + { + bar: 2, + c: [Circular *1] + } + * { + generatedMessage: true, + code: 'ERR_ASSERTION', + actual: [Object], + expected: [Object], + operator: 'deepEqual' + } + invalid subtest fail (*ms) 'test could not be started because its parent finished'