From 269030e2e035937325637d31628a8ec58cb59b5c Mon Sep 17 00:00:00 2001 From: Chapman Pendery <35637443+cpendery@users.noreply.github.com> Date: Thu, 7 Mar 2024 14:49:00 -0500 Subject: [PATCH] feat: add terminal trace support (#20) * feat: add terminal trace support Signed-off-by: Chapman Pendery * fix: readline/promises not supported in node16 Signed-off-by: Chapman Pendery --------- Signed-off-by: Chapman Pendery --- .gitignore | 3 +- README.md | 20 ++++++++++ src/cli/index.ts | 9 ++++- src/cli/show-trace.ts | 20 ++++++++++ src/config/config.ts | 37 +++++++++++++++++ src/runner/runner.ts | 19 +++++++-- src/runner/worker.ts | 62 ++++++++++++++++++++++++----- src/terminal/ansi.ts | 11 +++++ src/terminal/term.ts | 23 ++++++++++- src/test/testcase.ts | 2 +- src/trace/tracer.ts | 88 ++++++++++++++++++++++++++++++++++++++++ src/trace/viewer.ts | 93 +++++++++++++++++++++++++++++++++++++++++++ 12 files changed, 367 insertions(+), 20 deletions(-) create mode 100644 src/cli/show-trace.ts create mode 100644 src/trace/tracer.ts create mode 100644 src/trace/viewer.ts diff --git a/.gitignore b/.gitignore index 4e06148..7e53c34 100644 --- a/.gitignore +++ b/.gitignore @@ -2,4 +2,5 @@ node_modules/ lib/ .tui-test/ *.tgz -t*.md \ No newline at end of file +t*.md +tui-traces/ \ No newline at end of file diff --git a/README.md b/README.md index 3bdf4be..1b0b2e5 100644 --- a/README.md +++ b/README.md @@ -102,6 +102,26 @@ test("make a regex assertion", async ({ terminal }) => { }); ``` +## Traces + +TUI Test provides a rich tracing system to help you debug and diagnose issues with your tests. You can enable traces by setting the `trace` value in your `tui-test.config.ts` to `true` or by running the cli with the `-t/--trace` flag. + +Traces are contain a replay of everything the terminal received and can be used to diagnose issues with your tests, especially when issues happen on different machines. Traces are stored in by default in the `tui-traces` folder in the root of your project and can be replayed via the `show-trace` command. + +## Configuration + +TUI Test can be configured via the `tui-test.config.[ts|js]` file in the root of your project. The following is an example of a configuration file: + +```ts +import { defineConfig } from "@microsoft/tui-test"; + +export default defineConfig({ + retries: 3, + trace: true +}); + +``` + ## Contributing This project welcomes contributions and suggestions. Most contributions require you to agree to a diff --git a/src/cli/index.ts b/src/cli/index.ts index bb529cc..3a2b8aa 100644 --- a/src/cli/index.ts +++ b/src/cli/index.ts @@ -6,17 +6,19 @@ import { Command } from "commander"; import { getVersion } from "./version.js"; import { executableName } from "../utils/constants.js"; import { run } from "../runner/runner.js"; +import showTrace from "./show-trace.js"; type CommandOptions = { updateSnapshot: boolean | undefined; + trace: boolean | undefined; }; const action = async ( testFilter: string[] | undefined, options: CommandOptions ) => { - const { updateSnapshot } = options; - await run({ updateSnapshot: updateSnapshot ?? false, testFilter }); + const { updateSnapshot, trace } = options; + await run({ updateSnapshot: updateSnapshot ?? false, testFilter, trace }); }; export const program = new Command(); @@ -35,6 +37,9 @@ Examples: "Pass an argument to filter test files. Each argument is treated as a regular expression. Matching is performed against the absolute file paths" ) .option("-u, --updateSnapshot", `use this flag to re-record snapshots`) + .option("-t, --trace", `enable traces for test execution`) .version(await getVersion(), "-v, --version", "output the current version") .action(action) .showHelpAfterError("(add --help for additional information)"); + +program.addCommand(showTrace); diff --git a/src/cli/show-trace.ts b/src/cli/show-trace.ts new file mode 100644 index 0000000..c47a98d --- /dev/null +++ b/src/cli/show-trace.ts @@ -0,0 +1,20 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +import { Command } from "commander"; + +import { loadTrace } from "../trace/tracer.js"; +import { play } from "../trace/viewer.js"; + +const action = async (traceFile: string) => { + const trace = await loadTrace(traceFile); + await play(trace); +}; + +const cmd = new Command("show-trace") + .description(`view traces in the console`) + .argument("", "the trace to replay in the terminal"); + +cmd.action(action); + +export default cmd; diff --git a/src/config/config.ts b/src/config/config.ts index cf1813d..90a297f 100644 --- a/src/config/config.ts +++ b/src/config/config.ts @@ -31,6 +31,9 @@ export const loadConfig = async (): Promise> => { userConfig.workers ?? Math.max(Math.floor(os.cpus().length / 2), 1), 1 ), + trace: userConfig.trace ?? false, + traceFolder: + userConfig.traceFolder ?? path.join(process.cwd(), "tui-traces"), use: { shell: userConfig.use?.shell ?? defaultShell, rows: userConfig.use?.rows ?? 30, @@ -220,6 +223,40 @@ export declare type TestConfig = { */ workers?: number; + /** + * Record each test run for replay. + * + * **Usage** + * + * ```js + * // tui-test.config.ts + * import { defineConfig } from '@microsoft/tui-test'; + * + * export default defineConfig({ + * trace: true, + * }); + * ``` + * + */ + trace?: boolean; + + /** + * Folder to store the traces in. Defaults to `tui-traces` + * + * **Usage** + * + * ```js + * // tui-test.config.ts + * import { defineConfig } from '@microsoft/tui-test'; + * + * export default defineConfig({ + * traceFolder: "tui-traces", + * }); + * ``` + * + */ + traceFolder?: string; + /** * TUI Test supports running multiple test projects at the same time. * diff --git a/src/runner/runner.ts b/src/runner/runner.ts index ce6ddc9..28279e5 100644 --- a/src/runner/runner.ts +++ b/src/runner/runner.ts @@ -9,7 +9,12 @@ import chalk from "chalk"; import { Suite, getRootSuite } from "../test/suite.js"; import { transformFiles } from "./transform.js"; -import { getRetries, getTimeout, loadConfig } from "../config/config.js"; +import { + TestConfig, + getRetries, + getTimeout, + loadConfig, +} from "../config/config.js"; import { runTestWorker } from "./worker.js"; import { Shell, setupZshDotfiles } from "../terminal/shell.js"; import { ListReporter } from "../reporter/list.js"; @@ -28,6 +33,7 @@ declare global { type ExecutionOptions = { updateSnapshot: boolean; + trace?: boolean; testFilter?: string[]; }; @@ -52,9 +58,12 @@ const runSuites = async ( allSuites: Suite[], filteredTestIds: Set, reporter: BaseReporter, - { updateSnapshot }: ExecutionOptions, + options: ExecutionOptions, + config: Required, pool: Pool ) => { + const { updateSnapshot } = options; + const trace = options.trace ?? config.trace; const tasks: Promise[] = []; const suites = [...allSuites]; while (suites.length != 0) { @@ -70,8 +79,11 @@ const runSuites = async ( test, test.sourcePath()!, { timeout: getTimeout(), updateSnapshot }, + trace, pool, - reporter + reporter, + i, + config.traceFolder ); test.results.push(testResult); reporter.endTest(test, testResult); @@ -237,6 +249,7 @@ export const run = async (options: ExecutionOptions) => { new Set(allTests.map((test) => test.id)), reporter, options, + config, pool ); try { diff --git a/src/runner/worker.ts b/src/runner/worker.ts index 622633c..1fee470 100644 --- a/src/runner/worker.ts +++ b/src/runner/worker.ts @@ -2,6 +2,7 @@ // Licensed under the MIT License. import process from "node:process"; +import { EventEmitter } from "node:events"; import workerpool from "workerpool"; import { Suite } from "../test/suite.js"; @@ -12,6 +13,7 @@ import { expect } from "../test/test.js"; import { BaseReporter } from "../reporter/base.js"; import { poll } from "../utils/poll.js"; import { flushSnapshotExecutionCache } from "../test/matchers/toMatchSnapshot.js"; +import { saveTrace, TracePoint } from "../trace/tracer.js"; type WorkerResult = { error?: string; @@ -33,6 +35,8 @@ const runTest = async ( testId: string, testSuite: Suite, updateSnapshot: boolean, + trace: boolean, + tracePoints: TracePoint[], importPath: string ) => { process.setSourceMapsEnabled(true); @@ -45,13 +49,24 @@ const runTest = async ( } const test = globalThis.tests[testId]; const { shell, rows, columns, env, program } = test.suite.options ?? {}; - const terminal = await spawn({ - shell: shell ?? defaultShell, - rows: rows ?? 30, - cols: columns ?? 80, - env, - program, - }); + const traceEmitter = new EventEmitter(); + traceEmitter.on("data", (data: string, time: number) => + tracePoints.push({ data, time }) + ); + traceEmitter.on("size", (rows: number, cols: number) => + tracePoints.push({ rows, cols }) + ); + const terminal = await spawn( + { + shell: shell ?? defaultShell, + rows: rows ?? 30, + cols: columns ?? 80, + env, + program, + }, + trace, + traceEmitter + ); const allTests = Object.values(globalThis.tests); const testPath = test.filePath(); @@ -102,8 +117,11 @@ export async function runTestWorker( test: TestCase, importPath: string, { timeout, updateSnapshot }: WorkerExecutionOptions, + trace: boolean, pool: workerpool.Pool, - reporter: BaseReporter + reporter: BaseReporter, + attempt: number, + traceFolder: string ): Promise { const snapshots: Snapshot[] = []; if (test.expectedStatus === "skipped") { @@ -127,7 +145,15 @@ export async function runTestWorker( try { const poolPromise = pool.exec( "testWorker", - [test.id, getMockSuite(test), updateSnapshot, importPath], + [ + test.id, + getMockSuite(test), + updateSnapshot, + trace, + importPath, + attempt, + traceFolder, + ], { on: (payload) => { if (payload.stdout) { @@ -243,16 +269,27 @@ const testWorker = async ( testId: string, testSuite: Suite, updateSnapshot: boolean, - importPath: string + trace: boolean, + importPath: string, + attempt: number, + traceFolder: string ): Promise => { flushSnapshotExecutionCache(); const startTime = Date.now(); + const tracePoints = [{ data: "", time: startTime }]; workerpool.workerEmit({ startTime, }); try { - await runTest(testId, testSuite, updateSnapshot, importPath); + await runTest( + testId, + testSuite, + updateSnapshot, + trace, + tracePoints, + importPath + ); } catch (e) { let errorMessage; if (typeof e == "string") { @@ -268,6 +305,9 @@ const testWorker = async ( }); } } + if (trace) { + await saveTrace(tracePoints, testId, attempt, traceFolder); + } }; if (!workerpool.isMainThread) { diff --git a/src/terminal/ansi.ts b/src/terminal/ansi.ts index 5cac2f5..9bf5d3d 100644 --- a/src/terminal/ansi.ts +++ b/src/terminal/ansi.ts @@ -5,6 +5,7 @@ const ESC = "\u001B"; const CSI = "\u001B["; +const SEP = ";"; const keyUp = CSI + "A"; const keyDown = CSI + "B"; @@ -14,6 +15,12 @@ const keyBackspace = "\u007F"; const keyDelete = CSI + "3~"; const keyCtrlC = String.fromCharCode(3); const keyCtrlD = String.fromCharCode(4); +const saveScreen = CSI + "?47h"; +const restoreScreen = CSI + "?47l"; +const clearScreen = CSI + "2J"; +const cursorTo = (x: number, y: number) => { + return CSI + (y + 1) + SEP + (x + 1) + "H"; +}; export default { keyUp, @@ -25,4 +32,8 @@ export default { keyDelete, keyCtrlC, keyCtrlD, + saveScreen, + restoreScreen, + clearScreen, + cursorTo, }; diff --git a/src/terminal/term.ts b/src/terminal/term.ts index 16069cb..83745c7 100644 --- a/src/terminal/term.ts +++ b/src/terminal/term.ts @@ -4,6 +4,7 @@ import pty, { IPty, IEvent } from "@homebridge/node-pty-prebuilt-multiarch"; import xterm from "xterm-headless"; import process from "node:process"; +import { EventEmitter } from "node:events"; import ansi from "./ansi.js"; @@ -38,7 +39,11 @@ type CursorPosition = { baseY: number; }; -export const spawn = async (options: TerminalOptions): Promise => { +export const spawn = async ( + options: TerminalOptions, + trace: boolean, + traceEmitter: EventEmitter +): Promise => { if (options.program != null) { const { file, args } = options.program; const resolvedFile = await which(file, { nothrow: true }); @@ -52,6 +57,8 @@ export const spawn = async (options: TerminalOptions): Promise => { args ?? [], options.rows, options.cols, + trace, + traceEmitter, options.env ); } @@ -61,6 +68,8 @@ export const spawn = async (options: TerminalOptions): Promise => { options.shellArgs ?? shellArgs ?? [], options.rows, options.cols, + trace, + traceEmitter, { ...shellEnv(options.shell), ...options.env } ); }; @@ -91,6 +100,8 @@ export class Terminal { args: string[], private _rows: number, private _cols: number, + private _trace: boolean, + private _traceEmitter: EventEmitter, env?: { [key: string]: string | undefined } ) { this.#pty = pty.spawn(target, args ?? [], { @@ -105,8 +116,13 @@ export class Terminal { rows: this._rows, cols: this._cols, }); - + if (this._trace) { + this._traceEmitter.emit("size", this._rows, this._cols); + } this.#pty.onData((data) => { + if (this._trace) { + this._traceEmitter.emit("data", data, Date.now()); + } this.#term.write(data); }); this.onExit = this.#pty.onExit; @@ -123,6 +139,9 @@ export class Terminal { this._rows = rows; this.#pty.resize(columns, rows); this.#term.resize(columns, rows); + if (this._trace) { + this._traceEmitter.emit("size", rows, columns); + } } /** diff --git a/src/test/testcase.ts b/src/test/testcase.ts index 60056be..1a2f2a0 100644 --- a/src/test/testcase.ts +++ b/src/test/testcase.ts @@ -93,7 +93,7 @@ export class TestCase { titles.push(currentSuite.title); } else if (currentSuite.type === "file") { titles.push( - `${currentSuite.title}:${this.location.row}:${this.location.row}` + `${currentSuite.title}:${this.location.row}:${this.location.column}` ); } currentSuite = currentSuite.parentSuite; diff --git a/src/trace/tracer.ts b/src/trace/tracer.ts new file mode 100644 index 0000000..c8bd711 --- /dev/null +++ b/src/trace/tracer.ts @@ -0,0 +1,88 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +import path from "node:path"; +import fs from "node:fs"; +import zlib from "node:zlib"; +import process from "node:process"; +import fsAsync from "node:fs/promises"; +import { promisify } from "node:util"; + +export type TracePoint = DataTracePoint | SizeTracePoint; + +export type DataTracePoint = { + time: number; + data: string; +}; +export type SizeTracePoint = { + rows: number; + cols: number; +}; + +export type Trace = { + tracePoints: TracePoint[]; + testPath: string[]; + testName: string[]; + attempt: number; +}; + +const zipInflate = promisify(zlib.inflate); +const zipDeflate = promisify(zlib.deflate); + +const traceFilename = (testId: string, attempt: number) => { + const test = globalThis.tests[testId]; + const filename = path + .relative(process.cwd(), path.resolve(test.filePath()!)) + .replace(path.sep, "-"); + const title = test.titlePath().slice(1).join("-"); + const retry = attempt > 0 ? `-retry${attempt}` : ""; + const name = `${filename}-${title}${retry}`.replaceAll( + /[ /\\<>:"'|?*]/g, + "-" + ); + return name; +}; + +const testName = (testId: string) => { + const test = globalThis.tests[testId]; + const t = test.titlePath(); + const [filename, row, column] = t[0].split(":"); + const testPath = [ + ...path.relative(process.cwd(), path.resolve(filename)).split(path.sep), + row, + column, + ]; + const testName = t.slice(1); + return { testName, testPath }; +}; + +export const loadTrace = async (traceFilename: string): Promise => { + if (!fs.existsSync(traceFilename)) { + throw new Error("unable to load trace, file not found"); + } + return JSON.parse( + (await zipInflate(await fsAsync.readFile(traceFilename))).toString() + ); +}; + +export const saveTrace = async ( + tracePoints: TracePoint[], + testId: string, + attempt: number, + traceFolder: string +) => { + const filename = traceFilename(testId, attempt); + if (!fs.existsSync(traceFolder)) { + await fsAsync.mkdir(traceFolder, { recursive: true }); + } + const trace: Trace = { + tracePoints, + attempt, + ...testName(testId), + }; + + await fsAsync.writeFile( + path.join(traceFolder, filename), + await zipDeflate(Buffer.from(JSON.stringify(trace), "utf8")) + ); +}; diff --git a/src/trace/viewer.ts b/src/trace/viewer.ts new file mode 100644 index 0000000..ee76e7d --- /dev/null +++ b/src/trace/viewer.ts @@ -0,0 +1,93 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +import readline from "node:readline"; +import { EventEmitter } from "node:events"; +import chalk from "chalk"; + +import { DataTracePoint, SizeTracePoint, Trace } from "./tracer.js"; +import ansi from "../terminal/ansi.js"; + +const rl = readline.createInterface({ + input: process.stdin, + output: process.stdout, +}); + +const question = (query: string): Promise => + new Promise((resolve) => rl.question(query, (answer) => resolve(answer))); + +export const play = async (trace: Trace) => { + const startTime = trace.tracePoints.find( + (tracePoint): tracePoint is DataTracePoint => "time" in tracePoint + )!.time; + const startSize = trace.tracePoints.find( + (tracePoint): tracePoint is SizeTracePoint => "rows" in tracePoint + )!; + + if ( + process.stdout.columns != startSize.cols || + process.stdout.rows != startSize.rows + ) { + console.warn( + chalk.yellow( + `Warning: the current terminal size (rows: ${process.stdout.rows}, columns: ${process.stdout.columns}) doesn't match the starting dimensions used in the trace (rows: ${startSize.rows}, columns: ${startSize.cols}).` + ) + ); + } + + if ( + trace.tracePoints.filter((tracePoint) => "rows" in tracePoint).length > 1 + ) { + console.warn( + chalk.yellow( + `Warning: the trace contains resize actions which won't be emulated when viewing.` + ) + ); + } + + const answer = (await question("\nDo you want to start the trace [y/N]? ")) + .trim() + .toLowerCase(); + + if (answer !== "y" && answer !== "yes") { + process.stdout.write("Exiting trace viewer\n"); + process.exit(0); + } + + const dataPoints = trace.tracePoints + .filter( + (tracePoint): tracePoint is DataTracePoint => + "time" in tracePoint && tracePoint.data != "" + ) + .map((dataPoint) => ({ ...dataPoint, delay: dataPoint.time - startTime })); + + const totalEvents = dataPoints.length; + let executedEvents = 0; + const e = new EventEmitter(); + + process.stdout.write(ansi.saveScreen); + process.stdout.write(ansi.clearScreen); + process.stdout.write(ansi.cursorTo(0, 0)); + + dataPoints.forEach((dataPoint) => { + setTimeout(() => { + process.stdout.write(dataPoint.data); + e.emit("write"); + }, dataPoint.delay); + }); + + e.on("write", async () => { + executedEvents += 1; + if (executedEvents == totalEvents) { + await question("\n\nReplay complete, press any key to exit "); + process.stdout.write( + ansi.cursorTo(process.stdout.rows, process.stdout.columns) + ); + process.stdout.write(ansi.restoreScreen); + process.stdout.write("\n\n"); + process.exit(0); + } + }); + + return new Promise(() => {}); +};