pinojs / pino

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

pino streaming to tee flushes a maximum of 100 - 500 lines to the log file, never more #1396

Closed webhype closed 2 years ago

webhype commented 2 years ago

Expected result: 1000 - 3000 lines in the log file Actual result: 100 - 500 lines, seems random when it cuts off OS: Mac OS or Linux Code to reproduce, closely resembling pino-tee ESM examples at: https://github.com/pinojs/pino-tee/pull/18/files#diff-98328e3b3ad8e1560c1bbe15b7e4de95e8724b7b542d64c0a752116dd8d8c973

import pino from 'pino'
import childProcess from 'child_process'
import stream from 'stream'
import util from "util";
const setTimeoutPromise = util.promisify(setTimeout);

// Environment variables
const cwd = process.cwd();
const { env } = process;
const logPath = `${cwd}/public/logs`;

// Create a stream where the logs will be written
const logThrough = new stream.PassThrough();
const log = pino({ name: 'project' }, logThrough);

// Log to multiple files using a separate process
const child = childProcess.spawn(
//  process.execPath,
    "tee",
[
//  'node_modules/pino-tee/tee.js', // Or path to pino-tee
  'warn', `${logPath}/warn.log`,
  'error', `${logPath}/error.log`,
  'fatal', `${logPath}/fatal.log`
], { cwd, env });

logThrough.pipe(child.stdin);
// Writing some test logs
for (let i = 1; i < 1000; i++) {
    log.warn(`WARNING ${i}`);
    log.error(`ERROR ${i}`);
    log.fatal(`FATAL ${i}`);
}
// give some time to flush buffers
await setTimeoutPromise(5000);
mcollina commented 2 years ago

Closing in favor of https://github.com/pinojs/pino-tee/issues/89.

webhype commented 2 years ago

Upon further research, I think this issue should remain open here and the one on pino-tee one should be closed.

As you can see from the above code, the same problem happens regardless whether you call node node_modules/pino-tee/tee.js or you call the Linux / Mac OS command tee. So I feel the problem is really with pino, not with pino-tee.

mcollina commented 2 years ago

We are actually doing nothing with the stream, we just call .write() to it. I'll take a look tomorrow

mcollina commented 2 years ago

It's a node core bug: https://github.com/nodejs/node/issues/42630

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.