Pino object logger option gets cloned after #568

[stefanosala]

Prerequisites

• I have written a descriptive issue title
• I have searched existing issues to ensure the bug has not already been reported

Fastify version

4.10.2

Plugin version

5.7.0

Node.js version

18.12.1

Operating system

macOS

Operating system version (i.e. 20.04, 11.3, 10)

13.0.1

Description

After #568 was merged, the new behavior of deepmerge clone the options object and tries to clone any instance of Pino we pass as option, modifying it into a simple object so that all the Pino settings are lost.

Steps to Reproduce

Given the following fastify startup module:

import pino from 'pino';

export default async function (fastify, options) {
  fastify.get('/', async (req, reply) => ({ hello: 'world' }));
}

const logger = pino({
  transport: {
    target: 'pino-pretty',
  },
});

export const options = {
  logger,
};

When using fastify-cli like this:

node_modules/.bin/fastify start --options a.js

I get this output:

{"level":30,"time":1670931640310,"pid":68940,"hostname":"Stefanos-MacBook-Air.local","msg":"Server listening at http://[::1]:3000"}
{"level":30,"time":1670931640311,"pid":68940,"hostname":"Stefanos-MacBook-Air.local","msg":"Server listening at http://127.0.0.1:3000"}

Expected Behavior

The expected output would be something like this instead:

[12:41:03.421] INFO (69034): Server listening at http://[::1]:3000
[12:41:03.422] INFO (69034): Server listening at http://127.0.0.1:3000

I would tend to think that deepmerge should be modified in order to clone by reference any type of object that is not a plain JS object, but I'd appreciate any feedback in order to try and provide a patch for this.

[Eomm]

Thanks for reporting

Let me check what I broke

[jordanebelanger]

Thanks for reporting

Let me check what I broke

Would be great if this can get some attention, this was really hard to debug and a huge head scratcher while I tried to figure out why my logger was no longer working as expected in production.

[Tom-Brouwer]

Thanks for reporting

Let me check what I broke

Great, thanks for your response.

Like @jordanebelanger I have a custom logger defined in my options in app.js, and no logs were being generated anymore after an update of fastify-cli.

As mentioned by the TS, the issue is in version 5.6.1 and above. On 5.6.0 it is still working. The workaround for now is to stick to 5.6.0.

Please let me know if there's any more information you need.

[stefanosala]

@Eomm I've gone a bit into the rabbit hole and I can't seem to find an elegant solution to this issue.

deepmerge will try to clone the EventEmitter from Pino because we try to merge a logger option on this line and that seems to be "by design", so I'm not really sure how to help here, I'm sorry!

[Eomm]

I think we should explore a bit the cloneProtoObject parameter: https://github.com/fastify/fastify-cli/pull/568/files#diff-a32491fa91f5482043b89399c88b89b58e660137d926f75dab64e9c56cf454a0R9

If we check the obj prototype, we should be able to understand if we must clone it or not

[stefanosala]

Thanks, what type of objects do you think we should clone?
My guess would be to clone only plain objects (Object.getPrototypeOf(value) === Object.prototype)?

[stefanosala]

Actually, that callback isn't being called in this case because it goes on this line, where it is directly being merged into target.

In my example above, target is a plain object and source is an EventEmitter.

[segevfiner]

Offff. So I'm stuck with fastify-cli@5.6.0 for the time being...

[segevfiner]

I used the logging-module as a workaround which is also annoying as I need to craft a separate file and compile it specially to share state with the main bundle and it also doesn't support ESM (#760)

I think the problem might be that _deepmerge in @fastify/deepmerge isn't checking for cloneProtoObject and the prototype before entering mergeObject, which then will recurse using _deepmerge into the logger property so it never actually reaches cloneObject or cloneProtoObject

[vdp641]

Hi, any update on it? I've tried versions 5.9, 6, and 7 of the fastifly-cli, but I'm still encountering the following error:

FastifyError [Error]: Invalid logger object provided. The logger instance should have these functions(s): 'child'.

[mcollina]

I guess the easiest way is for a volunteer to send a PR to fix.