diff options
Diffstat (limited to 'dom/webgpu/tests/cts/checkout/src/common/internal/logging')
4 files changed, 279 insertions, 0 deletions
diff --git a/dom/webgpu/tests/cts/checkout/src/common/internal/logging/log_message.ts b/dom/webgpu/tests/cts/checkout/src/common/internal/logging/log_message.ts new file mode 100644 index 0000000000..ee006cdeb3 --- /dev/null +++ b/dom/webgpu/tests/cts/checkout/src/common/internal/logging/log_message.ts @@ -0,0 +1,44 @@ +import { ErrorWithExtra } from '../../util/util.js'; +import { extractImportantStackTrace } from '../stack.js'; + +export class LogMessageWithStack extends Error { + readonly extra: unknown; + + private stackHiddenMessage: string | undefined = undefined; + + constructor(name: string, ex: Error | ErrorWithExtra) { + super(ex.message); + + this.name = name; + this.stack = ex.stack; + if ('extra' in ex) { + this.extra = ex.extra; + } + } + + /** Set a flag so the stack is not printed in toJSON(). */ + setStackHidden(stackHiddenMessage: string) { + this.stackHiddenMessage ??= stackHiddenMessage; + } + + toJSON(): string { + let m = 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})`; + } + } + return m; + } +} + +/** + * Returns a string, nicely indented, for debug logs. + * This is used in the cmdline and wpt runtimes. In WPT, it shows up in the `*-actual.txt` file. + */ +export function prettyPrintLog(log: LogMessageWithStack): string { + return ' - ' + log.toJSON().replace(/\n/g, '\n '); +} diff --git a/dom/webgpu/tests/cts/checkout/src/common/internal/logging/logger.ts b/dom/webgpu/tests/cts/checkout/src/common/internal/logging/logger.ts new file mode 100644 index 0000000000..e4526cff54 --- /dev/null +++ b/dom/webgpu/tests/cts/checkout/src/common/internal/logging/logger.ts @@ -0,0 +1,30 @@ +import { version } from '../version.js'; + +import { LiveTestCaseResult } from './result.js'; +import { TestCaseRecorder } from './test_case_recorder.js'; + +export type LogResults = Map<string, LiveTestCaseResult>; + +export class Logger { + static globalDebugMode: boolean = false; + + readonly overriddenDebugMode: boolean | undefined; + readonly results: LogResults = new Map(); + + constructor({ overrideDebugMode }: { overrideDebugMode?: boolean } = {}) { + this.overriddenDebugMode = overrideDebugMode; + } + + record(name: string): [TestCaseRecorder, LiveTestCaseResult] { + const result: LiveTestCaseResult = { status: 'running', timems: -1 }; + this.results.set(name, result); + return [ + new TestCaseRecorder(result, this.overriddenDebugMode ?? Logger.globalDebugMode), + result, + ]; + } + + asJSON(space?: number): string { + return JSON.stringify({ version, results: Array.from(this.results) }, undefined, space); + } +} diff --git a/dom/webgpu/tests/cts/checkout/src/common/internal/logging/result.ts b/dom/webgpu/tests/cts/checkout/src/common/internal/logging/result.ts new file mode 100644 index 0000000000..3318e8c937 --- /dev/null +++ b/dom/webgpu/tests/cts/checkout/src/common/internal/logging/result.ts @@ -0,0 +1,21 @@ +import { LogMessageWithStack } from './log_message.js'; + +// MAINTENANCE_TODO: Add warn expectations +export type Expectation = 'pass' | 'skip' | 'fail'; + +export type Status = 'notrun' | 'running' | 'warn' | Expectation; + +export interface TestCaseResult { + status: Status; + timems: number; +} + +export interface LiveTestCaseResult extends TestCaseResult { + logs?: LogMessageWithStack[]; +} + +export interface TransferredTestCaseResult extends TestCaseResult { + // When transferred from a worker, a LogMessageWithStack turns into a generic Error + // (its prototype gets lost and replaced with Error). + logs?: Error[]; +} diff --git a/dom/webgpu/tests/cts/checkout/src/common/internal/logging/test_case_recorder.ts b/dom/webgpu/tests/cts/checkout/src/common/internal/logging/test_case_recorder.ts new file mode 100644 index 0000000000..f5c3252b5c --- /dev/null +++ b/dom/webgpu/tests/cts/checkout/src/common/internal/logging/test_case_recorder.ts @@ -0,0 +1,184 @@ +import { SkipTestCase, UnexpectedPassError } from '../../framework/fixture.js'; +import { globalTestConfig } from '../../framework/test_config.js'; +import { now, assert } from '../../util/util.js'; + +import { LogMessageWithStack } from './log_message.js'; +import { Expectation, LiveTestCaseResult, Status } from './result.js'; + +enum LogSeverity { + NotRun = 0, + Skip = 1, + Pass = 2, + Warn = 3, + ExpectFailed = 4, + ValidationFailed = 5, + ThrewException = 6, +} + +const kMaxLogStacks = 2; +const kMinSeverityForStack = LogSeverity.Warn; + +function logSeverityToString(status: LogSeverity): Status { + switch (status) { + case LogSeverity.NotRun: + return 'notrun'; + case LogSeverity.Pass: + return 'pass'; + case LogSeverity.Skip: + return 'skip'; + case LogSeverity.Warn: + return 'warn'; + default: + return 'fail'; // Everything else is an error + } +} + +/** Holds onto a LiveTestCaseResult owned by the Logger, and writes the results into it. */ +export class TestCaseRecorder { + readonly result: LiveTestCaseResult; + public nonskippedSubcaseCount: number = 0; + private inSubCase: boolean = false; + private subCaseStatus = LogSeverity.NotRun; + private finalCaseStatus = LogSeverity.NotRun; + private hideStacksBelowSeverity = kMinSeverityForStack; + private startTime = -1; + 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; + this.debugging = debugging; + } + + start(): void { + assert(this.startTime < 0, 'TestCaseRecorder cannot be reused'); + this.startTime = now(); + } + + finish(): void { + // This is a framework error. If this assert is hit, it won't be localized + // to a test. The whole test run will fail out. + assert(this.startTime >= 0, 'internal error: finish() before start()'); + + const timeMilliseconds = now() - this.startTime; + // Round to next microsecond to avoid storing useless .xxxx00000000000002 in results. + this.result.timems = Math.ceil(timeMilliseconds * 1000) / 1000; + + if (this.finalCaseStatus === LogSeverity.Skip && this.nonskippedSubcaseCount !== 0) { + this.threw(new Error('internal error: case is "skip" but has nonskipped subcases')); + } + + // Convert numeric enum back to string (but expose 'exception' as 'fail') + this.result.status = logSeverityToString(this.finalCaseStatus); + + this.result.logs = this.logs; + } + + beginSubCase() { + this.subCaseStatus = LogSeverity.NotRun; + this.inSubCase = true; + } + + endSubCase(expectedStatus: Expectation) { + if (this.subCaseStatus !== LogSeverity.Skip) { + this.nonskippedSubcaseCount++; + } + try { + if (expectedStatus === 'fail') { + if (this.subCaseStatus <= LogSeverity.Warn) { + throw new UnexpectedPassError(); + } else { + this.subCaseStatus = LogSeverity.Pass; + } + } + } finally { + this.inSubCase = false; + this.finalCaseStatus = Math.max(this.finalCaseStatus, this.subCaseStatus); + } + } + + injectResult(injectedResult: LiveTestCaseResult): void { + Object.assign(this.result, injectedResult); + } + + debug(ex: Error): void { + if (!this.debugging) return; + this.logImpl(LogSeverity.Pass, 'DEBUG', ex); + } + + info(ex: Error): void { + // We need this to use the lowest LogSeverity so it doesn't override the current severity for this test case. + this.logImpl(LogSeverity.NotRun, 'INFO', ex); + } + + skipped(ex: SkipTestCase): void { + this.logImpl(LogSeverity.Skip, 'SKIP', ex); + } + + warn(ex: Error): void { + this.logImpl(LogSeverity.Warn, 'WARN', ex); + } + + expectationFailed(ex: Error): void { + this.logImpl(LogSeverity.ExpectFailed, 'EXPECTATION FAILED', ex); + } + + validationFailed(ex: Error): void { + this.logImpl(LogSeverity.ValidationFailed, 'VALIDATION FAILED', ex); + } + + passed(): void { + if (this.inSubCase) { + this.subCaseStatus = Math.max(this.subCaseStatus, LogSeverity.Pass); + } else { + this.finalCaseStatus = Math.max(this.finalCaseStatus, LogSeverity.Pass); + } + } + + threw(ex: unknown): void { + if (ex instanceof SkipTestCase) { + this.skipped(ex); + return; + } + this.logImpl(LogSeverity.ThrewException, 'EXCEPTION', ex); + } + + private logImpl(level: LogSeverity, name: string, baseException: unknown): void { + assert(baseException instanceof Error, 'test threw a non-Error object'); + globalTestConfig.testHeartbeatCallback(); + const logMessage = new LogMessageWithStack(name, baseException); + + // Final case status should be the "worst" of all log entries. + if (this.inSubCase) { + this.subCaseStatus = Math.max(this.subCaseStatus, level); + } else { + this.finalCaseStatus = Math.max(this.finalCaseStatus, level); + } + + // setFirstLineOnly for all logs except `kMaxLogStacks` stacks at the highest severity + if (level > this.hideStacksBelowSeverity) { + this.logLinesAtCurrentSeverity = 0; + this.hideStacksBelowSeverity = level; + + // Go back and setFirstLineOnly for everything of a lower log level + for (const log of this.logs) { + log.setStackHidden('below max severity'); + } + } + if (level === this.hideStacksBelowSeverity) { + this.logLinesAtCurrentSeverity++; + } else if (level < kMinSeverityForStack) { + logMessage.setStackHidden(''); + } else if (level < this.hideStacksBelowSeverity) { + logMessage.setStackHidden('below max severity'); + } + if (this.logLinesAtCurrentSeverity > kMaxLogStacks) { + logMessage.setStackHidden(`only ${kMaxLogStacks} shown`); + } + + this.logs.push(logMessage); + } +} |