add logger for verdi cli

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 is applied automatically
to all verdi commands. Its default verbosity level can be controlled via
the new logging.verdi_loglevel configuration option.

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).

Co-authored-by: Sebastiaan Huber <mail@sphuber.net>

aiida/backends/sqlalchemy/manage.py

@@ -13,6 +13,8 @@
 import alembic
 import click
 
+from aiida.common.log import VERDI_LOGGER, LOG_LEVELS
+
 from aiida.cmdline.params import options
 
 
@@ -26,6 +28,9 @@ def execute_alembic_command(command_name, **kwargs):
 
     manager = SqlaBackendManager()
 
+    if VERDI_LOGGER.level <= LOG_LEVELS['DEBUG']:
+        kwargs.setdefault('verbose', True)
+
     with manager.alembic_config() as config:
         command = getattr(alembic.command, command_name)
         command(config, **kwargs)
@@ -51,18 +56,18 @@ def alembic_revision(message):
 
 
 @alembic_cli.command('current')
-@options.VERBOSE()
-def alembic_current(verbose):
+@options.VERBOSITY()
+def alembic_current():
     """Show the current revision."""
-    execute_alembic_command('current', verbose=verbose)
+    execute_alembic_command('current')
 
 
 @alembic_cli.command('history')
 @click.option('-r', '--rev-range')
-@options.VERBOSE()
-def alembic_history(rev_range, verbose):
+@options.VERBOSITY()
+def alembic_history(rev_range):
     """Show the history for the given revision range."""
-    execute_alembic_command('history', rev_range=rev_range, verbose=verbose)
+    execute_alembic_command('history', rev_range=rev_range)
 
 
 @alembic_cli.command('upgrade')

aiida/cmdline/commands/cmd_code.py

@@ -19,6 +19,7 @@
 from aiida.cmdline.utils import echo
 from aiida.cmdline.utils.decorators import with_dbenv
 from aiida.common.exceptions import InputValidationError
+from aiida.common.log import VERDI_LOGGER, LOG_LEVELS
 
 
 @verdi.group('code')
@@ -145,9 +146,8 @@ def code_duplicate(ctx, code, non_interactive, **kwargs):
 
 @verdi_code.command()
 @arguments.CODE()
-@options.VERBOSE()
 @with_dbenv()
-def show(code, verbose):
+def show(code):
     """Display detailed information for a code."""
     from aiida.repository import FileType
 
@@ -175,33 +175,29 @@ def show(code, verbose):
     table.append(['Prepend text', code.get_prepend_text()])
     table.append(['Append text', code.get_append_text()])
 
-    if verbose:
+    if VERDI_LOGGER.level <= LOG_LEVELS['DEBUG']:
         table.append(['Calculations', len(code.get_outgoing().all())])
 
     click.echo(tabulate.tabulate(table))
 
 
 @verdi_code.command()
 @arguments.CODES()
-@options.VERBOSE()
 @options.DRY_RUN()
 @options.FORCE()
 @with_dbenv()
-def delete(codes, verbose, dry_run, force):
+def delete(codes, dry_run, force):
     """Delete a code.
 
     Note that codes are part of the data provenance, and deleting a code will delete all calculations using it.
     """
     from aiida.manage.database.delete.nodes import delete_nodes
 
-    verbosity = 1
     if force:
-        verbosity = 0
-    elif verbose:
-        verbosity = 2
+        VERDI_LOGGER.setLevel('CRITICAL')
 
     node_pks_to_delete = [code.pk for code in codes]
-    delete_nodes(node_pks_to_delete, dry_run=dry_run, verbosity=verbosity, force=force)
+    delete_nodes(node_pks_to_delete, dry_run=dry_run, force=force)
 
 
 @verdi_code.command()

aiida/cmdline/commands/cmd_devel.py

@@ -13,7 +13,6 @@
 import click
 
 from aiida.cmdline.commands.cmd_verdi import verdi
-from aiida.cmdline.params import options
 from aiida.cmdline.params.types import TestModuleParamType
 from aiida.cmdline.utils import decorators, echo
 
@@ -91,10 +90,9 @@ def devel_validate_plugins():
 
 @verdi_devel.command('tests')
 @click.argument('paths', nargs=-1, type=TestModuleParamType(), required=False)
-@options.VERBOSE(help='Print the class and function name for each test.')
 @decorators.deprecated_command("This command has been removed in aiida-core v1.1.0. Please run 'pytest' instead.")
 @decorators.with_dbenv()
