Progressbar: Integration with Julia's logging interface

[FedeClaudi]

Followup on discussion started in #51 by ChrisRackauckas, see here

From Chris:

It's just how the info is handled, not how it's printed. For example, OrdinaryDiffEq.jl can do this:
https://github.com/SciML/OrdinaryDiffEq.jl/blob/e06e744b2e290170154890dd3ecb075e77b2fe5f/src/integrators/integrator_utils.jl#L129-L135
which emits logging information for a progress bar named OrdinaryDiffEq (i.e. for multiple concurrent progress bars) without having a dependency on any of the progress monitoring packages. That is then picked up in Juno, VS Code, ProgressLogging.jl, etc.

Thanks for the additional info Chris. I think this reflects my ignorance about Julia's ecosystem more than anything else, but I'm still confused:

1. How does that line you've linked to produce a progress bar? I thought @logmsg produced a single message.
2. How/when/where is the progress bar update?
3. How could one set how the progress bar looks?
4. is the progress bar actually printed to terminal or just logged to file?. You say "which emits logging information for a progress bar" and the logging level is -1 which makes me think that the progress bar is not actually shown to the user.

4 is the crucial point. Progressbars should be logged nicely, but the core feature is to show progress to the user, in real time. From what I can see what you're suggesting doesn't do that.

That is then picked up in Juno, VS Code, ProgressLogging.jl,

Again, my ignorance: what do Juno, VS Code and ProgressLogging do in this context exactly?

As mentioned in the issue discussion linked above, I need a progressbar capable of handling:

1. progress bars with multiple layouts and Term's styling
2. progressbars updated asynchronously from ongoing tasks: if you have something that does 10 iterations but each takes 5 minutes then you want a column shown elapsed time to be updated continunously, not once every 5 minutes.
3. Something capable of handling multiple progress bar related to distinct tasks (e.g. nested loops). Not only that, one should be able to add, start, pause and stop progress bars independently as required. As @pdimens and [Feature Request] Multiple progress bars #54 have reported this is a feature people (and I) want to be able to use.

all of which should render nicely in the terminal. So far nothing of what I've seen suggests that Julia's built-in interface (for logging or for progress bars?) can handle all of this. As mentioned I'm happy to conform if there's an infrastructure capable of handling Term's needs, but I won't sacrifice functionality otherwise.

Ps.: Can you provide an image of what the output from the line you've linked to looks like (in the terminal and a in a log file)?

[ChrisRackauckas]

How does that line you've linked to produce a progress bar? I thought @logmsg produced a single message.

It doesn't produce a progress bar. That's exactly the thing: progress bars should not be also defining the data format. This is just throwing a logging message that is then picked up by all of the progress bar packages that are used (but not the old deprecated ones like ProgressMeter.jl)

How/when/where is the progress bar update?

@pfitzseb would know this.

How could one set how the progress bar looks?

That's for the user of the progress bar, not the package emitting progress bar information. Why would the ODE solver be choosing for a user whether to emit to the terminal or VS Code? Why would an ODE solver have to know that VS Code is a thing that exists? It's a separation of concerns.

is the progress bar actually printed to terminal or just logged to file?

One, both, or neither. The ODE solver doesn't care. That's for the front end to choose.

[FedeClaudi]

I think I'm starting to get it more, and it's potentially very useful. But I still have some questions (though you mentioned perhaps someone else should answer them):

1. how/what picks up the @logmsg and decides to create a progress bar out of it? I.e. how do you choose if it should be Term or another package?
2. How/when/where is the progress bar update? (repeated). This is crucial, Term has a lot of code that handles its own internals to create/update progress bars (possible with multiple bars) and this should happened asynchronously from other code. Term should have complete control over when and how the progress info is displayed.

That's for the user of the progress bar, not the package emitting progress bar information.

This is were you start to loose me. A key feature of Term's progress bars are that they're highly customizible. There's several preset styles/column types but you can create your own to customize the progress bars for your application. Perhaps an ODE solvers wants to display specific types of information. I don't know much about how ODEs are solved under the hood, but you can imagine wanting to show something like objective function value or some other information about what's happening under the hood. Indeed perhaps you want to allow the users to choose how much detail they want to see and create different progress bar visualizations accordingly. Another package might want to display download file size/speed etc... It's not clear to me that going through @logmsg gives you this kind of flexibility.

