Skip to content

Commit 17acf70

Browse files
src: make the output modular
Previously the library would write to stdout and this was not configurable, which made testing more annoying. Add a `writer` property that can be overridden to more easily read output in tests.
1 parent 703b7b1 commit 17acf70

File tree

3 files changed

+198
-140
lines changed

3 files changed

+198
-140
lines changed

.gitignore

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,2 +1,3 @@
11
/node_modules/
22
/dist/
3+
package-lock.json

__tests__/index.ts

Lines changed: 129 additions & 103 deletions
Original file line numberDiff line numberDiff line change
@@ -1,25 +1,31 @@
11
/* eslint-disable @typescript-eslint/no-explicit-any */
22
import { advanceTo } from 'jest-date-mock'
3-
import { Logger, LEVEL } from '../src'
3+
import { Logger, LEVEL, formatLogLine, LogLine } from '../src'
44

55
advanceTo('2019-01-01T00:00:00.000Z')
66

7-
test('can log a message', () => {
8-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
7+
// Helper to capture log output using the writer option
8+
function createCaptureLogger(options: { level?: LEVEL; devMode?: boolean } = {}) {
9+
const output: string[] = []
10+
const logger = new Logger({
11+
...options,
12+
writer: (s) => output.push(s),
13+
})
14+
return { logger, output }
15+
}
916

10-
const logger = new Logger()
17+
test('can log a message', () => {
18+
const { logger, output } = createCaptureLogger()
1119
logger.log('info', 'test')
1220

13-
expect(spy).toHaveBeenCalledWith(`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test"}\n`)
21+
expect(output[0]).toBe(`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test"}`)
1422
})
1523

1624
test('allows the log level to be limited', () => {
17-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
18-
19-
const logger = new Logger({ level: 'error' })
25+
const { logger, output } = createCaptureLogger({ level: 'error' })
2026
logger.log('info', 'test')
2127

22-
expect(spy).not.toHaveBeenCalled()
28+
expect(output).toHaveLength(0)
2329
})
2430

2531
test('validates the level', () => {
@@ -29,97 +35,80 @@ test('validates the level', () => {
2935
})
3036

3137
test('can log data', () => {
32-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
33-
34-
const logger = new Logger()
38+
const { logger, output } = createCaptureLogger()
3539
logger.log('info', 'test', { some: 'data' })
3640

37-
expect(spy).toHaveBeenCalledWith(
38-
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"some":"data"}}\n`
39-
)
41+
expect(output[0]).toBe(`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"some":"data"}}`)
4042
})
4143

4244
interface fixture1 {
43-
fixture2?: any;
45+
fixture2?: any
4446
}
4547

4648
test('handles circular references', () => {
47-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
49+
const { logger, output } = createCaptureLogger()
4850

4951
const fixture1: fixture1 = {}
5052
const fixture2: object = { fixture1 }
5153
fixture1.fixture2 = fixture2
5254

53-
const logger = new Logger()
5455
logger.log('info', 'test', fixture1)
5556

56-
expect(spy).toHaveBeenCalledWith(
57-
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"fixture2":{"fixture1":"[Circular]"}}}\n`
57+
expect(output[0]).toBe(
58+
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"fixture2":{"fixture1":"[Circular]"}}}`
5859
)
5960
})
6061

6162
test('handles Buffers', () => {
62-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
63-
64-
const logger = new Logger()
63+
const { logger, output } = createCaptureLogger()
6564
logger.log('info', 'test', { buffer: Buffer.alloc(2) })
6665

67-
expect(spy).toHaveBeenCalledWith(
68-
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"buffer":{"type":"Buffer","data":[0,0]}}}\n`
66+
expect(output[0]).toBe(
67+
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"buffer":{"type":"Buffer","data":[0,0]}}}`
6968
)
7069
})
7170

7271
test('handles BigInts', () => {
73-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
74-
75-
const logger = new Logger()
72+
const { logger, output } = createCaptureLogger()
7673
logger.log('info', 'test', { bigint: BigInt('999999999999999999999') })
7774

78-
expect(spy).toHaveBeenCalledWith(
79-
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"bigint":"999999999999999999999"}}\n`
75+
expect(output[0]).toBe(
76+
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"bigint":"999999999999999999999"}}`
8077
)
8178
})
8279

8380
test('handles Maps', () => {
84-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
85-
86-
const logger = new Logger()
81+
const { logger, output } = createCaptureLogger()
8782
logger.log('info', 'test', { map: new Map([['test', 'map']]) })
8883

89-
expect(spy).toHaveBeenCalledWith(
90-
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"map":[["test","map"]]}}\n`
84+
expect(output[0]).toBe(
85+
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"map":[["test","map"]]}}`
9186
)
9287
})
9388

9489
test('handles Sets', () => {
95-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
96-
97-
const logger = new Logger()
90+
const { logger, output } = createCaptureLogger()
9891
logger.log('info', 'test', { set: new Set(['test']) })
9992

100-
expect(spy).toHaveBeenCalledWith(
101-
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"set":["test"]}}\n`
102-
)
93+
expect(output[0]).toBe(`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"set":["test"]}}`)
10394
})
10495

10596
interface dataError {
10697
data: {
10798
error: {
108-
message: string,
109-
name: string,
110-
stack: string[],
99+
message: string
100+
name: string
101+
stack: string[]
111102
}
112103
}
113104
}
114105

115106
test('handles Errors', () => {
116-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
117-
118-
const logger = new Logger()
107+
const { logger, output } = createCaptureLogger()
119108
logger.log('info', 'test', { error: new Error('Request timeout') })
120109

121-
expect(spy).toHaveBeenCalled()
122-
const log: dataError = JSON.parse(spy.mock.calls[0][0] as string) as dataError;
110+
expect(output).toHaveLength(1)
111+
const log: dataError = JSON.parse(output[0]) as dataError
123112
expect(log).toMatchObject({
124113
data: {
125114
error: {
@@ -135,13 +124,11 @@ test('handles Errors', () => {
135124
})
136125

137126
test('handles Errors at the top level', () => {
138-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
139-
140-
const logger = new Logger()
127+
const { logger, output } = createCaptureLogger()
141128
logger.log('info', 'test', new Error('Request timeout'))
142129

143-
expect(spy).toHaveBeenCalled()
144-
const log: dataError = JSON.parse(spy.mock.calls[0][0] as string) as dataError;
130+
expect(output).toHaveLength(1)
131+
const log: dataError = JSON.parse(output[0]) as dataError
145132
expect(log).toMatchObject({
146133
data: {
147134
message: 'Request timeout',
@@ -154,66 +141,51 @@ test('handles Errors at the top level', () => {
154141
})
155142

156143
class CustomError extends Error {
157-
serviceName?: string;
144+
serviceName?: string
158145
}
159146

160147
test('logs additional properties on Errors', () => {
161-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
162-
163-
const logger = new Logger()
148+
const { logger, output } = createCaptureLogger()
164149
const error: CustomError = new Error('Request timeout')
165150
error.serviceName = 'test'
166151
logger.log('info', 'test', { error })
167152

168-
expect(spy).toHaveBeenCalled()
169-
const log: dataError = JSON.parse(spy.mock.calls[0][0] as string) as dataError
153+
expect(output).toHaveLength(1)
154+
const log: dataError = JSON.parse(output[0]) as dataError
170155
expect(log).toHaveProperty('data.error.serviceName')
171156
})
172157

173158
test('devMode: can log a message', () => {
174-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
175-
176-
const logger = new Logger({ devMode: true })
159+
const { logger, output } = createCaptureLogger({ devMode: true })
177160
logger.log('info', 'test')
178161

179-
expect(spy).toHaveBeenCalled()
180-
expect(spy.mock.calls[0][0]).toMatchInlineSnapshot(`
162+
expect(output).toHaveLength(1)
163+
expect(output[0]).toMatchInlineSnapshot(`
181164
"
182-
INFO: test
183-
"
165+
INFO: test"
184166
`)
185167
})
186168

187169
test('info alias can log data', () => {
188-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
189-
190-
const logger = new Logger()
170+
const { logger, output } = createCaptureLogger()
191171
logger.info('test', { some: 'data' })
192172

193-
expect(spy).toHaveBeenCalledWith(
194-
`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"some":"data"}}\n`
195-
)
173+
expect(output[0]).toBe(`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"some":"data"}}`)
196174
})
197175

198176
test('error alias can log data', () => {
199-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
200-
201-
const logger = new Logger()
177+
const { logger, output } = createCaptureLogger()
202178
logger.error('test', { some: 'data' })
203179

204-
expect(spy).toHaveBeenCalledWith(
205-
`{"level":"ERROR","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"some":"data"}}\n`
206-
)
180+
expect(output[0]).toBe(`{"level":"ERROR","time":"2019-01-01T00:00:00.000Z","message":"test","data":{"some":"data"}}`)
207181
})
208182

209183
test('devMode: can log data', () => {
210-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
211-
212-
const logger = new Logger({ devMode: true })
184+
const { logger, output } = createCaptureLogger({ devMode: true })
213185
logger.log('info', 'test', { some: 'data', nested: { buffer: Buffer.alloc(2) } })
214186

215-
expect(spy).toHaveBeenCalled()
216-
expect(spy.mock.calls[0][0]).toMatchInlineSnapshot(`
187+
expect(output).toHaveLength(1)
188+
expect(output[0]).toMatchInlineSnapshot(`
217189
"
218190
INFO: test
219191
some: data
@@ -222,41 +194,95 @@ test('devMode: can log data', () => {
222194
type: Buffer
223195
data:
224196
- 0
225-
- 0
226-
"
197+
- 0"
227198
`)
228199
})
229200

230201
test('devMode: colors warn level yellow', () => {
231-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
232-
233-
const logger = new Logger({ devMode: true })
202+
const { logger, output } = createCaptureLogger({ devMode: true })
234203
logger.log('warn', 'test')
235204

236-
expect(spy).toHaveBeenCalled()
237-
expect(spy.mock.calls[0][0]).toMatchInlineSnapshot(`
205+
expect(output).toHaveLength(1)
206+
expect(output[0]).toMatchInlineSnapshot(`
238207
"
239-
WARN: test
240-
"
208+
WARN: test"
241209
`)
242210
})
243211

244212
test('devMode: colors error level red', () => {
245-
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
246-
247-
const logger = new Logger({ devMode: true })
213+
const { logger, output } = createCaptureLogger({ devMode: true })
248214
logger.log('error', 'test1')
249215
logger.log('crit', 'test2')
250216

251-
expect(spy).toBeCalledTimes(2)
252-
expect(spy.mock.calls[0][0]).toMatchInlineSnapshot(`
217+
expect(output).toHaveLength(2)
218+
expect(output[0]).toMatchInlineSnapshot(`
253219
"
254-
ERROR: test1
255-
"
220+
ERROR: test1"
256221
`)
257-
expect(spy.mock.calls[1][0]).toMatchInlineSnapshot(`
222+
expect(output[1]).toMatchInlineSnapshot(`
258223
"
259-
CRIT: test2
260-
"
224+
CRIT: test2"
261225
`)
262226
})
227+
228+
// Tests for the new formatLogLine pure function
229+
describe('formatLogLine', () => {
230+
test('formats a basic log line as JSON', () => {
231+
const logLine: LogLine = {
232+
level: 'INFO',
233+
time: '2019-01-01T00:00:00.000Z',
234+
message: 'test message',
235+
}
236+
237+
const result = formatLogLine(logLine, false)
238+
expect(result).toBe('{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test message"}')
239+
})
240+
241+
test('formats a log line with data as JSON', () => {
242+
const logLine: LogLine = {
243+
level: 'INFO',
244+
time: '2019-01-01T00:00:00.000Z',
245+
message: 'test message',
246+
data: { foo: 'bar' },
247+
}
248+
249+
const result = formatLogLine(logLine, false)
250+
expect(result).toBe(
251+
'{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test message","data":{"foo":"bar"}}'
252+
)
253+
})
254+
255+
test('formats a log line in dev mode', () => {
256+
const logLine: LogLine = {
257+
level: 'INFO',
258+
time: '2019-01-01T00:00:00.000Z',
259+
message: 'test message',
260+
}
261+
262+
const result = formatLogLine(logLine, true)
263+
expect(result).toContain('INFO: test message')
264+
})
265+
266+
test('handles BigInt in data', () => {
267+
const logLine: LogLine = {
268+
level: 'INFO',
269+
time: '2019-01-01T00:00:00.000Z',
270+
message: 'test',
271+
data: { bigint: BigInt('12345678901234567890') },
272+
}
273+
274+
const result = formatLogLine(logLine, false)
275+
expect(result).toContain('"bigint":"12345678901234567890"')
276+
})
277+
})
278+
279+
// Test that default writer still works (backwards compatibility)
280+
test('defaults to stdout when no writer provided', () => {
281+
const spy = jest.spyOn(process.stdout, 'write').mockImplementation()
282+
283+
const logger = new Logger()
284+
logger.log('info', 'test')
285+
286+
expect(spy).toHaveBeenCalledWith(`{"level":"INFO","time":"2019-01-01T00:00:00.000Z","message":"test"}\n`)
287+
spy.mockRestore()
288+
})

0 commit comments

Comments
 (0)