pino icon indicating copy to clipboard operation
pino copied to clipboard

Drop support for printf style logging because once again i deployed logger.info(msg, obj) instead of logger.info(obj, msg) to prod and cant debug prod.

Open Raynos opened this issue 1 year ago • 5 comments

Would you accept a pull request for a breaking change where we drop varags on the LogFn and do not support printf style logging.

// this is fine
logger.info('a message')
// this is good. I wont bike shed about how the arguments should be swapped like bunyan and the rest.
logger.info({
  something: 'happened'
}, 'a more descriptive image.

// This is horrible.
logger.info('oh hi %s', 'bye')

The issue I'm running into is that when I do the following

logger.info('a msg', { ... })

it's not a typescript error, because its technically an invalid printf expression and the vargs of ...any[] in the type signature makes the pino api basically untyped.

I want to make it harder for me to deploy broken log statements to prod when i swapped the arguments by accident and didnt catch it in review.

I'm happy to do the pull request, and of course it would be a major version.

Raynos avatar Aug 21 '24 17:08 Raynos

Sounds like a self inflicted issue. I recommend using https://getpino.io/#/docs/api?id=logmethod to standardize your logger instance to the way you like it.

jsumners avatar Aug 21 '24 18:08 jsumners

That hook doesn't help at all with the typescript definitions. Currently i cast the logger to an interface with a stricter type definition. But really it's a footgun for everyone.

Raynos avatar Aug 21 '24 23:08 Raynos

in my opinion, the least pino should do is compare the number of printf args to the number of arguments passed and either log warnings or simply log the objects as if you had passed the correct printf args at the end. Silently accepting bad arguments / gobbling errors is always bad.

Something like this works:

const logger = pino({
  hooks: {
    logMethod(fullargs, method) {
      if (fullargs.length === 0 || typeof fullargs[0] !== "string") {
        method.apply(this, fullargs);
        return;
      }
      const [msg, ...args] = fullargs;
      // if msg has less format specifiers than args, then add %o for each extra arg
      const count = (msg.match(/%[a-z]/g) || []).length;
      const msgNew =
        count < args.length ? msg + " %o".repeat(args.length - count) : msg;
      method.apply(this, [msgNew, ...(args as unknown[])]);
    },
  },
}

Result:

logger.info("testing output", [], { foo: 1 }, true, 1);
// [17:50:48.500] INFO: testing output [] {"foo":1} true 1

Edit: I can send a PR if you all are open to this

phiresky avatar Mar 09 '25 16:03 phiresky

in my opinion, the least pino should do is compare the number of printf args to the number of arguments passed and either log warnings or simply log the objects as if you had passed the correct printf args at the end.

That is an expensive operation. Interpolation tokens are processed at:

  1. https://github.com/pinojs/pino/blob/0bb3cd01b4259b7721b56aeb5ced5f5edbfec794/lib/tools.js#L62
  2. https://github.com/pinojs/pino/blob/0bb3cd01b4259b7721b56aeb5ced5f5edbfec794/lib/tools.js#L71

The processing is done through https://www.npmjs.com/package/quick-format-unescaped. If you study the code of that module, https://github.com/pinojs/quick-format-unescaped/blob/20ebf64c2f2e182f97923a423d468757b9a24a63/index.js, you'll see that it iterates through the format string once in order to replace the tokens as they are encountered. Your suggestion requires calculating how many tokens are present in the string so that the number of them can be compared to the number of provided substitution values.

We are unlikely to accept such a change as it will be measureably slower. But if you can implement a solution that does not degrade performance, we can consider it.

jsumners avatar Apr 16 '25 12:04 jsumners

That is an expensive operation

I concede that the code I sent is fairly expensive.

it iterates through the format string once in order to replace the tokens as they are encountered

The code you linked is a bit hard to comprehend, but it seems to be that it should be possible to simply at the end of the iteration loop compare the index a to the length of the args array argLen - and if the index is less than the length, append the additional arguments.

e.g.

while (a < argLen) str += String(args[a])

That would be basically zero cost if no unused args are present

phiresky avatar Apr 16 '25 12:04 phiresky