pino icon indicating copy to clipboard operation
pino copied to clipboard

proposal: spy transport

Open simone-sanfratello opened this issue 3 years ago • 7 comments

I'd like to have spy capabilities on pino ~~since its design, we can't use sinon or so to add spy capabilities on a pino instance~~

My use case: I want to ensure logs output, since alarms and metrics are bases on them. Because of application design, I can't inject a dummy log instance to spy, I need to spy the real instance, and I believe it's the cleanest solution

I'm thinking to write a transport, does it make sense?

so I'd like to do something like

logger.js

const destination = process.env.NODE_ENV == 'test' ? require('pino-spy') : productionDestination
const logger = pino(options, destination)

test.js

await t.rejects(() => fetchS3(...))
t.ok(logger.error.calledWith('Not Found S3, URL: https://bucket.s3....'))

of course, more api on spy are required

Thoughts?

simone-sanfratello avatar May 30 '22 07:05 simone-sanfratello

You can do it with https://getpino.io/#/docs/api?id=pino-multistream and split2.

Take a look at:

  • https://github.com/pinojs/pino/blob/37337510704bf81cfb1015d7729439cd599ef5b2/test/helper.js#L31-L42
  • https://github.com/pinojs/pino/blob/0a56154fa0a24ac2b4015b597e6ae06468821699/test/timestamp.test.js#L21

I think a less convoluted API to do that would be nice indeed.

mcollina avatar May 30 '22 08:05 mcollina

I'll go with that solution, thanks!

And as soon as I can I'll write a module to do that

simone-sanfratello avatar May 30 '22 08:05 simone-sanfratello

Maybe issue should be kept open, as there is still work to be done?

kibertoad avatar May 30 '22 09:05 kibertoad

I agree with @kibertoad, I think there is a lot that can be improved here. I think we can have

  1. A guide in the docs "how to test logging"
  2. Some utilities to avoid too much boilerplate

I have been copying that snipped around for quite some time.

mcollina avatar May 30 '22 10:05 mcollina

just an update, can be done with sinon too

simone-sanfratello avatar Jun 01 '22 12:06 simone-sanfratello

For anyone coming here searching for an easy way to spy on pino output.

I've ended up using a simpler version of the sink function suggested by @mcollina, that will call the spy function(in my case jest.fn()) on each new log line:

...
  const spyOnPinoOutput = jest.fn();
  const spyStream: DestinationStream = sink(spyOnPinoOutput);
  afterEach(() => jest.restoreAllMocks());
  
  const pino = pino(config, spyStream);
  
  it('message', async () => {
      const message = 'Some string';
      logger.log(message);
      expect(spyOnPinoOutput).toHaveBeenLastCalledWith(
        matchObject({ // Function with templated expect.anything() on some properties
          level: 'log',
          message,
        }),
      );
    });
    
   function sink(spyFunc: (...args: any[]) => void) {
    const result = split((data) => {
      try {
        return JSON.parse(data);
      } catch (err) {
        console.log(err);
        console.log(data);
      }
    });
    result.on('data', (data) => spyFunc(data));
    return result;
  }

EcksDy avatar Aug 01 '22 16:08 EcksDy

Just an update to anyone else searching this; I found an easier implementation in a different thread. Gotchas are described in the following comment within that thread, but YMMV.

Along with the async logging option and a 'module interceptor' type of mocking library, I was able to create very simple tests.

darcyrush avatar Jan 08 '24 14:01 darcyrush