Logging: handle verbosity as a ResourceOption (#12)

* fix(logging): handle verbosity as a ResourceOption

When `verbosity_option` is a `ResourceOption` (to make the verbosity settable by
a config), the logging level will not be set for the logs in the config files.

* test(logging): handle all `verbosity_option` cases

Ensure the log level is set in config files when `verbosity_option` is
not a `ResourceOption`.
Ensure the log level is still correctly imported from the config when
`verbosity_option` is a `ResourceOption`.

* docs: add details on verbosity option as Resource.

Add information on the behavior of the `verbosity_option` when it is set
as `ResourceOption`.
Fix a typos in an help message (propagating the change in the tests).

Author: Yannick-Dayer

src/clapper/click.py

@@ -58,6 +58,12 @@ def verbosity_option(
     * 2 (``-vv``): ``logger.setLevel(logging.INFO)``
     * 3 (``-vvv`` or more): ``logger.setLevel(logging.DEBUG)``
 
+    The verbosity level specified in this option will also be set during the loading of
+    the ``ResourceOption`` or ``CommandConfig`` configuration files  **unless**
+    ``verbosity_option`` is a ``ResourceOption`` itself. If this is the case, the
+    logging level during the configuration loading will be the default level of the
+    logger and the option will only effect the logging after the options handling.
+
 
     Arguments:
 
@@ -68,7 +74,7 @@ def verbosity_option(
         name: Long name of the option.  If not set, then use ``verbose`` --
             this will also become the name of the contextual parameter for click.
 
-        dlft: The default verbosity level to use (defaults to 0).
+        dflt: The default verbosity level to use (defaults to 0).
 
         **kwargs: Further keyword-arguments to be forwarded to the underlying
             :py:func:`click.option`
@@ -102,14 +108,14 @@ def callback(ctx, param, value):
             default=dflt,
             show_default=True,
             help=(
-                f"Increase the verbosity level from 0 (only error and "
-                f"critical) messages will be displayed, to 1 (like 0, but adds "
-                f"warnings), 2 (like 1, but adds info messags), and 3 (like 2, "
-                f"but also adds debugging messages) by adding the --{name} "
-                f"option as often as desired (e.g. '-vvv' for debug)."
+                f"Increase the verbosity level from 0 (only error and critical) "
+                f"messages will be displayed, to 1 (like 0, but adds warnings), 2 "
+                f"(like 1, but adds info messages), and 3 (like 2, but also adds "
+                f"debugging messages) by adding the --{name} option as often as "
+                f"desired (e.g. '-vvv' for debug)."
             ),
             callback=callback,
-            is_eager=True,  # Ensure the logger is set for ResourceOptions loading
+            is_eager=kwargs.get("cls", None) is not ResourceOption,
             **kwargs,
         )(f)
 
@@ -380,7 +386,7 @@ def consume_value(
     ) -> tuple[typing.Any, ParameterSource]:
         """Retrieve value for parameter from appropriate context.
 
-        This method will retrive the value of its own parameter from the
+        This method will retrieve the value of its own parameter from the
         appropriate context, by trying various sources.
 
         Parameters
@@ -645,7 +651,7 @@ def config_group(
     """Add a command group to list/describe/copy job configurations.
 
     This decorator adds a whole command group to a user predefined function
-    which is part of the user's CLI.  The command group provdes an interface to
+    which is part of the user's CLI.  The command group provides an interface to
     list, fully describe or locally copy configuration files distributed with
     the package.  Commands accept both entry-point or module names to be
     provided as input.

tests/data/test_dump_config.py

@@ -13,4 +13,4 @@
 
 # verbose = 0
 """Optional parameter: verbose (-v, --verbose) [default: 0]
-Increase the verbosity level from 0 (only error and critical) messages will be displayed, to 1 (like 0, but adds warnings), 2 (like 1, but adds info messags), and 3 (like 2, but also adds debugging messages) by adding the --verbose option as often as desired (e.g. '-vvv' for debug)."""
+Increase the verbosity level from 0 (only error and critical) messages will be displayed, to 1 (like 0, but adds warnings), 2 (like 1, but adds info messages), and 3 (like 2, but also adds debugging messages) by adding the --verbose option as often as desired (e.g. '-vvv' for debug)."""

tests/data/test_dump_config2.py

@@ -42,4 +42,4 @@
 
 # verbose = 0
 """Optional parameter: verbose (-v, --verbose) [default: 0]
-Increase the verbosity level from 0 (only error and critical) messages will be displayed, to 1 (like 0, but adds warnings), 2 (like 1, but adds info messags), and 3 (like 2, but also adds debugging messages) by adding the --verbose option as often as desired (e.g. '-vvv' for debug)."""
+Increase the verbosity level from 0 (only error and critical) messages will be displayed, to 1 (like 0, but adds warnings), 2 (like 1, but adds info messages), and 3 (like 2, but also adds debugging messages) by adding the --verbose option as often as desired (e.g. '-vvv' for debug)."""

tests/test_logging.py

@@ -243,7 +243,10 @@ def cli_config():
     @verbosity_option(logger, expose_value=False)
     def cli(**_):
         """This is the documentation provided by the user."""
-        pass
+        logger.debug("App Debug level message")
+        logger.info("App Info level message")
+        logger.warning("App Warning level message")
+        logger.error("App Error level message")
 
     return (cli, messages)
 
@@ -255,7 +258,7 @@ def test_logger_click_option_config_q(cli_config):
     cli, log_output = cli_config
     runner = CliRunner()
     result = runner.invoke(cli, ["--cmp", "complex-var"])
-    expected = "[ERROR] Error level message\n"
+    expected = "[ERROR] Error level message\n" "[ERROR] App Error level message\n"
     assert result.exit_code == 0, result.output
     assert log_output.getvalue() == expected
 
@@ -264,7 +267,12 @@ def test_logger_click_option_config_v(cli_config):
     cli, log_output = cli_config
     runner = CliRunner()
     result = runner.invoke(cli, ["--cmp", "complex-var", "-v"])
-    expected = "[WARNING] Warning level message\n" "[ERROR] Error level message\n"
+    expected = (
+        "[WARNING] Warning level message\n"
+        "[ERROR] Error level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
+    )
     assert result.exit_code == 0, result.output
     assert log_output.getvalue() == expected
 
@@ -277,6 +285,9 @@ def test_logger_click_option_config_vv(cli_config):
         "[INFO] Info level message\n"
         "[WARNING] Warning level message\n"
         "[ERROR] Error level message\n"
+        "[INFO] App Info level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
     )
     assert result.exit_code == 0, result.output
     assert log_output.getvalue() == expected
@@ -291,17 +302,23 @@ def test_logger_click_option_config_vvv(cli_config):
         "[INFO] Info level message\n"
         "[WARNING] Warning level message\n"
         "[ERROR] Error level message\n"
+        "[DEBUG] App Debug level message\n"
+        "[INFO] App Info level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
     )
     assert result.exit_code == 0, result.output
     assert log_output.getvalue().endswith(expected)
 
 
 # Loading configs using ConfigCommand
