Map log levels to StackDriver's severity

[m3co-code]

We have the requirement to use StackDriver's severity for our logs. That means the logs should contain a field severity with some integer value mapping to StackDriver's constants. Is there a canonical way to do this with pino? I couldn't figure out how to do it with the current API without using a custom serializer.

If not do you think it's interesting for more library users to build in hooks in order to modify the fields on a central place or can you think of something more usable?

[jsumners]

https://www.npmjs.com/package/pino-stackdriver

[m3co-code]

Thanks for the hint. That is not really helping us, though. For a bit of background: we're running GKE and log our logs according to Kubernetes/GKE standard way just to stdout. The heavy lifting is then done by Kubernetes and GKE. I'd like it to keep it that way and not switch internally to use StackDriver logging directly in some of our services. Therefore, it would still be great to have a mapping function to accomplish this and it could also be generic to serve more use-cases.

[pebo]

@marco-jantke did you solve this issue?

I tested pino in Google Cloud Run with the following options:

const logger = require('pino')(
    {
        customLevels: {
            debug: 100,
            info: 200,
            warn: 400,
            error: 500
        },
        base: null,
        messageKey: 'message',
        changeLevelName: 'severity',
        useOnlyCustomLevels: true,
        timestamp: false,
    }
)

The log entries was not picked up correctly. Are you sure that stack driver picks up severity as integers or do you need to use the string names instead? (https://cloud.google.com/run/docs/logging#container-logs).

The following format seems to work fine: {"severity":"INFO","message":"my message", "key1": "val1"}. Can pino be configured to output severity this way?

[m3co-code]

Hi @pebo, no I'm not really sure. I was following the documentation, but did not verify. It might be that I understood sth wrong, I'd more rely on your testings. Currently, we filter based on the JSON value of the severity field and not use the stackdriver native way. We didn't see a possibility to output the logs in the format you specified, that's why I opened the issue initially. Thanks for the collaboration!

[pebo]

It would be nice with an official solution, but here's a node module that outputs logs in a stackdriver friendly format.

'use strict'

// Logger mapping pino to stack driver format.
// See https://cloud.google.com/run/docs/logging.

const logger = require('pino')(
    {
        customLevels: {
            DEBUG: 100,
            INFO: 200,
            info: 201,
            WARNING: 400,
            ERROR: 500
        },
        base: null,
        messageKey: 'message',
        changeLevelName: 'severity',
        useOnlyCustomLevels: true,
        useLevelLabels: true,
        timestamp: false,
        level: process.env.LOG_LEVEL  || 'INFO'
    }
)

logger.debug = function(...args){
    this.DEBUG(...args);
}

logger.info = function(...args){
    this.INFO(...args);
}

logger.warn = function(...args){
    this.WARNING(...args);
}

logger.error = function(...args){
    this.ERROR(...args);
}

module.exports = {
   logger
}

Even if we define custom log levels it seems like a level info must be present. The solution above is far for perfect so any input on how to improve it would be greatly appreciated :)

[mcollina]

We have just landed support for the formatters #775. Would any of you check if they could improve things?

[pebo]

@mcollina Thanks for the update, this seems like a great feature!

With the level formatter we should be able to solve the level renaming issue and remove the need for wrapping pino.

The new log formatter could be useful for another scenario where we track http request trace ids (stored using cls-hooked). Currently we wrap pino to ge outputs like the example below:

{"severity":"WARNING","key":"some value","logging.googleapis.com/trace":"projects/a-project-id/traces/a-traceid","message":"A message","v":1}

If a request was made with the trace id header X-Cloud-Trace-Context: a-traceid, we add the key "logging.googleapis.com/trace" with the the value "projects/a-project-id/traces/a-traceid" but with the new features we should be able to solve this just using pino features.

Finally pino v6 will also allow us to drop the extra version field so this is looking really promising!

[pebo]

The formatters introduced in v6 works great with GCP / StackDriver logging. Example mapping:

// Map pino levels to GCP, https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#LogSeverity
function severity(label) {
  switch (label) {
    case 'trace': return 'DEBUG';
    case 'debug': return 'DEBUG';
    case 'info': return 'INFO';
    case 'warn': return 'WARNING';
    case 'error': return 'ERROR';
    case 'fatal': return 'CRITICAL';
    default: return 'DEFAULT';
  }
}

function level(label, number) {
  return { severity: severity(label)}
}

const logger = require('pino')(
  {
    formatters: {
      level
    },
    base: null,
    messageKey: 'message',
    timestamp: false,
    level: process.env.LOG_LEVEL ? process.env.LOG_LEVEL.toLowerCase() : 'info'
  }
)

[mcollina]

Would you mind to send us a a bit of docs related to this? It can also be a nice little module tbh.

[pebo]

Sure. Note that Google has recently rebranded Google Stackdriver Logs to Google Cloud Logging.

Not sure where the best documentation can be found but here's a starting point: https://cloud.google.com/run/docs/logging#writing_structured_logs

We are using pinojs in Cloud Run services so rather than logging via the Google Cloud logging API we simply write to stdout. The logs are picked up by the google infrastructure which adds some context like the service name, service version and a timestamp.

Google Cloud Logging supports structured logging so a pinojs api call likelog.warn({ key: 'helo warn'}, 'Warn with object') should result in the string {"severity":"WARNING","key":"helo warn","message":"Warn with object"}.

The level must be named severity and level values should be one of the values defined in the LogSeverity enum (https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#LogSeverity)

The message text payload should be named message. A config example: #726 (comment).

We are also using a traceId to connect log events belonging to the same HTTP request. The Google Cloud Run infrastructure will set a header X-Cloud-Trace-Context so we have a middleware parsing this header and storing it using cls-hooked. The traceId (if present) is then added to the log output using the formatter log function.

[metachris]

Just wanted to say thanks for this thread, this is a good solution for me too for running my services in the Google Cloud.

[jsumners]

Is there some action to be taken here? Or can we close this issue?

[metachris]

Since Google Cloud / StackDriver is pretty popular, I think it would be good to either add this solution to the documentation, or perhaps even provide a built-in way to use severity. 🤔

[jsumners]

PRs are welcome.

[rahulballal]

I have tried out almost all suggestions here. GKE plus Cloud Logging are not a happy bunch. Everything still shows up as info. I tried the level function to introduce the severity key. Even the severity key does not show up. Anything I log gets swallowed into the ‘jsonPaylod’ attribute. I am not sure what I am doing wrong. Official loggers and even ‘Pino-stackdriver’ requires a credential file which seems a bit much.

[mcollina]

A GDE friend pointed me to https://stackoverflow.com/questions/49283233/json-format-for-stackdriver-logging-in-google-kubernetes-engine.

[dgonzalez]

yes. That friend also says that there is something funky going on with StackDriver as I had a similar problem last week with a Cloud Function that logged warnings as info. I will ping the Google community and see what happens.

[rahulballal]

I finally got it working with the following setup. However, same setup did not seem to work with version 5.x but worked with 6.x version of pino. 🤷‍♂️

const pino = require('pino')

const SeverityLookup = {
  'default': 'DEFAULT',
  'silly': 'DEFAULT',
  'verbose': 'DEBUG',
  'debug': 'DEBUG',
  'http': 'notice',
  'info': 'INFO',
  'warn': 'WARNING',
  'error': 'ERROR',
}

const defaultPinoConfig = {
    messageKey: 'message',
    formatters: {
        level(label, number) {
            return { severity: SeverityLookup[label], level: number }
        },
    }
}

module.exports = (pinoConfigOverrides = {}) => pino(Object.assign({}, defaultPinoConfig, pinoConfigOverrides))

[mcollina]

pino v5 does not support the formatters.m option.

Could you send a PR to add this to our docs? Thanks!

[rahulballal]

@mcollina Is the FAQ page the right place for such documentation ? Sorry for the stupid question. I am happy to send a PR

[mcollina]

Yeah, the FAQ is totally the correct place.

[naseemkullah]

Thanks @rahulballal, @pebo and everybody.

[guillenotfound]

Just a quick note, when logging an object it won't work, add log formatter like below:

const productionPinoConfig: pino.LoggerOptions = {
  prettyPrint: false,
  formatters: {
    level(label: string, number: number) {
      return {
        severity: PinoLevelToSeverityLookup[label] || PinoLevelToSeverityLookup['info'],
        level: number,
      }
    },
    log(payload: any) {
      return { message: payload }
    },
  },
}

[jsumners]

Would you like to send a PR to update the documentation?

[guillenotfound]

There you go: #878

[naseemkullah]

FWIW I've requested that GCP provide a plugin for pino as to offload the config to the plugin, posting in this closed issue as I think it would interest folks in this thread: googleapis/nodejs-logging#875

[github-actions]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.