pinojs / pino

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

next: worker-thread messages not log when pino used in both main-thread and worker-thread #1095

Closed climba03003 closed 3 years ago

climba03003 commented 3 years ago

When I use pino in both main-thread and worker-thread. Only the main-thread can log messages.

Repro Link: https://replit.com/@climba03003/pino-issue-1095

// index.js
const { logger } = require('./logger.js')
const { Worker } = require('worker_threads')

const worker = new Worker('./pino.js')
setTimeout(function() {
  worker.terminate()
  process.exit(0)
}, 3000)

logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')

// logger.js
const pino = require('pino')

const logger = pino({ level: 'trace' }, pino.transport({
  targets: [
    { level: 'info', target: '#pino/file', options: {} }
  ]
}))

module.exports.logger = logger

// pino.js
const { logger } = require('./logger.js')

logger.info('worker - should show')
logger.info('worker - should show')
logger.info('worker - should show')
logger.info('worker - should show')
logger.info('worker - should show')
logger.info('worker - should show')
logger.info('worker - should show')

process.exit(0)
mcollina commented 3 years ago

Ah, this looks like a bug (!).

mcollina commented 3 years ago

Removing process.exit(0) from pino.js fixes it. The hooks that we use beforeExit and exit do not work the same in worker_threads so we cannot hook things correctly.

Maybe you could send a PR?

climba03003 commented 3 years ago

I do not know if I can comes up a solution. I have tested a lot of method, it seems that when ever I called process.exit inside the worker_threads, the worker is exit faster than pino can do anything (include register a process hook).

It would be better to use process.emit('beforeExit') or pino.final to terminate inside worker.

1.

// let pino to handle the stream flush before exit
process.emit('beforeExit')
// terminate the worker process
process.once('beforeExit', function() {
  // create some time buffer for pino to clear logs
  setTimeout(() => process.exit(0), 1000)
})

2.

pino.final(logger, function() {
  process.exit(0)
})
JekRock commented 3 years ago

From my understanding, the issue is that process.on doesn't deliver messages inside a worker thread. From the documentation:

Notable differences inside a Worker environment are:

  • Signals will not be delivered through process.on('...').

I don't see a way to attach a listener to the exit event from inside a worker thread when process.exit(0) is called though.

mcollina commented 3 years ago
const { logger } = require('./b.js')

logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')
logger.info('main - show log')

process.exit(0)

The process.exit(0) will block the worker thread initialization. It's not possible to make it work :/.

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.