add verbosity option for verdi commands

[ltalirz]

fix #3864
fix #4330

So far, the verdi cli has been using a number of variants of
click.secho in order to write information to the command line
(e.g. echo_info(), echo_warning(), echo_critical(), ...).

This automatically adds colored indicators for info/warning/... levels
but offers no way to control which level of information is printed.
For example, it is often useful to print information for debugging
purposes, and so it would be useful to be able to specify a verbosity
level when running verdi commands.

Here, we use python's logging module to build a custom handler that
outputs log messages via click.
We also add a click VERBOSITY option that can be added to any command,
which allows to specify the verbosity of the logger.
Note: The code added here is inspired by the click_log package (but
needed to be modified in order to fit the needs of AiiDA).

Todo

• decide where to place the verbosity option (verdi -v DEBUG profile list vs verdi profile list -v DEBUG)
• decide the format of the verbosity option (-v DEBUG vs -v -v -v etc.)
• decide whether to introduce a echo_debug function that simply uses CLI_LOGGER.debug. Perhaps cleaner than mixing echo and direct logging (?)
• replace uses of outdated options.VERBOSE and options.DEBUG
• Fix tests - the click test runner currently does not capture output from loggers as already noticed by @CasperWA elsewhere. Will look into this.
• Final point of discussion: the top-level verdi command already has a -v option, namely -v/--version. By adding the -v/--verbosity option only at the subcommand level, we avoid clashes but there is a minor potential for confusion. I personally find it acceptable

[codecov]

Codecov Report

Merging #3896 into develop will decrease coverage by 0.03%.
The diff coverage is 83.22%.

@@             Coverage Diff             @@
##           develop    #3896      +/-   ##
===========================================
- Coverage    79.36%   79.34%   -0.02%     
===========================================
  Files          476      469       -7     
  Lines        34951    34812     -139     
===========================================
- Hits         27736    27618     -118     
+ Misses        7215     7194      -21     

Flag	Coverage Δ
#django	72.96% <75.19%> (-0.26%)	⬇️
#sqlalchemy	72.18% <83.22%> (-0.27%)	⬇️

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

Impacted Files	Coverage Δ
aiida/backends/sqlalchemy/manage.py	0.00% <0.00%> (ø)
aiida/cmdline/commands/cmd_devel.py	44.69% <ø> (-2.25%)	⬇️
aiida/manage/configuration/options.py	75.00% <ø> (ø)
aiida/manage/database/delete/nodes.py	76.37% <70.00%> (-4.02%)	⬇️
aiida/common/log.py	96.43% <88.24%> (+0.85%)	⬆️
aiida/cmdline/params/options/verbosity.py	89.29% <89.29%> (ø)
aiida/cmdline/utils/echo.py	81.34% <90.91%> (+1.34%)	⬆️
aiida/cmdline/commands/cmd_code.py	90.37% <100.00%> (+0.73%)	⬆️
aiida/cmdline/commands/cmd_graph.py	91.31% <100.00%> (-8.69%)	⬇️
aiida/cmdline/commands/cmd_node.py	82.34% <100.00%> (-0.28%)	⬇️
... and 131 more

---

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 7c49471...45e5292. Read the comment docs.

[sphuber]

I am not sure if this is what the OP of #3864 had in mind (which is not to say that the changes here might not be useful). In their case they tried to setup manually and failed, but verdi quicksetup worked. My interpretation is that they would like to see, through the debug option, the exact commands being executed to make it work, i.e. the exact PostgreSQL commands for creating the databases etc. So in this regard, I am not sure if the added debug statements are really that useful.

[CasperWA]

Seems legit, thanks @ltalirz!

In conjunction with our discussions over in #3599, I think it would be better to call this --debug instead of --verbose, having it align better with the logging level as well.
However, if you simply want a more verbose version, I think this is fine if the logging level is then also changed. The two should match, otherwise, I am afraid setting the logging level may bleed into other actions unintentionally, showing unintended debug messages - if this is possible? I am not completely confident still in the intricacies of logging.

[CasperWA]

I am not sure if this is what the OP of #3864 had in mind (which is not to say that the changes here might not be useful). In their case they tried to setup manually and failed, but verdi quicksetup worked. My interpretation is that they would like to see, through the debug option, the exact commands being executed to make it work, i.e. the exact PostgreSQL commands for creating the databases etc. So in this regard, I am not sure if the added debug statements are really that useful.

Didn't see this comment before reviewing.
However, it doesn't contradict my review - in a sense. Indeed, it seems this should simply be shifted to another logging level than DEBUG.

