Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
35 changes: 25 additions & 10 deletions docs/howto/basics/command_line.md
Original file line number Diff line number Diff line change
Expand Up @@ -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)
74 changes: 60 additions & 14 deletions procrastinate/cli.py
Original file line number Diff line number Diff line change
Expand Up @@ -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(
Expand Down Expand Up @@ -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",
Expand Down Expand Up @@ -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)


Expand Down
156 changes: 156 additions & 0 deletions tests/unit/test_cli.py
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand Down
Loading