using `println` sometimes causes a "zombie" bar to appear

[arifd]

the zombie bar is just an uncleared bar that has been replaced on a newline by the correct, active version.

But it's jarring because i'm using MultiProgress and now It often makes me think another task/bar has been created.

To be clear, I have programmed all my bars to .finish_and_clear(). When they are not visible, i know my program is not working... Yet I scroll up in my history and I see bars. (if logs came in during a bar) and sometimes there isn't even a log in between the zombie bars and the active bars.

The content of the "println" are the pretty formated logs from tracing if that makes a difference, they can be long,and typically have about 3 or 4 newlines.

Is this a known issue, is it a feature and not a bug? is there some way to switch off this behavior?

It's unfortunate, because I want progress bars and logs, at the same time! :D

[djc]

Try With #460?

[arifd]

Unfortunately zombies appear to be equally as present running that commit...

indicatif = { git = "https://github.com/chris-laplante/indicatif.git", rev = "32a0cd7761e0ce91fe057b8873fcfa565afbd7c4" }

...in my Cargo.toml.

[chris-laplante]

Can you share the code you are trying?

[chris-laplante]

You mention the messages to println contain newlines. I think this is probably what is tripping up the MultiProgress. It doesn't currently attempt to count how many lines are actually displayed. #460 doesn't change that situation.

As a temporary workaround, can you try using MultiProgress::suspend to print the messages? E.g.

mp.suspend(|| eprintln!("messages\nmessages")));

[arifd]

I am creating the logs via tracing like this fmt::Layer::default().pretty() I take the &[u8] buffer from tracing and plug it directly into MultiProgress, like this mp.println(String::from_utf8_lossy(buffer))

an example of the zombies (on your commit) looks like this: (they are all zombies)

with the suspend trick mb.suspend(|| std::io::stderr().lock().write_all(buffer)); (using stderr().lock() so that I don't have to parse the bytes as a String) I am still getting zombies:

[chris-laplante]

Two other questions:

1. How are you adding the bars to MultiProgress? Are you using add or one of the insert_ methods?
2. Can you confirm that the zombie issue disappears when you don't print logs to the screen, whether via println or suspend?

[arifd]

1. I am using mb.add()
2. when no logs are being printed.... I am STILL getting zombies!!

In fact, this minimal example (on your commit) works! (haven't tested it on the crates.io release):

// cargo add tracing
// cargo add tracing-subscriber
// cargo add indicatif
// cargo add once_cell

use indicatif::{MultiProgress, ProgressBar};
use once_cell::sync::Lazy;
use std::{io::Write, time::Duration};
use tracing::{info, subscriber::set_global_default};
use tracing_subscriber::{
    fmt::{Layer, MakeWriter},
    prelude::__tracing_subscriber_SubscriberExt,
    Registry,
};

static MB: Lazy<MultiProgress> = Lazy::new(|| MultiProgress::new());

fn main() {
    let mb = MB.clone();

    let logs = Layer::default()
        .pretty()
        .with_writer(RedirectedWriter::new(|buffer: &[u8]| {
            MB.println(String::from_utf8_lossy(buffer))
        }));
    let subscriber = Registry::default().with(logs);
    set_global_default(subscriber).unwrap();

    std::thread::spawn(move || loop {
        let pb = ProgressBar::new_spinner();
        pb.enable_steady_tick(Duration::from_millis(250));
        let pb = mb.add(pb);
        std::thread::sleep(Duration::from_secs(1));
        pb.finish_and_clear();
    });

    std::thread::spawn(move || loop {
        info!("hello world");
        std::thread::sleep(Duration::from_millis(250));
    })
    .join()
    .unwrap();
}

// tracing boilerplate

#[derive(Clone)]
pub struct RedirectedWriter {
    f: fn(&[u8]) -> std::io::Result<()>,
}

impl RedirectedWriter {
    pub fn new(f: fn(&[u8]) -> std::io::Result<()>) -> Self {
        Self { f }
    }
}

impl Write for RedirectedWriter {
    fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
        (self.f)(buf)?;
        Ok(buf.len())
    }

    fn flush(&mut self) -> std::io::Result<()> {
        Ok(())
    }
}
impl MakeWriter<'_> for RedirectedWriter {
    type Writer = Self;

    fn make_writer(&self) -> Self::Writer {
        self.clone()
    }
}

