From 21c44997a8fab58e4f8af67c7cb8b72bcf3d6308 Mon Sep 17 00:00:00 2001 From: Michael Cousins Date: Sat, 11 May 2024 11:37:15 -0400 Subject: [PATCH] fixup: improve debug logging and testing --- README.md | 27 ++--- example/meaning-of-life.test.ts | 5 +- src/debug.ts | 41 ++++--- src/vitest-when.ts | 5 +- test/debug.test.ts | 182 ++++++++++++++++++++++++++++++++ test/vitest-when.test.ts | 85 --------------- 6 files changed, 220 insertions(+), 125 deletions(-) create mode 100644 test/debug.test.ts diff --git a/README.md b/README.md index b29fca0..c00fa63 100644 --- a/README.md +++ b/README.md @@ -491,7 +491,7 @@ debug(coolFunc) // - `coolFunc(1, 2, 4)` ``` -#### Options +#### `DebugOptions` ```ts import type { DebugOptions } from 'vitest-when' @@ -501,22 +501,23 @@ import type { DebugOptions } from 'vitest-when' | ------ | ------- | ------- | -------------------------------------- | | `log` | `true` | boolean | Whether the call to `debug` should log | -#### Result +#### `DebugResult` ```ts import type { DebugResult, DebugStubbing, DebugBehavior } from 'vitest-when' ``` -| fields | type | description | -| ---------------------------- | -------------------------------------------- | ---------------------------------------------------------- | -| `name` | `string` | The name of the mock, if set by [`mockName`][mockName] | -| `stubbings` | `DebugStubbing[]` | The list of configured stub behaviors | -| `stubbings[].args` | `unknown[]` | The stubbing's arguments to match | -| `stubbings[].behavior` | `DebugBehavior` | The configured behavior of the stubbing | -| `stubbings[].behavior.type` | `return`, `throw`, `resolve`, `reject`, `do` | Result type of the stubbing | -| `stubbings[].behavior.value` | `unknown` | Value for the behahior, if `type` is `return` or `resolve` | -| `stubbings[].behavior.error` | `unknown` | Error for the behavior, it `type` is `throw` or `reject` | -| `stubbings[].matchedCalls` | `unknown[][]` | Actual calls that matched the stubbing, if any | -| `unmatchedCalls` | `unknown[][]` | Actual calls that did not match a stubbing | +| fields | type | description | +| ---------------------------- | -------------------------------------------- | ----------------------------------------------------------- | +| `description` | `string` | A human-readable description of the stub, logged by default | +| `name` | `string` | The name of the mock, if set by [`mockName`][mockName] | +| `stubbings` | `DebugStubbing[]` | The list of configured stub behaviors | +| `stubbings[].args` | `unknown[]` | The stubbing's arguments to match | +| `stubbings[].behavior` | `DebugBehavior` | The configured behavior of the stubbing | +| `stubbings[].behavior.type` | `return`, `throw`, `resolve`, `reject`, `do` | Result type of the stubbing | +| `stubbings[].behavior.value` | `unknown` | Value for the behavior, if `type` is `return` or `resolve` | +| `stubbings[].behavior.error` | `unknown` | Error for the behavior, it `type` is `throw` or `reject` | +| `stubbings[].matchedCalls` | `unknown[][]` | Actual calls that matched the stubbing, if any | +| `unmatchedCalls` | `unknown[][]` | Actual calls that did not match a stubbing | [mockName]: https://vitest.dev/api/mock.html#mockname diff --git a/example/meaning-of-life.test.ts b/example/meaning-of-life.test.ts index 1a65d5c..ff44b0b 100644 --- a/example/meaning-of-life.test.ts +++ b/example/meaning-of-life.test.ts @@ -1,5 +1,5 @@ import { vi, describe, afterEach, it, expect } from 'vitest' -import { when } from 'vitest-when' +import { when, debug } from 'vitest-when' import * as deepThought from './deep-thought.ts' import * as earth from './earth.ts' @@ -19,6 +19,9 @@ describe('get the meaning of life', () => { const result = await subject.createMeaning() + debug(deepThought.calculateAnswer) + debug(earth.calculateQuestion) + expect(result).toEqual({ question: "What's 6 by 9?", answer: 42 }) }) }) diff --git a/src/debug.ts b/src/debug.ts index fa407c0..1b25815 100644 --- a/src/debug.ts +++ b/src/debug.ts @@ -9,6 +9,7 @@ import type { Behavior } from './behaviors' export interface DebugResult { name: string + description: string stubbings: readonly Stubbing[] unmatchedCalls: readonly unknown[][] } @@ -33,10 +34,13 @@ export const getDebug = ( calls: entry.calls, })) ?? [] - return { name, stubbings, unmatchedCalls } + const result = { name, stubbings, unmatchedCalls } + const description = formatDebug(result) + + return { ...result, description } } -export const formatDebug = (debug: DebugResult): string => { +const formatDebug = (debug: Omit): string => { const { name, stubbings, unmatchedCalls } = debug const callCount = stubbings.reduce( (result, { calls }) => result + calls.length, @@ -47,31 +51,22 @@ export const formatDebug = (debug: DebugResult): string => { return [ `\`${name}()\` has:`, + `* ${count(stubbingCount, 'stubbing')} with ${count(callCount, 'call')}`, + ...stubbings.map((stubbing) => ` * ${formatStubbing(stubbing)}`).reverse(), + `* ${count(unmatchedCallsCount, 'unmatched call')}`, + ...unmatchedCalls.map((args) => ` * \`${formatCall(args)}\``), '', - `${stubbingCount} ${plural( - 'stubbing', - stubbingCount, - )} with ${callCount} calls`, - ...stubbings - .map((stubbing) => `- ${formatStubbing(name, stubbing)}`) - .reverse(), - '', - `${unmatchedCallsCount} unmatched ${plural('call', unmatchedCallsCount)}`, - ...unmatchedCalls.map((args) => `- \`${formatCall(name, args)}\``), ].join('\n') } -const formatStubbing = ( - name: string, - { args, behavior, calls }: Stubbing, -): string => { - return `${calls.length} calls: \`${formatCall(name, args)} ${formatBehavior( - behavior, - )}\`` +const formatStubbing = ({ args, behavior, calls }: Stubbing): string => { + return `Called ${count(calls.length, 'time')}: \`${formatCall( + args, + )} ${formatBehavior(behavior)}\`` } -const formatCall = (name: string, args: readonly unknown[]): string => { - return `${name}(${args.map((a) => stringify(a)).join(', ')})` +const formatCall = (args: readonly unknown[]): string => { + return `(${args.map((a) => stringify(a)).join(', ')})` } const formatBehavior = (behavior: Behavior): string => { @@ -98,8 +93,8 @@ const formatBehavior = (behavior: Behavior): string => { } } -const plural = (thing: string, count: number) => - `${thing}${count === 1 ? '' : 's'}` +const count = (amount: number, thing: string) => + `${amount} ${thing}${amount === 1 ? '' : 's'}` const { AsymmetricMatcher, diff --git a/src/vitest-when.ts b/src/vitest-when.ts index ffda3ed..f562254 100644 --- a/src/vitest-when.ts +++ b/src/vitest-when.ts @@ -1,7 +1,7 @@ import { configureStub } from './stubs.ts' import type { WhenOptions } from './behaviors.ts' import type { AnyFunction } from './types.ts' -import { getDebug, formatDebug, type DebugResult } from './debug.ts' +import { getDebug, type DebugResult } from './debug.ts' export type { WhenOptions } from './behaviors.ts' export * from './errors.ts' @@ -52,8 +52,7 @@ export const debug = ( const result = getDebug(spy) if (options.log !== false) { - const description = formatDebug(result) - console.debug(description) + console.debug(result.description) } return result diff --git a/test/debug.test.ts b/test/debug.test.ts new file mode 100644 index 0000000..4e8ab2a --- /dev/null +++ b/test/debug.test.ts @@ -0,0 +1,182 @@ +import { vi, describe, expect, it } from 'vitest' + +import * as subject from '../src/vitest-when.ts' + +const DEBUG_OPTIONS = { log: false } + +describe('vitest-when debug', () => { + it('debugs a non-stubbed spy', () => { + const spy = vi.fn() + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result).toEqual({ + name: 'spy', + stubbings: [], + unmatchedCalls: [], + description: expect.stringContaining( + '0 stubbings with 0 calls', + ) as string, + }) + }) + + it('debugs uncalled stubbings', () => { + const spy = vi.fn() + + subject.when(spy).calledWith('hello', 'world').thenReturn(42) + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result).toEqual({ + name: 'spy', + stubbings: [ + { + args: ['hello', 'world'], + behavior: { type: 'return', value: 42 }, + calls: [], + }, + ], + unmatchedCalls: [], + description: expect.stringContaining('1 stubbing with 0 calls') as string, + }) + }) + + it('debugs called stubbings', () => { + const spy = vi.fn() + + subject.when(spy).calledWith(expect.any(String)).thenReturn(42) + + spy('hello') + spy('world') + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result).toMatchObject({ + name: 'spy', + stubbings: [ + { + args: [expect.any(String)], + behavior: { type: 'return', value: 42 }, + calls: [['hello'], ['world']], + }, + ], + unmatchedCalls: [], + description: expect.stringContaining('1 stubbing with 2 calls') as string, + }) + }) + + it('debugs unmatched calls', () => { + const spy = vi.fn() + + subject.when(spy).calledWith(expect.any(String)).thenReturn(42) + + spy(1234) + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result).toMatchObject({ + name: 'spy', + stubbings: [ + { + args: [expect.any(String)], + behavior: { type: 'return', value: 42 }, + calls: [], + }, + ], + unmatchedCalls: [[1234]], + description: expect.stringContaining('1 unmatched call') as string, + }) + }) + + it('describes thenReturn stubbings', () => { + const spy = vi.fn() + + subject.when(spy).calledWith('hello', 'world').thenReturn(42) + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result.description).toMatch('("hello", "world") => 42') + }) + + it('describes thenResolve stubbings', () => { + const spy = vi.fn() + + subject.when(spy).calledWith('hello', 'world').thenResolve(42) + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result.description).toMatch( + '("hello", "world") => Promise.resolve(42)', + ) + }) + + it('describes thenThrow stubbings', () => { + const spy = vi.fn() + + subject.when(spy).calledWith('hello', 'world').thenThrow(new Error('oh no')) + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result.description).toMatch( + '("hello", "world") => { throw [Error: oh no] }', + ) + }) + + it('describes thenReject stubbings', () => { + const spy = vi.fn() + + subject + .when(spy) + .calledWith('hello', 'world') + .thenReject(new Error('oh no')) + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result.description).toMatch( + '("hello", "world") => Promise.reject([Error: oh no])', + ) + }) + + it('describes thenDo stubbings', () => { + const spy = vi.fn() + + subject + .when(spy) + .calledWith('hello', 'world') + .thenDo(() => 42) + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result.description).toMatch( + '("hello", "world") => [Function anonymous]()', + ) + }) + + it('describes calls with non-JSONifiable objects', () => { + const spy = vi.fn() + const value = { + toJSON() { + throw new Error('oh no') + }, + } + + spy(value) + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result.description).toMatch('({"toJSON": [Function toJSON]})') + }) + + it('describes calls with long values', () => { + const spy = vi.fn() + const longString = Array.from({ length: 1001 }).join('x') + const value = Array.from({ length: 100 }) + value.fill(longString) + + spy(value) + + const result = subject.debug(spy, DEBUG_OPTIONS) + + expect(result.description).toMatch(/\(\["x.+, …\]\)/u) + }) +}) diff --git a/test/vitest-when.test.ts b/test/vitest-when.test.ts index cf1cd60..4f3ae86 100644 --- a/test/vitest-when.test.ts +++ b/test/vitest-when.test.ts @@ -264,89 +264,4 @@ describe('vitest-when', () => { // intentionally do not call the spy expect(true).toBe(true) }) - - it('should debug a non-stubbed spy', () => { - const spy = vi.fn() - - const result = subject.debug(spy, { log: false }) - - expect(result).toEqual({ - name: 'spy', - stubbings: [], - unmatchedCalls: [], - }) - }) - - it('debugs the name of a spy', () => { - const spy = vi.fn().mockName('harry') - - const result = subject.debug(spy, { log: false }) - - expect(result).toEqual({ - name: 'harry', - stubbings: [], - unmatchedCalls: [], - }) - }) - - it('debugs unmatched calls', () => { - const spy = vi.fn() - - spy('hello', 'world') - spy('fizz', 'buzz') - - const result = subject.debug(spy, { log: false }) - - expect(result).toEqual({ - name: 'spy', - stubbings: [], - unmatchedCalls: [ - ['hello', 'world'], - ['fizz', 'buzz'], - ], - }) - }) - - it('debugs uncalled stubbings', () => { - const spy = vi.fn() - - subject.when(spy).calledWith('hello', 'world').thenReturn(42) - - const result = subject.debug(spy, { log: false }) - - expect(result).toEqual({ - name: 'spy', - stubbings: [ - { - args: ['hello', 'world'], - behavior: { type: 'return', value: 42 }, - calls: [], - }, - ], - unmatchedCalls: [], - }) - }) - - it('debugs called stubbings', () => { - const spy = vi.fn() - - subject.when(spy).calledWith(expect.any(String)).thenReturn(42) - - spy('hello') - spy('world') - - const result = subject.debug(spy, { log: true }) - - expect(result).toEqual({ - name: 'spy', - stubbings: [ - { - args: [expect.any(String)], - behavior: { type: 'return', value: 42 }, - calls: [['hello'], ['world']], - }, - ], - unmatchedCalls: [], - }) - }) })