[ltalirz]

In their case they tried to setup manually and failed, but verdi quicksetup worked. My interpretation is that they would like to see, through the debug option, the exact commands being executed to make it work, i.e. the exact PostgreSQL commands for creating the databases etc.

I agree that the level of logging provided here is not yet very extensive, but I think it is a reasonable start and it becomes easy to extend in the future if more details are desired.
I suggest we close #3864 with a note saying that if more detailed logs are desired, we would need specific requests.

In conjunction with our discussions over in #3599, I think it would be better to call this --debug instead of --verbose, having it align better with the logging level as well.

I think you're right that the level of logging provided here can be considered "debug" level.

However, let me propose an alternative solution instead:
There is a widely used pattern for controlling the level of log messages (see e.g. kubectl, openstack cli): the repetition of the -v flag:

verdi   # log level 0   (logging.WARNING in python)
verdi -v   # log level 1  (logging.INFO in python)
verdi -v -v  # log level 2 (logging.DEBUG in python)

# Some clis also support directly requesting a log level:
verdi --vv=2  # log level 2

The obvious benefit of this pattern is that it is always easy to ask for "more information" without having to learn the names of the particular log levels and their meaning.

Since controlling the log level is something that should apply to verdi commands across the board, it would ideally be controlled at the verdi level.
Unfortunately, unless we want to force people to always put the -v flag directly after verdi (like -p), it seems such a behavior is explicitly not allowed in click, and the workarounds 1 2 look a bit messy to me.

So, as the next best thing, I propose that I will change the verbosity option to the form described above, make it available in the options module and use it for verdi setup and verdi quicksetup.

@sphuber @CasperWA Sounds good?

One thing we would need to decide is the correspondence of flags and python logging levels.
What about this:

VERBOSITY_LOG_LEVEL_MAP = {
 -1: logging.ERROR,  # only reachable via --vv=-1 . Could also start counting from 0 instead.
 0: logging.WARNING,
 1: logging.INFO,
 2: logging.DEBUG,
}

We should then also include a brief documentation of what those log levels mean in the AiiDA-core docs (see e.g. kubectl example).

[ltalirz]

Let me know whether you agree and I will finish the PR

[sphuber]

I see the advantage of having a single consistently functioning option like the --verbose one that you proposed. Regarding the limitation in click that you pointed out, I think the proposed solution of having a reusable option that we apply to any command that uses logging is fine. The slight duplication in the code is preferable to the user having to pass the option before the subcommand.

I just have two questions still.

1. For the VERBOSITY_LOG_LEVEL_MAP what about logging.CRITICAL if the user does not even want to see errors?
2. What do we do with all the echo.echo* commands? Is the idea that we keep those but also start using the logging module to echo information? I am not sure if that is a good idea. Would it be possible to marry the two? Or make the echo functions actually go through a logger and have the default logging behavior be such that it ends up on the console stdout just like it does now? Ultimately, I think it will be weird and confusing to have both LOGGER.info('some message') and echo.echo_info('some more info') in the source code

[ltalirz]

For the VERBOSITY_LOG_LEVEL_MAP what about logging.CRITICAL if the user does not even want to see errors?

Thanks, I simply overlooked this.
Do we need even something beyond CRITICAL (i.e. "never print anything whatsoever") or is this good enough?
I guess, people are usually fine if a program prints something when it crashes.

What do we do with all the echo.echo* commands? Is the idea that we keep those but also start using the logging module to echo information? I am not sure if that is a good idea. Would it be possible to marry the two? Or make the echo functions actually go through a logger and have the default logging behavior be such that it ends up on the console stdout just like it does now? Ultimately, I think it will be weird and confusing to have both LOGGER.info('some message') and echo.echo_info('some more info') in the source code

I agree that these two approaches will need to be married (in this PR) in the sense that the verbosity level should control whether echo.echo... are printed. I will look into this.

As for eliminating one of the two approaches entirely - the logger.info approach is more flexible, since you can specify the logger you want to log to (I have seen some use of this in the codebase).
On the other hand, in most of the cases, developers won't care about it and just want to use the default logger.
I wouldn't be too worried if we keep both approaches for the time being, suggesting people to use the echo.echo approach by default and switch to the logger. approach only when necessary.

[ltalirz]

@sphuber The PR now contains the approach we discussed in the issue (some minor things remain to be done, see to-do lists in the PR description).

Would you mind giving a quick top-level look to check whether the general approach looks good to you?
If yes, I'll continue and fix the remaining todo items.