+
+
 def test_logger_click_command_config_q(cli_config):
     cli, log_output = cli_config
     runner = CliRunner()
     result = runner.invoke(cli, ["complex"])
-    expected = "[ERROR] Error level message\n"
+    expected = "[ERROR] Error level message\n" "[ERROR] App Error level message\n"
     assert result.exit_code == 0, result.output
     assert log_output.getvalue() == expected
 
@@ -310,7 +327,12 @@ def test_logger_click_command_config_v(cli_config):
     cli, log_output = cli_config
     runner = CliRunner()
     result = runner.invoke(cli, ["complex", "-v"])
-    expected = "[WARNING] Warning level message\n" "[ERROR] Error level message\n"
+    expected = (
+        "[WARNING] Warning level message\n"
+        "[ERROR] Error level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
+    )
     assert result.exit_code == 0, result.output
     assert log_output.getvalue() == expected
 
@@ -323,6 +345,9 @@ def test_logger_click_command_config_vv(cli_config):
         "[INFO] Info level message\n"
         "[WARNING] Warning level message\n"
         "[ERROR] Error level message\n"
+        "[INFO] App Info level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
     )
     assert result.exit_code == 0, result.output
     assert log_output.getvalue() == expected
@@ -337,6 +362,150 @@ def test_logger_click_command_config_vvv(cli_config):
         "[INFO] Info level message\n"
         "[WARNING] Warning level message\n"
         "[ERROR] Error level message\n"
+        "[DEBUG] App Debug level message\n"
+        "[INFO] App Info level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
     )
     assert result.exit_code == 0, result.output
     assert log_output.getvalue().endswith(expected)
