pinojs / pino

🌲 super fast, all natural json logger
http://getpino.io
MIT License
14.21k stars 875 forks source link

Multistream resets logLevel to 30, logging trace and debug is not possible #1617

Open LunaDotGit opened 1 year ago

LunaDotGit commented 1 year ago

Hi, I have encountered an issue with logging using a pino multistream. Using a multistream, somehow disables the info and trace method, as the minimum value is set to 30 (corresponding to info). Any pino options and minimum Level Option in the Stream are discarded. Creating individual loggers without a Multistream, works fine.

Reference as code:

import pino from 'pino'
import pretty from 'pino-pretty'
import fs from 'fs'

const logDir = `logs/bot`

if (!fs.existsSync(logDir)) {
    fs.mkdirSync(logDir)
}

const logger = pino({ level: 'trace' }, pino.multistream([
    pretty({
        destination: pino.destination(`$logDir}/logger.log`),
        colorize: false,
        levelFirst: true,
        translateTime: 'dd.mm.yyyy h:MM:ss TT',
        ignore: 'pid,hostname',
    }),
    pretty({
        colorize: true,
        levelFirst: true,
        translateTime: 'dd.mm.yyyy h:MM:ss TT',
        ignore: 'pid,hostname',
    })
])
)

const message = 'This is a test'
//These will work
logger.info(message)
logger.warn(message)
logger.error(message)
logger.fatal(message)

// These will not work
logger.trace(message)
logger.debug(message)

const loggerWithoutMultistream = pino({ level: 'trace' }, pretty({
    destination: pino.destination(`${logDir}/logger.log`),
    colorize: false,
    levelFirst: true,
    translateTime: 'dd.mm.yyyy h:MM:ss TT',
    ignore: 'pid,hostname',
}))

// These will now work
loggerWithoutMultistream.trace(message)
loggerWithoutMultistream.debug(message)

When printing the object, the Multistream seems to edit minLevel in each individual Stream to 30, and set the pino.levelVal to 30 as well.

jsumners commented 1 year ago

Have you consulted the documentation? https://getpino.io/#/docs/api?id=pino-multistream

LunaDotGit commented 1 year ago

Documentation says to set level on the lowest level, as done in the example

jsumners commented 1 year ago

Have you tried it without the pretty stream?

LunaDotGit commented 1 year ago

Yes and they also don't work. See:

import pino from 'pino'

const logger = pino({ level: 'trace' }, pino.multistream([
    { stream: process.stdout }
])
)

const message = 'TEST'
//These will work
logger.info(message)
logger.warn(message)
logger.error(message)
logger.fatal(message)

// These will not work
logger.trace(message)
logger.debug(message)

const message2 = 'HELLO'

const loggerWithoutMultistream = pino({ level: 'trace' }, process.stdout)

// These will now work
loggerWithoutMultistream.trace(message2)
loggerWithoutMultistream.debug(message2)
mcollina commented 1 year ago

You need to set a level on the multistream as well.

Cheprer commented 1 year ago

level option is not in the options for multistream. There are only levels and dedupe as per docs. https://getpino.io/#/docs/api?id=pino-multistream

I have tried the example in the docs and the debug log message didn't print out on stdout. Would be nice to have a test for this later on.

var pino = require('pino')
var multistream = pino.multistream
var streams = [
  {stream: process.stdout},
  {level: 'error', stream: process.stderr},
]

var opts = {
    levels: {
        silent: Infinity,
        fatal: 60,
        error: 50,
        warn: 50,
        info: 30,
        debug: 20,
        trace: 10
    },
    dedupe: true,
}

var log = pino({
  level: 'debug' // this MUST be set at the lowest level of the
                // destinations
}, multistream(streams, opts))

log.debug('this will be written ONLY to process.stdout')
log.info('this will be written ONLY to process.stdout')
log.error('this will be written ONLY to process.stderr')
log.fatal('this will be written ONLY to process.stderr')

I have played around with it a bit and solution is to set level to each stream in multistream. Also created the PR with fix. @TheAnimeGuru

It is said in the docs not so clearly just above this example:

"In order for multistream to work, the log level must be set to the lowest level used in the streams array."

So correct example is this:

var pino = require('pino')
var multistream = pino.multistream
var streams = [
  {level: 'debug', stream: process.stdout},
  {level: 'error', stream: process.stderr},
]

var opts = {
    levels: {
        silent: Infinity,
        fatal: 60,
        error: 50,
        warn: 50,
        info: 30,
        debug: 20,
        trace: 10
    },
    dedupe: true,
}

var log = pino({
  level: 'debug' // this MUST be set at the lowest level of the
                // destinations
}, multistream(streams, opts))

log.debug('this will be written ONLY to process.stdout')
log.info('this will be written ONLY to process.stdout')
log.error('this will be written ONLY to process.stderr')
log.fatal('this will be written ONLY to process.stderr')
Raynos commented 1 year ago

Ran into this issue myself too.

Confused why multistream([stream]) is the same as multistream([{ level: 'info', stream }])

Raynos commented 1 year ago

https://github.com/pinojs/pino/blob/master/lib/multistream.js#L112

Yeah the default level is 'info' and it cannot access or read the pino logger instance to get my level, could downgrade 'info' to 'debug' ; seems reasonable.

mcollina commented 1 year ago

@Raynos if you have any improvements to clarify this it would be awesome.