[sphuber]

Thanks @ltalirz . Looking really good, I would continue in this direction. Shouldn't be far off now

[ltalirz]

@sphuber I've tried to address all remaining issues. Should be ready for review.

[sphuber]

Thanks @ltalirz , still have some comments and questions

[sphuber]

Don't we still need to forward the verbosity to this command? I know that the CLI levels do not map onto those that delete_nodes understand, but now the verbosity option will simply be ignored. won't it?

[sphuber]

I wonder if we want to add some property or method on the VERDI_LOGGER that makes this easier and does not require importing LOG_LEVELS. Not sure if this would require some complex logic and in the end is not worth it. Just something to think about

[ltalirz]

What about something like VERDI_LOGGER.includes('DEBUG') or VERDI_LOGGER.is_logging('DEBUG')?

[sphuber]

Why does this need to be added here? With the current setup, the subcommands won't have the verbosity option when calling the commands directly through the cli_runner? Instead of hotfixing it like this, I think we would need to find a more rigorous global solution

[ltalirz]

Why does this need to be added here? With the current setup, the subcommands won't have the verbosity option when calling the commands directly through the cli_runner?

Correct.

Instead of hotfixing it like this, I think we would need to find a more rigorous global solution

Happy to hear your suggestions.
The thing is that the verdi group stuff does not seem to be executed by the cli runner - either you need to force it to run that or you need to find another way to add the option (logically, however, I think the group is the right place to add it).

[sphuber]

See comment on test_node.py

[sphuber]

Should force=True be interpreted as suppress all logging?

[ltalirz]

I'm just replicating the previous behavior here...

[sphuber]

Hmm, this is a downside of the new solution that I didn't consider. Here the old paradigm of having an on/off switch was clearly superior. Now, one would have to look at the implementation to figure out that when passing --verbosity DEBUG one gets the number of calculations done with the code. That is not very intuitive. Is there a way we can improve this?

[ltalirz]

While I agree that this makes the if condition a bit longer here, I would like to point out that this occurs only in cases where it is not possible to express the logging logic via individual .info or .debug calls (which is possible in most cases).

Now, one would have to look at the implementation to figure out that when passing --verbosity DEBUG one gets the number of calculations done with the code. That is not very intuitive. Is there a way we can improve this?

At least to me, --verbosity DEBUG seems more intuitive than --verbose 2. Are you referring to the fact that by no longer having a dedicated --verbose option, the documentation of the specific behavior for this command is lost?
If that is the problem, we could simply add the logging behavior to the documentation of the command itself, i.e. adding a sentence like

Add `-v DEBUG` to get the number of calculations done with the code.

(or try to override the help string of the --verbosity option, but I would prefer the former).

[chrisjsewell]

There is a widely used pattern for controlling the level of log messages (see e.g. kubectl, openstack cli): the repetition of the -v flag:

@ltalirz maybe this is in one of the resolved conversations, but why did you decide against this?
It seems a lot more user friendly and intuitive to just be able to type -vv than e.g. -v DEBUG?

[sphuber]

The main argument, IIRC, is that since we are tying the implementation to the logging system, with its predefined logging levels, it makes more sense to have the interface reflect the same thing. Otherwise, one would need some translation table of what -vvvv means for example. Is that CRITICIAL or WARNING?

Of course that raises the question whether the implementation should affect the UI that much, but then the question really becomes whether Python's logging system should be used for the problem that is being tackled here. Not sure what the answer is to be honest.

[chrisjsewell]

and also, as we (me an Leo) just discussed, how do you handle interfacing with functions that are in some sense independent of the CLI (delete_nodes, export, etc): do they now have to specifically use VERDI_LOGGER, do you pass them a logger instance, do you pass them the verbosity level and let them deal with it?

[chrisjsewell]

Since we are tying the implementation to the logging system ... it makes more sense to have the interface reflect the same thing

