pinojs / pino

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

child process/thread and interleaved stdout output #1098

Closed ronag closed 3 years ago

ronag commented 3 years ago

We just encountered a little weird output from one of our services. We use both worker threads and cluster in this service. All of the child processes/threads use pino with sync: false to output to stdout. What we've noticed is that sometimes the output of the different child process become interleaved which makes us think that the writes from pino are not atomic in the sense that the full string of serialized json is guaranteed to be transferred to the parent process stdout in one piece.

Are we doing something wrong here? Should we instead use pino-transport to "transport" all messages from child processes to the parent process and have only the parent process write to stdout?

Pino: @6.13.0

ronag commented 3 years ago

Seems related to cluster / child process + sync: false. We changed to sync: true on our http cluster workers.

ronag commented 3 years ago

I suspect this can have something to do with sonic boom MAX_WRITE which I think might cause messages to be split.

jsumners commented 3 years ago

A test case would be most helpful.

mcollina commented 3 years ago

I think the diagnosis is correct and #96 is the only solution.

ronag commented 3 years ago

I think the diagnosis is correct and #96 is the only solution.

Do you mean https://github.com/pinojs/sonic-boom/issues/96?

mcollina commented 3 years ago

ah yes.

zekth commented 3 years ago

I can confirm i'm encountering something similar when logging a huge amount of data to stdout too.

mcollina commented 3 years ago

@zekth what version are you using?

zekth commented 3 years ago

6.13.2

I'll try to write a test to show the issue. But it happens on heavy load, might be hard to reproduce.

ronag commented 3 years ago

https://github.com/pinojs/sonic-boom/pull/102#issuecomment-931251229

mcollina commented 3 years ago

@zekth I would say try with pino@7. It should solve this.

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.