pino icon indicating copy to clipboard operation
pino copied to clipboard

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

Open LunaDotGit opened this issue 2 years ago • 9 comments

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.

LunaDotGit avatar Jan 04 '23 18:01 LunaDotGit

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

jsumners avatar Jan 04 '23 18:01 jsumners

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

LunaDotGit avatar Jan 04 '23 19:01 LunaDotGit

Have you tried it without the pretty stream?

jsumners avatar Jan 04 '23 19:01 jsumners

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)

LunaDotGit avatar Jan 04 '23 19:01 LunaDotGit

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

mcollina avatar Jan 05 '23 09:01 mcollina

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')

Cheprer avatar Feb 17 '23 14:02 Cheprer

Ran into this issue myself too.

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

Raynos avatar Apr 27 '23 17:04 Raynos

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.

Raynos avatar Apr 27 '23 17:04 Raynos

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

mcollina avatar Apr 27 '23 19:04 mcollina