Maybe the only other interesting thing I am doing to the progressbars, is every time a stage of processing progresses. I clone the pb (I clone because I can't move it out of the struct which impls Drop... I guess I could std::mem::swap with a fresh pb ( (that I will never .tick() nor .add() to the mb because I don't actually ever want to see it) if you would like me to)

then I .set_style() on the cloned pb to update the progress bar with new a template. I don't interact with the mb. i don't add it again or anything.

[arifd]

Look! Run this code for a while, you will see zombies:

use indicatif::{MultiProgress, ProgressBar, ProgressStyle};
use once_cell::sync::Lazy;
use std::time::Duration;

static MB: Lazy<MultiProgress> = Lazy::new(|| MultiProgress::new());

fn create_bar() {
    std::thread::spawn(move || loop {
        let pb = ProgressBar::new_spinner();
        pb.enable_steady_tick(Duration::from_millis(100));
        let _pb = MB.add(pb);
        let __pb = _pb.clone();
        std::thread::spawn(move || {
            let mut i = 0;
            loop {
                i += 1;
                let pb = _pb.clone();
                pb.set_style(ProgressStyle::with_template(&i.to_string()).unwrap());
                std::thread::sleep(Duration::from_millis(123));
            }
        });
        std::thread::sleep(Duration::from_secs(5));
        __pb.finish_and_clear();
    });
}

fn main() {
    loop {
        create_bar();
        std::thread::sleep(Duration::from_secs(2));
    }
}

[chris-laplante]

I think the issue is that you are starting the ticker before adding the progress bar to the MultiProgress. When I run your example I do indeed get zombies, but when I tweak it as follows I don't:

use indicatif::{MultiProgress, ProgressBar, ProgressStyle};
use once_cell::sync::Lazy;
use std::time::Duration;

static MB: Lazy<MultiProgress> = Lazy::new(|| MultiProgress::new());

fn create_bar() {
    std::thread::spawn(move || loop {
        let pb = ProgressBar::new_spinner();
        let _pb = MB.add(pb);
        _pb.enable_steady_tick(Duration::from_millis(100));
        let __pb = _pb.clone();
        std::thread::spawn(move || {
            let mut i = 0;
            loop {
                i += 1;
                let pb = _pb.clone();
                pb.set_style(ProgressStyle::with_template(&i.to_string()).unwrap());
                std::thread::sleep(Duration::from_millis(123));
            }
        });
        std::thread::sleep(Duration::from_secs(5));
        __pb.finish_and_clear();
    });
}

fn main() {
    loop {
        create_bar();
        std::thread::sleep(Duration::from_secs(2));
    }
}

[arifd]

That's frustrating because in my actual code, the only place where i mb.add() I do so, and then set .enable_steady_tick()

The other interesting moments happen during state changes, I clone the pb then .set_style() and give it a new style. But there is no more interaction with mb since it has been already added, the only behaviours I need are to change the style and kill it when done

[arifd]

