Add progress monitor

[epruesse]

As promised in #854 I had a go at adding a progress monitor to spdlog.

See https://github.com/epruesse/SINA/blob/dev/src/progress.h

It needs cleanup, but it works. I considered a few options, including using fopencookie to create a custom FILE* and receiving writes from ansicolor_sink. Instead, I ended up creating a terminal_sink that expects TargetStream to not just understand ANSI color codes, but also move cursor up (ESC [ A) and clear line (ESC [ K).

terminal_sink allows registering persistent status_msg objects which are always shown at the bottom below the latest log message. Every time a log message is printed, these messages are re-rendered (which would allow other use cases as well - e.g. showing system usage data). The status_msg itself can also trigger a re-render.

logger_progress is then a progress monitor class that given a logger will maintain itself as a status_msg for applicable sinks on the logger during its lifetime. So to show a progress logger, you'd do:

int count=800000;
{
  logger_progress monitor(spdlog_logger, "Doing something fast", count);
  for (int i = 0; i < count; ++i) {
     monitor++;
     spdlog_logger->info("did something");
  }
}

Additional options set the log level to something other than info, tell the monitor to use plain ascii characters instead of unicode bars and set a width.

Caveats: I did have to patch spdlog:

• un-final the ansi-color sink to derive from it
• make target_file_ and mutex_ be protected rather than private
• turn console_mutex::mutex_t into a std::recursive_mutex.

And yes ... it's using dynamic_cast and plenty virtuals and probably made the assembly look horrific. It's still fast though. I borrowed some tricks from the python tqdm package -only re-rendering the status after a minimum time and guessing at that from the typical number of iterations. That way, the 'hot' part of logger_progress.update(int) doesn't take many cycles to decide that it won't need to do anything.

Right now it just picks up the terminal width at startup - technically it should listen to SIGWINCH and re-render to match the new terminal size. Its working for my purposes at this point though. (edit 3/28/19 - implemented)

Would you be interested in a PR?

[gabime]

Congrats, this looks really really awesome!
I am mot sure i'm ready to merge it yet. Lets wait a while and see if there is demand and also give this code time to mature and clean (also, could you try to avoid the recursive mutex?).

[epruesse]

Perhaps focus first on the status_msg interface part only. That's a smaller piece of code, and the bit interacting with spdlog and currently necessitating the patch.

• I can replace the recursive lock either with an additional lock or by adding a lock-free ansicolor_sink::log_unguarded() function. Which would you prefer?
• What's the best way to derive from ansicolor_sink? I'm not sure what the performance impact of not having it final is in practice.

Is the general design OK with you? Focussing on just the terminal_sink and status_msg parts would make for a quicker PR. The rest can even stay a separate project if you prefer.

[mvala]

+1

[ghost]

this is really nice

[gabime]

Closing. Although very nice, this feature doesn't fit well in a log library imo.
Thanks @epruesse

[epruesse]

@gabime I can make it a separate lib to be added on top of spdlog. I do need some way of subclassing the ansicolor sink though. Any chance of having an intermediate class that isn't final?

[epruesse]

The alternative is copying that sink I suppose.

[epruesse]

(Keeping it separate is probably the best way indeed. If I look at other implementations, whether it's boost progress/logging or python tqdm/logging or others, it's usually distinct pieces of code)

[gabime]

Copy paste is your friend. Especially in this case, where a progress sink isn't really a color sink, but something else indeed.

[pwm1234]

@epruesse This looks really nice! Do you have any plans to make a separate progress class or should I just copy/paste from https://github.com/epruesse/SINA/blob/dev/src/progress.h? I am a big fan the python version of tqdm, but the C++ port does not seem to have much to it. I am also a big fan of spdlog, so having the two together looks really awesome. I do, however, see how gabime thinks it is best to leave it out of the core spdlog codebase. But what about a separate repo like https://github.com/guangie88/spdlog_setup?

@gabime perhaps a separate spdlog_contrib or extensions repo for add-ons like this that could be quite helpful but are not part of your core purpose for spdlog? Just a thought. Thanks to both of you for your contributions.

[epruesse]

@pwm1234 You can't just copy paste that file - I patched some parts of spdlog. As Gabi said, I'll have to do some copy pasting. Yes, I'm planning to create a repo for that. Give me a few weeks to fit that in.

[pwm1234]

Great! Can you please update this issue with the url for the repo when you have made it? (I am subscribed to this issue so I should get an email--I do not want to miss it!)

[michalber]

Hi everyone!
Long time since last post but I was inspired by @epruesse and created separate repo containing progress monitor. Also I have made some improvments to the code. Feel free to check it out:
https://github.com/michalber/spdmon

[gabime]

Looking good.
Could you elaborate more about it ? Is the idea is to create a temporary spdmon::LoggerProgress monitor object that wrap a logger, perform the progress bar and then discard it and continue with the original logger ?

[epruesse]

From memory, not having looked at the new code yet: The usage is like boost program monitor or python tqdm. You create a progress monitor as an object with the logger as argument. As long as this exists, a status bar with the progress bar as content will be displayed as the bottom most row. The progress monitor object can then be incremented. Fast code avoids doing anything if the last update was recent, so this doesn't cost too much in tight loops. You can create multiple of these, e.g. in hierarchical loops. They disappear when the object is destructed.

[michalber]

Exactly as @epruesse said. Moreover, spdmon::LoggerProgress has two constructors: with and without passing external spdlog::logger. When no logger is passed, spdmon::LoggerProgress creates new logger - to log progress bar and logs - and makes it as default one. When some logger is passed, spdmon::LoggerProgress discards all sinks logging to stdout and from other sinks new logger is created - including custom sink to log progress bar. When spdmon::LoggerProgress is destroyed, default logger is reverted (which was default one before creating monitor progress). I do not know if it is possibile to create mamy of these monitors, because of creating new default logger inside class (in my version).