Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: browser respect child logger log level #1725

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
149 changes: 106 additions & 43 deletions browser.js
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,38 @@ const stdSerializers = {
err: asErrValue,
errWithCause: asErrValue
}
function levelToValue (level, logger) {
return level === 'silent'
? Infinity
: logger.levels.values[level]
}
const baseLogFunctionSymbol = Symbol('pino.logFuncs')
const hierarchySymbol = Symbol('pino.hierarchy')

const logFallbackMap = {
error: 'log',
fatal: 'error',
warn: 'error',
info: 'log',
debug: 'log',
trace: 'log'
}

function appendChildLogger (parentLogger, childLogger) {
const newEntry = {
logger: childLogger,
parent: parentLogger[hierarchySymbol]
}
childLogger[hierarchySymbol] = newEntry
}

function setupBaseLogFunctions (logger, levels, proto) {
const logFunctions = {}
levels.forEach(level => {
logFunctions[level] = proto[level] ? proto[level] : (_console[level] || _console[logFallbackMap[level] ?? 'log'] || noop)
})
logger[baseLogFunctionSymbol] = logFunctions
}

function shouldSerialize (serialize, serializers) {
if (Array.isArray(serialize)) {
Expand Down Expand Up @@ -61,6 +93,10 @@ function pino (opts) {
const logger = Object.create(proto)
if (!logger.log) logger.log = noop

setupBaseLogFunctions(logger, levels, proto)
// setup root hierarchy entry
appendChildLogger({}, logger)

Object.defineProperty(logger, 'levelVal', {
get: getLevelVal
})
Expand Down Expand Up @@ -94,9 +130,7 @@ function pino (opts) {
if (transmit) logger._logEvent = createLogEventShape()

function getLevelVal () {
return this.level === 'silent'
? Infinity
: this.levels.values[this.level]
return levelToValue(this.level, this)
}

function getLevel () {
Expand All @@ -108,15 +142,15 @@ function pino (opts) {
}
this._level = level

set(setOpts, logger, 'error', 'log') // <-- must stay first
set(setOpts, logger, 'fatal', 'error')
set(setOpts, logger, 'warn', 'error')
set(setOpts, logger, 'info', 'log')
set(setOpts, logger, 'debug', 'log')
set(setOpts, logger, 'trace', 'log')
set(this, setOpts, logger, 'error') // <-- must stay first
set(this, setOpts, logger, 'fatal')
set(this, setOpts, logger, 'warn')
set(this, setOpts, logger, 'info')
set(this, setOpts, logger, 'debug')
set(this, setOpts, logger, 'trace')

customLevels.forEach(function (level) {
set(setOpts, logger, level, 'log')
customLevels.forEach((level) => {
set(this, setOpts, logger, level)
})
}

Expand All @@ -139,12 +173,10 @@ function pino (opts) {
}
function Child (parent) {
this._childLevel = (parent._childLevel | 0) + 1
this.error = bind(parent, bindings, 'error')
this.fatal = bind(parent, bindings, 'fatal')
this.warn = bind(parent, bindings, 'warn')
this.info = bind(parent, bindings, 'info')
this.debug = bind(parent, bindings, 'debug')
this.trace = bind(parent, bindings, 'trace')

// make sure bindings are available in the `set` function
this.bindings = bindings

if (childSerializers) {
this.serializers = childSerializers
this._serialize = childSerialize
Expand All @@ -156,7 +188,14 @@ function pino (opts) {
}
}
Child.prototype = this
return new Child(this)
const newLogger = new Child(this)

// must happen before the level is assigned
appendChildLogger(this, newLogger)
// required to actually initialize the logger functions for any given child
newLogger.level = this.level

return newLogger
}
return logger
}
Expand Down Expand Up @@ -203,19 +242,54 @@ pino.levels = {
pino.stdSerializers = stdSerializers
pino.stdTimeFunctions = Object.assign({}, { nullTime, epochTime, unixTime, isoTime })

function set (opts, logger, level, fallback) {
const proto = Object.getPrototypeOf(logger)
logger[level] = logger.levelVal > logger.levels.values[level]
function getBindingChain (logger) {
const bindings = []
if (logger.bindings) {
bindings.push(logger.bindings)
}

// traverse up the tree to get all bindings
let hierarchy = logger[hierarchySymbol]
while (hierarchy.parent) {
hierarchy = hierarchy.parent
if (hierarchy.logger.bindings) {
bindings.push(hierarchy.logger.bindings)
}
}

return bindings.reverse()
}

function set (self, opts, rootLogger, level) {
// override the current log functions with either `noop` or the base log function
self[level] = levelToValue(self.level, rootLogger) > levelToValue(level, rootLogger)
? noop
: (proto[level] ? proto[level] : (_console[level] || _console[fallback] || noop))
: rootLogger[baseLogFunctionSymbol][level]

wrap(opts, logger, level)
if (!opts.transmit && self[level] === noop) {
return
}

// make sure the log format is correct
self[level] = createWrap(self, opts, rootLogger, level)

// prepend bindings if it is not the root logger
const bindings = getBindingChain(self)
if (bindings.length === 0) {
// early exit in case for rootLogger
return
}
self[level] = prependBindingsInArguments(bindings, self[level])
}

function wrap (opts, logger, level) {
if (!opts.transmit && logger[level] === noop) return
function prependBindingsInArguments (bindings, logFunc) {
return function () {
return logFunc.apply(this, [...bindings, ...arguments])
}
}

logger[level] = (function (write) {
function createWrap (self, opts, rootLogger, level) {
return (function (write) {
return function LOG () {
const ts = opts.timestamp()
const args = new Array(arguments.length)
Expand All @@ -229,22 +303,22 @@ function wrap (opts, logger, level) {
else write.apply(proto, args)

if (opts.transmit) {
const transmitLevel = opts.transmit.level || logger.level
const transmitValue = logger.levels.values[transmitLevel]
const methodValue = logger.levels.values[level]
const transmitLevel = opts.transmit.level || self._level
const transmitValue = rootLogger.levels.values[transmitLevel]
const methodValue = rootLogger.levels.values[level]
if (methodValue < transmitValue) return
transmit(this, {
ts,
methodLevel: level,
methodValue,
transmitLevel,
transmitValue: logger.levels.values[opts.transmit.level || logger.level],
transmitValue: rootLogger.levels.values[opts.transmit.level || self._level],
send: opts.transmit.send,
val: logger.levelVal
val: levelToValue(self._level, rootLogger)
}, args)
}
}
})(logger[level])
})(self[baseLogFunctionSymbol][level])
}

function asObject (logger, level, args, ts) {
Expand Down Expand Up @@ -283,17 +357,6 @@ function applySerializers (args, serialize, serializers, stdErrSerialize) {
}
}

function bind (parent, bindings, level) {
return function () {
const args = new Array(1 + arguments.length)
args[0] = bindings
for (var i = 1; i < args.length; i++) {
args[i] = arguments[i - 1]
}
return parent[level].apply(this, args)
}
}

function transmit (logger, opts, args) {
const send = opts.send
const ts = opts.ts
Expand Down
106 changes: 106 additions & 0 deletions test/browser-child.test.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,106 @@
'use strict'
const test = require('tape')
const pino = require('../browser')

test('child has parent level', ({ end, same, is }) => {
const instance = pino({
level: 'error',
browser: {}
})

const child = instance.child({})

same(child.level, instance.level)
end()
})

test('changing child level does not affect parent', ({ end, same, is }) => {
const instance = pino({
level: 'error',
browser: {}
})

const child = instance.child({})
child.level = 'info'

same(instance.level, 'error')
end()
})

test('child should log, if its own level allows it', ({ end, same, is }) => {
const expected = [
{
level: 30,
msg: 'this is info'
},
{
level: 40,
msg: 'this is warn'
},
{
level: 50,
msg: 'this is an error'
}
]
const instance = pino({
level: 'error',
browser: {
write (actual) {
checkLogObjects(is, same, actual, expected.shift())
}
}
})

const child = instance.child({})
child.level = 'info'

child.debug('this is debug')
child.info('this is info')
child.warn('this is warn')
child.error('this is an error')

same(expected.length, 0, 'not all messages were read')
end()
})

test('changing child log level should not affect parent log behavior', ({ end, same, is }) => {
const expected = [
{
level: 50,
msg: 'this is an error'
},
{
level: 60,
msg: 'this is fatal'
}
]
const instance = pino({
level: 'error',
browser: {
write (actual) {
checkLogObjects(is, same, actual, expected.shift())
}
}
})

const child = instance.child({})
child.level = 'info'

instance.warn('this is warn')
instance.error('this is an error')
instance.fatal('this is fatal')

same(expected.length, 0, 'not all messages were read')
end()
})

function checkLogObjects (is, same, actual, expected) {
is(actual.time <= Date.now(), true, 'time is greater than Date.now()')

const actualCopy = Object.assign({}, actual)
const expectedCopy = Object.assign({}, expected)
delete actualCopy.time
delete expectedCopy.time

same(actualCopy, expectedCopy)
}