diff --git a/changelog.md b/changelog.md index 61ff3c0..4b8550a 100644 --- a/changelog.md +++ b/changelog.md @@ -1,5 +1,13 @@ # Changelog +## 2025-05-24 - 1.11.0 - feat(cli) +Add new timeout and file range options with enhanced logfile diff logging + +- Introduce --timeout option to safeguard tests from running too long +- Add --startFrom and --stopAt options to control the range of test files executed +- Enhance logfile organization by automatically moving previous logs and generating diff reports for failed or changed test outputs +- Update CLI argument parsing and internal timeout handling for both Node.js and browser tests + ## 2025-05-24 - 1.10.2 - fix(tstest-logging) Improve log file handling with log rotation and diff reporting diff --git a/readme.md b/readme.md index c35a339..e2b0bf9 100644 --- a/readme.md +++ b/readme.md @@ -68,8 +68,11 @@ tstest "test/unit/*.ts" | `--verbose`, `-v` | Show all console output from tests | | `--no-color` | Disable colored output | | `--json` | Output results as JSON | -| `--logfile` | Save detailed logs to `.nogit/testlogs/[testname].log` | +| `--logfile` | Save detailed logs with automatic error and diff tracking | | `--tags ` | Run only tests with specific tags (comma-separated) | +| `--timeout ` | Timeout test files after specified seconds | +| `--startFrom ` | Start running from test file number n | +| `--stopAt ` | Stop running at test file number n | ### Example Outputs @@ -571,14 +574,88 @@ tstest "test/**/*.spec.ts" "test/**/*.test.ts" **Important**: Always quote glob patterns to prevent shell expansion. Without quotes, the shell will expand the pattern and only pass the first matching file to tstest. -### Automatic Logging +### Enhanced Test Logging + +The `--logfile` option provides intelligent test logging with automatic organization: -Use `--logfile` to automatically save test output: ```bash tstest test/ --logfile ``` -This creates detailed logs in `.nogit/testlogs/[testname].log` for each test file. +**Log Organization:** +- **Current Run**: `.nogit/testlogs/[testname].log` +- **Previous Run**: `.nogit/testlogs/previous/[testname].log` +- **Failed Tests**: `.nogit/testlogs/00err/[testname].log` +- **Changed Output**: `.nogit/testlogs/00diff/[testname].log` + +**Features:** +- Previous logs are automatically moved to the `previous/` folder +- Failed tests create copies in `00err/` for quick identification +- Tests with changed output create diff reports in `00diff/` +- The `00err/` and `00diff/` folders are cleared on each run + +**Example Diff Report:** +``` +DIFF REPORT: test__api__integration.log +Generated: 2025-05-24T01:29:13.847Z +================================================================================ + +- [Line 8] ✅ api test passes (150ms) ++ [Line 8] ✅ api test passes (165ms) + +================================================================================ +Previous version had 40 lines +Current version has 40 lines +``` + +### Test Timeout Protection + +Prevent runaway tests with the `--timeout` option: + +```bash +# Timeout any test file that runs longer than 60 seconds +tstest test/ --timeout 60 + +# Shorter timeout for unit tests +tstest test/unit/ --timeout 10 +``` + +When a test exceeds the timeout: +- The test process is terminated (SIGTERM) +- The test is marked as failed +- An error log is created in `.nogit/testlogs/00err/` +- Clear error message shows the timeout duration + +### Test File Range Control + +Run specific ranges of test files using `--startFrom` and `--stopAt`: + +```bash +# Run tests starting from the 5th file +tstest test/ --startFrom 5 + +# Run only files 5 through 10 +tstest test/ --startFrom 5 --stopAt 10 + +# Run only the first 3 test files +tstest test/ --stopAt 3 +``` + +This is particularly useful for: +- Debugging specific test failures in large test suites +- Running tests in chunks on different CI runners +- Quickly testing changes to specific test files + +The output shows which files are skipped: +``` +⏭️ test/auth.test.ts (1/10) + Skipped: before start range (5) +⏭️ test/user.test.ts (2/10) + Skipped: before start range (5) +▶️ test/api.test.ts (5/10) + Runtime: node.js + ✅ api endpoints work (145ms) +``` ### Performance Analysis @@ -620,8 +697,51 @@ tstest test/ --json > test-results.json tstest test/ --quiet ``` +**Advanced CI Example:** +```bash +# Run tests with comprehensive logging and safety features +tstest test/ \ + --timeout 300 \ + --logfile \ + --json > test-results.json + +# Run specific test chunks in parallel CI jobs +tstest test/ --startFrom 1 --stopAt 10 # Job 1 +tstest test/ --startFrom 11 --stopAt 20 # Job 2 +tstest test/ --startFrom 21 # Job 3 +``` + +### Debugging Failed Tests + +When tests fail, use the enhanced logging features: + +```bash +# Run with logging to capture detailed output +tstest test/ --logfile --verbose + +# Check error logs +ls .nogit/testlogs/00err/ + +# Review diffs for flaky tests +cat .nogit/testlogs/00diff/test__api__endpoints.log + +# Re-run specific failed tests +tstest test/api/endpoints.test.ts --verbose --timeout 60 +``` + ## Changelog +### Version 1.10.0 +- ⏱️ Added `--timeout ` option for test file timeout protection +- 🎯 Added `--startFrom ` and `--stopAt ` options for test file range control +- 📁 Enhanced `--logfile` with intelligent log organization: + - Previous logs moved to `previous/` folder + - Failed tests copied to `00err/` folder + - Changed tests create diff reports in `00diff/` folder +- 🔍 Improved test discovery to show skipped files with clear reasons +- 🐛 Fixed TypeScript compilation warnings and unused variables +- 📊 Test summaries now include skipped file counts + ### Version 1.9.2 - 🐛 Fixed test timing display issue (removed duplicate timing in output) - 📝 Improved internal protocol design documentation diff --git a/ts/00_commitinfo_data.ts b/ts/00_commitinfo_data.ts index 5b4dbd7..5d182ac 100644 --- a/ts/00_commitinfo_data.ts +++ b/ts/00_commitinfo_data.ts @@ -3,6 +3,6 @@ */ export const commitinfo = { name: '@git.zone/tstest', - version: '1.10.2', + version: '1.11.0', description: 'a test utility to run tests that match test/**/*.ts' } diff --git a/ts/index.ts b/ts/index.ts index 7d2f5f4..0d005b6 100644 --- a/ts/index.ts +++ b/ts/index.ts @@ -15,6 +15,7 @@ export const runCli = async () => { let tags: string[] = []; let startFromFile: number | null = null; let stopAtFile: number | null = null; + let timeoutSeconds: number | null = null; // Parse options for (let i = 0; i < args.length; i++) { @@ -70,6 +71,19 @@ export const runCli = async () => { process.exit(1); } break; + case '--timeout': + if (i + 1 < args.length) { + const value = parseInt(args[++i], 10); + if (isNaN(value) || value < 1) { + console.error('Error: --timeout must be a positive integer (seconds)'); + process.exit(1); + } + timeoutSeconds = value; + } else { + console.error('Error: --timeout requires a number argument (seconds)'); + process.exit(1); + } + break; default: if (!arg.startsWith('-')) { testPath = arg; @@ -95,6 +109,7 @@ export const runCli = async () => { console.error(' --tags Run only tests with specified tags (comma-separated)'); console.error(' --startFrom Start running from test file number n'); console.error(' --stopAt Stop running at test file number n'); + console.error(' --timeout Timeout test files after s seconds'); process.exit(1); } @@ -109,7 +124,7 @@ export const runCli = async () => { executionMode = TestExecutionMode.DIRECTORY; } - const tsTestInstance = new TsTest(process.cwd(), testPath, executionMode, logOptions, tags, startFromFile, stopAtFile); + const tsTestInstance = new TsTest(process.cwd(), testPath, executionMode, logOptions, tags, startFromFile, stopAtFile, timeoutSeconds); await tsTestInstance.run(); }; diff --git a/ts/tstest.classes.tap.parser.ts b/ts/tstest.classes.tap.parser.ts index cd2f8b2..86825e9 100644 --- a/ts/tstest.classes.tap.parser.ts +++ b/ts/tstest.classes.tap.parser.ts @@ -31,6 +31,34 @@ export class TapParser { constructor(public fileName: string, logger?: TsTestLogger) { this.logger = logger; } + + /** + * Handle test file timeout + */ + public handleTimeout(timeoutSeconds: number) { + // Create a fake failing test result for timeout + this._getNewTapTestResult(); + this.activeTapTestResult.testOk = false; + this.activeTapTestResult.testSettled = true; + this.testStore.push(this.activeTapTestResult); + + // Set expected vs received to force failure + this.expectedTests = 1; + this.receivedTests = 0; + + // Log the timeout error + if (this.logger) { + this.logger.testResult( + `Test file timeout`, + false, + timeoutSeconds * 1000, + `Error: Test file exceeded timeout of ${timeoutSeconds} seconds` + ); + this.logger.testErrorDetails(`Test execution was terminated after ${timeoutSeconds} seconds`); + // Force file end with failure + this.logger.testFileEnd(0, 1, timeoutSeconds * 1000); + } + } private _getNewTapTestResult() { this.activeTapTestResult = new TapTestResult(this.testStore.length + 1); @@ -69,7 +97,7 @@ export class TapParser { } else if (this.testStatusRegex.test(logLine)) { logLineIsTapProtocol = true; const regexResult = this.testStatusRegex.exec(logLine); - const testId = parseInt(regexResult[2]); + // const testId = parseInt(regexResult[2]); // Currently unused const testOk = (() => { if (regexResult[1] === 'ok') { return true; @@ -81,21 +109,16 @@ export class TapParser { const testMetadata = regexResult[5]; // This will be either "time=XXXms" or "SKIP reason" or "TODO reason" let testDuration = 0; - let isSkipped = false; - let isTodo = false; if (testMetadata) { const timeMatch = testMetadata.match(/time=(\d+)ms/); - const skipMatch = testMetadata.match(/SKIP\s*(.*)/); - const todoMatch = testMetadata.match(/TODO\s*(.*)/); + // const skipMatch = testMetadata.match(/SKIP\s*(.*)/); // Currently unused + // const todoMatch = testMetadata.match(/TODO\s*(.*)/); // Currently unused if (timeMatch) { testDuration = parseInt(timeMatch[1]); - } else if (skipMatch) { - isSkipped = true; - } else if (todoMatch) { - isTodo = true; } + // Skip/todo handling could be added here in the future } // test for protocol error - disabled as it's not critical @@ -305,13 +328,16 @@ export class TapParser { this.logger.error(`Only ${this.receivedTests} out of ${this.expectedTests} completed!`); } } - if (!this.expectedTests) { + if (!this.expectedTests && this.receivedTests === 0) { if (this.logger) { this.logger.error('No tests were defined. Therefore the testfile failed!'); + this.logger.testFileEnd(0, 1, 0); // Count as 1 failure } } else if (this.expectedTests !== this.receivedTests) { if (this.logger) { this.logger.error('The amount of received tests and expectedTests is unequal! Therefore the testfile failed'); + const errorCount = this.getErrorTests().length || 1; // At least 1 error + this.logger.testFileEnd(this.receivedTests - errorCount, errorCount, 0); } } else if (this.getErrorTests().length === 0) { if (this.logger) { diff --git a/ts/tstest.classes.tstest.ts b/ts/tstest.classes.tstest.ts index c1c7e0e..84faaee 100644 --- a/ts/tstest.classes.tstest.ts +++ b/ts/tstest.classes.tstest.ts @@ -18,6 +18,7 @@ export class TsTest { public filterTags: string[]; public startFromFile: number | null; public stopAtFile: number | null; + public timeoutSeconds: number | null; public smartshellInstance = new plugins.smartshell.Smartshell({ executor: 'bash', @@ -28,13 +29,14 @@ export class TsTest { public tsbundleInstance = new plugins.tsbundle.TsBundle(); - constructor(cwdArg: string, testPathArg: string, executionModeArg: TestExecutionMode, logOptions: LogOptions = {}, tags: string[] = [], startFromFile: number | null = null, stopAtFile: number | null = null) { + constructor(cwdArg: string, testPathArg: string, executionModeArg: TestExecutionMode, logOptions: LogOptions = {}, tags: string[] = [], startFromFile: number | null = null, stopAtFile: number | null = null, timeoutSeconds: number | null = null) { this.executionMode = executionModeArg; this.testDir = new TestDirectory(cwdArg, testPathArg, executionModeArg); this.logger = new TsTestLogger(logOptions); this.filterTags = tags; this.startFromFile = startFromFile; this.stopAtFile = stopAtFile; + this.timeoutSeconds = timeoutSeconds; } async run() { @@ -147,7 +149,30 @@ export class TsTest { const execResultStreaming = await this.smartshellInstance.execStreamingSilent( `tsrun ${fileNameArg}${tsrunOptions}` ); - await tapParser.handleTapProcess(execResultStreaming.childProcess); + + // Handle timeout if specified + if (this.timeoutSeconds !== null) { + const timeoutMs = this.timeoutSeconds * 1000; + const timeoutPromise = new Promise((_resolve, reject) => { + setTimeout(() => { + execResultStreaming.childProcess.kill('SIGTERM'); + reject(new Error(`Test file timed out after ${this.timeoutSeconds} seconds`)); + }, timeoutMs); + }); + + try { + await Promise.race([ + tapParser.handleTapProcess(execResultStreaming.childProcess), + timeoutPromise + ]); + } catch (error) { + // Handle timeout error + tapParser.handleTimeout(this.timeoutSeconds); + } + } else { + await tapParser.handleTapProcess(execResultStreaming.childProcess); + } + return tapParser; } @@ -205,9 +230,10 @@ export class TsTest { }); }); - // lets do the browser bit + // lets do the browser bit with timeout handling await this.smartbrowserInstance.start(); - await this.smartbrowserInstance.evaluateOnPage( + + const evaluatePromise = this.smartbrowserInstance.evaluateOnPage( `http://localhost:3007/test?bundleName=${bundleFileName}`, async () => { // lets enable real time comms @@ -264,6 +290,29 @@ export class TsTest { return logStore.join('\n'); } ); + + // Handle timeout if specified + if (this.timeoutSeconds !== null) { + const timeoutMs = this.timeoutSeconds * 1000; + const timeoutPromise = new Promise((_resolve, reject) => { + setTimeout(() => { + reject(new Error(`Test file timed out after ${this.timeoutSeconds} seconds`)); + }, timeoutMs); + }); + + try { + await Promise.race([ + evaluatePromise, + timeoutPromise + ]); + } catch (error) { + // Handle timeout error + tapParser.handleTimeout(this.timeoutSeconds); + } + } else { + await evaluatePromise; + } + await this.smartbrowserInstance.stop(); await server.stop(); wss.close(); @@ -280,28 +329,38 @@ export class TsTest { private async movePreviousLogFiles() { const logDir = plugins.path.join('.nogit', 'testlogs'); const previousDir = plugins.path.join('.nogit', 'testlogs', 'previous'); + const errDir = plugins.path.join('.nogit', 'testlogs', '00err'); + const diffDir = plugins.path.join('.nogit', 'testlogs', '00diff'); try { - // Get all files in log directory + // Delete 00err and 00diff directories if they exist + if (await plugins.smartfile.fs.isDirectory(errDir)) { + await plugins.smartfile.fs.remove(errDir); + } + if (await plugins.smartfile.fs.isDirectory(diffDir)) { + await plugins.smartfile.fs.remove(diffDir); + } + + // Get all .log files in log directory (not in subdirectories) const files = await plugins.smartfile.fs.listFileTree(logDir, '*.log'); - if (files.length === 0) { + const logFiles = files.filter(file => !file.includes('/')); + + if (logFiles.length === 0) { return; } // Ensure previous directory exists await plugins.smartfile.fs.ensureDir(previousDir); - // Move each file to previous directory - for (const file of files) { + // Move each log file to previous directory + for (const file of logFiles) { const filename = plugins.path.basename(file); const sourcePath = plugins.path.join(logDir, filename); const destPath = plugins.path.join(previousDir, filename); try { - // Read file content and write to new location - const content = await plugins.smartfile.fs.toStringSync(sourcePath); - await plugins.smartfile.fs.toFs(content, destPath); - // Remove original file + // Copy file to new location and remove original + await plugins.smartfile.fs.copy(sourcePath, destPath); await plugins.smartfile.fs.remove(sourcePath); } catch (error) { // Silently continue if a file can't be moved diff --git a/ts/tstest.logging.ts b/ts/tstest.logging.ts index 57ccc02..8c53b52 100644 --- a/ts/tstest.logging.ts +++ b/ts/tstest.logging.ts @@ -256,7 +256,11 @@ export class TsTestLogger { // Create error copy if there were failures if (failed > 0) { - const errorLogPath = path.join(logDir, `00err_${logBasename}`); + const errorDir = path.join(logDir, '00err'); + if (!fs.existsSync(errorDir)) { + fs.mkdirSync(errorDir, { recursive: true }); + } + const errorLogPath = path.join(errorDir, logBasename); fs.writeFileSync(errorLogPath, logContent); } @@ -267,7 +271,11 @@ export class TsTestLogger { // Simple check if content differs if (previousContent !== logContent) { - const diffLogPath = path.join(logDir, `00diff_${logBasename}`); + const diffDir = path.join(logDir, '00diff'); + if (!fs.existsSync(diffDir)) { + fs.mkdirSync(diffDir, { recursive: true }); + } + const diffLogPath = path.join(diffDir, logBasename); const diffContent = this.createDiff(previousContent, logContent, logBasename); fs.writeFileSync(diffLogPath, diffContent); }