-def devel_tests(paths, verbose):  # pylint: disable=unused-argument
+def devel_tests(paths):  # pylint: disable=unused-argument
     """Run the unittest suite or parts of it.
 
     .. deprecated:: 1.1.0

aiida/cmdline/commands/cmd_graph.py

@@ -12,7 +12,7 @@
 import click
 
 from aiida.cmdline.commands.cmd_verdi import verdi
-from aiida.cmdline.params import arguments, options
+from aiida.cmdline.params import arguments
 from aiida.cmdline.utils import decorators
 
 
@@ -56,7 +56,6 @@ def verdi_graph():
 )
 @click.option('-o', '--process-out', is_flag=True, help='Show outgoing links for all processes.')
 @click.option('-i', '--process-in', is_flag=True, help='Show incoming links for all processes.')
-@options.VERBOSE(help='Print verbose information of the graph traversal.')
 @click.option(
     '-e',
     '--engine',
@@ -69,7 +68,7 @@ def verdi_graph():
 @click.pass_context
 @decorators.with_dbenv()
 def generate(  # pylint: disable=too-many-arguments, unused-argument
-    ctx, root_node, link_types, identifier, ancestor_depth, descendant_depth, process_out, process_in, engine, verbose,
+    ctx, root_node, link_types, identifier, ancestor_depth, descendant_depth, process_out, process_in, engine,
     output_format, show
 ):
     """

aiida/cmdline/commands/cmd_node.py

@@ -23,6 +23,7 @@
 from aiida.common import exceptions
 from aiida.common import timezone
 from aiida.common.links import GraphTraversalRules
+from aiida.common.log import VERDI_LOGGER
 
 
 @verdi.group('node')
@@ -297,12 +298,11 @@ def tree(nodes, depth):
 
 @verdi_node.command('delete')
 @arguments.NODES('nodes', required=True)
-@options.VERBOSE()
 @options.DRY_RUN()
 @options.FORCE()
 @options.graph_traversal_rules(GraphTraversalRules.DELETE.value)
 @with_dbenv()
-def node_delete(nodes, dry_run, verbose, force, **kwargs):
+def node_delete(nodes, dry_run, force, **kwargs):
     """Delete nodes from the provenance graph.
 
     This will not only delete the nodes explicitly provided via the command line, but will also include
@@ -311,15 +311,12 @@ def node_delete(nodes, dry_run, verbose, force, **kwargs):
     """
     from aiida.manage.database.delete.nodes import delete_nodes
 
-    verbosity = 1
     if force:
-        verbosity = 0
-    elif verbose:
-        verbosity = 2
+        VERDI_LOGGER.setLevel('CRITICAL')
 
     node_pks_to_delete = [node.pk for node in nodes]
 
-    delete_nodes(node_pks_to_delete, dry_run=dry_run, verbosity=verbosity, force=force, **kwargs)
+    delete_nodes(node_pks_to_delete, dry_run=dry_run, force=force, **kwargs)
 
 
 @verdi_node.command('rehash')
@@ -415,7 +412,6 @@ def verdi_graph():
 )
 @click.option('-o', '--process-out', is_flag=True, help='Show outgoing links for all processes.')
 @click.option('-i', '--process-in', is_flag=True, help='Show incoming links for all processes.')