Why would the ODE solver be choosing for a user whether to emit to the terminal or VS Code?

And here is where I'm completely lost. What do you mean to emit to VS Code? To it's embedded Julia REPL? Progress bars in term will show wherever STDOUT (or another IO) goes. The user or your package don't have to care about that? Ultimately the visualization calls print to show the progress bar, handling where the progress bar shows shouldn't give any more work than deciding where stuff gets printed.

Thanks for the help and info.

[ChrisRackauckas]

I don't know much about how ODEs are solved under the hood, but you can imagine wanting to show something like objective function value or some other information about what's happening under the hood. Indeed perhaps you want to allow the users to choose how much detail they want to see and create different progress bar visualizations accordingly. It's not clear to me that going through @logmsg gives you this kind of flexibility.

That's part of the message in the logging info https://github.com/SciML/OrdinaryDiffEq.jl/blob/master/src/integrators/integrator_utils.jl#L235. It's then up to the package picking up the logging info how to actually display that.

And here is where I'm completely lost. What do you mean to emit to VS Code? To it's embedded Julia REPL?

No, it, like Juno, has a progress bar built into it. It captures the logging information and redirects it away from the REPL and to this bar in the window unless the user says to change the logging frontend.

[pfitzseb]

Did you take a look at the ProgressLogging docs? We're basically (ab)using the logging interface to decouple progress bar updates from the rendering. VS Code runs all user code with its own logger, which special cases ProgressLogging log-messages and pipes everything else through to the global/parent logger.

[FedeClaudi]

Did you take a look at the ProgressLogging docs?

I did, but there's not much as far as docs go beyond the few lines that are also in the README. There's one minimal example and no display of what the output is or any explanation of what's happening under the hood (or other ways in which the package can be used).

How am I to understand "We're basically (ab)using the logging interface to decouple progress bar updates from the rendering." from that? How would one know how to personalize the display or integrate ProgressLogging with another library?

@ChrisRackauckas

That's part of the message in the logging

As far as I can tell ODE_DEFAULT_PROG_MESSAGE returns a string? How is the message updated? When? Term's progressbars can be customized so there needs to be a way for users to provide much more than just a string.

No, it, like Juno, has a progress bar built into it. It captures the logging information and redirects it away from the REPL and to this bar in the window unless the user says to change the logging frontend.

I see, that seems useful indeed. I haven't used Juno yet bot one day I will make sure Term works on it. For now this wouldn't be possible with Term.

---

I thank you both for your time, but it seems to me like this is not going to work out.
Term needs to do so much more than logging a simple progress bar. You can have multiple nested progress bars, you can choose which columns to use, how they look or you can create your own custom ones... I don't see how going through the logging infrastructure enables this (though I'm happy to be corrected).

E.g. this code in Term:

    pbar = ProgressBar(; refresh_rate=60, expand=false, width=150)
    outer = addjob!(pbar; N=3, description="outer")

    start!(pbar)
    for i in 1:3
        inner = addjob!(pbar, N=100, description="inner $i")
        for j in 1:100
            update!(inner)
            sleep(0.005)
        end

        update!(outer)
        removejob!(pbar, inner)
        sleep(0.02)
    end
    stop!(pbar)

Has one main progress bar for the outer loop and other ones for the inner loops which are spawned/deleted as necessary, while this creates 3 progress bars that are updated simultaneously but finish at different times:

    pbar = ProgressBar(; refresh_rate=60, expand=false, width=150)
    j1 = addjob!(pbar; N=50, description="First")
    j2 = addjob!(pbar; N=75, description="Second")
    j3 = addjob!(pbar; N=100, description="Third")

    for i in 1:100
        update!(j1)
        update!(j2)
        update!(j3)
        sleep(0.005)
    end
    stop!(pbar)

I just don't understand how you would achieve this kind of control with the things you're suggesting. I suppose in the end if all you want is a simple progressbar then all this overhead is unnecessary (though Term also has a track function that creates a progress bar for any loop/iterable). If you care about how the progressbar looks or then it's worth it. It would required an additional dependency for your package and some code to handle the progressbars, but in my opinion it's worth it (and Term can do so much more than progress bars. For an ODE solver it can create a styled summary message with all the info one wants).
This means it can't use Juno or VS Code's built in progress bars interfaces I suppose? I'm fine with that.

[pfitzseb]

