Configure logging with support for verbose flags

[jaimergp]

Addresses #379

[codecov]

Codecov Report

Merging #391 into pymbar4 will increase coverage by 0.37%.
The diff coverage is 66.66%.

[mrshirts]

Is there a way we can make this a bit more concise? As it is, it doubles the number of lines to add a comment, which adds significant code length with just duplicate lines? Maybe there can be a wrapper function in utils that wraps this, so one can just give the comment and the level? (maybe that gets in the way of the use of name)?

[jaimergp]

That's a good point. I think I can come up with something...

The level of the message is independent of the verbose flag. In other words, verbose does not control when a messages gets logged, but when the message is emitted (in our case, to stdout by default). So what we are doing now is temporarily changing the emission threshold down from warning to info. That's something we can't workaround because that's the backend for the logging mechanism.

However, I think we could wrap up this logic in a nicer way. Some quick ideas, let me know which one you like more:

# A
with emit_if_verbose(__name__, verbose=verbose):
    logger.info("Something something")

# B
logger.log("Something something", level=logging.INFO, force_emit=verbose)

I tend to prefer A because it's less hacky and more aligned with the logging design principles.

[mrshirts]

I think I prefer the second?

I think the second part is to document somewhere how people ask for emission of the other levels.

[jaimergp]

Let me know what you think about it. It's a bit hacky, but hopefully not too much :)

My only concern is what happens when pymbar is used in another project that is already using logging without our custom subclass. Maybe that extra keyword can cause problems if it's not consumed before hand... but maybe the logging machinery is isolated enough? We'll see during the rc stage I guess.

[mrshirts]

Anything else needed for this?

[jaimergp]

Ideally, some manual testing, to see if the logging machinery behaves the way a user would expect. I did a couple of quick ones with the examples and was successful, but I'd like more feedback if possible.

[jaimergp]

@mrshirts anything else you want to add here?

[jaimergp]

This is needs some more testing in real world conditions, ideally in a notebook or somewhere where you are using other libraries at the same time. Does anybody have a good example?

[Lnaden]

My one question with this, is there a reason you cannot add a different level for verbosity? Since INFO, DEBUG, etc are all just int, can we not make a level for VERBOSE and then if verbose we just set the logger level to that? I think that would be much simpler than carrying around the force_emit=verbose in all the calls.

[mrshirts]

The one thing that I want to make sure of is it's very clear to users in the documentation how to make a given function call verbose.