-@options.VERBOSE(help='Print verbose information of the graph traversal.')
 @click.option(
     '-e',
     '--engine',
@@ -436,15 +432,14 @@ def verdi_graph():
 @click.option('-s', '--show', is_flag=True, help='Open the rendered result with the default application.')
 @decorators.with_dbenv()
 def graph_generate(
-    root_node, link_types, identifier, ancestor_depth, descendant_depth, process_out, process_in, engine, verbose,
-    output_format, highlight_classes, show
+    root_node, link_types, identifier, ancestor_depth, descendant_depth, process_out, process_in, engine, output_format,
+    highlight_classes, show
 ):
     """
     Generate a graph from a ROOT_NODE (specified by pk or uuid).
     """
     # pylint: disable=too-many-arguments
     from aiida.tools.visualization import Graph
-    print_func = echo.echo_info if verbose else None
     link_types = {'all': (), 'logic': ('input_work', 'return'), 'data': ('input_calc', 'create')}[link_types]
 
     echo.echo_info(f'Initiating graphviz engine: {engine}')
@@ -458,7 +453,6 @@ def graph_generate(
         annotate_links='both',
         include_process_outputs=process_out,
         highlight_classes=highlight_classes,
-        print_func=print_func
     )
     echo.echo_info(f'Recursing descendants, max depth={descendant_depth}')
     graph.recurse_descendants(
@@ -468,7 +462,6 @@ def graph_generate(
         annotate_links='both',
         include_process_inputs=process_in,
         highlight_classes=highlight_classes,
-        print_func=print_func
     )
     output_file_name = graph.graphviz.render(
         filename=f'{root_node.pk}.{engine}', format=output_format, view=show, cleanup=True

aiida/cmdline/commands/cmd_restapi.py

@@ -16,7 +16,8 @@
 import click
 
 from aiida.cmdline.commands.cmd_verdi import verdi
-from aiida.cmdline.params.options import HOSTNAME, PORT, DEBUG
+from aiida.cmdline.params.options import HOSTNAME, PORT
+from aiida.common.log import VERDI_LOGGER, LOG_LEVELS
 from aiida.restapi.common import config
 
 
@@ -30,15 +31,14 @@
     default=config.CLI_DEFAULTS['CONFIG_DIR'],
     help='Path to the configuration directory'
 )
-@DEBUG(default=config.APP_CONFIG['DEBUG'])
 @click.option(
     '--wsgi-profile',
     is_flag=True,
     default=config.CLI_DEFAULTS['WSGI_PROFILE'],
     help='Whether to enable WSGI profiler middleware for finding bottlenecks'
 )
 @click.option('--hookup/--no-hookup', 'hookup', is_flag=True, default=None, help='Hookup app to flask server')
-def restapi(hostname, port, config_dir, debug, wsgi_profile, hookup):
+def restapi(hostname, port, config_dir, wsgi_profile, hookup):
     """
     Run the AiiDA REST API server.
 
@@ -47,12 +47,13 @@ def restapi(hostname, port, config_dir, debug, wsgi_profile, hookup):
         verdi -p <profile_name> restapi --hostname 127.0.0.5 --port 6789
     """
     from aiida.restapi.run_api import run_api
+
     # Invoke the runner
     run_api(
         hostname=hostname,
         port=port,
         config=config_dir,
-        debug=debug,
+        debug=VERDI_LOGGER.level <= LOG_LEVELS['DEBUG'],
         wsgi_profile=wsgi_profile,
         hookup=hookup,
     )

aiida/cmdline/commands/cmd_setup.py

@@ -9,6 +9,7 @@
 ###########################################################################
 """The `verdi setup` and `verdi quicksetup` commands."""
 
+import pprint
 import click
 
 from aiida.cmdline.commands.cmd_verdi import verdi
@@ -66,43 +67,46 @@ def setup(
     profile.broker_virtual_host = broker_virtual_host
     profile.repository_uri = f'file://{repository}'
 
+    echo.echo_debug('Loading config file')
     config = get_config()
 
-    # Creating the profile
+    echo.echo_debug('Adding profile to config file and setting it as new default')
     config.add_profile(profile)
     config.set_default_profile(profile.name)
 
-    # Load the profile
+    echo.echo_debug('Loading new profile')
     load_profile(profile.name)
-    echo.echo_success(f'created new profile `{profile.name}`.')
+    echo.echo_success(f'Created new profile `{profile.name}`.')
 
     # Migrate the database
-    echo.echo_info('migrating the database.')
+    echo.echo_info('Migrating the database.')
     backend = get_manager()._load_backend(schema_check=False)  # pylint: disable=protected-access
 
     try:
         backend.migrate()
     except Exception as exception:  # pylint: disable=broad-except
         echo.echo_critical(
-            f'database migration failed, probably because connection details are incorrect:\n{exception}'
+            f'Database migration failed, probably because connection details are incorrect:\n{exception}'
         )
     else:
-        echo.echo_success('database migration completed.')
+        echo.echo_success('Database migration completed.')
 
-    # Optionally setting configuration default user settings
+    echo.echo_debug('Storing default user settings, if not yet present')
     config.set_option('user.email', email, override=False)
     config.set_option('user.first_name', first_name, override=False)
     config.set_option('user.last_name', last_name, override=False)
     config.set_option('user.institution', institution, override=False)
 
-    # Create the user if it does not yet exist
+    echo.echo_debug('Creating new database user, if not yet present')
     created, user = orm.User.objects.get_or_create(
         email=email, first_name=first_name, last_name=last_name, institution=institution
     )
     if created:
         user.store()
     profile.default_user = user.email
     config.update_profile(profile)
+
+    echo.echo_debug('Storing config file to disk')
     config.store()
 
 
@@ -155,6 +159,7 @@ def quicksetup(
     if not postgres.is_connected:
         echo.echo_critical('failed to determine the PostgreSQL setup')
 
+    echo.echo_debug('Creating PostgreSQL user and database')
     try:
         db_username, db_name = postgres.create_dbuser_db_safe(dbname=db_name, dbuser=db_username, dbpass=db_password)
     except Exception as exception:
@@ -194,4 +199,5 @@ def quicksetup(
         'broker_virtual_host': broker_virtual_host,
         'repository': repository,
     }
+    echo.echo_debug('Calling `verdi setup` with parameters\n{}'.format(pprint.pformat(setup_parameters)))
     ctx.invoke(setup, **setup_parameters)