I don't quite see why any of that wouldn't be possible with the ProgressLogging infrastructure. TerminalLoggers.jl is another frontend for it and you'd write your examples as e.g.

julia> using Logging, ProgressLogging, TerminalLoggers, UUIDs

julia> global_logger(TerminalLoggers.TerminalLogger());

julia> @progress for i in 1:10
         @progress name = "iter $i" for j in 1:10
           sleep(0.1)
         end
       end
  iter 1 100%|█████████████████████████████████████████████████████| Time: 0:00:01
  iter 2 100%|█████████████████████████████████████████████████████| Time: 0:00:01
  iter 3 100%|█████████████████████████████████████████████████████| Time: 0:00:01
  iter 4 100%|█████████████████████████████████████████████████████| Time: 0:00:01
  iter 5 100%|█████████████████████████████████████████████████████| Time: 0:00:01
  iter 6 100%|█████████████████████████████████████████████████████| Time: 0:00:01
  iter 7 100%|█████████████████████████████████████████████████████| Time: 0:00:01
  iter 8 100%|█████████████████████████████████████████████████████| Time: 0:00:01
  iter 9 100%|█████████████████████████████████████████████████████| Time: 0:00:01
  iter 10 100%|████████████████████████████████████████████████████| Time: 0:00:01
Progress: 100%|████████████████████████████████████████████████████| Time: 0:00:11

julia> id1, id2, id3 = uuid4(), uuid4(), uuid4();
       for i in 1:100
           @info ProgressLogging.Progress(id1, min(i/50, 1), name="first")
           @info ProgressLogging.Progress(id2, min(i/75, 1), name="second")
           @info ProgressLogging.Progress(id3, min(i/100, 1), name="third")
           sleep(0.005)
       end
       @info ProgressLogging.Progress(id1, done=true)
       @info ProgressLogging.Progress(id2, done=true)
       @info ProgressLogging.Progress(id3, done=true)
first 100%|████████████████████████████████████████████████████████| Time: 0:00:00
second 100%|███████████████████████████████████████████████████████| Time: 0:00:00
third 100%|████████████████████████████████████████████████████████| Time: 0:00:00

[FedeClaudi]

I think I'm starting to understand more now, thank you. I would have to replace ProgressLogging.Progress with whatever I want in Term and this should return a type instance for which I write a custom handle_message method to interface with the logging machinery?

I think that could work, but I don't think I like it, for several reasons:

1. as you say this is abusing the logging syntax, I don't like that. I don't like the syntax of the second example at all.
2. if for every update I need to create a new instance (e.g. of Progress in the example) that seems very wasteful. Creating the styled display in Term takes some work but this is only done once when a new progressbar is created. Updates require minimal work. Having to create a new object all the time is a shame.
3. I don't like that you have to set the global_logger, this would conflict with Term's logging functionality

Also I couldn't get it to work in VS Code, it shows this at the bottom instead of printing to the console. I think this is what @ChrisRackauckas was referring to above, but this is emphatically not what I would like to happen with Term:

)
it looks fine in the REPL, but the whole point of Term is that the user chooses how the progressbar should look like, so I don't want other applications to mess around with it? Again, if you don't care about this then Term is not for you, but if you do then this system won't work.

Also, a slight change to the example messes everything up:

using UUIDs

id1, id2, id3 = uuid4(), uuid4(), uuid4();
    for i in 1:100
        i % 25 == 0 && @info ProgressLogging.Progress(id1, min(i/50, 1), name="first")
        @info ProgressLogging.Progress(id2, min(i/75, 1), name="second")
        @info ProgressLogging.Progress(id3, min(i/100, 1), name="third")
        sleep(0.005)
    end
    @info ProgressLogging.Progress(id1, done=true)
    @info ProgressLogging.Progress(id2, done=true)
@info ProgressLogging.Progress(id3, done=true)

The first bar now should be updated more rarely, but it should still be visible, when I try it in the REPL it disappears when it's not updated, this is decidedly not what I want to happen. Also, this would mean that progressbars are updated only when@info is used, again I don't want to happen. In Term progressbars are updated asynchronously in a dedicated task and all bars are shown correctly regardless of which/when they get updated.

[pfitzseb]

