Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

stdSerializers cannot be avoided for Request and Response #1991

Open
gerardolima opened this issue Jun 15, 2024 · 4 comments
Open

stdSerializers cannot be avoided for Request and Response #1991

gerardolima opened this issue Jun 15, 2024 · 4 comments

Comments

@gerardolima
Copy link

gerardolima commented Jun 15, 2024

First of all, thank you for this great library!!

When any logger method (ie info) receives a Request, pino serializes the object using pino.stdSerializers.req and stores in req property; this value is, then, passed to the actual serializer function given by the options. This also happens to Response objects:

const opts = {
  serializers: { 
    'req': mySerializerReq,
    'res': mySerializerRes,
}
const logger = pino(opts)
logger.info(myReq) // serialized as `mySerializerReq(pino.stdSerializers.req(myReq))`
logger.info(myRes) // serialized as  `mySerializerRes(pino.stdSerializers.res(myRes))`

This is inefficient, performance-wise, and also can lead to unexpected behaviour, when the provided serializer requires some property from the object that is removed by pino.stdSerializers.*.

@gerardolima
Copy link
Author

I tested using this script, below:

import {describe, it} from 'node:test'
import assert from 'node:assert/strict'
import pino from 'pino';

const makeWriter = () => {
  const acc = [];
  return {
    write: (chunk) => { acc.push(chunk); },
    entries: () => [...acc],
  };
};

describe('stdSerializers', () => {

  it('serializes `.mySpecialProperty` for Errors', () => {
    // this test is OK
     
    // `err` property is resolved at `pino/lib/proto.js:write`
    // see https://github.com/pinojs/pino/blob/8db130eba0439e61c802448d31eb1998cebfbc98/lib/proto.js#L191

    const myErr = new Error()
    myErr.mySpecialProperty = Math.random()

    const writer = makeWriter()
    const opts = { serializers: { 'err': obj => ({ mySpecialProperty: obj.mySpecialProperty }) } }
    const logger = pino(opts, writer)

    logger.info(myErr)

    const entries = writer.entries()
    assert.equal(entries.length, 1)

    const obj = JSON.parse(entries[0])
    assert.deepEqual(obj.err, {mySpecialProperty: myErr.mySpecialProperty})
  })

  it('serializes `.mySpecialProperty` for Requests', () => {
    // this test fails

    // error property is resolved at `pino/lib/tools.js:genLog:LOG` -> `pino-std-serializers/index.d.ts:mapHttpRequest`
    // see https://github.com/pinojs/pino/blob/8db130eba0439e61c802448d31eb1998cebfbc98/lib/tools.js#L44
    // see https://github.com/pinojs/pino-std-serializers/blob/dc2ce14ebb9497d2ebe1a37c9f0da8d711ef5cc0/index.d.ts#L89

    const myReq = {
      method: 'any-fake-method',
      headers: 'any-fake-headers',
      socket: 'any-fake-socket',
    }
    myReq.mySpecialProperty = Math.random()

    const writer = makeWriter()
    const opts = { serializers: { 'req': obj => ({ mySpecialProperty: obj.mySpecialProperty }) } }
    const logger = pino(opts, writer)

    logger.info(myReq)

    const entries = writer.entries()
    assert.equal(entries.length, 1)

    const obj = JSON.parse(entries[0])
    assert.deepEqual(obj.req, {mySpecialProperty: myReq.mySpecialProperty})
  })

  it('serializes `.mySpecialProperty` for Responses', () => {
    // this test fails

    // error property is resolved at `pino/lib/tools.js:genLog:LOG` -> `pino-std-serializers/index.d.ts:mapHttpResponse`
    // see https://github.com/pinojs/pino/blob/8db130eba0439e61c802448d31eb1998cebfbc98/lib/tools.js#L46
    // see  https://github.com/pinojs/pino-std-serializers/blob/dc2ce14ebb9497d2ebe1a37c9f0da8d711ef5cc0/index.d.ts#L116

    const myRes = {
      setHeader: () => undefined,
    }
    myRes.mySpecialProperty = Math.random()

    const writer = makeWriter()
    const opts = { serializers: { 'res': obj => ({ mySpecialProperty: obj.mySpecialProperty }) } }
    const logger = pino(opts, writer)

    logger.info(myRes, 'any-message')

    const entries = writer.entries()
    assert.equal(entries.length, 1)

    const obj = JSON.parse(entries[0])
    assert.deepEqual(obj.res, {mySpecialProperty: myRes.mySpecialProperty})
  })
})

@mcollina
Copy link
Member

I think we should deprecate this behavior in this release, and remove in the next one. Would you like to send a PR?

@gerardolima
Copy link
Author

I think we should deprecate this behavior in this release, and remove in the next one. Would you like to send a PR?

I would like it very much to contribute, but right now I'm overwhelmed. Do you already have a date for the next release?

@mcollina
Copy link
Member

They happen when they happen

gerardolima pushed a commit to gerardolima/pino that referenced this issue Nov 9, 2024
When serializers are defined for HTTP Request or HTTP Response, do not
run the correspondent `stdSerializers` before calling the provided
serializer functions.

ISSUE pinojs#1991
gerardolima added a commit to gerardolima/pino that referenced this issue Nov 9, 2024
When serializers are defined for HTTP Request or HTTP Response, do not
run the correspondent `stdSerializers` before calling the provided
serializer functions.

ISSUE pinojs#1991
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants