diff --git a/docs/howto/basics/command_line.md b/docs/howto/basics/command_line.md index 0c345146d..fe1143309 100644 --- a/docs/howto/basics/command_line.md +++ b/docs/howto/basics/command_line.md @@ -56,21 +56,36 @@ In both case, the app you specify must have an asynchronous connector. ## Logging -Three different options allow you to control how the command-line tool should log -events: +Several options allow you to control how the command-line tool should log events: -- Verbosity controls the log level (you'll see message of this level and above): +- **Verbosity** controls the log level (you'll see messages of this level and above): - | Flags | Environment equivalent | Log level | - | ----- | ------------------------- | --------- | - | | PROCRASTINATE_VERBOSITY=0 | `warning` | - | -v | PROCRASTINATE_VERBOSITY=1 | `info` | - | -vv | PROCRASTINATE_VERBOSITY=2 | `debug` | + | Flags | Environment equivalent | Log level | + | -------------- | ----------------------- | --------- | + | | PROCRASTINATE_VERBOSE=0 | `info` | + | -v (or higher) | PROCRASTINATE_VERBOSE=1 | `debug` | -- Log format: `--log-format=` / `PROCRASTINATE_LOG_FORMAT=` lets you control how + Note: Values beyond 1 have no additional effect. + +- **Log level** allows explicit control over the logging level (mutually exclusive with `-v`): + + `--log-level=LEVEL` / `PROCRASTINATE_LOG_LEVEL=LEVEL` where `LEVEL` is one of: + `debug`, `info`, `warning`, `error`, or `critical`. + + This option provides access to log levels not available through `-v` flags, + such as `warning`, `error`, and `critical`. You cannot use `--log-level` and + `-v` together. + + Examples: + ```console + $ procrastinate --log-level=warning worker + $ PROCRASTINATE_LOG_LEVEL=error procrastinate worker + ``` + +- **Log format**: `--log-format=` / `PROCRASTINATE_LOG_FORMAT=` lets you control how the log line will be formatted. It uses `%`-style placeholders by default. -- Log format style: `--log-format-style=` / `PROCRASTINATE_LOG_FORMAT_STYLE=` +- **Log format style**: `--log-format-style=` / `PROCRASTINATE_LOG_FORMAT_STYLE=` lets you choose different styles for the log-format, such as `{` or `$`. For more information on log formats, refer to the [Python documentation](https://docs.python.org/3/library/logging.html?highlight=logging#logrecord-attributes) diff --git a/procrastinate/cli.py b/procrastinate/cli.py index 7fb43364f..8fff5cb8e 100644 --- a/procrastinate/cli.py +++ b/procrastinate/cli.py @@ -31,8 +31,19 @@ def get_log_level(verbosity: int) -> int: Style = Union[Literal["%"], Literal["{"], Literal["$"]] -def configure_logging(verbosity: int, format: str, style: Style) -> None: - level = get_log_level(verbosity=verbosity) +def configure_logging( + verbosity: int | None = None, + log_level: str | None = None, + format: str = logging.BASIC_FORMAT, + style: Style = "%", +) -> None: + if log_level is not None: + level = getattr(logging, log_level.upper()) + elif verbosity is not None: + level = get_log_level(verbosity=verbosity) + else: + level = logging.INFO + logging.basicConfig(level=level, format=format, style=style) level_name = logging.getLevelName(level) logger.debug( @@ -176,18 +187,22 @@ def add_cli_features(parser: argparse.ArgumentParser): Add features to the parser to make it more CLI-friendly. This is not necessary when the parser is used as a subparser. """ - add_argument( - parser, + log_group = parser.add_argument_group("Logging") + + # Create mutually exclusive group for verbosity control + verbosity_group = log_group.add_mutually_exclusive_group() + verbosity_group.add_argument( "-v", "--verbose", default=0, action="count", - help="Use multiple times to increase verbosity", - envvar="VERBOSE", - envvar_help="set to desired verbosity level", - envvar_type=int, + help=f"Increase verbosity (0=info, 1+=debug) (env: {ENV_PREFIX}_VERBOSE)", + ) + verbosity_group.add_argument( + "--log-level", + choices=["debug", "info", "warning", "error", "critical"], + help=f"Set log level explicitly (env: {ENV_PREFIX}_LOG_LEVEL)", ) - log_group = parser.add_argument_group("Logging") add_argument( log_group, "--log-format", @@ -517,11 +532,42 @@ async def cli(args): add_cli_features(parser) parsed = vars(parser.parse_args(args)) - configure_logging( - verbosity=parsed.pop("verbose"), - format=parsed.pop("log_format"), - style=parsed.pop("log_format_style"), - ) + # Determine log level from either --log-level or --verbose (mutually exclusive) + log_level = parsed.pop("log_level", None) + verbosity = parsed.pop("verbose") + + # If --log-level was not specified on command line, check environment variable + if log_level is None: + log_level_env = os.environ.get(f"{ENV_PREFIX}_LOG_LEVEL") + if log_level_env and log_level_env.lower() in [ + "debug", + "info", + "warning", + "error", + "critical", + ]: + log_level = log_level_env.lower() + + # If --log-level is set (from CLI or env), use it; otherwise use --verbose + if log_level is not None: + configure_logging( + log_level=log_level, + format=parsed.pop("log_format"), + style=parsed.pop("log_format_style"), + ) + else: + # If no -v flags were used on command line, check environment variable + if verbosity == 0: + verbose_value = os.environ.get(f"{ENV_PREFIX}_VERBOSE") + if verbose_value and verbose_value != "": + verbosity = int(verbose_value) + + configure_logging( + verbosity=verbosity, + format=parsed.pop("log_format"), + style=parsed.pop("log_format_style"), + ) + await execute_command(parsed) diff --git a/tests/unit/test_cli.py b/tests/unit/test_cli.py index 38a03a314..5ec5d88e1 100644 --- a/tests/unit/test_cli.py +++ b/tests/unit/test_cli.py @@ -34,6 +34,162 @@ def test_configure_logging(mocker, caplog): assert records[0].value == "DEBUG" +@pytest.mark.parametrize( + "log_level_name, expected_level", + [ + ("debug", logging.DEBUG), + ("info", logging.INFO), + ("warning", logging.WARNING), + ("error", logging.ERROR), + ("critical", logging.CRITICAL), + ], +) +def test_configure_logging_with_log_level( + mocker, caplog, log_level_name, expected_level +): + config = mocker.patch("logging.basicConfig") + + caplog.set_level("DEBUG") + + cli.configure_logging(log_level=log_level_name) + + config.assert_called_once_with( + level=expected_level, format=logging.BASIC_FORMAT, style="%" + ) + records = [record for record in caplog.records if record.action == "set_log_level"] + assert len(records) == 1 + assert records[0].value == logging.getLevelName(expected_level) + + +def test_configure_logging_default_level(mocker, caplog): + """Test that when no verbosity or log_level is set, default is INFO.""" + config = mocker.patch("logging.basicConfig") + + caplog.set_level("DEBUG") + + cli.configure_logging() + + config.assert_called_once_with( + level=logging.INFO, format=logging.BASIC_FORMAT, style="%" + ) + records = [record for record in caplog.records if record.action == "set_log_level"] + assert len(records) == 1 + assert records[0].value == "INFO" + + +@pytest.mark.parametrize( + "verbose_env, cli_flags, expected", + [ + (None, [], 0), # Default is 0 + ("1", [], 1), # PROCRASTINATE_VERBOSE works + ("0", ["-v"], 1), # CLI flag overrides env=0 + ("2", ["-v"], 1), # CLI flag overrides env=2 + (None, ["-v"], 1), # -v gives verbosity 1 + (None, ["-vv"], 2), # -vv gives verbosity 2 (clamped to debug in get_log_level) + ], +) +async def test_verbose_env_vars(monkeypatch, mocker, verbose_env, cli_flags, expected): + """Test that PROCRASTINATE_VERBOSE works and command line flags override environment variables.""" + # Clear any existing values + monkeypatch.delenv("PROCRASTINATE_VERBOSE", raising=False) + + # Set the env var if provided + if verbose_env is not None: + monkeypatch.setenv("PROCRASTINATE_VERBOSE", verbose_env) + + # Mock execute_command to capture the verbosity value + captured_verbosity = None + + async def mock_execute_command(parsed): + # Don't actually execute, just return + pass + + original_configure_logging = cli.configure_logging + + def mock_configure_logging(**kwargs): + nonlocal captured_verbosity + captured_verbosity = kwargs.get("verbosity") + # Call original to ensure it works + original_configure_logging(**kwargs) + + mocker.patch("procrastinate.cli.execute_command", side_effect=mock_execute_command) + mocker.patch( + "procrastinate.cli.configure_logging", side_effect=mock_configure_logging + ) + + # Run cli with the provided flags + args = [*cli_flags, "--app=", "defer", "test"] + await cli.cli(args) + + assert captured_verbosity == expected + + +@pytest.mark.parametrize( + "log_level_env, cli_flags, expected_level", + [ + (None, ["--log-level", "warning"], "warning"), # CLI --log-level works + (None, ["--log-level", "error"], "error"), # CLI --log-level=error works + ( + None, + ["--log-level", "critical"], + "critical", + ), # CLI --log-level=critical works + ("warning", [], "warning"), # PROCRASTINATE_LOG_LEVEL works + ("error", [], "error"), # PROCRASTINATE_LOG_LEVEL=error works + ("warning", ["--log-level", "error"], "error"), # CLI overrides env + ], +) +async def test_log_level_option( + monkeypatch, mocker, log_level_env, cli_flags, expected_level +): + """Test that --log-level and PROCRASTINATE_LOG_LEVEL work correctly.""" + # Clear any existing values + monkeypatch.delenv("PROCRASTINATE_LOG_LEVEL", raising=False) + monkeypatch.delenv("PROCRASTINATE_VERBOSE", raising=False) + + # Set the env var if provided + if log_level_env is not None: + monkeypatch.setenv("PROCRASTINATE_LOG_LEVEL", log_level_env) + + # Mock execute_command to capture the log level + captured_log_level = None + + async def mock_execute_command(parsed): + pass + + original_configure_logging = cli.configure_logging + + def mock_configure_logging(**kwargs): + nonlocal captured_log_level + captured_log_level = kwargs.get("log_level") + original_configure_logging(**kwargs) + + mocker.patch("procrastinate.cli.execute_command", side_effect=mock_execute_command) + mocker.patch( + "procrastinate.cli.configure_logging", side_effect=mock_configure_logging + ) + + # Run cli with the provided flags + args = [*cli_flags, "--app=", "defer", "test"] + await cli.cli(args) + + assert captured_log_level == expected_level + + +async def test_log_level_and_verbose_mutually_exclusive(monkeypatch): + """Test that --log-level and --verbose are mutually exclusive.""" + monkeypatch.delenv("PROCRASTINATE_LOG_LEVEL", raising=False) + monkeypatch.delenv("PROCRASTINATE_VERBOSE", raising=False) + + parser = cli.create_parser() + cli.add_arguments(parser) + cli.add_cli_features(parser) + + # This should raise an error because they're mutually exclusive + with pytest.raises(SystemExit): + parser.parse_args(["--app=", "-v", "--log-level", "warning", "defer", "test"]) + + def test_main(mocker): mock = mocker.patch("procrastinate.cli.cli", new=mocker.AsyncMock()) cli.main()