1. You're free to expose whatever syntax you want. Logging is the transport mechanism.
2. Creating Progress instances is cheap (free when compared to IO etc); there's also a legacy syntax that uses plain kwargs.
3. I mean, that's the user's choice. Term.install_term_logger() does the same, no? So you could just make the log message handling part of your own logger.

Also I couldn't get it to work in VS Code, it shows this at the bottom instead of printing to the console.

There's a setting for that; VS Code is currently fairly intrusive in that it inserts itself between the global logger and user code (which can of course be circumvented via with_logger).

Also, a slight change to the example messes everything up:

It doesn't, really. The progress meter is only created once the first @info is called, so just start iterating from 0 (that way the condition is true on the first iteration) or insert additional statements before the loop or whatever else you fancy.

Also, this would mean that progressbars are updated only when@info is used, again I don't want to happen. In Term progressbars are updated asynchronously in a dedicated task and all bars are shown correctly regardless of which/when they get updated.

What does that mean? You also have explicit statements for updating progress (update!, apparently); whether those do something in some async task or emit a log message doesn't really matter, does it?

---

Anyways, I think you're looking at this from the wrong perspective -- seems to me that the important part is for Term to be able to act as a progress frontend, so that library authors can write frontend-independent logging code.

[FedeClaudi]

Okay I think I finally understand. I really appreciate both of you taking the time to walk me through this, now I should spend some time thinking about it and mess around with progress bars.

I still have some reserves about going through the logging interface and having to set a global logger, but if I find a way to have all of term's features and a nice syntax I think it should be doable.

Thanks again, I'll keep you posted

[pfitzseb]

having to set a global logger

That's not any different from https://fedeclaudi.github.io/Term.jl/dev/adv/logging/?

[FedeClaudi]

yeah but that's specifically if you want Term's logging stuff. If you just want a progress bar you don't have to do that.

[mkschleg]

I feel like you should be able to have both functionalities. If you use Term's logging stuff, you can then use ProgressLogging, if not a user can still choose to use your loggers independently by hand. I see all the logging backends as buying into someone's ecosystem for my logging needs, less as a piecemeal combination of things. Really, I want to use Term.jl's logger but can't because I have code that I will run in Pluto, VSCode, and on the terminal in different scenarios. Having to write progress bar logic for each is not something I can/want to do (before ProgressLogging.jl I just accepted progress bars only on the terminal).

Just my 2 cents though.

[FedeClaudi]

I want to use Term.jl's logger but can't because I have code that I will run in Pluto, VSCode, and on the terminal in different scenarios

I haven't tested Juno, but the logger works equally in the REPL and in VS Code.

Having to write progress bar logic for each is not something I can/want

That's separate from logging? It seems to be that there's a conflation between logging stuff and having a progress bar. To me, a progress bar only makes sense in a terminal (be it REPL, VS Code's version of the REPL or something else in Juno) as a visual display to update the user about progress. For me logging is more about the package's internals and I would not normally expect my software to show logging messages unless something went wrong.

Having to write progress bar logic for each is not something I can/want to do

Why would you have to do that? When you call print do you need to implement different logic based on where you are? Term's progress bar is just a clever way to print/erase/re-print text to the console to give the illusion of a progress bar. The same exact code works exactly the same in VS Code as in the REPL.

In fact, as per @pfitzseb's comment:

There's a setting for that; VS Code is currently fairly intrusive in that it inserts itself between the global logger and user code (which can of course be circumvented via with_logger).

it's with the logging system that you need extra care based on what you're using to run your code.

[FedeClaudi]

From @pfitzseb previous comment:

Anyways, I think you're looking at this from the wrong perspective -- seems to me that the important part is for Term to be able to act as a progress frontend, so that library authors can write frontend-independent logging code.

Wait, let me see if I understand correctly. You mean that the package developer does not specify what the progress bar should look like, just that there should be one, and then the user can choose to use Term or another library to visualize the progress bar? If that's the case I previously misunderstood what you meant.
So you'd write something like this (from OrdinaryDiffEq):

 if integrator.opts.progress
    @logmsg(LogLevel(-1),
    integrator.opts.progress_name,
    _id = :OrdinaryDiffEq,
    message=integrator.opts.progress_message(integrator.dt,integrator.u,integrator.p,integrator.t),
    progress="done")
  end

and what the progressbar looks like depends on what "progressbar rendering package" the user has? That's cool I guess, I can see the benefit in that. It's something that Term should do, be one of the "rendering packages" a downstream user can use.

But a core feature of Term in general and the progressbars in particular is customization and being able to create beautiful terminal output, which inevitably involves specifying what the bar should look like using Term. So I think Term should do that, align with the original suggestion of @ChrisRackauckas but also have it's own logging API for users that want more control and don't want to use the logging system (which I realize now is probably what @mkschleg suggested earlier).

I still don't understand the whole think about having to write different logic based on where the code's running. That's beyond me. But I think if understand how to do it I will implement the recomended behavior too.

[mkschleg]

Yes. Maybe a better example of needing different logic for different frontends is in a Pluto notebook. Progress bars designed for the terminal don't work in a Pluto notebook. They should show up in the terminal, but when i'm working with a notebook I don't really want to have to also know where the associated terminal is (usually in a tmux session on another computer that I'm detached from).

