Log level incorrectly shows up as USERLVL when `useLevelLabels: true`

[tonyxiao]

I created pino with option useLevelLabels: true. When formatting via pino-pretty those log lines show up as

[2019-04-23 13:56:29.560 +0000] USERLVL (runScript): Request did succeed

The log line itself cpontains

{
  "level": "info",
  "time": 1556027789560,
  "name": "runScript",
  "msg": "Request did succeed",
  "v": 1
}

Given that useLevelLabels is a feature built into pino, pino-pretty should be able to understand their corresponding string based levels.

[jsumners]

1. That log line looks like it should be showing as INFO. Does your sample have a typo or did you find a bug?
2. It would be extraordinarily complex to make pino-pretty recognize any user defined levels in a pino instance. Pino custom levels are mutable and pino-pretty merely reads the stream pino writes to.

[tonyxiao]

I'm pretty certain it's a bug, see

$ echo '{ "level": "info", "time": 1556027789560, "name": "runScript", "msg": "Request did succeed", "v": 1 }' | ./node_modules/.bin/pino-pretty
[1556027789560] USERLVL (runScript): Request did succeed

$ cat yarn.lock | grep pino-pretty
pino-pretty@^2.6.0:
  resolved "https://registry.yarnpkg.com/pino-pretty/-/pino-pretty-2.6.0.tgz#05e69e5d458e8b304936e0097045c38c382e7c27"

[tonyxiao]

It would be extraordinarily complex to make pino-pretty recognize any user defined levels in a pino instance. Pino custom levels are mutable and pino-pretty merely reads the stream pino writes to.

Outside of the standard ones defined by pino, couldn't pino-pretty simply output the level as-is rather than displaying USERLVL?

[jsumners]

Ah, it is not a bug. pino-pretty 2.x does not support "level": "info". It only support levels as integers. So it's a conflict between pino configuration and what pino-pretty@2 supports. pino-pretty@next has you covered in this regard.

As for parroting the level, as hinted, the level can either be a string or a number. It would also be difficult to maintain the alignment for level labels. That being said, feel free to submit a PR against my plain-ndjson branch if you would like to see this behavior changed. It's going to be at least Sunday before I can close out that branch.

[tonyxiao]

Ah got it. Confirming pino-pretty@next works. It's worth noting that I installed pino not pino@next so it'd be great if pino-pretty can be synced with pino version wise.

maintain the alignment for level labels

What I'm saying is we don't need to maintain anything beyond the standard ones defined (10,20,30,40,50 + trace,debug,info,warn,error). The rest just display exactly as USERLVL today except instead of using the word USERLVL it would be as the level themselves.

[mcollina]

pino and pino-pretty have two separate versions, so their @next branch are not synced up anyway right now. The @next branch should be able to work with pino@5 and even pino@4 if I understand things correctly.

[jsumners]

What I'm saying is we don't need to maintain anything beyond the standard ones defined (10,20,30,40,50 + trace,debug,info,warn,error). The rest just display exactly as USERLVL today except instead of using the word USERLVL it would be as the level themselves.

Again, a PR is welcome.

@mcollina yes, the @next branch should work with input from pino@4 and pino@5. @next really removes the requirement that the ndjson be a Pino log line, but does a "best effort" format if it thinks the ndjson is a log line.

[faustbrian]

Is there currently any way to work around this? I am currently using the RFC5424 Syslog levels https://tools.ietf.org/html/rfc5424 for more granular logging and the ones that are not defined by pino itself in https://github.com/pinojs/pino-pretty/blob/master/lib/constants.js#L12-L20 just end up showing as USERLVL which is rather unfortunate.

const log = pino({
    base: null,
    customLevels: {
        emergency: 0,
        alert: 1,
        critical: 2,
        error: 3,
        warning: 4,
        notice: 5,
        info: 6,
        debug: 7,
    },
    level: "emergency",
    useLevelLabels: true,
    useOnlyCustomLevels: true,
    safe: true,
});

log.emergency("Hello World");
log.alert("Hello World");
log.critical("Hello World");
log.error("Hello World");
log.warning("Hello World");
log.notice("Hello World");
log.info("Hello World");
log.debug("Hello World");

[2019-09-02 02:45:57.300] USERLVL: Hello World
[2019-09-02 02:45:57.308] USERLVL: Hello World
[2019-09-02 02:45:57.309] USERLVL: Hello World
[2019-09-02 02:45:57.309] ERROR: Hello World
[2019-09-02 02:45:57.310] USERLVL: Hello World
[2019-09-02 02:45:57.310] USERLVL: Hello World
[2019-09-02 02:45:57.311] INFO : Hello World
[2019-09-02 02:45:57.311] DEBUG: Hello World

[jsumners]

No one has taken on the task of implementing this.

[faustbrian]

Would there be a preferred syntax for the implementation? I had something like the following in mind.

