pino-http: customProps always logs duplicate keys

I stumbled into the same issue but the workaround proposed above didn’t work for me since I want to log some custom context that is not yet available when the customProps function is first called.

This worked for me to log those props only when the request is finished by checking res.writableEnded property:

customProps: function (_req, res) {
  if (!res.writableEnded) {
    return {};
  }

  return {
    context: getRequestContext()
  };
},

This seems to work:

const requestsSeen = new WeakSet();
// ...
customProps: (req) => {
  if (requestsSeen.has(req)) {
    return undefined;
  }
  requestsSeen.add(req);
  
  return { stuff };
}

This is not fixed and a PR would be greatly appreciated, I currently have no time to work on this and I’m not really using it anywhere.

Your usecase is a bit far from mine.

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

This issue hasn’t been fixed in v8.5.0.

The workaround made by @ilari-makimattila looks good to me, and those who might be using in Typescript can try this.

import express from 'express';
import pino from 'pino-http';

const app = express();
const logger = pino({
  customProps: (req, res) => {
    if (req.isLogged) return {};

    req.isLogged = true;
    return  {
      auth: decodeToken(req.headers.authorization),
    }
  },
});

declare module 'http' {
  interface IncomingMessage {
    isLogged: boolean;
  }
}

• related, #288

@cat-pierrecharles I also wrote the unit test requested by the maintainer in my fix. Please wait a moment for it to be merged into the master branch.

Hey everyone, I think this issue is still happening. I’m using customProps and like everyone else it is still duplicating the values. Could anything be done to fix this?

Yeah. I can reproduce in pino-http.

Here an example:

File: pino-config.ts

import { Options } from 'pino-http';
import { IncomingMessage } from 'http';

export const pinoHttpConfig: Options = {
  quietReqLogger: false,
  autoLogging: true,
  base: { hostname: os.hostname },
  level: 'info',
  formatters: {
    level: (label: string) => {
      return { level: label };
    },
  },
  timestamp: () => `,"time":"${new Date(Date.now()).toISOString()}"`,
  serializers: {
    req: () => {},
  },
  customProps: function (req: IncomingMessage) {
    // Dummy message
    return { hola: 'hola' };
  },
};

Then, with pino-http:

File: logger.middleware.ts

import pino from 'pino-http';

import { pinoHttpConfig } from './pino.config';

export function LoggerMiddleware() {
  return pino(pinoHttpConfig);
}

Injecting middleware in express app:

app.use(LoggerMiddleware());

Output:

As you can see: “hola”, appears twice.

I have the same issue.

Couldn’t we just remove the customPropBindings on the loggingMiddleware

const customPropBindings = (typeof customProps === ‘function’) ? customProps(req, res) : customProps if (customPropBindings) { fullReqLogger = fullReqLogger.child(customPropBindings) }

This will be done on the onResFinished function. I tested it quickly and it work.

The only question i have is, does the function onResFinished called on 100% use cases ? Like on network failure, timeout …

What do you think ?