[FedeClaudi]

Gotcha. My bias against notebooks shows here I guess, I'd like to stay away from them as much as possible...

But I guess in the end Term will support the infrastructure proposed above too, so we all get what we want. Thanks everyone for the input!

[mkschleg]

Given your previous message, maybe there are two (or three) packages in this one package that could be useful to split apart?

1. You have the features "to create beautiful terminal output",
2. an associated logger which takes advantage of those features,
3. (?) and eventually an exception renderer.

The logic to respond to messages from ProgressLogging would be in 2, but the actual progress bar rendering code would be 1. If someone wanted more customization for progress bars they can use 1, while those who want your progress bars to also show up as a downstream renderer in the logging system can use 2.

It is also possible that you could hijack some functionality when message passing in ProgressLogging to make your progress bars even more customizable than others. Idk how that would work, but something that could be iterated on independently from 1 and possibly in collaboration w/ other logging renderers.

[mkschleg]

Yeah. My workflow is mostly terminal, but I also do a lot of data analysis and exploration which is easier for me in notebooks.

[FedeClaudi]

Yeah. My workflow is mostly terminal, but I also do a lot of data analysis and exploration which is easier for me in notebooks.

Fair

I won't be splitting Term up. Perhaps one day one can make a lightweight version for specific needs, but for the time being Term will be a single thing.

[FedeClaudi]

Hey everyone,

I've got basic integration with ProgressLogging to work:

using ProgressLogging
using Term
install_term_logger()


@progress for i in  1:100
    sleep(0.01)
end

and

for i in 1:60
    @info ProgressLogging.Progress(id1, min(i/60, 1), name="first")
    i % 10 == 0 && println("test")
    sleep(0.001)
end

give a progressbar sticking to the bottom of the terminal:

It's not great, it doesn't handle multiple bars for instance.

This functionality is there for people who will want to use ProgressLogging and Term, but the docs will explicitly discourage this option and recommend using Term's API directly. Term's API is a lot more powerful and efficient so that will be the best way to handle progressbars. With a bunch more work one could integrate the two more completely, similarly to what's done in TerminalLoggers, but this would required more effort than I'm willing to put into this. As I said I don't like, at all, having to go through the logging system to produce progress bars. Especially so since in VS Code you need to do extra steps to even get it to work.

However, hopefully the minimal working functionality (in terms of integration with ProgressLoggin) could be a starting point for someone interested in working on this, I'm happy to have anyone contribute this functionality to Term.

[FedeClaudi]

I couldn't help myself, I had to make it better before release. Now you can use nested @progress and ProgressLogging.Progress statements and they will render correctly as multiple progressbars:

@progress "outer...." for i in 1:6
    @progress "inner... $i" for j in  1:100
        sleep(0.01)
    end
end

[kescobo]

This is late to the game, and maybe more motivation isn't required, but another benefit of using the Logging interface that would be critical to many of my applications is that I would want to be able to use things like TeeLoggers from LoggingExtras.jl in order to have both a log file generated as well as terminal-based displays.

[FedeClaudi]

I see, good to know.

It should work although I don't use these systems so testing from someone more experienced will be crucial.

To be honest though, I still don't get why you'd want to log progress bars to a file, I've always seen them as as a temporary display to calm my impatience but not something I'd need to go check at a later time. Nonetheless, Term is not for me but for the community so as it seems that this is a sought after feature it will be there.

[kescobo]

No - agree progress bars to a file does not make sense. I'm more thinking in the context of other logging functionality.

[chudayroi]

let me review. thank you