ClimaTimeSteppers.jl icon indicating copy to clipboard operation
ClimaTimeSteppers.jl copied to clipboard

Add Progress Bar

Open dennisYatunin opened this issue 2 years ago • 6 comments

Purpose

This PR adds progress bar callbacks to ClimaTimeSteppers.jl.

Content

The specific callbacks implemented here are BasicProgressCallback and TerminalProgressCallback. The first one is designed for use with non-overwritable output streams (e.g., log files), so it just incrementally appends block characters to the end of the progress bar. The second is designed for use with UNIX terminals, so it overwrites the progress bar on every update; this allows it to also print an estimate of the estimated time remaining, as well as an optional user-specified message.

This PR also includes documentation and unit tests for both callbacks. Each unit test is run twice—once as a demonstration that uses stdout as the output stream, and once as an actual unit test that uses an IOBuffer.


  • [x] I have read and checked the items on the review checklist.

dennisYatunin avatar Dec 02 '22 00:12 dennisYatunin

@charleskawczynski I've added docstrings and extended the unit tests to also act as demos. Is this good now?

dennisYatunin avatar Dec 05 '22 23:12 dennisYatunin

@charleskawczynski I've added docstrings and extended the unit tests to also act as demos. Is this good now?

Thanks, I think the doc string looks good. The demo looks like it prints several lines between progress prints, I think I'd prefer if we made this a bit more compact

charleskawczynski avatar Dec 06 '22 00:12 charleskawczynski

I don't think the demo prints anything in between progress prints. It prints the basic progress bar, then prints the terminal progress bar (which is cleared when the integrator finishes), and then prints the same two things for a time-reversed integrator.

dennisYatunin avatar Dec 06 '22 00:12 dennisYatunin

I tried running this in ClimaAtmos locally with progress = true, and this is what I'm seeing:

ode_configuration: 0.422692 seconds (541.83 k allocations: 31.395 MiB, 97.27% compilation time)
get_callbacks: 0.416607 seconds (587.56 k allocations: 32.087 MiB, 99.91% compilation time)
Define problem: 12.030750 seconds (2.57 M allocations: 138.597 MiB, 99.82% compilation time)
args_integrator: 13.725587 seconds (5.92 M allocations: 327.233 MiB, 0.54% gc time, 99.82% compilation time)
Progress: ▐                                                                                                         ▌ 0.0%
Time Remaining: 
Define integrator: 8.366946 seconds (6.55 M allocations: 391.092 MiB, 0.77% gc time, 99.81% compilation time)
get_integrator: 12.712724 seconds (16.84 M allocations: 944.312 MiB, 1.40% gc time, 99.87% compilation time)
┌ Info: Running
│   job_id = ""
Progress: ▐█████████████████████████                                                                                ▌ 24.1%
Time Remaining: 2 minutes, 29 seconds

On the main branch, I see:

get_callbacks: 0.328151 seconds (587.50 k allocations: 32.082 MiB, 99.87% compilation time)
Define problem: 11.114446 seconds (2.55 M allocations: 138.330 MiB, 99.81% compilation time)
args_integrator: 12.483061 seconds (5.85 M allocations: 324.974 MiB, 0.60% gc time, 99.80% compilation time)
Define integrator: 7.640386 seconds (6.52 M allocations: 388.700 MiB, 0.75% gc time, 99.85% compilation time)
get_integrator: 11.338884 seconds (15.04 M allocations: 979.940 MiB, 1.70% gc time, 99.90% compilation time)
┌ Info: Running
│   job_id = ""
│   output_dir = "output/"
└   tspan = (0.0f0, 864000.0f0)
218.553134 seconds (277.44 M allocations: 10.755 GiB, 2.31% gc time, 12.92% compilation time)

So, it looks like this is unintentionally deleting characters/lines.

charleskawczynski avatar Dec 08 '22 16:12 charleskawczynski

I think, to more precisely test this code, it needs to be broken down into smaller functions, so that we can unit test those functions.

charleskawczynski avatar Dec 08 '22 16:12 charleskawczynski

@charleskawczynski The progress bar isn't designed to work correctly when users arbitrarily print things while the progress bar is running. The OrdinaryDiffEq progress bar also doesn't work correctly in that situation, and I'm not sure what it would even mean for a progress bar to work correctly in that situation. I've made it so that users can print things under the TerminalProgressBar by passing a custom_message function, which is already more than what's available in OrdinaryDiffEq, but that's not the same thing as being able to call @info throughout the code. If you want to use a progress bar while also calling @info everywhere, maybe try having the logger put the results of @info into a log file while the progress bar displays in the terminal, or vice versa?

Eventually, if people like using this progress bar, we could have @info append to the output of custom_message when using a TerminalProgressBar, but that's a project for another time.

dennisYatunin avatar Dec 08 '22 22:12 dennisYatunin