diff --git a/examples/mars-rover/tests.ts b/examples/mars-rover/tests.ts index 5118b11..ab3c672 100644 --- a/examples/mars-rover/tests.ts +++ b/examples/mars-rover/tests.ts @@ -1,3 +1,4 @@ +import chalk from 'chalk' import path from 'path' import { runFolder } from '../../runner/runFolder.js' import { RoverContext, steps } from './steps.js' @@ -5,6 +6,14 @@ import { RoverContext, steps } from './steps.js' const runner = await runFolder({ folder: path.join(process.cwd(), 'examples', 'mars-rover'), name: 'Mars Rover', + logObserver: { + onProgress: ({ ts }, ...progress) => + console.error( + chalk.gray(`ยป`), + chalk.cyan(`@${ts}`), + ...progress.map((s) => chalk.yellow(s)), + ), + }, }) runner.addStepRunners(...steps) diff --git a/runner/logger.spec.ts b/runner/logger.spec.ts index e0e8aac..aafe704 100644 --- a/runner/logger.spec.ts +++ b/runner/logger.spec.ts @@ -1,10 +1,13 @@ import assert from 'assert/strict' import { describe, it } from 'node:test' +import { Step } from '../parser/grammar.js' import { LogEntry, logger, LogLevel } from './logger.js' describe('logger()', () => { describe('should allow to log messages', () => { - const { progress, debug, error, getLogs, info } = logger({ + const step = {} as Step + const { progress, debug, error, getLogs, info, context } = logger({ + context: step , getRelativeTs: () => 42, }) const expected: LogEntry[] = [] @@ -55,5 +58,52 @@ describe('logger()', () => { assert.deepEqual(getLogs(), expected) }) + + describe('context provides the source of the log', () => { + it('should provide the context', () => assert.equal(context, step)) + }) + }) + + describe('listening to logs', () => { + it('should call log listeners', () => { + const debugLogs: any[] = [] + const infoLogs: any[] = [] + const progressLogs: any[] = [] + const errorLogs: any[] = [] + const step = {} as Step + const l = logger({ + context: step, + getRelativeTs: () => 42, + onDebug: (...args) => debugLogs.push(args), + onInfo: (...args) => infoLogs.push(args), + onProgress: (...args) => progressLogs.push(args), + onError: (...args) => errorLogs.push(args), + }) + + l.debug('foo', 'bar') + assert.deepEqual(debugLogs, [ + [{ context: step, ts: 42, level: LogLevel.DEBUG }, 'foo', 'bar'], + ]) + + l.info('bar', 'foo') + assert.deepEqual(infoLogs, [ + [{ context: step, ts: 42, level: LogLevel.INFO }, 'bar', 'foo'], + ]) + + l.progress('progress', 'foo') + assert.deepEqual(progressLogs, [ + [ + { context: step, ts: 42, level: LogLevel.PROGRESS }, + 'progress', + 'foo', + ], + ]) + + const e = new Error() + l.error(e) + assert.deepEqual(errorLogs, [ + [{ context: step, ts: 42, level: LogLevel.ERROR }, e], + ]) + }) }) }) diff --git a/runner/logger.ts b/runner/logger.ts index 2b56eb0..1b801e8 100644 --- a/runner/logger.ts +++ b/runner/logger.ts @@ -1,8 +1,26 @@ -export type Logger = { +import { Feature, Scenario, Step } from '../parser/grammar.js' + +export type Logger = { + /** + * Logs a debug message + */ debug: (...args: string[]) => void + /** + * Logs a info message + */ info: (...args: string[]) => void + /** + * Logs a error message + */ error: (error: ErrorInfo) => void + /** + * Logs a progress message + */ progress: (...args: string[]) => void + /** + * Returns the context of the logger. + */ + context: Context } type ErrorInfo = { @@ -26,37 +44,87 @@ export type LogEntry = { ts: number } -export const logger = ({ +type LogObserverInfo = { + context: Feature | Scenario | Step + level: LogLevel + /** + * Time in ms from beginning of the feature run when the log message was created + */ + ts: number +} + +export type LogObserver = { + /** + * Register a listener that receives debug logs + */ + onDebug?: (info: LogObserverInfo, ...args: string[]) => unknown + /** + * Register a listener that receives info logs + */ + onInfo?: (info: LogObserverInfo, ...args: string[]) => unknown + /** + * Register a listener that receives error logs + */ + onError?: (info: LogObserverInfo, error: ErrorInfo) => unknown + /** + * Register a listener that receives progress logs + */ + onProgress?: (info: LogObserverInfo, ...args: string[]) => unknown +} + +export const logger = ({ + context, getRelativeTs, + onDebug, + onError, + onInfo, + onProgress, }: { + /** + * The context the logs of this logger are coming from + */ + context: Context + /** + * Returns the number of milliseconds that have elapse since the "start" of the test run. + */ getRelativeTs: () => number -}): Logger & { getLogs: () => LogEntry[] } => { +} & LogObserver): Logger & { getLogs: () => LogEntry[] } => { const logs: LogEntry[] = [] + const ts = getRelativeTs() return { - debug: (...message) => + debug: (...message) => { logs.push({ message, level: LogLevel.DEBUG, - ts: getRelativeTs(), - }), - progress: (...message) => + ts, + }) + onDebug?.({ context, ts, level: LogLevel.DEBUG }, ...message) + }, + progress: (...message) => { logs.push({ message, level: LogLevel.PROGRESS, - ts: getRelativeTs(), - }), - info: (...message) => + ts, + }) + onProgress?.({ context, ts, level: LogLevel.PROGRESS }, ...message) + }, + info: (...message) => { logs.push({ message, level: LogLevel.INFO, - ts: getRelativeTs(), - }), - error: (error) => + ts, + }) + onInfo?.({ context, ts, level: LogLevel.INFO }, ...message) + }, + error: (error) => { logs.push({ message: [error.message], level: LogLevel.ERROR, - ts: getRelativeTs(), - }), + ts, + }) + onError?.({ context, ts, level: LogLevel.ERROR }, error) + }, getLogs: () => logs, + context, } } diff --git a/runner/runFeature.spec.ts b/runner/runFeature.spec.ts index 15e9dae..30f4efe 100644 --- a/runner/runFeature.spec.ts +++ b/runner/runFeature.spec.ts @@ -176,4 +176,52 @@ describe('runFeature()', () => { }, ]) }) + + describe('observe logs', () => { + it('should allow to pass a log observer', async () => { + const observedLogs: any[] = [] + const featureResult = await runFeature({ + stepRunners: [ + async ({ + log: { + feature: { debug, error, info, progress }, + }, + }) => { + debug(`A debug message`, `with two parts`) + error({ message: `Some error` }) + info(`An info`) + progress(`Doing something`, `the thing`) + }, + ], + feature: ( + await loadFeatureFile( + path.join( + process.cwd(), + 'runner', + 'test-data', + 'runFeature', + 'OneStep.feature.md', + ), + ) + ).feature, + context: {}, + getRelativeTs: () => 42, + logObserver: { + onDebug: (_, ...args) => observedLogs.push([LogLevel.DEBUG, ...args]), + onError: (_, error) => observedLogs.push([LogLevel.ERROR, error]), + onInfo: (_, ...args) => observedLogs.push([LogLevel.INFO, ...args]), + onProgress: (_, ...args) => + observedLogs.push([LogLevel.PROGRESS, ...args]), + }, + }) + + assert.equal(featureResult.ok, true) + assert.deepEqual(observedLogs, [ + [LogLevel.DEBUG, `A debug message`, `with two parts`], + [LogLevel.ERROR, { message: `Some error` }], + [LogLevel.INFO, `An info`], + [LogLevel.PROGRESS, `Doing something`, `the thing`], + ]) + }) + }) }) diff --git a/runner/runFeature.ts b/runner/runFeature.ts index a9aab55..c5a8b07 100644 --- a/runner/runFeature.ts +++ b/runner/runFeature.ts @@ -1,5 +1,5 @@ import { Feature, Keyword, Row, Scenario } from '../parser/grammar.js' -import { LogEntry, logger } from './logger.js' +import { LogEntry, logger, LogObserver } from './logger.js' import { replaceFromExamples } from './replaceFromExamples.js' import { runScenario, ScenarioResult } from './runScenario.js' import { StepRunner } from './runStep.js' @@ -21,17 +21,22 @@ export const runFeature = async >({ feature, context, getRelativeTs, + logObserver, }: { stepRunners: StepRunner[] feature: Feature context: Context getRelativeTs?: () => number + logObserver?: LogObserver }): Promise => { const scenarioResults: [ScenarioExecution, ScenarioResult][] = [] const startTs = Date.now() const relTs = getRelativeTs ?? (() => Date.now() - startTs) - const featureLogger = logger({ getRelativeTs: relTs }) - + const featureLogger = logger({ + getRelativeTs: relTs, + context: feature, + ...logObserver, + }) let aborted = false for (const scenario of feature.scenarios) { if (scenario.keyword === Keyword.ScenarioOutline) { @@ -96,6 +101,7 @@ export const runFeature = async >({ context, getRelativeTs: relTs, featureLogger, + logObserver, }) scenarioResults.push([ scenario as ScenarioExecution, diff --git a/runner/runFolder.ts b/runner/runFolder.ts index fda02f3..3ba065b 100644 --- a/runner/runFolder.ts +++ b/runner/runFolder.ts @@ -1,9 +1,11 @@ +import { LogObserver } from './logger.js' import { parseFeaturesInFolder } from './parseFeaturesInFolder.js' import { Runner, runSuite } from './runSuite.js' export const runFolder = async >({ folder, name, + logObserver, }: { /** * The name for the test suite @@ -13,5 +15,9 @@ export const runFolder = async >({ * A path to a folder to load the features from */ folder: string + /** + * Observe logs while they are being emitted + */ + logObserver?: LogObserver }): Promise> => - runSuite(await parseFeaturesInFolder(folder), name) + runSuite(await parseFeaturesInFolder(folder), name, logObserver) diff --git a/runner/runScenario.spec.ts b/runner/runScenario.spec.ts index 87e5994..44fb4ae 100644 --- a/runner/runScenario.spec.ts +++ b/runner/runScenario.spec.ts @@ -33,7 +33,7 @@ describe('runScenario()', () => { scenario: feature.scenarios[0] as Scenario, context: {}, getRelativeTs: getRelativeTs, - featureLogger: logger({ getRelativeTs }), + featureLogger: logger({ getRelativeTs, context: feature }), } }) @@ -138,7 +138,7 @@ describe('runScenario()', () => { scenario: feature.scenarios[0] as Scenario, context: {}, getRelativeTs: getRelativeTs, - featureLogger: logger({ getRelativeTs }), + featureLogger: logger({ getRelativeTs, context: feature }), }) assert.equal(scenarioResult.ok, true) diff --git a/runner/runScenario.ts b/runner/runScenario.ts index 380a798..7899ce9 100644 --- a/runner/runScenario.ts +++ b/runner/runScenario.ts @@ -1,5 +1,5 @@ import { Feature, Scenario, Step } from '../parser/grammar.js' -import { LogEntry, logger, Logger } from './logger.js' +import { LogEntry, logger, Logger, LogObserver } from './logger.js' import { runStep, StepResult, StepRunner } from './runStep.js' export type ScenarioResult = { @@ -17,16 +17,22 @@ export const runScenario = async >({ context, getRelativeTs, featureLogger, + logObserver, }: { stepRunners: StepRunner[] feature: Feature scenario: Scenario context: Context - featureLogger: Logger + featureLogger: Logger getRelativeTs: () => number + logObserver?: LogObserver }): Promise> => { const startTs = Date.now() - const scenarioLogger = logger({ getRelativeTs }) + const scenarioLogger = logger({ + getRelativeTs, + context: scenario, + ...logObserver, + }) const stepResults: [Step, StepResult][] = [] let aborted = false @@ -58,6 +64,7 @@ export const runScenario = async >({ getRelativeTs, featureLogger, scenarioLogger, + logObserver, }) stepResults.push([ step, diff --git a/runner/runStep.spec.ts b/runner/runStep.spec.ts index 66d8ec4..39b633a 100644 --- a/runner/runStep.spec.ts +++ b/runner/runStep.spec.ts @@ -26,16 +26,20 @@ describe('runStep()', () => { beforeEach(async () => { const feature = await f() const getRelativeTs = () => 42 + const scenario = feature.scenarios[0] as Scenario runStepArgs = { stepRunners: [], feature, - scenario: feature.scenarios[0] as Scenario, + scenario, step: feature.scenarios[0].steps[0], context: {}, previousResults: [], getRelativeTs: getRelativeTs, - featureLogger: logger({ getRelativeTs }), - scenarioLogger: logger({ getRelativeTs }), + featureLogger: logger({ getRelativeTs, context: feature }), + scenarioLogger: logger({ + getRelativeTs, + context: scenario, + }), } }) diff --git a/runner/runStep.ts b/runner/runStep.ts index 5dd6de4..22de06b 100644 --- a/runner/runStep.ts +++ b/runner/runStep.ts @@ -1,7 +1,7 @@ import { Feature, Scenario, Step, StepKeyword } from '../parser/grammar.js' import { formatRetryConfig, getRetryConfig } from './getRetryConfig.js' import { getUnreplacedPlaceholders } from './getUnreplacedPlaceholders.js' -import { LogEntry, logger, Logger } from './logger.js' +import { LogEntry, logger, Logger, LogObserver } from './logger.js' import { replaceFromContext } from './replaceFromContext.js' import { ScenarioExecution } from './runFeature.js' @@ -36,9 +36,9 @@ export type StepRunnerArgs> = { feature: Feature context: Context log: { - step: Logger - scenario: Logger - feature: Logger + step: Logger + scenario: Logger + feature: Logger } previousResult?: [Step, any] previousResults: [Step, any][] @@ -57,6 +57,7 @@ export const runStep = async >({ getRelativeTs, featureLogger, scenarioLogger, + logObserver, }: { stepRunners: StepRunner[] feature: Feature @@ -65,10 +66,11 @@ export const runStep = async >({ context: Context previousResults: [Step, any][] getRelativeTs: () => number - featureLogger: Logger - scenarioLogger: Logger + featureLogger: Logger + scenarioLogger: Logger + logObserver?: LogObserver }): Promise> => { - const stepLogger = logger({ getRelativeTs }) + const stepLogger = logger({ getRelativeTs, context: step, ...logObserver }) const replacedStep = replaceFromContext(context)(step) const unreplaced = getUnreplacedPlaceholders(replacedStep) diff --git a/runner/runSuite.ts b/runner/runSuite.ts index 391de1c..71b5d88 100644 --- a/runner/runSuite.ts +++ b/runner/runSuite.ts @@ -1,4 +1,5 @@ import { ParsedPath } from 'path' +import { LogObserver } from './logger.js' import { orderFeatures } from './orderFeatures.js' import { FeatureFile } from './parseFeaturesInFolder.js' import { FeatureResult, runFeature } from './runFeature.js' @@ -24,6 +25,7 @@ export type Runner> = { export const runSuite = >( featureFiles: FeatureFile[], name: string, + logObserver?: LogObserver, ): Runner => { const stepRunners: StepRunner[] = [] @@ -70,6 +72,7 @@ export const runSuite = >( feature, // Create a new context per feature context: JSON.parse(JSON.stringify(context ?? {})), + logObserver, }) featureResults.push([file, result]) featureNameResultMap[feature.title ?? file.name] = result.ok