v7 transport w/ worker_thread can we disable or force flush?

[JohnPolansky]

I'm trying to use pino as a logger for a simple script used to archive job/task data so far it's been pretty awesome easy to configure. However I wanted to add a a progress bar and setup https://github.com/visionmedia/node-progress/ as a simple one. Now the progress bar obviously takes over the current line on terminal to do its updates, however I've noticed what I first took to be some sort of async issue between pino and progress bar. You can see what I mean below:

[04:09:07.371] DEBUG: Archivable Parent Jobs: 17
======-----------  1750/21825 8% 32407 Jobs/s Time(sec): T: 0.1 R: 0.6[04:09:07.589] DEBUG: Archivable Jobs: 21825
[04:09:07.589] INFO: Gathering Task Data! - ( May take a few minutes, depending on archive size. )
==============  21825/21825 100% 32575 Jobs/s Time(sec): T: 0.7 R: 0.0
[04:09:08.264] DEBUG: Archivable Tasks: 251949

Note I shrunk the progress bar in text output so it would "fit in the text" window.

As you can see Pino logs the Parent Jobs then it "should" log out the Archivable Jobs and Gathering Tasks logs then start the progress bar. Which is how I have it in the code. However as you can see the progress bar starts writing to the current line and the DEBUG: Archivable Jobs: 21825 gets added after and breaks the progress bar. The Gathering Task Data! message.

Obviously this isn't ideal for display it makes a bit of a mess. After playing around with various configurations. I discovered that the standard pino logger does NOT exhibit this issue. Meaning if I do

const logger = pino();

then the logs and progress bar line up perfectly. However when I add the transport for pino-pretty it breaks. At first I thought it was related to pino-pretty however I tried this and found that it also breaks the progress bar:

const logger = pino({
    transport: {
        target: 'pino/file',
    }
);

I also get the issue, so it doesn't appear to be pino-print since using the standard transport for stdout also has the issue when displaying json. I started trying to dig around and I found your article:
https://www.nearform.com/blog/pino7-0-0-pino-transport-worker_thread-transport/

Which I found very informative but it now makes me wonder if the worker-threads are basically introducing an async like issue where Pino isn't finishing the logs before the progress bar starts. I was curious for your input

• might it be possible to disable worker threads for transports (my script is simple and doesn't really benefit from them)
• might it be possible to flush the pino worker thread?
  • I tried using logger.flush() which I realize is for sync: true but that didn't work

Thanks in advance!

[mcollina]

Yes, using the worker threads cause a delay. Most transports are just streams, you can create one in the main thread and pass it in directly as a stream.

[JohnPolansky]

@mcollina

Thanks for your suggestion. I confess I'm very new to worker threads, but excited to understand this. From what you said it sounds like you are suggesting to create a worker in the main and pass it to pino and that I should also have that same worker perform the progress_bar output so they queue together. I believe I understand how to pass the pino instance the worker thread but I'm struggling to understand how I would get the same worker thread to also process the progress_bar

I've included a simple example that demonstrates the overlap issue. I was hoping you might be able to shed some additional details on your response above. Part of me feels like I could create a worker.js and have two functions (progress and pino logging) and I use post.message to pass in the action I want, but if that's the case I don't see how it would be compatible with the worker config pino uses.

I'm sorry if I'm missing something obvious, but I'm very excited to see if I can get this to work as my work frequently have a need for a progress bars for long running tasks. Thanks in advance.

import ProgressBar from 'progress';
import pino from 'pino';

import { MessageChannel } from 'node:worker_threads';
const { port1, port2 } = new MessageChannel();

const log = pino({
  // If you comment out the `transport` you can see the log/progress bar work and don't overlap
  transport: {
    target: 'pino/file',
    worker: {
        workerData: {
          port: port1,
        },
        transferList: [port1],
    },
  },
});

log.info('Script Start!')
log.info('Start long running task!')

const totalCount = 100
var bar = new ProgressBar(':bar', { width: 40, total: totalCount });

var timer = setInterval(function () {
  bar.tick();
  if (bar.complete) {
    clearInterval(timer);
    log.info('Script End!!')
  }
}, 10);

[mcollina]

No, I'm suggesting:

import ProgressBar from 'progress';
import pino from 'pino';

const stream = pino.destination('/path/to/your/file')
const log = pino(stream);

log.info('Script Start!')
log.info('Start long running task!')

const totalCount = 100
var bar = new ProgressBar(':bar', { width: 40, total: totalCount });

var timer = setInterval(function () {
  bar.tick();
  if (bar.complete) {
    clearInterval(timer);
    log.info('Script End!!')
  }
}, 10);

[github-actions]

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.