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

Summarize the max severity at the top of logs, star all max-severity logs #3163

Open
wants to merge 2 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
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
12 changes: 7 additions & 5 deletions src/common/internal/logging/log_message.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import { extractImportantStackTrace } from '../stack.js';
export class LogMessageWithStack extends Error {
readonly extra: unknown;

private showStar: boolean = true;
private stackHiddenMessage: string | undefined = undefined;

constructor(name: string, ex: Error | ErrorWithExtra) {
Expand All @@ -16,19 +17,20 @@ export class LogMessageWithStack extends Error {
}
}

/** Set a flag so the stack is not printed in toJSON(). */
setStackHidden(stackHiddenMessage: string) {
this.stackHiddenMessage ??= stackHiddenMessage;
/** Set a flag so the stack is not printed in toJSON(), and important messages are starred. */
setPrintOptions(showStar: boolean, stackHiddenMessage: string) {
this.showStar = showStar;
this.stackHiddenMessage = stackHiddenMessage;
}

toJSON(): string {
let m = this.name;
let m = (this.showStar ? '☆ ' : ' ') + this.name;
if (this.message) m += ': ' + this.message;
if (this.stack) {
if (this.stackHiddenMessage === undefined) {
m += '\n' + extractImportantStackTrace(this);
} else if (this.stackHiddenMessage) {
m += `\n at (elided: ${this.stackHiddenMessage})`;
m += `\n at (elided: ${this.stackHiddenMessage})`;
}
}
return m;
Expand Down
42 changes: 30 additions & 12 deletions src/common/internal/logging/test_case_recorder.ts
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,13 @@ enum LogSeverity {
const kMaxLogStacks = 2;
const kMinSeverityForStack = LogSeverity.Warn;

function logSeverityToString(status: LogSeverity): Status {
function logSeverityToString(severity: LogSeverity): string {
return ['NotRun', 'Skip', 'Pass', 'Warn', 'ExpectFailed', 'ValidationFailed', 'ThrewException'][
severity
];
}

function logSeverityToStatus(status: LogSeverity): Status {
switch (status) {
case LogSeverity.NotRun:
return 'notrun';
Expand All @@ -42,11 +48,10 @@ export class TestCaseRecorder {
private finalCaseStatus = LogSeverity.NotRun;
private hideStacksBelowSeverity = kMinSeverityForStack;
private startTime = -1;
private preambleLog?: LogMessageWithStack;
private logs: LogMessageWithStack[] = [];
private logLinesAtCurrentSeverity = 0;
private debugging = false;
/** Used to dedup log messages which have identical stacks. */
private messagesForPreviouslySeenStacks = new Map<string, LogMessageWithStack>();

constructor(result: LiveTestCaseResult, debugging: boolean) {
this.result = result;
Expand All @@ -72,7 +77,7 @@ export class TestCaseRecorder {
}

// Convert numeric enum back to string (but expose 'exception' as 'fail')
this.result.status = logSeverityToString(this.finalCaseStatus);
this.result.status = logSeverityToStatus(this.finalCaseStatus);

this.result.logs = this.logs;
}
Expand Down Expand Up @@ -146,6 +151,18 @@ export class TestCaseRecorder {
this.logImpl(LogSeverity.ThrewException, 'EXCEPTION', ex);
}

private updatePreamble() {
if (this.preambleLog === undefined) {
const preambleError = new Error();
preambleError.stack = undefined;
this.preambleLog = new LogMessageWithStack('SUMMARY', preambleError);
this.logs.unshift(this.preambleLog);
}
this.preambleLog.message = `highest severity is ☆ ${logSeverityToString(
this.hideStacksBelowSeverity
)}`;
}

private logImpl(level: LogSeverity, name: string, baseException: unknown): void {
assert(baseException instanceof Error, 'test threw a non-Error object');
globalTestConfig.testHeartbeatCallback();
Expand All @@ -158,25 +175,26 @@ export class TestCaseRecorder {
this.finalCaseStatus = Math.max(this.finalCaseStatus, level);
}

// setFirstLineOnly for all logs except `kMaxLogStacks` stacks at the highest severity
// Hide stack for all logs except `kMaxLogStacks` stacks at the highest severity
if (level > this.hideStacksBelowSeverity) {
this.logLinesAtCurrentSeverity = 0;
this.hideStacksBelowSeverity = level;
this.updatePreamble();

// Go back and setFirstLineOnly for everything of a lower log level
// Go back and hide stack for everything of a lower log level
for (const log of this.logs) {
log.setStackHidden('below max severity');
log.setPrintOptions(false, 'below max severity');
}
}
if (level === this.hideStacksBelowSeverity) {
this.logLinesAtCurrentSeverity++;
if (this.logLinesAtCurrentSeverity > kMaxLogStacks) {
logMessage.setPrintOptions(true, `only ${kMaxLogStacks} shown`);
}
} else if (level < kMinSeverityForStack) {
logMessage.setStackHidden('');
logMessage.setPrintOptions(false, '');
} else if (level < this.hideStacksBelowSeverity) {
logMessage.setStackHidden('below max severity');
}
if (this.logLinesAtCurrentSeverity > kMaxLogStacks) {
logMessage.setStackHidden(`only ${kMaxLogStacks} shown`);
logMessage.setPrintOptions(false, 'below max severity');
}

this.logs.push(logMessage);
Expand Down
47 changes: 0 additions & 47 deletions src/demo/a/b/c.spec.ts
Original file line number Diff line number Diff line change
@@ -1,7 +1,6 @@
export const description = 'Description for c.spec.ts';

import { makeTestGroup } from '../../../common/framework/test_group.js';
import { unreachable } from '../../../common/util/util.js';
import { UnitTest } from '../../../unittests/unit_test.js';

export const g = makeTestGroup(UnitTest);
Expand Down Expand Up @@ -32,49 +31,3 @@ g.test('deep_case_tree')
.combine('z', [1, 2])
)
.fn(() => {});

g.test('statuses,debug').fn(t => {
t.debug('debug');
});

g.test('statuses,skip').fn(t => {
t.skip('skip');
});

g.test('statuses,warn').fn(t => {
t.warn('warn');
});

g.test('statuses,fail').fn(t => {
t.fail('fail');
});

g.test('statuses,throw').fn(() => {
unreachable('unreachable');
});

g.test('multiple_same_stack').fn(t => {
for (let i = 0; i < 3; ++i) {
t.fail(
i === 2
? 'this should appear after deduplicated line'
: 'this should be "seen 2 times with identical stack"'
);
}
});

g.test('multiple_same_level').fn(t => {
t.fail('this should print a stack');
t.fail('this should print a stack');
t.fail('this should not print a stack');
});

g.test('lower_levels_hidden,before').fn(t => {
t.warn('warn - this should not print a stack');
t.fail('fail');
});

g.test('lower_levels_hidden,after').fn(t => {
t.fail('fail');
t.warn('warn - this should not print a stack');
});
82 changes: 82 additions & 0 deletions src/demo/logs.spec.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,82 @@
export const description = 'Demos of how log levels show up in log outputs';

import { makeTestGroup } from '../common/framework/test_group.js';
import { unreachable } from '../common/util/util.js';
import { UnitTest } from '../unittests/unit_test.js';

export const g = makeTestGroup(UnitTest);

g.test('statuses,debug').fn(t => {
t.debug('debug');
});

g.test('statuses,skip').fn(t => {
t.skip('skip');
});

g.test('statuses,warn').fn(t => {
t.warn('warn');
});

g.test('statuses,fail').fn(t => {
t.fail('fail');
});

g.test('statuses,throw').fn(() => {
unreachable('unreachable');
});

g.test('multiple_same_level').fn(t => {
t.fail('this should print a stack');
t.fail('this should print a stack');
t.fail('this should not print a stack');
});

g.test('multiple_lower_level').fn(t => {
t.fail('this should print a stack');
t.fail('this should print a stack');
t.fail('this should not print a stack');
t.warn('this should not print a stack');
t.warn('this should not print a stack');
t.warn('this should not print a stack');
});

g.test('lower_levels_hidden,before').fn(t => {
t.warn('warn - this should not print a stack');
t.fail('fail');
});

g.test('lower_levels_hidden,after').fn(t => {
t.fail('fail');
t.warn('warn - this should not print a stack');
});

g.test('exception_over_validation').fn(t => {
t.rec.validationFailed(new Error('first, but lower priority - stack should be elided'));
t.rec.threw(new Error('second, but higher priority - stack should be shown'));
t.rec.validationFailed(new Error('third, lower priority - stack should be elided'));
});

g.test('validation_over_expectation').fn(t => {
t.rec.expectationFailed(new Error('first, but lower priority - stack should be elided'));
t.rec.validationFailed(new Error('second, but higher priority - stack should be shown'));
t.rec.expectationFailed(new Error('third, lower priority - stack should be elided'));
});

g.test('expectation_over_warn').fn(t => {
t.rec.warn(new Error('first, but lower priority - stack should be elided'));
t.rec.expectationFailed(new Error('second, but higher priority - stack should be shown'));
t.rec.warn(new Error('third, lower priority - stack should be elided'));
});

g.test('warn_over_skip').fn(t => {
t.rec.skipped(new Error('stacks are never shown for this level'));
t.rec.warn(new Error('second, but higher priority - stack should be shown'));
t.rec.skipped(new Error('stacks are never shown for this level'));
});

g.test('skip_over_info').fn(t => {
t.rec.info(new Error('stacks are never shown for this level'));
t.rec.skipped(new Error('stacks are never shown for this level'));
t.rec.info(new Error('stacks are never shown for this level'));
});
Loading
Loading