emersonford/tracing-indicatif

Tracing layer that automatically creates and manages progress bars for active spans.

tracing-indicatif

A tracing layer that automatically creates and manages indicatif progress bars for active spans.

Progress bars are a great way to make your CLIs feel more responsive. However, adding and managing progress bars in your libraries can be invasive, unergonomic, and difficult to keep track of.

This library aims to make it easy to show progress bars for your CLI by tying progress bars to tracing spans. For CLIs/libraries already using tracing spans, this allow for a dead simple (3 line) code change to enable a smooth progress bar experience for your program. This eliminates having to have code in your libraries to manually manage progress bar instances.

This ends up working quite well as progress bars are fundamentally tracking the lifetime of some "span" (whether that "span" is defined explicitly or implicitly), so might as well make that relationship explicit.

Demo

See the examples folder for demo code.

Default Configuration

Default Configuration with Child Spans

Progress Bar

Build Console Like

A recreation of buck2's superconsole.

Features

• Customize progress bars using the same ProgressStyle API as indicatif.
• Supports displaying parent-child span relationship between progress bars.
• Limit the number of progress bars visible on the terminal.
• Prevents progress bars from clobbering tracing logs.

tracing-indicatif's Issues

Progress bars don't seem to finish?

I'm using tracing-indicatif in a stream, using the .instrument() function available on futures.

Something like the following:

            let num_elems = elems.len();
            let results: Vec<_> = futures::stream::iter(elems)
                .map(|elem| {
                    let some_service = some_service.clone();
                    async move {
                        let resp = some_service
                            .get(elem)
                            .await
                            .map(|resp| (elem, resp));

                        // once the .get is done, increment the progress bar.
                        Span::current().pb_inc(1);

                        resp
                    }
                })
                .buffer_unordered(10)
                .try_collect()
                .instrument({
                    let span = tracing::info_span!("doing_work", "indicatif.pb_show" = tracing::field::Empty);
                    span.pb_set_message("Doing work");
                    span.pb_set_length(num_elems);
                    span.pb_set_style(
                        &ProgressStyle::with_template(
                            "{prefix}{wide_msg} {bar:30} [{elapsed_precise}]  {pos:>7}/{len:7}",
                        )
                        .unwrap(),
                    );
                    span.pb_start();
                    span
                })
                .await?;

            do_other_work();

While I get progress bars, and the progress bar updates, it seems the "Doing work" progress never finishes, even after it's dropped (during do_other_work()).

The timer keeps counting up.

A more complete example (and screencast): https://asciinema.org/a/ap9qC60A5IjvI12vQ2IBwEHOM.

As can be seen, the "Checking paths" progress bar keeps running, even though we're already at "Ingesting paths".

Suspend output for some time to interact with the console

While it is possible to use the stdout/stderr wrappers to output something to the console, for some use-cases this is not enough.

I want to prompt the user with a selection using dialoguer, which wants to have the real terminal writer (by having an AsRawFd trait bound on the Term constructor).

I think this can be ultimately accomplished by exposing the suspend function of the MultiProgress, allowing to hide progress bars during the user interaction (as suggested in console-rs/indicatif#158). This has a side-effect of blocking every other thing that tries to write to the output (including the tracing fmt layer if it was registered), but I think there's no real way to multiplex that..

Feature Request: Configurable tick interval

There are two places where enable_steady_tick is called with a hard coded 100ms value.

Personal preference: I like 1 second re-draws for these types of things...

It would be nice to have a way to configure it:

1. Change the value, with default 100ms if not changed.
2. Ability to disable the tick (ie. it only draws when we call another method that draws like set position, inc, etc.)

I would like to add: this library is really great!

max_progress_bars deadlocks

Entering a large number of spans simultaneously on different threads seem to cause deadlocks. Raising with_max_progress_bars avoids this, which hints that the limiting is what causes the deadlock.

I encountered this issue ussing Rayon (which on my machine uses 8 threads by default, which is slightly above the default limit of 7 bars), but the example below is written with plain threads.

use tracing_indicatif::IndicatifLayer;
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;

fn main() {
	let indicatif_layer = IndicatifLayer::new();
	tracing_subscriber::registry()
		.with(tracing_subscriber::fmt::layer().with_writer(indicatif_layer.get_stderr_writer()))
		.with(indicatif_layer)
		.init();

	let handles = (0..256).map(|i| {
		std::thread::spawn(move || {
			tracing::info!("before {i}");
			let _span = tracing::info_span!("ch").entered();
			tracing::info!("after {i}");
		})
	}).collect::<Vec<_>>();
	handles.into_iter().for_each(|i| i.join().unwrap());
}

Another race condition, causing poison

This one seems a little more subtle than #2, but under certain conditions it seem a race condition causes None.unwrap():

thread '<unnamed>' panicked at 'called `Option::unwrap()` on a `None` value', ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tracing-indicatif-0.3.2/src/pb_manager.rs:140:69

Followed by any subsequent use getting a poison error:

thread '<unnamed>' panicked at 'Mutex poisoned: PoisonError { .. }', ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tracing-subscriber-0.3.17/src/registry/sharded.rs:433:54
thread '<unnamed>' panicked at 'called `Result::unwrap()` on an `Err` value: PoisonError { .. }', ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tracing-indicatif-0.3.2/src/lib.rs:546:22

The repro is almost the same as in #2, but with the info! statements removed. Presumably they either cause synchronization via get_stderr_writer, or simply affect the timing. It's not guaranteed to happen; for me it happens about every other time when running this program in debug build.

use tracing_indicatif::IndicatifLayer;
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;

fn main() {
	let indicatif_layer = IndicatifLayer::new();
	tracing_subscriber::registry()
		.with(tracing_subscriber::fmt::layer().with_writer(indicatif_layer.get_stderr_writer()))
		.with(indicatif_layer)
		.init();

	let handles = (0..256)
		.map(|_| {
			std::thread::spawn(move || {
				let _span = tracing::info_span!("ch").entered();
			})
		})
		.collect::<Vec<_>>();
	handles.into_iter().for_each(|i| i.join().unwrap());
}

Bad behavior if current progress bar is longer than terminal is wide

Really love using tracing-indicatif - ever since adding it in boinkor-net/deploy-flake#177. Unfortunately, I'm noticing one weird behavior in terminal windows that can't fit the entirety of a progress line: If multiple spans are active, and the parent span has a progress spinner, instead of getting updated in-place, it scrolls away.

This is probably easier to show in a video than to explain in words:

Screen.Recording.2023-02-28.at.21.28.23.mov

As you can see there, the "build" span is actively working (and it's longer than the terminal is wide), and every time the progress spinner ticks forward, the parent span's progress bar scrolls off by one line.

If I make the terminal wide enough to fit the line, that behavior stops; but it would be nice if tracing-indicatif could accommodate tighter spaces better.

How to log progress bar to file

Hi, nice work! This crate saved my day😀.
Could I use this crate to record progress bar in log file? I didn't find any way to make it neither through the documents, nor from the source code. Could u please give me some advice? Thanks 🙏🏻

This project is really nice

I've added tracing-indicatif to an internal tool recently and it's so simple and so useful

Peek.2023-08-31.20-15.3.webm

I don't even need to write custom slow file tracking tooling anymore, i can just watch and see which entries are slow, i get to see the configuration live and even logging while using a progress bar just works!