Duplicate message keys from logMethod hook

[10xLaCroixDrinker]

I have a logMethod hook that takes an error from the beginning or end of the arguments and puts it in the error field, while using the rest of the arguments for the message field. This works fine when using the default message key msg, but when using a custom message key it results in two messages in the output. One message is the one added by the hook and the other is the error message.

const pino = require('pino');
const util = require('util');

const logger = pino({
  messageKey: 'message',
  errorKey: 'error',
  hooks: {
    logMethod(inputArgs, method) {
      if (inputArgs.length > 1) {
        let error;
        if (inputArgs[0] instanceof Error) error = inputArgs.shift();
        if (inputArgs[inputArgs.length - 1] instanceof Error) error = inputArgs.pop();
        if (error) {
          const message = util.format(...inputArgs);
          return method.call(this, { error, message });
        }
      }
      return method.apply(this, inputArgs);
    },
  },
})

logger.error('This is a %s', 'test', new Error('test error'));

Output:

{"level":50,"time":1693517627310,"pid":18782,"hostname":"<redacted>","error":{"type":"Error","message":"test error","stack":"Error: test error<stack redacted>"},"message":"This is a test"}

[jsumners]

Please provide a minimal reproducible example. Doing so will help us diagnose your issue. It should be the bare minimum code needed to trigger the issue, and easily runnable without any changes or extra code.

You may use a GitHub repository to host the code if it is too much to fit in a code block (or two).

[10xLaCroixDrinker]

@jsumners updated the example in the description

[jsumners]

What is the issue? The below is directly from your provided code and looks correct to me:

❯ node index.js | jq
{
  "level": 50,
  "time": 1693570899268,
  "pid": 72912,
  "hostname": "blah",
  "error": {
    "type": "Error",
    "message": "test error",
    "stack": "Error: test error\n    at Object.<anonymous> (/private/tmp/01/index.js:23:38)\n    at Module._compile (node:internal/modules/cjs/loader:1256:14)\n    at Module._extensions..js (node:internal/modules/cjs/loader:1310:10)\n    at Module.load (node:internal/modules/cjs/loader:1119:32)\n    at Module._load (node:internal/modules/cjs/loader:960:12)\n    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:81:12)\n    at node:internal/main/run_main_module:23:47"
  },
  "message": "This is a test"
}

What output are you expecting to see?

[10xLaCroixDrinker]

My mistake @jsumners. My example must be missing something. I'll update again later today. The expected result is that there are two message keys at the root level of the log entry.

[10xLaCroixDrinker]

This is now resolved

[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.