Skip to content

Commit

Permalink
Logging infrastructure for gempyor
Browse files Browse the repository at this point in the history
Added `gempyor.logging` module with `_get_logging_level`,
`get_script_logger`, and `ClickHandler` along with corresponding
documentation and unit tests.
  • Loading branch information
TimothyWillard committed Jan 7, 2025
1 parent af3ad81 commit 71e2f47
Show file tree
Hide file tree
Showing 4 changed files with 347 additions and 0 deletions.
170 changes: 170 additions & 0 deletions flepimop/gempyor_pkg/src/gempyor/logging.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,170 @@
"""
Logging utilities for consistent script output.
This module provides functionality for creating consistent outputs from CLI tools
provided by this package. Currently exported are:
- `ClickHandler`: Custom logging handler specifically designed for CLI output using
click.
- `get_script_logger`: Factory for creating a logger instance with a consistent style
across CLI tools.
"""

__all__ = ["ClickHandler", "get_script_logger"]


import logging
from typing import Any, IO

import click


DEFAULT_LOG_FORMAT = "%(asctime)s:%(levelname)s:%(name)s> %(message)s"


class ClickHandler(logging.Handler):
"""
Custom logging handler specifically for click based CLI tools.
"""

_punctuation = (".", ",", "?", "!", ":")

def __init__(
self,
level: int | str = 0,
file: IO[Any] | None = None,
nl: bool = True,
err: bool = False,
color: bool | None = None,
punctuate: bool = True,
) -> None:
"""
Initialize an instance of the click handler.
Args:
level: The logging level to use for this handler.
file: The file to write to. Defaults to stdout.
nl: Print a newline after the message. Enabled by default.
err: Write to stderr instead of stdout.
color: Force showing or hiding colors and other styles. By default click
will remove color if the output does not look like an interactive
terminal.
punctuate: A boolean indicating if punctuation should be added to the end
of a log message provided if missing.
Notes:
For more details on the `file`, `nl`, `err`, and `color` args please refer
to [`click.echo`](https://click.palletsprojects.com/en/8.1.x/api/#click.echo).
"""
super().__init__(level)
self._file = file
self._nl = nl
self._err = err
self._color = color
self._punctuate = punctuate

def emit(self, record: logging.LogRecord) -> None:
"""
Emit a given log record via `click.echo`
Args:
record: The log record to output.
See Also:
[`logging.Handler.emit`](https://docs.python.org/3/library/logging.html#logging.Handler.emit)
"""
msg = self.format(record)
msg = (
f"{msg}."
if self._punctuate and not msg.endswith(self._punctuation)
else msg
)
click.echo(
message=msg, file=self._file, nl=self._nl, err=self._err, color=self._color
)


def get_script_logger(
name: str,
verbosity: int,
handler: logging.Handler | None = None,
log_format: str = DEFAULT_LOG_FORMAT,
) -> logging.Logger:
"""
Create a logger for use in scripts.
Args:
name: The name to display in the log message, useful for locating the source
of logging messages. Almost always `__name__`.
verbosity: A non-negative integer for the verbosity level.
handler: An optional logging handler to use in creating the logger returned, or
`None` to just use the `ClickHandler`.
log_format: The format to use for logged messages. Passed directly to the `fmt`
argument of [logging.Formatter](https://docs.python.org/3/library/logging.html#logging.Formatter).
Returns:
An instance of `logging.Logger` that has the appropriate level set based on
`verbosity` and a custom handler for outputting for CLI tools.
Examples:
>>> from gempyor.logging import get_script_logger
>>> logger = get_script_logger(__name__, 3)
>>> logger.info("This is a log info message")
2024-10-29 16:07:20,272:INFO:__main__> This is a log info message.
"""
logger = logging.getLogger(name)
logger.setLevel(_get_logging_level(verbosity))
handler = ClickHandler() if handler is None else handler
log_formatter = logging.Formatter(log_format)
for old_handler in logger.handlers:
logger.removeHandler(old_handler)
handler.setFormatter(log_formatter)
logger.addHandler(handler)
logger.propagate = False
return logger


def _get_logging_level(verbosity: int) -> int:
"""
An internal method to convert verbosity to a logging level.
Args:
verbosity: A non-negative integer for the verbosity level or level from
`logging` that will be returned as is.
Examples:
>>> _get_logging_level(0)
40
>>> _get_logging_level(1)
30
>>> _get_logging_level(2)
20
>>> _get_logging_level(3)
10
>>> _get_logging_level(4)
10
>>> import logging
>>> _get_logging_level(logging.ERROR) == logging.ERROR
True
Raises:
ValueError: If `verbosity` is less than zero.
Returns:
The log level from the `logging` module corresponding to the given `verbosity`.
"""
if verbosity < 0:
raise ValueError(f"`verbosity` must be non-negative, was given '{verbosity}'.")
if verbosity in (
logging.DEBUG,
logging.INFO,
logging.WARNING,
logging.ERROR,
logging.CRITICAL,
):
return verbosity
verbosity_to_logging_level = {
0: logging.ERROR,
1: logging.WARNING,
2: logging.INFO,
}
return verbosity_to_logging_level.get(verbosity, logging.DEBUG)
34 changes: 34 additions & 0 deletions flepimop/gempyor_pkg/tests/logging/test__get_logging_level.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
import logging