@chris-laplante here is the entirety of my interaction with indicatif. (minus the PROGRESS.println(String::from_utf8_lossy(buffer)) logs which happens in another mod) (it's not too much) if you're curious as to the cause of the bug: https://gist.github.com/arifd/51499d11b19ef3be7409ce1c49820ed9

[chris-laplante]

That's frustrating because in my actual code, the only place where i mb.add() I do so, and then set .enable_steady_tick()

The other interesting moments happen during state changes, I clone the pb then .set_style() and give it a new style. But there is no more interaction with mb since it has been already added, the only behaviours I need are to change the style and kill it when done

Does your output end up going into scrollback? In order words, are you trying to display more lines than there are rows in your terminal?

[chris-laplante]

@chris-laplante here is the entirety of my interaction with indicatif. (minus the PROGRESS.println(String::from_utf8_lossy(buffer)) logs which happens in another mod) (it's not too much) if you're curious as to the cause of the bug: https://gist.github.com/arifd/51499d11b19ef3be7409ce1c49820ed9

I don't see any reason why this shouldn't work :(.

[arifd]

That's frustrating because in my actual code, the only place where i mb.add() I do so, and then set .enable_steady_tick() The other interesting moments happen during state changes, I clone the pb then .set_style() and give it a new style. But there is no more interaction with mb since it has been already added, the only behaviours I need are to change the style and kill it when done

Does your output end up going into scrollback? In order words, are you trying to display more lines than there are rows in your terminal? It's hard for me to provide you a good screenshot unfortunately, but yes, i will get zombies, even before all the rows have been filled up with content, and even without any logs being printed. In this screenshot there did happen to be a couple logs but then I got zombies anyway. The zombies in this screen shot are the lines beginning with [645, 664, 688, 645, 664, 645, 664, 645, 664, 688]. In fact, we can know they are zombies, because we never work the same ID at the same time. Apart from that, in real life you can see the spinner is stuck.

[chris-laplante]

Without code that I can run myself it's hard to say :/. The best chance of getting this fixed is if you can come up with a self-contained reproducer. I know that's easier said than done but for inspiration you can look at the render tests: https://github.com/console-rs/indicatif/blob/main/tests/render.rs. If you could implement your reproducer as a render test, that'd be even better.

Besides that, looks like you're using Visual Studio Code? Can you try running your program in a different terminal emulator? This is to rule out issues with vscode's escape sequence processing.

[arifd]

Okay sure, I'll try to get at it over the weekend. Cheers.

[Bragolgirith]

I get what I think is a similar issue with the following code:

fn main() {
    let multi_progress = MultiProgress::new();
    let style = ProgressStyle::with_template("[{elapsed_precise}] {bar:40.cyan/blue} {pos:>7}/{len:7} {msg}")
        .unwrap()
        .progress_chars("##-");

    let threads_count: u64 = 10;
    let operations_count: u64 = 100;

    // Start 10 threads
    let threads = (0..threads_count)
        .map(|thread_index| {
            // Add a progress bar for each thread
            let pb = multi_progress.add(ProgressBar::new(operations_count));
            pb.set_style(style.clone());
            pb.set_message(format!("Thread #{}: running", thread_index));

            thread::spawn(move || {
                // Start 100 operations in each thread
                for operation_index in 0..operations_count {
                    // Print a single line anywhere (e.g. on thread 5, operation 50).
                    // The printed line is not visible (which I assume is expected)
                    // and a few zombie bars are spawned instead.
                    if thread_index == 5 && operation_index == 50 {
                        println!("Hello, World!");
                        pb.set_message(format!("Thread #{}: running (println was here)", thread_index));
                    }

                    // Simulate 20ms of work
                    thread::sleep(Duration::from_millis(20));

                    // Update the progress bar
                    pb.inc(1);
                }
            })
        })
        .collect::<Vec<_>>();

    for thread in threads {
        thread.join().unwrap();
    }
    println!("All threads finished");
}

(Tested on Windows 11, with both PowerShell and Command Prompt. indicatif = "0.17.2")

[chris-laplante]

(Tested on Windows 11, with both PowerShell and Command Prompt. indicatif = "0.17.2")

This is expected - a bare println! bypasses all the MultiProgress machinery and throws off the line counts. To fix your code, just replace the println!("Hello, World!"); with pb.println("Hello, World!"); :slightly_smiling_face: