Aktueller Stand

This commit is contained in:
2026-01-22 19:05:45 +01:00
parent 85dee61a4d
commit e280e4eadb
1967 changed files with 397327 additions and 74093 deletions

View File

@@ -4,7 +4,7 @@ const stream = require('node:stream')
const os = require('node:os')
const fs = require('node:fs')
const t = require('tap')
const t = require('node:test')
const split = require('split2')
const { streamSym } = require('pino/lib/symbols')
@@ -14,10 +14,9 @@ const helper = require('../helper')
const { FST_ERR_LOG_INVALID_LOGGER } = require('../../lib/errors')
const { once, on } = stream
const { createTempFile, request } = require('./logger-test-utils')
const { partialDeepStrictEqual } = require('../toolkit')
t.test('logger instantiation', (t) => {
t.setTimeout(60000)
t.test('logger instantiation', { timeout: 60000 }, async (t) => {
let localhost
let localhostForURL
@@ -26,19 +25,19 @@ t.test('logger instantiation', (t) => {
[localhost, localhostForURL] = await helper.getLoopbackHost()
})
t.test('can use external logger instance', async (t) => {
await t.test('can use external logger instance', async (t) => {
const lines = [/^Server listening at /, /^incoming request$/, /^log success$/, /^request completed$/]
t.plan(lines.length + 1)
const stream = split(JSON.parse)
const logger = require('pino')(stream)
const loggerInstance = require('pino')(stream)
const fastify = Fastify({ logger })
t.teardown(fastify.close.bind(fastify))
const fastify = Fastify({ loggerInstance })
t.after(() => fastify.close())
fastify.get('/foo', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
req.log.info('log success')
reply.send({ hello: 'world' })
})
@@ -49,30 +48,30 @@ t.test('logger instantiation', (t) => {
for await (const [line] of on(stream, 'data')) {
const regex = lines.shift()
t.ok(regex.test(line.msg), '"' + line.msg + '" does not match "' + regex + '"')
t.assert.ok(regex.test(line.msg), '"' + line.msg + '" does not match "' + regex + '"')
if (lines.length === 0) break
}
})
t.test('should create a default logger if provided one is invalid', (t) => {
await t.test('should create a default logger if provided one is invalid', (t) => {
t.plan(8)
const logger = new Date()
const fastify = Fastify({ logger })
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
t.equal(typeof fastify.log, 'object')
t.equal(typeof fastify.log.fatal, 'function')
t.equal(typeof fastify.log.error, 'function')
t.equal(typeof fastify.log.warn, 'function')
t.equal(typeof fastify.log.info, 'function')
t.equal(typeof fastify.log.debug, 'function')
t.equal(typeof fastify.log.trace, 'function')
t.equal(typeof fastify.log.child, 'function')
t.assert.strictEqual(typeof fastify.log, 'object')
t.assert.strictEqual(typeof fastify.log.fatal, 'function')
t.assert.strictEqual(typeof fastify.log.error, 'function')
t.assert.strictEqual(typeof fastify.log.warn, 'function')
t.assert.strictEqual(typeof fastify.log.info, 'function')
t.assert.strictEqual(typeof fastify.log.debug, 'function')
t.assert.strictEqual(typeof fastify.log.trace, 'function')
t.assert.strictEqual(typeof fastify.log.child, 'function')
})
t.test('expose the logger', async (t) => {
await t.test('expose the logger', async (t) => {
t.plan(2)
const stream = split(JSON.parse)
const fastify = Fastify({
@@ -81,49 +80,45 @@ t.test('logger instantiation', (t) => {
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
await fastify.ready()
t.ok(fastify.log)
t.same(typeof fastify.log, 'object')
t.assert.ok(fastify.log)
t.assert.strictEqual(typeof fastify.log, 'object')
})
t.test('Wrap IPv6 address in listening log message', async (t) => {
const interfaces = os.networkInterfaces()
const ipv6 = Object.keys(interfaces)
.filter(name => name.substr(0, 2) === 'lo')
.map(name => interfaces[name])
.reduce((list, set) => list.concat(set), [])
.filter(info => info.family === 'IPv6')
.map(info => info.address)
.shift()
await t.test('Wrap IPv6 address in listening log message', { skip: !ipv6 }, async (t) => {
t.plan(1)
const interfaces = os.networkInterfaces()
const ipv6 = Object.keys(interfaces)
.filter(name => name.substr(0, 2) === 'lo')
.map(name => interfaces[name])
.reduce((list, set) => list.concat(set), [])
.filter(info => info.family === 'IPv6')
.map(info => info.address)
.shift()
if (ipv6 === undefined) {
t.pass('No IPv6 loopback interface')
} else {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
stream,
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
await fastify.ready()
await fastify.listen({ port: 0, host: ipv6 })
{
const [line] = await once(stream, 'data')
t.same(line.msg, `Server listening at http://[${ipv6}]:${fastify.server.address().port}`)
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
stream,
level: 'info'
}
})
t.after(() => fastify.close())
await fastify.ready()
await fastify.listen({ port: 0, host: ipv6 })
{
const [line] = await once(stream, 'data')
t.assert.strictEqual(line.msg, `Server listening at http://[${ipv6}]:${fastify.server.address().port}`)
}
})
t.test('Do not wrap IPv4 address', async (t) => {
await t.test('Do not wrap IPv4 address', async (t) => {
t.plan(1)
const stream = split(JSON.parse)
const fastify = Fastify({
@@ -132,24 +127,18 @@ t.test('logger instantiation', (t) => {
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
await fastify.ready()
await fastify.listen({ port: 0, host: '127.0.0.1' })
{
const [line] = await once(stream, 'data')
t.same(line.msg, `Server listening at http://127.0.0.1:${fastify.server.address().port}`)
t.assert.strictEqual(line.msg, `Server listening at http://127.0.0.1:${fastify.server.address().port}`)
}
})
t.test('file option', async (t) => {
const lines = [
{ msg: /Server listening at/ },
{ reqId: /req-/, req: { method: 'GET', url: '/' }, msg: 'incoming request' },
{ reqId: /req-/, res: { statusCode: 200 }, msg: 'request completed' }
]
await t.test('file option', async (t) => {
const { file, cleanup } = createTempFile(t)
// 0600 permissions (read/write for owner only)
if (process.env.CITGM) { fs.writeFileSync(file, '', { mode: 0o600 }) }
@@ -158,7 +147,7 @@ t.test('logger instantiation', (t) => {
logger: { file }
})
t.teardown(async () => {
t.after(async () => {
await helper.sleep(250)
// may fail on win
try {
@@ -174,15 +163,20 @@ t.test('logger instantiation', (t) => {
console.warn(err)
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
reply.send({ hello: 'world' })
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: `Server listening at ${server}` },
{ req: { method: 'GET', url: '/' }, msg: 'incoming request' },
{ res: { statusCode: 200 }, msg: 'request completed' }
]
await request(`http://${localhostForURL}:` + fastify.server.address().port)
await helper.sleep(250)
@@ -195,26 +189,26 @@ t.test('logger instantiation', (t) => {
for (let line of log) {
line = JSON.parse(line)
if (id === undefined && line.reqId) id = line.reqId
if (id !== undefined && line.reqId) t.equal(line.reqId, id)
t.match(line, lines.shift())
if (id !== undefined && line.reqId) t.assert.strictEqual(line.reqId, id)
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
}
})
t.test('should be able to use a custom logger', (t) => {
await t.test('should be able to use a custom logger', (t) => {
t.plan(7)
const logger = {
fatal: (msg) => { t.equal(msg, 'fatal') },
error: (msg) => { t.equal(msg, 'error') },
warn: (msg) => { t.equal(msg, 'warn') },
info: (msg) => { t.equal(msg, 'info') },
debug: (msg) => { t.equal(msg, 'debug') },
trace: (msg) => { t.equal(msg, 'trace') },
child: () => logger
const loggerInstance = {
fatal: (msg) => { t.assert.strictEqual(msg, 'fatal') },
error: (msg) => { t.assert.strictEqual(msg, 'error') },
warn: (msg) => { t.assert.strictEqual(msg, 'warn') },
info: (msg) => { t.assert.strictEqual(msg, 'info') },
debug: (msg) => { t.assert.strictEqual(msg, 'debug') },
trace: (msg) => { t.assert.strictEqual(msg, 'trace') },
child: () => loggerInstance
}
const fastify = Fastify({ logger })
t.teardown(fastify.close.bind(fastify))
const fastify = Fastify({ loggerInstance })
t.after(() => fastify.close())
fastify.log.fatal('fatal')
fastify.log.error('error')
@@ -223,17 +217,17 @@ t.test('logger instantiation', (t) => {
fastify.log.debug('debug')
fastify.log.trace('trace')
const child = fastify.log.child()
t.equal(child, logger)
t.assert.strictEqual(child, loggerInstance)
})
t.test('should throw in case a partially matching logger is provided', async (t) => {
await t.test('should throw in case a partially matching logger is provided', async (t) => {
t.plan(1)
try {
const fastify = Fastify({ logger: console })
await fastify.ready()
} catch (err) {
t.equal(
t.assert.strictEqual(
err instanceof FST_ERR_LOG_INVALID_LOGGER,
true,
"Invalid logger object provided. The logger instance should have these functions(s): 'fatal,child'."
@@ -241,12 +235,12 @@ t.test('logger instantiation', (t) => {
}
})
t.test('can use external logger instance with custom serializer', async (t) => {
await t.test('can use external logger instance with custom serializer', async (t) => {
const lines = [['level', 30], ['req', { url: '/foo' }], ['level', 30], ['res', { statusCode: 200 }]]
t.plan(lines.length + 1)
const stream = split(JSON.parse)
const logger = require('pino')({
const loggerInstance = require('pino')({
level: 'info',
serializers: {
req: function (req) {
@@ -258,12 +252,12 @@ t.test('logger instantiation', (t) => {
}, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/foo', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
req.log.info('log success')
reply.send({ hello: 'world' })
})
@@ -277,20 +271,12 @@ t.test('logger instantiation', (t) => {
const check = lines.shift()
const key = check[0]
const value = check[1]
t.same(line[key], value)
t.assert.deepStrictEqual(line[key], value)
if (lines.length === 0) break
}
})
t.test('The logger should accept custom serializer', async (t) => {
const lines = [
{ msg: /^Server listening at / },
{ req: { url: '/custom' }, msg: 'incoming request' },
{ res: { statusCode: 500 }, msg: 'kaboom' },
{ res: { statusCode: 500 }, msg: 'request completed' }
]
t.plan(lines.length + 1)
await t.test('The logger should accept custom serializer', async (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
@@ -305,25 +291,32 @@ t.test('logger instantiation', (t) => {
}
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/custom', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
reply.send(new Error('kaboom'))
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: `Server listening at ${server}` },
{ req: { url: '/custom' }, msg: 'incoming request' },
{ res: { statusCode: 500 }, msg: 'kaboom' },
{ res: { statusCode: 500 }, msg: 'request completed' }
]
t.plan(lines.length + 1)
await request(`http://${localhostForURL}:` + fastify.server.address().port + '/custom')
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('should throw in case the external logger provided does not have a child method', async (t) => {
await t.test('should throw in case the external logger provided does not have a child method', async (t) => {
t.plan(1)
const loggerInstance = {
info: console.info,
@@ -338,7 +331,7 @@ t.test('logger instantiation', (t) => {
const fastify = Fastify({ logger: loggerInstance })
await fastify.ready()
} catch (err) {
t.equal(
t.assert.strictEqual(
err instanceof FST_ERR_LOG_INVALID_LOGGER,
true,
"Invalid logger object provided. The logger instance should have these functions(s): 'child'."

View File

@@ -2,7 +2,7 @@
const stream = require('node:stream')
const t = require('tap')
const t = require('node:test')
const split = require('split2')
const pino = require('pino')
@@ -10,53 +10,45 @@ const Fastify = require('../../fastify')
const helper = require('../helper')
const { once, on } = stream
const { request } = require('./logger-test-utils')
const { partialDeepStrictEqual } = require('../toolkit')
t.test('logging', (t) => {
t.setTimeout(60000)
t.test('logging', { timeout: 60000 }, async (t) => {
let localhost
let localhostForURL
t.plan(13)
t.plan(14)
t.before(async function () {
[localhost, localhostForURL] = await helper.getLoopbackHost()
})
t.test('The default 404 handler logs the incoming request', async (t) => {
await t.test('The default 404 handler logs the incoming request', async (t) => {
const lines = ['incoming request', 'Route GET:/not-found not found', 'request completed']
t.plan(lines.length + 1)
const stream = split(JSON.parse)
const logger = pino({ level: 'trace' }, stream)
const loggerInstance = pino({ level: 'trace' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
await fastify.ready()
{
const response = await fastify.inject({ method: 'GET', url: '/not-found' })
t.equal(response.statusCode, 404)
t.assert.strictEqual(response.statusCode, 404)
}
for await (const [line] of on(stream, 'data')) {
t.equal(line.msg, lines.shift())
t.assert.strictEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('should not rely on raw request to log errors', async (t) => {
const lines = [
{ msg: /Server listening at/ },
{ level: 30, msg: 'incoming request' },
{ res: { statusCode: 415 }, msg: 'something happened' },
{ res: { statusCode: 415 }, msg: 'request completed' }
]
t.plan(lines.length + 1)
await t.test('should not rely on raw request to log errors', async (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
@@ -64,32 +56,64 @@ t.test('logging', (t) => {
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/error', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
reply.status(415).send(new Error('something happened'))
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: `Server listening at ${server}` },
{ level: 30, msg: 'incoming request' },
{ res: { statusCode: 415 }, msg: 'something happened' },
{ res: { statusCode: 415 }, msg: 'request completed' }
]
t.plan(lines.length + 1)
await request(`http://${localhostForURL}:` + fastify.server.address().port + '/error')
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('should log the error if no error handler is defined', async (t) => {
await t.test('should log the error if no error handler is defined', async (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
stream,
level: 'info'
}
})
t.after(() => fastify.close())
fastify.get('/error', function (req, reply) {
t.assert.ok(req.log)
reply.send(new Error('a generic error'))
})
await fastify.ready()
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: /Server listening at/ },
{ msg: `Server listening at ${server}` },
{ msg: 'incoming request' },
{ level: 50, msg: 'a generic error' },
{ res: { statusCode: 500 }, msg: 'request completed' }
]
t.plan(lines.length + 1)
await request(`http://${localhostForURL}:` + fastify.server.address().port + '/error')
for await (const [line] of on(stream, 'data')) {
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
await t.test('should log as info if error status code >= 400 and < 500 if no error handler is defined', async (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
@@ -97,32 +121,36 @@ t.test('logging', (t) => {
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/error', function (req, reply) {
t.ok(req.log)
reply.send(new Error('a generic error'))
fastify.get('/400', function (req, reply) {
t.assert.ok(req.log)
reply.send(Object.assign(new Error('a 400 error'), { statusCode: 400 }))
})
fastify.get('/503', function (req, reply) {
t.assert.ok(req.log)
reply.send(Object.assign(new Error('a 503 error'), { statusCode: 503 }))
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
await request(`http://${localhostForURL}:` + fastify.server.address().port + '/error')
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
if (lines.length === 0) break
}
})
t.test('should log as info if error status code >= 400 and < 500 if no error handler is defined', async (t) => {
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: /Server listening at/ },
{ msg: `Server listening at ${server}` },
{ msg: 'incoming request' },
{ level: 30, msg: 'a 400 error' },
{ res: { statusCode: 400 }, msg: 'request completed' }
]
t.plan(lines.length + 1)
await request(`http://${localhostForURL}:` + fastify.server.address().port + '/400')
for await (const [line] of on(stream, 'data')) {
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
await t.test('should log as error if error status code >= 500 if no error handler is defined', async (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
@@ -130,67 +158,31 @@ t.test('logging', (t) => {
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
fastify.get('/400', function (req, reply) {
t.ok(req.log)
reply.send(Object.assign(new Error('a 400 error'), { statusCode: 400 }))
})
t.after(() => fastify.close())
fastify.get('/503', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
reply.send(Object.assign(new Error('a 503 error'), { statusCode: 503 }))
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
await request(`http://${localhostForURL}:` + fastify.server.address().port + '/400')
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
if (lines.length === 0) break
}
})
t.test('should log as error if error status code >= 500 if no error handler is defined', async (t) => {
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: /Server listening at/ },
{ msg: `Server listening at ${server}` },
{ msg: 'incoming request' },
{ level: 50, msg: 'a 503 error' },
{ res: { statusCode: 503 }, msg: 'request completed' }
]
t.plan(lines.length + 1)
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
stream,
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
fastify.get('/503', function (req, reply) {
t.ok(req.log)
reply.send(Object.assign(new Error('a 503 error'), { statusCode: 503 }))
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
await request(`http://${localhostForURL}:` + fastify.server.address().port + '/503')
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('should not log the error if error handler is defined and it does not error', async (t) => {
const lines = [
{ msg: /Server listening at/ },
{ level: 30, msg: 'incoming request' },
{ res: { statusCode: 200 }, msg: 'request completed' }
]
t.plan(lines.length + 2)
await t.test('should not log the error if error handler is defined and it does not error', async (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
@@ -198,28 +190,34 @@ t.test('logging', (t) => {
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/error', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
reply.send(new Error('something happened'))
})
fastify.setErrorHandler((err, req, reply) => {
t.ok(err)
t.assert.ok(err)
reply.send('something bad happened')
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: `Server listening at ${server}` },
{ level: 30, msg: 'incoming request' },
{ res: { statusCode: 200 }, msg: 'request completed' }
]
t.plan(lines.length + 2)
await request(`http://${localhostForURL}:` + fastify.server.address().port + '/error')
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('reply.send logs an error if called twice in a row', async (t) => {
await t.test('reply.send logs an error if called twice in a row', async (t) => {
const lines = [
'incoming request',
'request completed',
@@ -229,12 +227,12 @@ t.test('logging', (t) => {
t.plan(lines.length + 1)
const stream = split(JSON.parse)
const logger = pino(stream)
const loggerInstance = pino(stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', (req, reply) => {
reply.send({ hello: 'world' })
@@ -244,19 +242,19 @@ t.test('logging', (t) => {
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.ok(partialDeepStrictEqual(body, { hello: 'world' }))
for await (const [line] of on(stream, 'data')) {
t.same(line.msg, lines.shift())
t.assert.strictEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('should not log incoming request and outgoing response when disabled', async (t) => {
await t.test('should not log incoming request and outgoing response when disabled', async (t) => {
t.plan(1)
const stream = split(JSON.parse)
const fastify = Fastify({ disableRequestLogging: true, logger: { level: 'info', stream } })
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/500', (req, reply) => {
reply.code(500).send(Error('500 error'))
@@ -267,27 +265,64 @@ t.test('logging', (t) => {
await fastify.inject({ method: 'GET', url: '/500' })
// no more readable data
t.equal(stream.readableLength, 0)
t.assert.strictEqual(stream.readableLength, 0)
})
t.test('should not log incoming request, outgoing response and route not found for 404 onBadUrl when disabled', async (t) => {
await t.test('should not log incoming request, outgoing response and route not found for 404 onBadUrl when disabled', async (t) => {
t.plan(1)
const stream = split(JSON.parse)
const fastify = Fastify({ disableRequestLogging: true, logger: { level: 'info', stream } })
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
await fastify.ready()
await fastify.inject({ method: 'GET', url: '/%c0' })
// no more readable data
t.equal(stream.readableLength, 0)
t.assert.strictEqual(stream.readableLength, 0)
})
t.test('defaults to info level', async (t) => {
await t.test('should log incoming request and outgoing response based on disableRequestLogging function', async (t) => {
const lines = [
{ reqId: /req-/, req: { method: 'GET' }, msg: 'incoming request' },
{ reqId: /req-/, res: { statusCode: 200 }, msg: 'request completed' }
'incoming request',
'request completed'
]
t.plan(lines.length)
const stream = split(JSON.parse)
const loggerInstance = pino(stream)
const fastify = Fastify({
disableRequestLogging: (request) => {
return request.url !== '/not-logged'
},
loggerInstance
})
t.after(() => fastify.close())
fastify.get('/logged', (req, reply) => {
return reply.code(200).send({})
})
fastify.get('/not-logged', (req, reply) => {
return reply.code(200).send({})
})
await fastify.ready()
await fastify.inject({ method: 'GET', url: '/not-logged' })
await fastify.inject({ method: 'GET', url: '/logged' })
for await (const [line] of on(stream, 'data')) {
t.assert.strictEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
await t.test('defaults to info level', async (t) => {
const lines = [
{ req: { method: 'GET' }, msg: 'incoming request' },
{ res: { statusCode: 200 }, msg: 'request completed' }
]
t.plan(lines.length * 2 + 1)
const stream = split(JSON.parse)
@@ -296,10 +331,10 @@ t.test('logging', (t) => {
stream
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
reply.send({ hello: 'world' })
})
@@ -313,20 +348,13 @@ t.test('logging', (t) => {
// we skip the non-request log
if (typeof line.reqId !== 'string') continue
if (id === undefined && line.reqId) id = line.reqId
if (id !== undefined && line.reqId) t.equal(line.reqId, id)
t.match(line, lines.shift())
if (id !== undefined && line.reqId) t.assert.strictEqual(line.reqId, id)
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('test log stream', async (t) => {
const lines = [
{ msg: /^Server listening at / },
{ reqId: /req-/, req: { method: 'GET' }, msg: 'incoming request' },
{ reqId: /req-/, res: { statusCode: 200 }, msg: 'request completed' }
]
t.plan(lines.length + 3)
await t.test('test log stream', async (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
@@ -334,36 +362,34 @@ t.test('logging', (t) => {
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
reply.send({ hello: 'world' })
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: `Server listening at ${server}` },
{ req: { method: 'GET' }, msg: 'incoming request' },
{ res: { statusCode: 200 }, msg: 'request completed' }
]
t.plan(lines.length + 3)
await request(`http://${localhostForURL}:` + fastify.server.address().port)
let id
for await (const [line] of on(stream, 'data')) {
if (id === undefined && line.reqId) id = line.reqId
if (id !== undefined && line.reqId) t.equal(line.reqId, id)
t.match(line, lines.shift())
if (id !== undefined && line.reqId) t.assert.strictEqual(line.reqId, id)
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('test error log stream', async (t) => {
const lines = [
{ msg: /^Server listening at / },
{ reqId: /req-/, req: { method: 'GET' }, msg: 'incoming request' },
{ reqId: /req-/, res: { statusCode: 500 }, msg: 'kaboom' },
{ reqId: /req-/, res: { statusCode: 500 }, msg: 'request completed' }
]
t.plan(lines.length + 4)
await t.test('test error log stream', async (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
@@ -371,28 +397,35 @@ t.test('logging', (t) => {
level: 'info'
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/error', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
reply.send(new Error('kaboom'))
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: `Server listening at ${server}` },
{ req: { method: 'GET' }, msg: 'incoming request' },
{ res: { statusCode: 500 }, msg: 'kaboom' },
{ res: { statusCode: 500 }, msg: 'request completed' }
]
t.plan(lines.length + 4)
await request(`http://${localhostForURL}:` + fastify.server.address().port + '/error')
let id
for await (const [line] of on(stream, 'data')) {
if (id === undefined && line.reqId) id = line.reqId
if (id !== undefined && line.reqId) t.equal(line.reqId, id)
t.match(line, lines.shift())
if (id !== undefined && line.reqId) t.assert.strictEqual(line.reqId, id)
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('should not log the error if request logging is disabled', async (t) => {
await t.test('should not log the error if request logging is disabled', async (t) => {
t.plan(4)
const stream = split(JSON.parse)
@@ -403,10 +436,10 @@ t.test('logging', (t) => {
},
disableRequestLogging: true
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/error', function (req, reply) {
t.ok(req.log)
t.assert.ok(req.log)
reply.send(new Error('a generic error'))
})
@@ -417,11 +450,11 @@ t.test('logging', (t) => {
{
const [line] = await once(stream, 'data')
t.type(line.msg, 'string')
t.ok(line.msg.startsWith('Server listening at'), 'message is set')
t.assert.ok(typeof line.msg === 'string')
t.assert.ok(line.msg.startsWith('Server listening at'), 'message is set')
}
// no more readable data
t.equal(stream.readableLength, 0)
t.assert.strictEqual(stream.readableLength, 0)
})
})

View File

@@ -2,58 +2,56 @@
const stream = require('node:stream')
const t = require('tap')
const t = require('node:test')
const split = require('split2')
const pino = require('pino')
const Fastify = require('../../fastify')
const { on } = stream
t.test('logger options', (t) => {
t.setTimeout(60000)
t.test('logger options', { timeout: 60000 }, async (t) => {
t.plan(16)
t.plan(12)
t.test('logger can be silenced', (t) => {
await t.test('logger can be silenced', (t) => {
t.plan(17)
const fastify = Fastify({
logger: false
})
t.teardown(fastify.close.bind(fastify))
t.ok(fastify.log)
t.equal(typeof fastify.log, 'object')
t.equal(typeof fastify.log.fatal, 'function')
t.equal(typeof fastify.log.error, 'function')
t.equal(typeof fastify.log.warn, 'function')
t.equal(typeof fastify.log.info, 'function')
t.equal(typeof fastify.log.debug, 'function')
t.equal(typeof fastify.log.trace, 'function')
t.equal(typeof fastify.log.child, 'function')
t.after(() => fastify.close())
t.assert.ok(fastify.log)
t.assert.deepEqual(typeof fastify.log, 'object')
t.assert.deepEqual(typeof fastify.log.fatal, 'function')
t.assert.deepEqual(typeof fastify.log.error, 'function')
t.assert.deepEqual(typeof fastify.log.warn, 'function')
t.assert.deepEqual(typeof fastify.log.info, 'function')
t.assert.deepEqual(typeof fastify.log.debug, 'function')
t.assert.deepEqual(typeof fastify.log.trace, 'function')
t.assert.deepEqual(typeof fastify.log.child, 'function')
const childLog = fastify.log.child()
t.equal(typeof childLog, 'object')
t.equal(typeof childLog.fatal, 'function')
t.equal(typeof childLog.error, 'function')
t.equal(typeof childLog.warn, 'function')
t.equal(typeof childLog.info, 'function')
t.equal(typeof childLog.debug, 'function')
t.equal(typeof childLog.trace, 'function')
t.equal(typeof childLog.child, 'function')
t.assert.deepEqual(typeof childLog, 'object')
t.assert.deepEqual(typeof childLog.fatal, 'function')
t.assert.deepEqual(typeof childLog.error, 'function')
t.assert.deepEqual(typeof childLog.warn, 'function')
t.assert.deepEqual(typeof childLog.info, 'function')
t.assert.deepEqual(typeof childLog.debug, 'function')
t.assert.deepEqual(typeof childLog.trace, 'function')
t.assert.deepEqual(typeof childLog.child, 'function')
})
t.test('Should set a custom logLevel for a plugin', async (t) => {
await t.test('Should set a custom logLevel for a plugin', async (t) => {
const lines = ['incoming request', 'Hello', 'request completed']
t.plan(lines.length + 2)
const stream = split(JSON.parse)
const logger = pino({ level: 'error' }, stream)
const loggerInstance = pino({ level: 'error' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', (req, reply) => {
req.log.info('Not Exist') // we should not see this log
@@ -73,33 +71,33 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body.hello, 'world')
}
{
const response = await fastify.inject({ method: 'GET', url: '/plugin' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body.hello, 'world')
}
for await (const [line] of on(stream, 'data')) {
t.same(line.msg, lines.shift())
t.assert.deepEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('Should set a custom logSerializers for a plugin', async (t) => {
await t.test('Should set a custom logSerializers for a plugin', async (t) => {
const lines = ['incoming request', 'XHello', 'request completed']
t.plan(lines.length + 1)
const stream = split(JSON.parse)
const logger = pino({ level: 'error' }, stream)
const loggerInstance = pino({ level: 'error' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.register(function (instance, opts, done) {
instance.get('/plugin', (req, reply) => {
@@ -114,28 +112,28 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/plugin' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body.hello, 'world')
}
for await (const [line] of on(stream, 'data')) {
// either test or msg
t.equal(line.test || line.msg, lines.shift())
t.assert.deepEqual(line.test || line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('Should set a custom logLevel for every plugin', async (t) => {
await t.test('Should set a custom logLevel for every plugin', async (t) => {
const lines = ['incoming request', 'info', 'request completed', 'incoming request', 'debug', 'request completed']
t.plan(lines.length * 2 + 3)
const stream = split(JSON.parse)
const logger = pino({ level: 'error' }, stream)
const loggerInstance = pino({ level: 'error' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', (req, reply) => {
req.log.warn('Hello') // we should not see this log
@@ -165,39 +163,39 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
{
const response = await fastify.inject({ method: 'GET', url: '/info' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
{
const response = await fastify.inject({ method: 'GET', url: '/debug' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
for await (const [line] of on(stream, 'data')) {
t.ok(line.level === 30 || line.level === 20)
t.equal(line.msg, lines.shift())
t.assert.ok(line.level === 30 || line.level === 20)
t.assert.deepEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('Should set a custom logSerializers for every plugin', async (t) => {
await t.test('Should set a custom logSerializers for every plugin', async (t) => {
const lines = ['incoming request', 'Hello', 'request completed', 'incoming request', 'XHello', 'request completed', 'incoming request', 'ZHello', 'request completed']
t.plan(lines.length + 3)
const stream = split(JSON.parse)
const logger = pino({ level: 'info' }, stream)
const loggerInstance = pino({ level: 'info' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', (req, reply) => {
req.log.warn({ test: 'Hello' })
@@ -225,38 +223,38 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
{
const response = await fastify.inject({ method: 'GET', url: '/test1' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
{
const response = await fastify.inject({ method: 'GET', url: '/test2' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
for await (const [line] of on(stream, 'data')) {
t.equal(line.test || line.msg, lines.shift())
t.assert.deepEqual(line.test || line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('Should override serializers from route', async (t) => {
await t.test('Should override serializers from route', async (t) => {
const lines = ['incoming request', 'ZHello', 'request completed']
t.plan(lines.length + 1)
const stream = split(JSON.parse)
const logger = pino({ level: 'info' }, stream)
const loggerInstance = pino({ level: 'info' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.register(function (instance, opts, done) {
instance.get('/', {
@@ -275,26 +273,26 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
for await (const [line] of on(stream, 'data')) {
t.equal(line.test || line.msg, lines.shift())
t.assert.deepEqual(line.test || line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('Should override serializers from plugin', async (t) => {
await t.test('Should override serializers from plugin', async (t) => {
const lines = ['incoming request', 'ZHello', 'request completed']
t.plan(lines.length + 1)
const stream = split(JSON.parse)
const logger = pino({ level: 'info' }, stream)
const loggerInstance = pino({ level: 'info' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.register(function (instance, opts, done) {
instance.register(context1, {
@@ -318,27 +316,27 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
for await (const [line] of on(stream, 'data')) {
t.equal(line.test || line.msg, lines.shift())
t.assert.deepEqual(line.test || line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('Should increase the log level for a specific plugin', async (t) => {
await t.test('Should increase the log level for a specific plugin', async (t) => {
const lines = ['Hello']
t.plan(lines.length * 2 + 1)
const stream = split(JSON.parse)
const logger = pino({ level: 'info' }, stream)
const loggerInstance = pino({ level: 'info' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.register(function (instance, opts, done) {
instance.get('/', (req, reply) => {
@@ -353,28 +351,28 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
for await (const [line] of on(stream, 'data')) {
t.equal(line.level, 50)
t.equal(line.msg, lines.shift())
t.assert.deepEqual(line.level, 50)
t.assert.deepEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('Should set the log level for the customized 404 handler', async (t) => {
await t.test('Should set the log level for the customized 404 handler', async (t) => {
const lines = ['Hello']
t.plan(lines.length * 2 + 1)
const stream = split(JSON.parse)
const logger = pino({ level: 'warn' }, stream)
const loggerInstance = pino({ level: 'warn' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.register(function (instance, opts, done) {
instance.setNotFoundHandler(function (req, reply) {
@@ -388,28 +386,28 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
t.equal(response.statusCode, 404)
t.assert.deepEqual(response.statusCode, 404)
}
for await (const [line] of on(stream, 'data')) {
t.equal(line.level, 50)
t.equal(line.msg, lines.shift())
t.assert.deepEqual(line.level, 50)
t.assert.deepEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('Should set the log level for the customized 500 handler', async (t) => {
await t.test('Should set the log level for the customized 500 handler', async (t) => {
const lines = ['Hello']
t.plan(lines.length * 2 + 1)
const stream = split(JSON.parse)
const logger = pino({ level: 'warn' }, stream)
const loggerInstance = pino({ level: 'warn' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.register(function (instance, opts, done) {
instance.get('/', (req, reply) => {
@@ -428,28 +426,28 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
t.equal(response.statusCode, 500)
t.assert.deepEqual(response.statusCode, 500)
}
for await (const [line] of on(stream, 'data')) {
t.equal(line.level, 60)
t.equal(line.msg, lines.shift())
t.assert.deepEqual(line.level, 60)
t.assert.deepEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('Should set a custom log level for a specific route', async (t) => {
await t.test('Should set a custom log level for a specific route', async (t) => {
const lines = ['incoming request', 'Hello', 'request completed']
t.plan(lines.length + 2)
const stream = split(JSON.parse)
const logger = pino({ level: 'error' }, stream)
const loggerInstance = pino({ level: 'error' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/log', { logLevel: 'info' }, (req, reply) => {
req.log.info('Hello')
@@ -466,35 +464,116 @@ t.test('logger options', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/log' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
{
const response = await fastify.inject({ method: 'GET', url: '/no-log' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepEqual(body, { hello: 'world' })
}
for await (const [line] of on(stream, 'data')) {
t.equal(line.msg, lines.shift())
t.assert.deepEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
t.test('should pass when using unWritable props in the logger option', (t) => {
await t.test('should pass when using unWritable props in the logger option', (t) => {
t.plan(8)
const fastify = Fastify({
logger: Object.defineProperty({}, 'level', { value: 'info' })
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
t.equal(typeof fastify.log, 'object')
t.equal(typeof fastify.log.fatal, 'function')
t.equal(typeof fastify.log.error, 'function')
t.equal(typeof fastify.log.warn, 'function')
t.equal(typeof fastify.log.info, 'function')
t.equal(typeof fastify.log.debug, 'function')
t.equal(typeof fastify.log.trace, 'function')
t.equal(typeof fastify.log.child, 'function')
t.assert.deepEqual(typeof fastify.log, 'object')
t.assert.deepEqual(typeof fastify.log.fatal, 'function')
t.assert.deepEqual(typeof fastify.log.error, 'function')
t.assert.deepEqual(typeof fastify.log.warn, 'function')
t.assert.deepEqual(typeof fastify.log.info, 'function')
t.assert.deepEqual(typeof fastify.log.debug, 'function')
t.assert.deepEqual(typeof fastify.log.trace, 'function')
t.assert.deepEqual(typeof fastify.log.child, 'function')
})
await t.test('Should throw an error if logger instance is passed to `logger`', async (t) => {
t.plan(2)
const stream = split(JSON.parse)
const logger = require('pino')(stream)
try {
Fastify({ logger })
} catch (err) {
t.assert.ok(err)
t.assert.deepEqual(err.code, 'FST_ERR_LOG_INVALID_LOGGER_CONFIG')
}
})
await t.test('Should throw an error if options are passed to `loggerInstance`', async (t) => {
t.plan(2)
try {
Fastify({ loggerInstance: { level: 'log' } })
} catch (err) {
t.assert.ok(err)
t.assert.strictEqual(err.code, 'FST_ERR_LOG_INVALID_LOGGER_INSTANCE')
}
})
await t.test('If both `loggerInstance` and `logger` are provided, an error should be thrown', async (t) => {
t.plan(2)
const loggerInstanceStream = split(JSON.parse)
const loggerInstance = pino({ level: 'error' }, loggerInstanceStream)
const loggerStream = split(JSON.parse)
try {
Fastify({
logger: {
stream: loggerStream,
level: 'info'
},
loggerInstance
})
} catch (err) {
t.assert.ok(err)
t.assert.deepEqual(err.code, 'FST_ERR_LOG_LOGGER_AND_LOGGER_INSTANCE_PROVIDED')
}
})
await t.test('`logger` should take pino configuration and create a pino logger', async (t) => {
const lines = ['hello', 'world']
t.plan(2 * lines.length + 2)
const loggerStream = split(JSON.parse)
const fastify = Fastify({
logger: {
stream: loggerStream,
level: 'error'
}
})
t.after(() => fastify.close())
fastify.get('/hello', (req, reply) => {
req.log.error('hello')
reply.code(404).send()
})
fastify.get('/world', (req, reply) => {
req.log.error('world')
reply.code(201).send()
})
await fastify.ready()
{
const response = await fastify.inject({ method: 'GET', url: '/hello' })
t.assert.deepEqual(response.statusCode, 404)
}
{
const response = await fastify.inject({ method: 'GET', url: '/world' })
t.assert.deepEqual(response.statusCode, 201)
}
for await (const [line] of on(loggerStream, 'data')) {
t.assert.deepEqual(line.level, 50)
t.assert.deepEqual(line.msg, lines.shift())
if (lines.length === 0) break
}
})
})

View File

@@ -2,17 +2,16 @@
const stream = require('node:stream')
const t = require('tap')
const t = require('node:test')
const split = require('split2')
const Fastify = require('../../fastify')
const helper = require('../helper')
const { on } = stream
const { request } = require('./logger-test-utils')
const { partialDeepStrictEqual } = require('../toolkit')
t.test('request', (t) => {
t.setTimeout(60000)
t.test('request', { timeout: 60000 }, async (t) => {
let localhost
t.plan(7)
@@ -20,7 +19,7 @@ t.test('request', (t) => {
[localhost] = await helper.getLoopbackHost()
})
t.test('The request id header key can be customized', async (t) => {
await t.test('The request id header key can be customized', async (t) => {
const lines = ['incoming request', 'some log message', 'request completed']
t.plan(lines.length * 2 + 2)
const REQUEST_ID = '42'
@@ -30,26 +29,26 @@ t.test('request', (t) => {
logger: { stream, level: 'info' },
requestIdHeader: 'my-custom-request-id'
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', (req, reply) => {
t.equal(req.id, REQUEST_ID)
t.assert.strictEqual(req.id, REQUEST_ID)
req.log.info('some log message')
reply.send({ id: req.id })
})
const response = await fastify.inject({ method: 'GET', url: '/', headers: { 'my-custom-request-id': REQUEST_ID } })
const body = await response.json()
t.equal(body.id, REQUEST_ID)
t.assert.strictEqual(body.id, REQUEST_ID)
for await (const [line] of on(stream, 'data')) {
t.equal(line.reqId, REQUEST_ID)
t.equal(line.msg, lines.shift(), 'message is set')
t.assert.strictEqual(line.reqId, REQUEST_ID)
t.assert.strictEqual(line.msg, lines.shift(), 'message is set')
if (lines.length === 0) break
}
})
t.test('The request id header key can be ignored', async (t) => {
await t.test('The request id header key can be ignored', async (t) => {
const lines = ['incoming request', 'some log message', 'request completed']
t.plan(lines.length * 2 + 2)
const REQUEST_ID = 'ignore-me'
@@ -59,33 +58,33 @@ t.test('request', (t) => {
logger: { stream, level: 'info' },
requestIdHeader: false
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', (req, reply) => {
t.equal(req.id, 'req-1')
t.assert.strictEqual(req.id, 'req-1')
req.log.info('some log message')
reply.send({ id: req.id })
})
const response = await fastify.inject({ method: 'GET', url: '/', headers: { 'request-id': REQUEST_ID } })
const body = await response.json()
t.equal(body.id, 'req-1')
t.assert.strictEqual(body.id, 'req-1')
for await (const [line] of on(stream, 'data')) {
t.equal(line.reqId, 'req-1')
t.equal(line.msg, lines.shift(), 'message is set')
t.assert.strictEqual(line.reqId, 'req-1')
t.assert.strictEqual(line.msg, lines.shift(), 'message is set')
if (lines.length === 0) break
}
})
t.test('The request id header key can be customized along with a custom id generator', async (t) => {
await t.test('The request id header key can be customized along with a custom id generator', async (t) => {
const REQUEST_ID = '42'
const matches = [
{ reqId: REQUEST_ID, msg: /incoming request/ },
{ reqId: REQUEST_ID, msg: /some log message/ },
{ reqId: REQUEST_ID, msg: /request completed/ },
{ reqId: 'foo', msg: /incoming request/ },
{ reqId: 'foo', msg: /some log message 2/ },
{ reqId: 'foo', msg: /request completed/ }
{ reqId: REQUEST_ID, msg: 'incoming request' },
{ reqId: REQUEST_ID, msg: 'some log message' },
{ reqId: REQUEST_ID, msg: 'request completed' },
{ reqId: 'foo', msg: 'incoming request' },
{ reqId: 'foo', msg: 'some log message 2' },
{ reqId: 'foo', msg: 'request completed' }
]
t.plan(matches.length + 4)
@@ -97,16 +96,16 @@ t.test('request', (t) => {
return 'foo'
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/one', (req, reply) => {
t.equal(req.id, REQUEST_ID)
t.assert.strictEqual(req.id, REQUEST_ID)
req.log.info('some log message')
reply.send({ id: req.id })
})
fastify.get('/two', (req, reply) => {
t.equal(req.id, 'foo')
t.assert.strictEqual(req.id, 'foo')
req.log.info('some log message 2')
reply.send({ id: req.id })
})
@@ -114,30 +113,30 @@ t.test('request', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/one', headers: { 'my-custom-request-id': REQUEST_ID } })
const body = await response.json()
t.equal(body.id, REQUEST_ID)
t.assert.strictEqual(body.id, REQUEST_ID)
}
{
const response = await fastify.inject({ method: 'GET', url: '/two' })
const body = await response.json()
t.equal(body.id, 'foo')
t.assert.strictEqual(body.id, 'foo')
}
for await (const [line] of on(stream, 'data')) {
t.match(line, matches.shift())
t.assert.ok(partialDeepStrictEqual(line, matches.shift()))
if (matches.length === 0) break
}
})
t.test('The request id header key can be ignored along with a custom id generator', async (t) => {
await t.test('The request id header key can be ignored along with a custom id generator', async (t) => {
const REQUEST_ID = 'ignore-me'
const matches = [
{ reqId: 'foo', msg: /incoming request/ },
{ reqId: 'foo', msg: /some log message/ },
{ reqId: 'foo', msg: /request completed/ },
{ reqId: 'foo', msg: /incoming request/ },
{ reqId: 'foo', msg: /some log message 2/ },
{ reqId: 'foo', msg: /request completed/ }
{ reqId: 'foo', msg: 'incoming request' },
{ reqId: 'foo', msg: 'some log message' },
{ reqId: 'foo', msg: 'request completed' },
{ reqId: 'foo', msg: 'incoming request' },
{ reqId: 'foo', msg: 'some log message 2' },
{ reqId: 'foo', msg: 'request completed' }
]
t.plan(matches.length + 4)
@@ -149,16 +148,16 @@ t.test('request', (t) => {
return 'foo'
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/one', (req, reply) => {
t.equal(req.id, 'foo')
t.assert.strictEqual(req.id, 'foo')
req.log.info('some log message')
reply.send({ id: req.id })
})
fastify.get('/two', (req, reply) => {
t.equal(req.id, 'foo')
t.assert.strictEqual(req.id, 'foo')
req.log.info('some log message 2')
reply.send({ id: req.id })
})
@@ -166,27 +165,27 @@ t.test('request', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/one', headers: { 'request-id': REQUEST_ID } })
const body = await response.json()
t.equal(body.id, 'foo')
t.assert.strictEqual(body.id, 'foo')
}
{
const response = await fastify.inject({ method: 'GET', url: '/two' })
const body = await response.json()
t.equal(body.id, 'foo')
t.assert.strictEqual(body.id, 'foo')
}
for await (const [line] of on(stream, 'data')) {
t.match(line, matches.shift())
t.assert.ok(partialDeepStrictEqual(line, matches.shift()))
if (matches.length === 0) break
}
})
t.test('The request id log label can be changed', async (t) => {
await t.test('The request id log label can be changed', async (t) => {
const REQUEST_ID = '42'
const matches = [
{ traceId: REQUEST_ID, msg: /incoming request/ },
{ traceId: REQUEST_ID, msg: /some log message/ },
{ traceId: REQUEST_ID, msg: /request completed/ }
{ traceId: REQUEST_ID, msg: 'incoming request' },
{ traceId: REQUEST_ID, msg: 'some log message' },
{ traceId: REQUEST_ID, msg: 'request completed' }
]
t.plan(matches.length + 2)
@@ -196,10 +195,10 @@ t.test('request', (t) => {
requestIdHeader: 'my-custom-request-id',
requestIdLogLabel: 'traceId'
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/one', (req, reply) => {
t.equal(req.id, REQUEST_ID)
t.assert.strictEqual(req.id, REQUEST_ID)
req.log.info('some log message')
reply.send({ id: req.id })
})
@@ -207,22 +206,16 @@ t.test('request', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/one', headers: { 'my-custom-request-id': REQUEST_ID } })
const body = await response.json()
t.equal(body.id, REQUEST_ID)
t.assert.strictEqual(body.id, REQUEST_ID)
}
for await (const [line] of on(stream, 'data')) {
t.match(line, matches.shift())
t.assert.ok(partialDeepStrictEqual(line, matches.shift()))
if (matches.length === 0) break
}
})
t.test('should redact the authorization header if so specified', async (t) => {
const lines = [
{ msg: /Server listening at/ },
{ req: { headers: { authorization: '[Redacted]' } }, msg: 'incoming request' },
{ res: { statusCode: 200 }, msg: 'request completed' }
]
t.plan(lines.length + 3)
await t.test('should redact the authorization header if so specified', async (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({
logger: {
@@ -243,15 +236,22 @@ t.test('request', (t) => {
}
}
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', function (req, reply) {
t.same(req.headers.authorization, 'Bearer abcde')
t.assert.deepStrictEqual(req.headers.authorization, 'Bearer abcde')
reply.send({ hello: 'world' })
})
await fastify.ready()
await fastify.listen({ port: 0, host: localhost })
const server = await fastify.listen({ port: 0, host: localhost })
const lines = [
{ msg: `Server listening at ${server}` },
{ req: { headers: { authorization: '[Redacted]' } }, msg: 'incoming request' },
{ res: { statusCode: 200 }, msg: 'request completed' }
]
t.plan(lines.length + 3)
await request({
method: 'GET',
@@ -262,17 +262,17 @@ t.test('request', (t) => {
authorization: 'Bearer abcde'
}
}, function (response, body) {
t.equal(response.statusCode, 200)
t.same(body, JSON.stringify({ hello: 'world' }))
t.assert.strictEqual(response.statusCode, 200)
t.assert.deepStrictEqual(body, JSON.stringify({ hello: 'world' }))
})
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('should not throw error when serializing custom req', (t) => {
await t.test('should not throw error when serializing custom req', (t) => {
t.plan(1)
const lines = []
@@ -283,10 +283,10 @@ t.test('request', (t) => {
}
})
const fastify = Fastify({ logger: { level: 'info', stream: dest } })
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.log.info({ req: {} })
t.same(lines[0].req, {})
t.assert.deepStrictEqual(lines[0].req, {})
})
})

View File

@@ -2,19 +2,18 @@
const stream = require('node:stream')
const t = require('tap')
const t = require('node:test')
const split = require('split2')
const pino = require('pino')
const Fastify = require('../../fastify')
const { partialDeepStrictEqual } = require('../toolkit')
const { on } = stream
t.test('response serialization', (t) => {
t.setTimeout(60000)
t.test('response serialization', { timeout: 60000 }, async (t) => {
t.plan(4)
t.test('Should use serializers from plugin and route', async (t) => {
await t.test('Should use serializers from plugin and route', async (t) => {
const lines = [
{ msg: 'incoming request' },
{ test: 'XHello', test2: 'ZHello' },
@@ -24,11 +23,11 @@ t.test('response serialization', (t) => {
const stream = split(JSON.parse)
const logger = pino({ level: 'info' }, stream)
const loggerInstance = pino({ level: 'info' }, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.register(context1, {
logSerializers: { test: value => 'X' + value }
@@ -51,16 +50,16 @@ t.test('response serialization', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepStrictEqual(body, { hello: 'world' })
}
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('Should use serializers from instance fastify and route', async (t) => {
await t.test('Should use serializers from instance fastify and route', async (t) => {
const lines = [
{ msg: 'incoming request' },
{ test: 'XHello', test2: 'ZHello' },
@@ -70,7 +69,7 @@ t.test('response serialization', (t) => {
const stream = split(JSON.parse)
const logger = pino({
const loggerInstance = pino({
level: 'info',
serializers: {
test: value => 'X' + value,
@@ -78,9 +77,9 @@ t.test('response serialization', (t) => {
}
}, stream)
const fastify = Fastify({
logger
loggerInstance
})
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/', {
logSerializers: {
@@ -96,16 +95,16 @@ t.test('response serialization', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepStrictEqual(body, { hello: 'world' })
}
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('Should use serializers inherit from contexts', async (t) => {
await t.test('Should use serializers inherit from contexts', async (t) => {
const lines = [
{ msg: 'incoming request' },
{ test: 'XHello', test2: 'YHello', test3: 'ZHello' },
@@ -115,15 +114,15 @@ t.test('response serialization', (t) => {
const stream = split(JSON.parse)
const logger = pino({
const loggerInstance = pino({
level: 'info',
serializers: {
test: value => 'X' + value
}
}, stream)
const fastify = Fastify({ logger })
t.teardown(fastify.close.bind(fastify))
const fastify = Fastify({ loggerInstance })
t.after(() => fastify.close())
fastify.register(context1, { logSerializers: { test2: value => 'Y' + value } })
@@ -144,16 +143,16 @@ t.test('response serialization', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/' })
const body = await response.json()
t.same(body, { hello: 'world' })
t.assert.deepStrictEqual(body, { hello: 'world' })
}
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})
t.test('should serialize request and response', async (t) => {
await t.test('should serialize request and response', async (t) => {
const lines = [
{ req: { method: 'GET', url: '/500' }, msg: 'incoming request' },
{ req: { method: 'GET', url: '/500' }, msg: '500 error' },
@@ -163,7 +162,7 @@ t.test('response serialization', (t) => {
const stream = split(JSON.parse)
const fastify = Fastify({ logger: { level: 'info', stream } })
t.teardown(fastify.close.bind(fastify))
t.after(() => fastify.close())
fastify.get('/500', (req, reply) => {
reply.code(500).send(Error('500 error'))
@@ -173,11 +172,11 @@ t.test('response serialization', (t) => {
{
const response = await fastify.inject({ method: 'GET', url: '/500' })
t.equal(response.statusCode, 500)
t.assert.strictEqual(response.statusCode, 500)
}
for await (const [line] of on(stream, 'data')) {
t.match(line, lines.shift())
t.assert.ok(partialDeepStrictEqual(line, lines.shift()))
if (lines.length === 0) break
}
})