pinojs / pino-pretty

🌲Basic prettifier for Pino log lines
MIT License
1.21k stars 147 forks source link

Logs missing in Jest tests #480

Open OliverJAsh opened 9 months ago

OliverJAsh commented 9 months ago

I am following the recommendation here: https://github.com/pinojs/pino-pretty/tree/db278755318e2f1c565df736bbedd7eb7a2fd73f#usage-with-jest

Reduced test case:

package.json:

{
  "dependencies": {
    "jest": "^29.7.0",
    "pino": "^8.16.2",
    "pino-pretty": "^10.2.3"
  }
}

test.js:

const pino = require('pino')
const pretty = require('pino-pretty')

test('test pino-pretty', () => {
  const logger = pino(pretty({ sync: true }));
  logger.info('Info');
  logger.error('Error');
});

When I run jest test.js I get this output:

 RUNS  ./test.js
 PASS  ./test.jsNFO (81668): Info
  ✓ test pino-pretty (6 ms)

Test Suites: 1 passed, 1 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        0.129 s, estimated 1 s
Ran all test suites matching /test.js/i.
✨  Done in 0.37s.
jsumners commented 9 months ago

All I can suggest is that if you need to verify the final NDJSON of individual logs, you should supply a stream that collects the logs and then inspect that collection. See https://github.com/pinojs/pino/issues/1274#issuecomment-997971329.

mcollina commented 9 months ago

I think we have a bug in our docs, I don't think Jest would ever render things correctly.

FiveOFive commented 7 months ago

I think we have a bug in our docs, I don't think Jest would ever render things correctly.

Is that confirmed that Jest won't ever render correctly? I'm also trying to follow those docs but it seems like even with sync: true the log entries are still showing up after tests

Ugikie commented 4 months ago

Confirming this because I'm also using sync: true and jest is still complaining about open handles

mostlylikeable commented 3 weeks ago

I was able to workaround this by using prettyFactory directly in tests. I've tried configuring { sync: true }, using as transport, destination and other things and wasn't able to get all log messages to show up. It seems like there's still something stuck in the buffer even when using { sync: true }, and i'm not sure if it has something to do with the event-based nature of sonic-boom not playing well with jest or what, but this is working (well enough) for me.

// foo.ts
import pino from 'pino';
import PinoPretty, { prettyFactory } from 'pino-pretty';

const getPino = () => {
  const isJest = !!process.env.JEST_WORKER_ID;
  if (isJest) {
    const prettify = prettyFactory({ sync: true });
    // configure custom stream that forwards pretty message to console
    return pino({}, {
      write(data: unknown) {
        console.log(prettify(data));
      },
    });
  }
  return pino({}, PinoPretty());
};

export const foo = () => {
  const logger = getPino();
  console.log('console test');
  logger.info('pino test');
};
image