+
+
+# Verbosity option set in config file is ignored (not a ResourceOption)
+
+
+def test_logger_click_command_config_q_plus_config(cli_config):
+    cli, log_output = cli_config
+    runner = CliRunner()
+    result = runner.invoke(cli, ["verbose-config", "complex"])
+    expected = "[ERROR] Error level message\n" "[ERROR] App Error level message\n"
+    assert result.exit_code == 0, result.output
+    assert log_output.getvalue() == expected
+
+
+def test_logger_click_command_config_v_plus_config(cli_config):
+    cli, log_output = cli_config
+    runner = CliRunner()
+    result = runner.invoke(cli, ["verbose-config", "complex", "-v"])
+    expected = (
+        "[WARNING] Warning level message\n"
+        "[ERROR] Error level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
+    )
+    assert result.exit_code == 0, result.output
+    assert log_output.getvalue() == expected
+
+
+# Testing verbosity option as config option (legacy mode)
+# The logging level will not be correct in the config files, but can be set as a config.
+
+
+@pytest.fixture
+def cli_verbosity_config():
+    messages = io.StringIO()
+    logger = clapper.logging.setup(
+        "clapper_test",
+        format="[%(levelname)s] %(message)s",
+        low_level_stream=messages,
+        high_level_stream=messages,
+    )
+    logger.setLevel("ERROR")  # Enforce a default level
+
+    @click.command(entry_point_group="clapper.test.config", cls=ConfigCommand)
+    @click.option("--cmp", entry_point_group="clapper.test.config", cls=ResourceOption)
+    @verbosity_option(logger, expose_value=False, cls=ResourceOption)
+    def cli(**_):
+        """This is the documentation provided by the user."""
+        logger.debug("App Debug level message")
+        logger.info("App Info level message")
+        logger.warning("App Warning level message")
+        logger.error("App Error level message")
+
+    return (cli, messages)
+
+
+def test_logger_click_option_config_verbose_as_config_q(cli_verbosity_config):
+    cli, log_output = cli_verbosity_config
+    runner = CliRunner()
+    result = runner.invoke(cli, ["--cmp", "complex-var"])
+    expected = "[ERROR] Error level message\n" "[ERROR] App Error level message\n"
+    assert result.exit_code == 0, result.output
+    assert log_output.getvalue() == expected
+
+
+def test_logger_click_option_config_verbose_as_config_v(cli_verbosity_config):
+    cli, log_output = cli_verbosity_config
+    runner = CliRunner()
+    result = runner.invoke(cli, ["--cmp", "complex-var", "-v"])
+    expected = (
+        "[ERROR] Error level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
+    )
+    assert result.exit_code == 0, result.output
+    assert log_output.getvalue() == expected
+
+
+def test_logger_click_option_config_verbose_as_config_vv(cli_verbosity_config):
+    cli, log_output = cli_verbosity_config
+    runner = CliRunner()
+    result = runner.invoke(cli, ["--cmp", "complex-var", "-vv"])
+    expected = (
+        "[ERROR] Error level message\n"
+        "[INFO] App Info level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
+    )
+    assert result.exit_code == 0, result.output
+    assert log_output.getvalue() == expected
+
+
+def test_logger_click_option_config_verbose_as_config_vvv(cli_verbosity_config):
+    cli, log_output = cli_verbosity_config
+    runner = CliRunner()
+    result = runner.invoke(cli, ["--cmp", "complex-var", "-vvv"])
+    expected_start = "[ERROR] Error level message\n"
+    expected_end = (
+        "[DEBUG] App Debug level message\n"
+        "[INFO] App Info level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
+    )
+    assert result.exit_code == 0, result.output
+    output = log_output.getvalue()
+    assert output.startswith(expected_start)
+    assert output.endswith(expected_end)
+
+
+# Verbosity option set in config file is handled (verbosity_option is a ResourceOption)
+
+
+def test_logger_option_config_verbose_as_config_q_plus_config(cli_verbosity_config):
+    cli, log_output = cli_verbosity_config
+    runner = CliRunner()
+    result = runner.invoke(cli, ["verbose-config", "complex"])
+    expected = (
+        "[ERROR] Error level message\n"
+        "[INFO] App Info level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
+    )
+    assert result.exit_code == 0, result.output
+    assert log_output.getvalue() == expected
+
+
+# specifying the verbosity option in the CLI overrides the option
+
+
+def test_logger_option_config_verbose_as_config_v_plus_config(cli_verbosity_config):
+    cli, log_output = cli_verbosity_config
+    runner = CliRunner()
+    result = runner.invoke(cli, ["verbose-config", "complex", "-v"])
+    expected = (
+        "[ERROR] Error level message\n"
+        "[WARNING] App Warning level message\n"
+        "[ERROR] App Error level message\n"
+    )
+    assert result.exit_code == 0, result.output
+    assert log_output.getvalue() == expected