feat(cli): Add new timeout and file range options with enhanced logfile diff logging

This commit is contained in:
Philipp Kunz 2025-05-24 01:32:41 +00:00
parent b525754035
commit 31bf090410
7 changed files with 266 additions and 30 deletions

View File

@ -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 <seconds> 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

128
readme.md
View File

@ -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 <tags>` | Run only tests with specific tags (comma-separated) |
| `--timeout <seconds>` | Timeout test files after specified seconds |
| `--startFrom <n>` | Start running from test file number n |
| `--stopAt <n>` | 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 <seconds>` option for test file timeout protection
- 🎯 Added `--startFrom <n>` and `--stopAt <n>` 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

View File

@ -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'
}

View File

@ -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 <tags> Run only tests with specified tags (comma-separated)');
console.error(' --startFrom <n> Start running from test file number n');
console.error(' --stopAt <n> Stop running at test file number n');
console.error(' --timeout <s> 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();
};

View File

@ -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) {

View File

@ -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<void>((_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<void>((_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

View File

@ -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);
}