pinojs / pino

🌲 super fast, all natural json logger
http://getpino.io
MIT License
14.21k stars 875 forks source link

V7 leaves around open handles in Jest tests #1268

Closed dhalbrook closed 2 years ago

dhalbrook commented 2 years ago

This isn't a bug per se, but just to note that V7 of Pino relies on the "thread-stream" library, which will leave open handles around during your Jest CI loop.

We got around it by simply mocking 'thread-stream' like so:

jest.mock('thread-stream');

but ideally it would be possible to add a config option to the pino constructor to bypass this library's use.

mcollina commented 2 years ago

Can you please upload a full repro? If you are not using transports this should not happen.

(Transports are shut down when the GC runs, so you are good and there are no leaks).

dhalbrook commented 2 years ago

I'm running jest using these arguments:

cross-env NODE_ENV=test jest --runInBand --detectOpenHandles --verbose

Here's an example of a stack trace:

Jest has detected the following 2 open handles potentially keeping Jest from exiting:

  ●  WORKER

       97 | });
       98 | 
    >  99 | /**
          |              ^
      100 |  * Get a logger scoped to a given node module.
      101 |  * @param module the module
      102 |  * @param options options for the log

      at createWorker (../../node_modules/thread-stream/index.js:49:18)
      at new ThreadStream (../../node_modules/thread-stream/index.js:203:19)
      at buildStream (../../node_modules/pino/lib/transport.js:39:18)
      at transport (../../node_modules/pino/lib/transport.js:109:10)
      at normalizeArgs (../../node_modules/pino/lib/tools.js:409:16)
      at pino (../../node_modules/pino/pino.js:83:28)
      at buildLogger (../utils/log.ts:99:85)
      at Object.<anonymous> (../utils/log.ts:105:16)
      at Object.<anonymous> (../utils/intlPolyfills.ts:23:12)
      at Object.<anonymous> (../test-framework/jest/jestSetupMockGlobals.ts:5:22)

  ●  WORKER

       97 | });
       98 | 
    >  99 | /**
          |              ^
      100 |  * Get a logger scoped to a given node module.
      101 |  * @param module the module
      102 |  * @param options options for the log

      at createWorker (../../node_modules/thread-stream/index.js:49:18)
      at new ThreadStream (../../node_modules/thread-stream/index.js:203:19)
      at buildStream (../../node_modules/pino/lib/transport.js:39:18)
      at transport (../../node_modules/pino/lib/transport.js:109:10)
      at normalizeArgs (../../node_modules/pino/lib/tools.js:409:16)
      at pino (../../node_modules/pino/pino.js:83:28)
      at buildLogger (../utils/log.ts:99:85)
      at Object.<anonymous> (../utils/log.ts:105:16)
      at Object.<anonymous> (../utils/intlPolyfills.ts:23:12)
      at Object.<anonymous> (../test-framework/jest/jestSetupMockGlobals.ts:5:22)
      at TestScheduler.scheduleTests (../node_modules/@jest/core/build/TestScheduler.js:333:13)
      at runJest (../node_modules/@jest/core/build/runJest.js:404:19)
      at _run10000 (../node_modules/@jest/core/build/cli/index.js:320:7)
      at runCLI (../node_modules/@jest/core/build/cli/index.js:173:3)

buildLogger looks like this:

function buildLogger(name: string, level: pino.LevelWithSilent): pino.Logger {
  const options = getOptions(name, level);
  const destination = getDestination(name);
  return destination ? pino(options, destination) : pino(options);
}

I've verified that the destination is undefined in this case.

The pino version is 7.1.0

dhalbrook commented 2 years ago

OK, I tracked down my issue. I had "pretty-print" enabled during my test, which caused transports to be used.

Once I disabled pretty-print things are working as expected.

github-actions[bot] commented 2 years ago

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.