console-rs / indicatif

A command line progress reporting library for Rust
MIT License
4.43k stars 243 forks source link

Odd Clear Behavior in yarnish and multi example #451

Closed mitsuhiko closed 1 year ago

mitsuhiko commented 2 years ago

This seems like a regression from what I remember. The yarnish example has 4 virtual concurrent build spinners and once they are done, three print out waiting... and one is cleared resulting in this:

[1/4] 🔍  Resolving packages...
[2/4] 🚚  Fetching packages...
[3/4] 🔗  Linking dependencies...
[4/4] 📃  Building fresh packages...
[1/?]   waiting...
[2/?]   waiting...
[3/?]   waiting...
✨  Done in 13 seconds

I expected either none of them to show up or all 4.

Likewise I think there is a bug in the multi example where one retains the bar:

starting!
pb1 is done!
[00:00:02] ########################################     128/128     done
pb3 is done!
pb2 is done!

Tested on 39ebd5faa898c5ab802e4ad79dcddb0224d14101. Both of those examples use the multi bar clear function.

mitsuhiko commented 2 years ago

I bisected it down on the yarnish example. First run claimed 1d47e1dbd57bf4013e36bda3eed6a1e9f068a6b6 to be the regression but clearly some flakiness caused the bisect to isolate the wrong one.

A few reruns showed 0f33289ecb258e31ff86cb8c3d9228268cd84dd6 (fix for #426) to be the issue. The commit before that seems to work fine still.

mitsuhiko commented 2 years ago

I think that belongs to https://github.com/console-rs/indicatif/pull/438 but I'm not entirely sure. There is no clear merge commit mentioning the PR.

djc commented 2 years ago

Yes, it's #438.

chris-laplante commented 2 years ago

I'll take a look.

chris-laplante commented 2 years ago

What's strange is that if you add a call to drop(pb) after the call to finish_with_message, after: https://github.com/console-rs/indicatif/blob/20a857a4ee42e29664e5fd1259b72a5563add8bd/examples/yarnish.rs#L87

then it works as expected. I would have thought that pb would automatically get dropped when scope/closure the thread is executing is done, right? So I don't understand why the drop makes a difference.

mitsuhiko commented 2 years ago

I cannot reproduce that it works as expected. This is fundamentally some sort of race condition so every once in a while it works when you run it. Potentially you just had a few lucky runs.

chris-laplante commented 2 years ago

Hah, sure enough I re-ran it and you're right :/.

chris-laplante commented 2 years ago

The issue here is that the zombie pruning code I added changed the semantics of MultiProgress. Previously, MultiProgress never forgot about progress bars (unless you MultiProgress::removed them). That's true even if you call finish (or friends) on the ProgressBars. Zombie pruning taught MultiProgress to forget about progress bars that don't exist anymore (because they got dropped). Because of this, clear no longer clears those dropped ProgressBars.

The yarnish example is acting non-deterministically because the order in which those 4 pbs are dropped is random. Zombie pruning (and adjustment of last_line_count) happens in MultiState::draw, but MultiState::clear doesn't use draw. I haven't traced through exactly what is happening, but I don't think I'll bother because I have a proposition.

I now see that zombie pruning changes the behavior of MultiProgress in unintended ways. I'd like to propose turning off zombie handling by default, and making it an option you can set on MultiProgress. For example, MultiProgress:set_reap_zombies(True). If zombie reaping is enabled, I'd also propose making MultiProgress::clear an illegal operation. It doesn't make sense to call clear on a MultiProgress that can't necessarily clear everything it was responsible for drawing. If a user utilizing MultiProgress in zombie reap mode needs to clear pbs, then they are responsible for not letting those pbs becomes zombies in the first place.

(Here's how you could write the yarnish example using zombie reaping by the way: https://github.com/chris-laplante/indicatif/commit/98478c664ef142cb2aee547b82aa5598d95c8659#diff-23742e02d3318a218c4777f365fd16cd606fb46a7770c9433a4a9ec46d98f655)

What do you think?

djc commented 2 years ago

To restate the reason for introducing zombie reaping in the first place (from #426):

Since we never call MultiProgress::remove on ProgressBars that are dropped/finished (see #419), bars are always redrawn even when they don't need to be. When the number of bars (n) becomes greater than terminal lines (m), on each draw MultiProgress will clear the last m lines but write n lines, leaving m - n lines in the scrollback history.

So could we get the terminal height from console and only reap once we run out of lines instead of requiring extra configuration/setup from the user?

mitsuhiko commented 2 years ago

To me it seems at least that this keeping track in to_clear and manually invoking finish_and_clear is something that the MultiProgress could do automatically itself?

chris-laplante commented 2 years ago

So could we get the terminal height from console and only reap once we run out of lines instead of requiring extra configuration/setup from the user?

Personally I'd rather not deal with console height if we don't have to, since the user can resize the terminal whenever they want and mess us up. I think even if we did something based on height, it still wouldn't fix clear. Once a pb has been reaped MultiProgress has lost track of it. Regardless of when that happens, clear won't be able to touch it.

chris-laplante commented 2 years ago

To me it seems at least that this keeping track in to_clear and manually invoking finish_and_clear is something that the MultiProgress could do automatically itself?

I think this is on the right track. MultiProgress should keep track of previously-reaped progress bars. The last number of lines that were printed is enough. Then clear just has to also clear that number in addition to whatever is being displayed by the currently active set.

One wrinkle: calling MultiProgress::println should reset the reaped line counter to 0, since clear can't erase lines above the printed message without also erasing the message itself. We should do it for MultiProgress::suspend too - making the assumption that the user wrote something to the terminal during the suspend.

chris-laplante commented 2 years ago

I did some more digging on this today. I think I can fix the zombie reaping so that MultiProgress::clear works well, with a caveat. Previously you could do a draw operation after a clear (e.g. just a tick on some pb that's part of the MultiProgress) and it would be able to reconstitute everything, including stuff that had been dropped. Now that zombie reaping is a thing, that re-draw will only be able to re-draw what hasn't been reaped.

Also, I think I can more clearly characterize the interaction between reaping and MultiProgress::println. println will be able to print lines above anything that hasn't been reaped. I don't foresee this as an issue because MultiProgress::println is new for 0.17.0 anyway. What do you think? Are these limitations ok?

chris-laplante commented 2 years ago

@djc @mitsuhiko thoughts on above?

mitsuhiko commented 2 years ago

I think it makes sense.

djc commented 2 years ago

I did some more digging on this today. I think I can fix the zombie reaping so that MultiProgress::clear works well, with a caveat. Previously you could do a draw operation after a clear (e.g. just a tick on some pb that's part of the MultiProgress) and it would be able to reconstitute everything, including stuff that had been dropped. Now that zombie reaping is a thing, that re-draw will only be able to re-draw what hasn't been reaped.

This seems to make sense -- remind me what the criteria for getting reaped again? Does it even make sense to tick something in a state where it can be reaped?

Also, I think I can more clearly characterize the interaction between reaping and MultiProgress::println. println will be able to print lines above anything that hasn't been reaped. I don't foresee this as an issue because MultiProgress::println is new for 0.17.0 anyway. What do you think? Are these limitations ok?

Seems fine!

chris-laplante commented 2 years ago

This seems to make sense -- remind me what the criteria for getting reaped again? Does it even make sense to tick something in a state where it can be reaped?

A progress bar becomes a zombie when it is droped. So you will never be able to tick it after that, no.

chris-laplante commented 2 years ago

Hi @mitsuhiko - when you get a chance, can you please re-test with main?

mitsuhiko commented 1 year ago

This seems to be resolved.