pino: CPU Hang with infinite decirc

Hello,

I experienced downtime from pino logger. A developer accidentally logged an express req in pino, and on catch It made our api hang with full CPU.

Here a small exemple of the expressjs middleware used :

import { NextFunction, Request, Response } from 'express'
import pino from 'pino'

export const webhook = (
  req: Request,
  res: Response,
  next: NextFunction,
) => {
  const logger = pino({
    name: 'test',
    prettyPrint: {
      colorize: true,
      translateTime: true,
      messageFormat: '{hostname} - {pid} - {msg}',
      ignore: 'hostname,pid',
    },
  })

  logger.error({ req })
}

Node version : 12.9.0 Typescript : 4.1.3 Pino : 6.11.2 Pino-pretty : 4.7.1 Express : 4.17.1

Here is a profiler trace Capture d’écran 2021-03-24 à 13 51 32

About this issue

Original URL
State: closed
Created 3 years ago
Comments: 25 (20 by maintainers)

Most upvoted comments

I had to change the default depth and edge limit in fast-safe-stringify because it broke folks. I’m going to send a PR to set them in pino instead.

mcollina on Sep 8, 2021

I would be ok in adding an option to fast-safe-stringify.

mcollina on Apr 14, 2021

can you open a PR?

mcollina on Apr 14, 2021

I did a quick investigation of this and posting the result here.

the popular safe-json-stringify has the same issue as fast-safe-stringify
@bugsnag/safe-json-stringify, a fork of the above which includes a hard limit on object depth/breadth, handles it properly
a plain JSON.stringify with a simple replacer that handles cycles works fine

Based on this, it looks like the issue seems to be related to the deeply nested nature of the prism object that’s being logged. I’m not sure why the popular safe-json-stringify and @davidmarkclements 's fast-safe-stringify are not handling this properly, considering that a replacer which handles cycles and makes this work is a few lines of code, but I guess it’s for some performance optimization of some sort which I’m not aware of.

simoneb on Mar 29, 2021

I tried to remove all custom stuff attached on req and it worked.

I just found the cause as I attach a PrismaClient (Postgresql ORM) on it

import { PrismaClient } from '@prisma/client'

const prisma = new PrismaClient()
app.use((req, res, next) => {
  req.prisma = prisma
  next()
})

I will try to produce a minimal example

SebastienElet on Mar 24, 2021