I feel that makes sense from a developer perspective, but not necessarily from a user one, i.e. the user should not have to care about the underlying implementation
(I can't think of any other CLI that uses -v WARNING?)

[sphuber]

I feel that makes sense from a developer perspective, but not necessarily from a user one, i.e. the user should not have to care about the underlying implementation

See my comment just before yours:

Of course that raises the question whether the implementation should affect the UI that much

I definitely agree that we shouldn't tie UI to implementation for that reason, but here it was a question about two different UI's, both of which have their downsides. The advantage of the -v WARNING one, as I see it, is that the log level is directly included in the messages that are printed. So when you see a message like Warning: node not found and you want to suppress it, it is somewhat intuitive that you need to set -v ERROR to suppress it. With the other system, it is not immediately clear how many v's you need. Of course this assumes people are somewhat familiar with Python log levels, but they are used in more places, for example in verdi config to set log levels for other parts of the code.

That being said:

how do you handle interfacing with functions that are in some sense independent of the CLI (delete_nodes, export, etc): do they now have to specifically use VERDI_LOGGER, do you pass them a logger instance, do you pass them the verbosity level and let them deal with it?

I think this is the real problem with this PR. As I already commented during the review, the fact that now the VERDI_LOGGER and its concepts are sneaking into code that are not necessarily run from verdi is bad business. Code that is indepedent of the CLI and simply used by parts of the CLI, should not be changed to be made explicitly dependent just so that it respects logging levels of the CLI. I would also really like to see that addressed before merging.

[ltalirz]

@sphuber Regarding your last point, chris and me discussed that indeed I will fix this for code that is not specific to the cli.

The only question is: how? There are a couple of possibilities

1. keep the original boolean flags and translate the logger status into them
2. pass a logger instance.
   Here one would have to decide whether to add a default and, if yes, what the default should be (should it be a "dummy" logger that doesn't print anything or should it e.g. be the standard AiiDA logger?)

[ltalirz]

@chrisjsewell For the discussion of -vvv vs -v LEVEL, see #4330 (comment)

One of the drawbacks of the -v approach is that it does not allow to decrease the log level, i.e. we would then still need flags like --silent on top for commands like verdi export migrate.

[sphuber]

The only question is: how?

Your two solutions are assuming that the delete_nodes code does the right thing and needs to print information to stdout. I personally however think that it is actually the current delete_nodes implementation that is incorrect. It is written to be a utility function that should be reusable and any code that is just "utility" code, as in that should be callable from various environments (i.e. a CLI or notebook or by some daemon process, whatever) should never just print to stdout. Instead, it should use logging. Any calling code can then control the logging level or even what logger handlers are configured to redirect/format/control the actual output. This way the lower level code is completely independent.

TLDR: delete_nodes should use logging and never print, and it should not accept any verbose, silent or what have you arguments. The CLI should then simply control the loglevel of what actually gets send to stdout. If delete_nodes properly uses a logger that is a child of the aiida namespace, then verdi can simply change the loglevel of that handler to control what gets printed.

[chrisjsewell]

One of the drawbacks of the -v approach is that it does not allow to decrease the log level

In some places they use -vvv for verbose and -qqq for quiet, but agree there is no ideal solution

[chrisjsewell]

then verdi can simply change the loglevel of that handler to control what gets printed.

yeh this seems the way to go

[chrisjsewell]

Perhaps this may be of interest: https://github.com/sphinx-doc/sphinx/blob/0476e1cea93b587e3c0ab295aa20b2b9f0f81a34/sphinx/util/logging.py#L59

[chrisjsewell]

How about something like:

@options.VERBOSITY(loggers=(VERDI_LOGGER, EXPORT_LOGGER))
# or
@options.VERBOSITY(additional_loggers=(EXPORT_LOGGER,))

i.e. allowing for multiple loggers to be set up with the verbosity level

[sphuber]

How about something like:

@options.VERBOSITY(loggers=(VERDI_LOGGER, EXPORT_LOGGER))
# or
@options.VERBOSITY(additional_loggers=(EXPORT_LOGGER,))

i.e. allowing for multiple loggers to be set up with the verbosity level

Not sure, this way it is easy to miss some logger that might be called downstream. I think instead the VERBOSITY option should simply reconfigure the logging and set a new level according to the value that is passed and remove all existing handlers and simply add a single "verdi" logger that redirects the output of any logger to stdout with the log level as a prefix.

I can make an example implementation later maybe

[chrisjsewell]

I can make an example implementation later maybe

yeh it will probably be clearer then.

For the export function, I guess really what I want is only the EXPORT_LOGGER to be "active". If a debug verbosity level gets set, I don't want to suddenly have a massive amount of stdout coming from other areas of aiida (although actually, searching for .debug there is very little debug logging outside of importexport)

[ltalirz]

Configuring loggers

Perhaps it's helpful to take a step back first and write down what we want.

Goal

I think we want the following:

• While running verdi commands, all logging output from the process is printed to the console.
  The verbosity of aiida-related log messages is controlled by the --verbosity flag.
  • Note: I think we probably don't want the verbosity flag to apply to loggers from other packages, e.g. tornado, paramiko, ... who might have different interpretations of the log levels (but this can be discussed).
• While running the daemon, all logging output should go to the daemon log file.
  The verbosity of all log messages should be controlled by verdi config settings

Status quo (in this PR)

There are a few loggers around:

• Loggers from external packages (tornado, plumpy, kiwipy, paramiko, ...): configured to log to the console with log level determined by verdi config
  Will log to the daemon log file for daemon processes.
• AiiDA logger and dependent ones:
  • aiida logger: configured to log to the console with log level determined by verdi config.
    Will log to the daemon log file for daemon processes.
  • EXEC_LOGGER, EXPORT_LOGGER, IMPORT_LOGGER, SCHEDULER_LOGGER: inherit explicitly from aiida logger via AIIDA_LOGGER.getChild('execmanager')
  • _LOGGERs in aiida/engine/transports.py, aiida/orm/implementation/sqlalchemy/groups.py, aiida/orm/querybuilder.py, aiida/schedulers/plugins/pbsbaseclasses.py, aiida/schedulers/plugins/pbspro.py: inherit implicitly from the aiida logger via logging.getLogger(__name__)
• verdi logger: configured to log through click with default log level determined by verdi config, and log level override via --verbosity option
  Will log to the daemon log file for daemon processes.

How to get there

I think we can achieve the goals stated above if we:

• make the --verbosity option configure the level of the AiiDA logger (and thus the level of all dependent loggers)
• make the verdi logger a child of the AiiDA logger
• in CLI code:
  • use whichever logger you like: aiida / verdi / export /... (doesn't really matter... )
  • continue to use AiiDA click commands as before (which are routed through the verdi logger with the ClickHandler)
• in non-CLI code: use the aiida or module-level logger (e.g. EXPORT_LOGGER)

@sphuber @chrisjsewell Do you agree?

Edit: Finally, I propose to rename the verdi logger to CMDLINE_LOGGER and move it to aiida.cmdline (which then makes it follow the naming of other dependent loggers.

[ltalirz]

It basically works, only that I'm currently still setting the the level of the CMDLINE_LOGGER and not of the AIIDA_LOGGER - the reason is that configure_logging is called after the verbosity set by the verdi commands.

If verdi output is routed through loggers, I think it makes sense to move the configuration of the loggers to an earlier point in the call graph.

Just to be sure this does not result in slowing things down, I checked the speed of this function - it seems reasonable:

In [1]: from aiida.common.log import configure_logging

In [2]: %timeit configure_logging()
1.31 ms ± 65 µs per loop (mean ± std. dev. of 7 runs, 1000 loops each)

[sphuber]

Here is a summary of a design meeting of August 16th 2021 with @ramirezfranciscof @chrisjsewell @ltalirz and yourstruly. We decided to start with the discussion on the implementation, since this would like influence the interface, even though typically directly tying a user interface to implementation details is ill-advised.

Implementation

Design considerations

The control of the verbosity of output generated by CLI commands should not merely affect the output directly generated by the command itself, but also that of all output that is generated by the module code that it calls. This means that it should control the logging, which is the recommended way of outputting information for module code. It therefore seems most natural to use the same mechanism for the output produced directly by the CLI command, and so also have that go through the logging module. The CLI can then provide a single option that controls the logging in general and both the output of the command as well as module code will behave consistently. Any attempts to deviate from this homogeneous solution, will either lead to requiring a complex interface to control both independent systems or it will lead to inconsistent behavior where only one respects the behavior requested by the user and the other remains unaffected.

Logging and the REPORT level

The de facto mechanism to emit output in Python code, and in programming in general, is logging. This approach allows module code to emit information with a given level, indicating the importance of the message, and the caller can control what part of this information is shown and how it is shown, without touching the code. This provides a clear separation of concerns and makes the code modular and easily configurable.

Logging is already used extensively in aiida-core, not just in "normal" module code, but it is also used for the reporting system in processes, such as work chains. When calling the report method of a WorkChain, it actually emits a log message at the REPORT level through the logging system, which then gets redirected to the database through a database handler. This system allows a work chain developer to communicate important messages describing progress to the user.

Note that REPORT is not a built-in log level, but is a custom level defined by aiida-core that sits between WARNING and INFO. The reason is that we could not set either of those as the default level. When running a work chain, one does not want to see exclusively warnings, but also plain informational messages. However, the level INFO in module code is traditionally used for information that is too verbose to be shown by default. That is also why the default log message in Python is WARNING. This meant that we could not use the INFO level for work chain reporting, because we would have to set that as the default, but that would also mean that all info logs from module would be shown, which are typically too verbose.

The same asymmetry goes for the command line. So far, we have been using the echo_info utility to report information from commands that should always be shown by default, for example the final result of a command. But yet again, for the default behavior, we do not want an invoking of a CLI command to also show all INFO log messages from the module code it happens to be calling. The chosen solution then is to extend the concept of the REPORT log level and have that also be the default for the CLI. For that purpose, the aiida.cmdline.utils.echo.echo_report utility function will be created and existing uses of echo_info should be replaced by it, if their message should be displayed by default.

The echo utilities

The aiida.cmdline.utils.echo module contains utility functions that so far have been used to display messages from verdi commands. They are a simple wrapper around the click.echo and click.secho functions. The proposed solution is to instead make them a wrapper around the logging module and have them log messages to a CMDLINE_LOGGER instance, which is a child of the global AIIDA_LOGGER. We then define a handler for this logger that will format these messages as the utilities currently do. This approach achieves the goal of having a single homogeneous system for messaging in both the module and CLI code.

Config options

Currently, the logging level can already be controlled through the configuration options. The verdi config command allows setting, for example, the aiida.log_level option, which is used to define the log level of the AIIDA_LOGGER.

User interface

Since the implementation will use the logging mechanism, to control it, the user interface needs to provide an option that maps onto the logging levels.

Design considerations

Again for reasons of simplicity, we will not allow to configure the logging level for any other logger but the main AIIDA_LOGGER and all its children will therefore be configured the same way. There were three candidates considered for the approach:

1. Flags: two mutually exclusive flags, -v and -q, where the number of letters increase the verbosity or quietness, e.g. -vvv and -qq
2. Numerical option: a single option -v that takes a numerical value, e.g., from 0 to 6.
3. Textual option: a single option -v that takes a string value that maps directly onto the log level, e.g., ERROR or INFO.

The last option, solution number 3, was chosen unanimously. Its main disadvantage is that initially it is perhaps less intuitive, as one needs to know the exact levels that are available. These will be included in the help string, however, which should alleviate this somewhat. That being said, at least these levels are explicit and clear in the absolute sense. Once the available levels are known, what they represent should be immediately clear. The accepted values of options 1 and 2 only have relative meaning, but individually it is not clear how they will affect the messaging verbosity. This is the case to a lesser extend for option 1, but there one needs two separate flags to switch between certain behaviors, which is confusing in and of itself.

In this case, the fact that the values of option 3 map directly to the logging mechanism is another advantage. Normally this tying of the interface to the implementation is not advisable, but in this case it makes sense, because the user can already configure the default log level of AiiDA through the configuration options. With this design, the Python default can be changed on a permanent basis through the configuration option and the CLI option can be used to change that on a per-call basis. Having these two options use the same value system, makes it easy to understand how they interact.

Behavior

With the chosen design, the verbosity can be controlled with a single value. Therefore each command will provide the -v/--verbosity flag. Since all commands will understand this option, it should be passable at any level. That is to say:

verdi some -v DEBUG command

Should be the same as:

verdi some command -v DEBUG

Just in case the option is specified multiple times, the value that is specified furthest down will be dominant, e.g., for:

verdi some -v DEBUG command -v ERROR

the log level will be set to ERROR. There is one current problem and that is that currently the -v shortcut is reserved by the top-level verdi command as the shorthand for the --version option. We should either remove that shorthand or not allow the --verbosity option to specified on the top-level verdi command.

The -v/--verbosity option should accept both upper- and lower-case versions of the log levels, i.e.

verdi command -v DEBUG

and

verdi command -v debug

are equivalent.

Implementations

The main question concerning the implementation is to guarantee that all commands accept the verbosity option and properly propagate its value to the logging system. Having each command manually add the option runs the risk that certain commands will forget. Additionally, it puts an extra burden on the developer where this could be automated. So ideally, this option is automatically added to each command and the value processed once a command is invoked. The problem is that click doesn't seem to support this concept of group-shared options, so we might need to come up with a work around.

[sphuber]

@chrisjsewell @ltalirz @ramirezfranciscof See the above comment with a summary of our discussion and decision. I am sure I may have forgotten some details. In that case, please report them below and I will update the post. At some point, we should probably refine it a bit more and put it in the documentation under the "Architecture" section as documentation of this design process.

[sphuber]

Superseded by #5085