import pytest

from gempyor.logging import _get_logging_level


@pytest.mark.parametrize("verbosity", (-1, -100))
def test__get_logging_level_negative_verbosity_value_error(verbosity: int) -> None:
with pytest.raises(
ValueError, match=f"`verbosity` must be non-negative, was given '{verbosity}'."
):
_get_logging_level(verbosity)


@pytest.mark.parametrize(
("verbosity", "expected_level"),
(
(logging.ERROR, logging.ERROR),
(logging.WARNING, logging.WARNING),
(logging.INFO, logging.INFO),
(logging.DEBUG, logging.DEBUG),
(0, logging.ERROR),
(1, logging.WARNING),
(2, logging.INFO),
(3, logging.DEBUG),
(4, logging.DEBUG),
(5, logging.DEBUG),
),
)
def test__get_logging_level_output_validation(
verbosity: int, expected_level: int
) -> None:
assert _get_logging_level(verbosity) == expected_level
71 changes: 71 additions & 0 deletions flepimop/gempyor_pkg/tests/logging/test_click_handler_class.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,71 @@
import io
import logging
from typing import Any, IO

import pytest

from gempyor.logging import ClickHandler


@pytest.mark.parametrize(
"level",
(logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL),
)
@pytest.mark.parametrize("file", (None, io.StringIO))
@pytest.mark.parametrize("nl", (True, False))
@pytest.mark.parametrize("err", (False, True))
@pytest.mark.parametrize("color", (None, False))
@pytest.mark.parametrize("punctuate", (True, False))
def test_click_handler_init(
level: int | str,
file: IO[Any] | None,
nl: bool,
err: bool,
color: bool | None,
punctuate: bool,
) -> None:
handler = ClickHandler(
level=level, file=file, nl=nl, err=err, color=color, punctuate=punctuate
)
assert handler.level == level
assert handler._file == file
assert handler._nl == nl
assert handler._err == err
assert handler._color == color
assert handler._punctuate == punctuate


@pytest.mark.parametrize("punctuate", (True, False))
@pytest.mark.parametrize(
"msg",
(
"This is a message",
"Another message.",
"Start to a list:",
"Middle of a sentence,",
"Oh-no!",
"Question?",
),
)
def test_click_handler_punctuation_formatting(punctuate: bool, msg: str) -> None:
buffer = io.StringIO()
handler = ClickHandler(level=logging.DEBUG, file=buffer, punctuate=punctuate)
log_record = logging.LogRecord(
name="",
level=logging.DEBUG,
pathname="",
lineno=1,
msg=msg,
args=None,
exc_info=None,
)
handler.emit(log_record)
buffer.seek(0)
handler_msg = buffer.getvalue()
if not punctuate:
assert handler_msg == msg + "\n"
else:
assert (
handler_msg
== (msg if msg.endswith(ClickHandler._punctuation) else f"{msg}.") + "\n"
)
72 changes: 72 additions & 0 deletions flepimop/gempyor_pkg/tests/logging/test_get_script_logger.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,72 @@
import logging
import random
import string

import pytest

from gempyor.logging import _get_logging_level, get_script_logger, DEFAULT_LOG_FORMAT


@pytest.mark.parametrize("name", ("foobar", "fizzbuzz"))
@pytest.mark.parametrize(
"verbosity",
(
0,
1,
2,
3,
4,
logging.CRITICAL,
logging.ERROR,
logging.WARNING,
logging.INFO,
logging.DEBUG,
),
)
@pytest.mark.parametrize("handler", (None, logging.StreamHandler()))
@pytest.mark.parametrize("log_format", (None, "%(message)s"))
def test_get_script_logger(
caplog: pytest.LogCaptureFixture,
name: str,
verbosity: int,
handler: logging.Handler | None,
log_format: str | None,
) -> None:
caplog.set_level(logging.DEBUG, logger=name)

if log_format is None:
logger = get_script_logger(name, verbosity, handler=handler)
else:
logger = get_script_logger(
name, verbosity, handler=handler, log_format=log_format
)

# pytest-dev/pytest#3697
logger.propagate = True

assert isinstance(logger, logging.Logger)
assert logger.name == name
assert logger.level == _get_logging_level(verbosity)
if handler is not None:
assert len(logger.handlers) == 1
assert logger.handlers[0] == handler
assert logger.handlers[0].formatter._fmt == (
log_format if log_format else DEFAULT_LOG_FORMAT
)

i = 0
for val, lvl in [
(10, "debug"),
(20, "info"),
(30, "warning"),
(40, "error"),
(50, "critical"),
]:
msg = "".join(random.choice(string.ascii_letters) for _ in range(20))
getattr(logger, lvl)(msg)
if val < _get_logging_level(verbosity):
assert len(caplog.records) == i
continue
assert caplog.records[i].levelno == val
assert caplog.records[i].message == msg
i += 1

0 comments on commit 71e2f47

Please sign in to comment.