Skip to content

Commit

Permalink
Summarize the max severity at the top of logs, star all max-severity …
Browse files Browse the repository at this point in the history
…logs
  • Loading branch information
kainino0x committed Nov 13, 2023
1 parent 0e06340 commit be4982d
Show file tree
Hide file tree
Showing 6 changed files with 144 additions and 86 deletions.
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

0 comments on commit be4982d

Please sign in to comment.