CLI: rework the logging verbosity implementation

[sphuber]

Fixes #5116

The intended behavior of logging of the system when invoked through the
command line interface verdi is as follows:

• The verbosity of output produced by invoked CLI commands can be
  controlled through a single -v/--verbosity option that is accepted
  by the CLI at every command level.
• It takes the values of the log levels of Python's logging system,
  including AiiDA's custom REPORT level.
• The verbosity level should be applied to all logging messages, so not
  just those messages that are logged directly by the command itself,
  but also any messages logged by module code that is indirectly called
  in the stack.

Given that the implementation is built on top of the logging system, the
log level set by the verbosity option has to be added to the logging
configuration somehow. The logging is configured by invoking the method
aiida.common.log.configure_logging which consumes a dictionary with
the logging configuration that has certain fields that are dynamically
determined from the loaded profile. Unfortunately, this method can be
called by module code as well, therefore, the verbosity option can not
rely on using this method to configure the logging. Because once the
callback is finished, any other code invoked by the command that calls
this same method, will undo the changes of the verbosity option.

The original implementation attempted to solve this problem by storing
the selected log level through the verbosity option, in the profile
instance loaded in memory. Since the log level would be read dynamically
from the profile in the configure_logging method, even when it would
be recalled, the correct log level would be configured.

This approach had various disadvantages, however. It tied the option
closely to the concept of a profile. Even though all verdi commands
have the profile option added by default and therefore this does not
really pose a problem, it made the verbosity option useless in any other
context. The tight coupling also made the logic more difficult to
understand. Finally, even though the change of the profile setting was
only made in memory and so in principle the change should be temporary
within the scope of the CLI command, if the command decided to store the
profile, which can for example happen in commands that are designed to
change the profile, the change in log level option would also be written
to disk, causing an undesirable side effect of this implementation.

Here, we change the implementation by fully decoupling the verbosity
option from the profile and simply having the callback write the
selected log level to a global constant in the aiida.common.log module
called CLI_LOG_LEVEL. The configure_logging module will check this
constant and when set, will configure all loggers with the cli handler
with the correspondig log level. This design still has a downside in
that it hard-couples the generic aiida.common.log module to the more
specific aiida.cmdline module, but it is not obvious to get the CLI
dependent log level injected into this module some other way.

Finally, the original implementation allowed a default value for the
verbosity option to be configured through the config by setting the
logging.aiida_loglevel option. However, since that also determines the
log level for AiiDA when not run through the CLI, i.e. during normal
operations, this could have undesirable side-effects. For example, if
the option was set to WARNING to temporarily limit the number of logs
from processes when being run, certain CLI commands would also no longer
report any output.

[sphuber]

@ltalirz given that you requested the change in behavior, would be good if you could have a look to see if this matches your expectation. Note that there is one test failing, but that is the one that I added and it is a peculiarity of the testing itself in combination with the logging. I don't think the underlying functionality is actually broken. So you can already have a look at the implementation while I try to find a way to fix the test.

[ltalirz]

thanks a lot @sphuber !

looks good to me, I have mainly one question on the hierarchy of the loggers

[codecov]

Codecov Report

Merging #5119 (01c0f13) into develop (706e48b) will increase coverage by 0.01%.
The diff coverage is 100.00%.

@@             Coverage Diff             @@
##           develop    #5119      +/-   ##
===========================================
+ Coverage    80.75%   80.76%   +0.01%     
===========================================
  Files          534      534              
  Lines        36974    36962      -12     
===========================================
- Hits         29853    29847       -6     
+ Misses        7121     7115       -6     

Flag	Coverage Δ
django	75.59% <100.00%> (+0.01%)	⬆️
sqlalchemy	74.69% <100.00%> (+0.01%)	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files	Coverage Δ
aiida/cmdline/commands/cmd_profile.py	79.67% <ø> (ø)
aiida/cmdline/utils/decorators.py	70.18% <ø> (-1.01%)	⬇️
aiida/cmdline/commands/cmd_verdi.py	86.85% <100.00%> (-0.39%)	⬇️
aiida/cmdline/params/options/main.py	96.04% <100.00%> (+2.05%)	⬆️
aiida/cmdline/params/types/profile.py	64.29% <100.00%> (+4.83%)	⬆️
aiida/common/log.py	81.04% <100.00%> (+0.34%)	⬆️
aiida/cmdline/utils/echo.py	82.93% <0.00%> (+2.44%)	⬆️

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 706e48b...01c0f13. Read the comment docs.

[ltalirz]

thanks a lot @sphuber , looks good to me!