pretty({
    levelFirst: false,
    translateTime: "yyyy-mm-dd HH:MM:ss.l",
    customLevels: {
        default: 'USERLVL',
        0: {
            name: 'emergency',
            label: 'EMERGENCY',
            color: 'red'
        },
        1: {
            name: 'alert',
            label: 'ALERT',
            color: 'red'
        },
        2: {
            name: 'critical',
            label: 'CRITICAL',
            color: 'red'
        },
        3: {
            name: 'error',
            label: 'ERROR',
            color: 'red'
        },
        4: {
            name: 'warning',
            label: 'WARNING',
            color: 'red'
        },
        5: {
            name: 'notice',
            label: 'NOTICE',
            color: 'red'
        },
        6: {
            name: 'info',
            label: 'INFO',
            color: 'red'
        },
        7: {
            name: 'debug',
            label: 'DEBUG',
            color: 'red'
        },
    }
});

or maybe even just an array of objects { level, name, label, color }.

[mcollina]

I don't understand the role of the numbers as keys. What do pino option look like for the same example?

[faustbrian]

I just chose numbers in the examples because https://github.com/pinojs/pino-pretty/blob/master/lib/constants.js#L12-L20 uses numbers, for a nicer syntax I would use below code.

pretty({
    levelFirst: false,
    translateTime: "yyyy-mm-dd HH:MM:ss.l",
    customLevels: {
        default: 'USERLVL',
        emergency: {
            label: 'EMERGENCY',
            color: 'red' // this could be anything that chalk supports, i.e. red/bgRed/inverse/bold/etc.
        },
        alert: {
            label: 'ALERT',
            color: 'red'
        },
        critical: {
            label: 'CRITICAL',
            color: 'red'
        },
        error: {
            label: 'ERROR',
            color: 'red'
        },
        warning: {
            label: 'WARNING',
            color: 'red'
        },
        notice: {
            label: 'NOTICE',
            color: 'red'
        },
        info: {
            label: 'INFO',
            color: 'red'
        },
        debug: {
            label: 'DEBUG',
            color: 'red'
        },
    }
});

[mcollina]

I understand now. The syntax is https://github.com/pinojs/pino-pretty/issues/62#issuecomment-526986757 is ok, use the numbers.

[faustbrian]

I had a quick look at what kind of changes would be required to make this work, which seem to be quite a bit.

Currently all level & coloring related functionalities work based on the constants.LEVELS and constants.LEVEL_NAMES variables that are hardcoded in constants.js and colors.js. There are 2 approaches how I think this could be implemented.

1. Keep it very dummy and pass opts.customLevels to the colorizer methods which means a levels would need to be added to 2-3 methods.
2. Introduce a configuration object that holds all options and can be shared between files due to how the node.js require module cache works. This would leave everything in constants.js intact by only storing copies of the default levels in the new configuration object.

What approach would be preferred?

[jsumners]

I think it would be good to work with the author of #75 to determine how it could be done under that mechanism.

[jsumners]

@faustbrian I think option 2 sounds the best.

[casperle]

Hi guys, does somebody working on it?

[rstoermer]

Any news?

[mcollina]

Would you like to send a Pull Request to address this issue? Remember to add unit tests.

[55Cancri]

Sucks that after 3 years, custom log levels are still not supported in pino pretty

[kibertoad]

@55Cancri They've been waiting for your submission, clearly! Would you like to send a PR? https://github.com/pinojs/pino-pretty/pull/317 is not covering what you need?

[rodrigo-oleria]

Are there any news related to this.. Anyone able to get to show the log level correctly with pino-pretty?

[cckn]

@rodrigo-oleria I've successfully addressed a similar issue with Pino and pino-pretty by defining custom log levels. Here's the TypeScript code that worked for me:

const levels = {
  fatal: 60,
  error: 50,
  warn: 40,
  info: 30,
  custom: 26, // custom level 1
  ascii: 25, // custom level 2
  debug: 20,
  trace: 10,
}

export const logger = pino({
  level: process.env.LOG_LEVER || 'ascii',
  customLevels: levels,
  useOnlyCustomLevels: true,

  transport: {
    target: 'pino-pretty',
    options: {
      customLevels: 'custom:26,ascii:25',     // split by ','
      customColors: 'custom:cyan,ascii:gray', // split by ','
      useOnlyCustomProps: false,
    },
  },
})

While the lack of type safety in this configuration might be inconvenient, the infrequency of changes to the logger's setup makes this a manageable aspect for me.

The key was ensuring the custom levels and their colors were accurately defined and integrated into both Pino and the pino-pretty transport options. This setup has been effective in my use case.

[brainthinks]

K well I was just fighting with this for a while. I tried the approach from @cckn , but that resulted in all of the non-custom levels being pretty-printed as USERLVL, which is even worse than just my custom levels showing that. Here is how I fixed this issue for myself:

import { pino, type LoggerOptions, type Level } from 'pino';

type CustomLevels = Level | 'silly';

const customLevels = {
  ...pino.levels.values,
  silly: 1,
} as { [level in CustomLevels]: number };

const options: LoggerOptions<CustomLevels> = {
  customLevels,
  useOnlyCustomLevels: true,
  transport: {
    target: 'pino-pretty',
    options: {
      colorize: true,
      customLevels: Object.entries(customLevels).map(([ key, value ]) => (`${key}:${value}`)).join(','),
    },
  },
  level: 'silly',
};

const logger = pino<CustomLevels>(options);

// this displays the correct label and is correctly typed
logger.silly('test');

Hopefully this helps someone.