[ENH]: Logging with a color formatter #412

Merged
fraimondo merged 5 commits from enh/color_format into main 2024-12-05 15:50:38 +00:00
6 changed files with 232 additions and 14 deletions

View file

@ -0,0 +1 @@
Introduce new CLI parameter ``--verbose-datalad`` to control ``datalad``'s logging handler by `Fede Raimondo`_

View file

@ -0,0 +1 @@
Add support for coloured :class:`logging.Formatter` to use with ``junifer``'s :class:`logging.StreamHandler` based on environment by `Fede Raimondo`_

View file

@ -37,6 +37,9 @@ class GnuParallelLocalAdapter(QueueContextAdapter):
virtual environment of any kind (default None). virtual environment of any kind (default None).
verbose : str, optional verbose : str, optional
The level of verbosity (default "info"). The level of verbosity (default "info").
verbose_datalad : str or None, optional
The level of verbosity for datalad. If None, will be the same
as ``verbose`` (default None).
submit : bool, optional submit : bool, optional
Whether to submit the jobs (default False). Whether to submit the jobs (default False).
@ -65,6 +68,7 @@ class GnuParallelLocalAdapter(QueueContextAdapter):
pre_collect: Optional[str] = None, pre_collect: Optional[str] = None,
env: Optional[dict[str, str]] = None, env: Optional[dict[str, str]] = None,
verbose: str = "info", verbose: str = "info",
verbose_datalad: Optional[str] = None,
submit: bool = False, submit: bool = False,
) -> None: ) -> None:
"""Initialize the class.""" """Initialize the class."""
@ -76,6 +80,7 @@ class GnuParallelLocalAdapter(QueueContextAdapter):
self._pre_collect = pre_collect self._pre_collect = pre_collect
self._check_env(env) self._check_env(env)
self._verbose = verbose self._verbose = verbose
self._verbose_datalad = verbose_datalad
self._submit = submit self._submit = submit
self._log_dir = self._job_dir / "logs" self._log_dir = self._job_dir / "logs"
@ -155,6 +160,11 @@ class GnuParallelLocalAdapter(QueueContextAdapter):
def run(self) -> str: def run(self) -> str:
"""Return run commands.""" """Return run commands."""
verbose_args = f"--verbose {self._verbose}"
if self._verbose_datalad:
verbose_args = (
f"{verbose_args} --verbose-datalad {self._verbose_datalad}"
)
return ( return (
f"#!/usr/bin/env {self._shell}\n\n" f"#!/usr/bin/env {self._shell}\n\n"
"# This script is auto-generated by junifer.\n\n" "# This script is auto-generated by junifer.\n\n"
@ -169,7 +179,7 @@ class GnuParallelLocalAdapter(QueueContextAdapter):
f"{self._job_dir.resolve()!s}/{self._executable} " f"{self._job_dir.resolve()!s}/{self._executable} "
f"{self._arguments} run " f"{self._arguments} run "
f"{self._yaml_config_path.resolve()!s} " f"{self._yaml_config_path.resolve()!s} "
f"--verbose {self._verbose} " f"{verbose_args} "
f"--element" f"--element"
) )
@ -184,6 +194,11 @@ class GnuParallelLocalAdapter(QueueContextAdapter):
def collect(self) -> str: def collect(self) -> str:
"""Return collect commands.""" """Return collect commands."""
verbose_args = f"--verbose {self._verbose}"
if self._verbose_datalad:
verbose_args = (
f"{verbose_args} --verbose-datalad {self._verbose_datalad}"
)
return ( return (
f"#!/usr/bin/env {self._shell}\n\n" f"#!/usr/bin/env {self._shell}\n\n"
"# This script is auto-generated by junifer.\n\n" "# This script is auto-generated by junifer.\n\n"
@ -193,7 +208,7 @@ class GnuParallelLocalAdapter(QueueContextAdapter):
f"{self._job_dir.resolve()!s}/{self._executable} " f"{self._job_dir.resolve()!s}/{self._executable} "
f"{self._arguments} collect " f"{self._arguments} collect "
f"{self._yaml_config_path.resolve()!s} " f"{self._yaml_config_path.resolve()!s} "
f"--verbose {self._verbose}" f"{verbose_args}"
) )
def prepare(self) -> None: def prepare(self) -> None:

View file

@ -37,6 +37,9 @@ class HTCondorAdapter(QueueContextAdapter):
virtual environment of any kind (default None). virtual environment of any kind (default None).
verbose : str, optional verbose : str, optional
The level of verbosity (default "info"). The level of verbosity (default "info").
verbose_datalad : str or None, optional
The level of verbosity for datalad. If None, will be the same
as ``verbose`` (default None).
cpus : int, optional cpus : int, optional
The number of CPU cores to use (default 1). The number of CPU cores to use (default 1).
mem : str, optional mem : str, optional
@ -83,6 +86,7 @@ class HTCondorAdapter(QueueContextAdapter):
pre_collect: Optional[str] = None, pre_collect: Optional[str] = None,
env: Optional[dict[str, str]] = None, env: Optional[dict[str, str]] = None,
verbose: str = "info", verbose: str = "info",
verbose_datalad: Optional[str] = None,
cpus: int = 1, cpus: int = 1,
mem: str = "8G", mem: str = "8G",
disk: str = "1G", disk: str = "1G",
@ -99,6 +103,7 @@ class HTCondorAdapter(QueueContextAdapter):
self._pre_collect = pre_collect self._pre_collect = pre_collect
self._check_env(env) self._check_env(env)
self._verbose = verbose self._verbose = verbose
self._verbose_datalad = verbose_datalad
self._cpus = cpus self._cpus = cpus
self._mem = mem self._mem = mem
self._disk = disk self._disk = disk
@ -201,10 +206,15 @@ class HTCondorAdapter(QueueContextAdapter):
def run(self) -> str: def run(self) -> str:
"""Return run commands.""" """Return run commands."""
verbose_args = f"--verbose {self._verbose} "
if self._verbose_datalad is not None:
verbose_args = (
f"{verbose_args} --verbose-datalad {self._verbose_datalad} "
)
junifer_run_args = ( junifer_run_args = (
"run " "run "
f"{self._yaml_config_path.resolve()!s} " f"{self._yaml_config_path.resolve()!s} "
f"--verbose {self._verbose} " f"{verbose_args}"
"--element $(element)" "--element $(element)"
) )
log_dir_prefix = ( log_dir_prefix = (
@ -246,10 +256,16 @@ class HTCondorAdapter(QueueContextAdapter):
def collect(self) -> str: def collect(self) -> str:
"""Return collect commands.""" """Return collect commands."""
verbose_args = f"--verbose {self._verbose} "
if self._verbose_datalad is not None:
verbose_args = (
f"{verbose_args} --verbose-datalad {self._verbose_datalad} "
)
junifer_collect_args = ( junifer_collect_args = (
"collect " "collect "
f"{self._yaml_config_path.resolve()!s} " f"{self._yaml_config_path.resolve()!s} "
f"--verbose {self._verbose}" f"{verbose_args}"
) )
log_dir_prefix = f"{self._log_dir.resolve()!s}/junifer_collect" log_dir_prefix = f"{self._log_dir.resolve()!s}/junifer_collect"
fixed = ( fixed = (

View file

@ -45,6 +45,32 @@ __all__ = [
] ]
def _validate_optional_verbose(
ctx: click.Context, param: str, value: Optional[str]
):
"""Validate optional verbose option.
Parameters
----------
ctx : click.Context
The context of the command.
param : str
The parameter to validate.
value : str
The value to validate.
Returns
-------
str or int or None
The validated value.
"""
if value is None:
return value
else:
return _validate_verbose(ctx, param, value)
def _validate_verbose( def _validate_verbose(
ctx: click.Context, param: str, value: str ctx: click.Context, param: str, value: str
) -> Union[str, int]: ) -> Union[str, int]:
@ -105,8 +131,17 @@ def cli() -> None: # pragma: no cover
callback=_validate_verbose, callback=_validate_verbose,
default="info", default="info",
) )
@click.option(
"--verbose-datalad",
type=click.UNPROCESSED,
callback=_validate_optional_verbose,
default=None,
)
def run( def run(
filepath: click.Path, element: tuple[str], verbose: Union[str, int] filepath: click.Path,
element: tuple[str],
verbose: Union[str, int],
verbose_datalad: Optional[Union[str, int]],
) -> None: ) -> None:
"""Run feature extraction. """Run feature extraction.
@ -120,10 +155,12 @@ def run(
The element(s) to operate on. The element(s) to operate on.
verbose : click.Choice verbose : click.Choice
The verbosity level: warning, info or debug (default "info"). The verbosity level: warning, info or debug (default "info").
verbose_datalad : click.Choice or None
The verbosity level for datalad: warning, info or debug (default None).
""" """
# Setup logging # Setup logging
configure_logging(level=verbose) configure_logging(level=verbose, level_datalad=verbose_datalad)
# TODO(synchon): add validation # TODO(synchon): add validation
# Parse YAML # Parse YAML
config = parse_yaml(filepath) config = parse_yaml(filepath)
@ -167,7 +204,17 @@ def run(
callback=_validate_verbose, callback=_validate_verbose,
default="info", default="info",
) )
def collect(filepath: click.Path, verbose: Union[str, int]) -> None: @click.option(
"--verbose-datalad",
type=click.UNPROCESSED,
callback=_validate_optional_verbose,
default=None,
)
def collect(
filepath: click.Path,
verbose: Union[str, int],
verbose_datalad: Union[str, int, None],
) -> None:
"""Collect extracted features. """Collect extracted features.
\f \f
@ -178,10 +225,12 @@ def collect(filepath: click.Path, verbose: Union[str, int]) -> None:
The filepath to the configuration file. The filepath to the configuration file.
verbose : click.Choice verbose : click.Choice
The verbosity level: warning, info or debug (default "info"). The verbosity level: warning, info or debug (default "info").
verbose_datalad : click.Choice or None
The verbosity level for datalad: warning, info or debug (default None).
""" """
# Setup logging # Setup logging
configure_logging(level=verbose) configure_logging(level=verbose, level_datalad=verbose_datalad)
# TODO: add validation # TODO: add validation
# Parse YAML # Parse YAML
config = parse_yaml(filepath) config = parse_yaml(filepath)
@ -208,12 +257,19 @@ def collect(filepath: click.Path, verbose: Union[str, int]) -> None:
callback=_validate_verbose, callback=_validate_verbose,
default="info", default="info",
) )
@click.option(
"--verbose-datalad",
type=click.UNPROCESSED,
callback=_validate_optional_verbose,
default=None,
)
def queue( def queue(
filepath: click.Path, filepath: click.Path,
element: tuple[str], element: tuple[str],
overwrite: bool, overwrite: bool,
submit: bool, submit: bool,
verbose: Union[str, int], verbose: Union[str, int],
verbose_datalad: Union[str, int, None],
) -> None: ) -> None:
"""Queue feature extraction. """Queue feature extraction.
@ -231,6 +287,8 @@ def queue(
Whether to submit the job. Whether to submit the job.
verbose : click.Choice verbose : click.Choice
The verbosity level: warning, info or debug (default "info"). The verbosity level: warning, info or debug (default "info").
verbose_datalad : click.Choice or None
The verbosity level for datalad: warning, info or debug (default None).
Raises Raises
------ ------
@ -239,7 +297,7 @@ def queue(
""" """
# Setup logging # Setup logging
configure_logging(level=verbose) configure_logging(level=verbose, level_datalad=verbose_datalad)
# TODO: add validation # TODO: add validation
# Parse YAML # Parse YAML
config = parse_yaml(filepath) # type: ignore config = parse_yaml(filepath) # type: ignore
@ -365,9 +423,16 @@ def selftest(subpkg: str) -> None:
callback=_validate_verbose, callback=_validate_verbose,
default="info", default="info",
) )
@click.option(
"--verbose-datalad",
type=click.UNPROCESSED,
callback=_validate_optional_verbose,
default=None,
)
def reset( def reset(
filepath: click.Path, filepath: click.Path,
verbose: Union[str, int], verbose: Union[str, int],
verbose_datalad: Union[str, int, None],
) -> None: ) -> None:
"""Reset generated assets. """Reset generated assets.
@ -379,10 +444,12 @@ def reset(
The filepath to the configuration file. The filepath to the configuration file.
verbose : click.Choice verbose : click.Choice
The verbosity level: warning, info or debug (default "info"). The verbosity level: warning, info or debug (default "info").
verbose_datalad : click.Choice or None
The verbosity level for datalad: warning, info or debug (default None).
""" """
# Setup logging # Setup logging
configure_logging(level=verbose) configure_logging(level=verbose, level_datalad=verbose_datalad)
# Parse YAML # Parse YAML
config = parse_yaml(filepath) config = parse_yaml(filepath)
# Perform operation # Perform operation
@ -409,11 +476,18 @@ def reset(
callback=_validate_verbose, callback=_validate_verbose,
default="info", default="info",
) )
@click.option(
"--verbose-datalad",
type=click.UNPROCESSED,
callback=_validate_optional_verbose,
default=None,
)
def list_elements( def list_elements(
filepath: click.Path, filepath: click.Path,
element: tuple[str], element: tuple[str],
output_file: Optional[click.Path], output_file: Optional[click.Path],
verbose: Union[str, int], verbose: Union[str, int],
verbose_datalad: Union[str, int, None],
) -> None: ) -> None:
"""List elements of a dataset. """List elements of a dataset.
@ -430,10 +504,12 @@ def list_elements(
stdout is not performed. stdout is not performed.
verbose : click.Choice verbose : click.Choice
The verbosity level: warning, info or debug (default "info"). The verbosity level: warning, info or debug (default "info").
verbose_datalad : click.Choice or None
The verbosity level for datalad: warning, info or debug (default None
""" """
# Setup logging # Setup logging
configure_logging(level=verbose) configure_logging(level=verbose, level_datalad=verbose_datalad)
# Parse YAML # Parse YAML
config = parse_yaml(filepath) config = parse_yaml(filepath)
# Fetch datagrabber # Fetch datagrabber

View file

@ -4,6 +4,7 @@
# Synchon Mandal <s.mandal@fz-juelich.de> # Synchon Mandal <s.mandal@fz-juelich.de>
# License: AGPL # License: AGPL
import os
import sys import sys
@ -16,7 +17,7 @@ import logging
import warnings import warnings
from pathlib import Path from pathlib import Path
from subprocess import PIPE, Popen, TimeoutExpired from subprocess import PIPE, Popen, TimeoutExpired
from typing import NoReturn, Optional, Union from typing import ClassVar, NoReturn, Optional, Union
from warnings import warn from warnings import warn
import datalad import datalad
@ -80,6 +81,59 @@ class WrapStdOut(logging.StreamHandler):
raise AttributeError(f"'file' object has not attribute '{name}'") raise AttributeError(f"'file' object has not attribute '{name}'")
class ColorFormatter(logging.Formatter):
"""Color formatter for logging messages.
Parameters
----------
fmt : str
The format string for the logging message.
datefmt : str, optional
The format string for the date.
"""
BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE = range(8)
COLORS: ClassVar[dict[str, int]] = {
"WARNING": YELLOW,
"INFO": GREEN,
"DEBUG": BLUE,
"CRITICAL": MAGENTA,
"ERROR": RED,
}
RESET_SEQ: str = "\033[0m"
COLOR_SEQ: str = "\033[1;%dm"
BOLD_SEQ: str = "\033[1m"
def __init__(self, fmt: str, datefmt: Optional[str] = None) -> None:
"""Initialize the ColorFormatter."""
logging.Formatter.__init__(self, fmt, datefmt)
synchon commented 2024-12-05 09:59:26 +00:00 (Migrated from github.com)

Any preference for range(...) over an IntEnum?

Any preference for `range(...)` over an `IntEnum`?
fraimondo commented 2024-12-05 10:12:40 +00:00 (Migrated from github.com)

just copilot being copilot

just copilot being copilot
def format(self, record: logging.LogRecord) -> str:
"""Format the log record.
Parameters
----------
record : logging.LogRecord
The log record to format.
Returns
-------
str
The formatted log record.
"""
levelname = record.levelname
if levelname in self.COLORS:
levelname_color = (
self.COLOR_SEQ % (30 + self.COLORS[levelname]) + levelname
)
record.levelname = levelname_color + self.RESET_SEQ
return logging.Formatter.format(self, record)
def _get_git_head(path: Path) -> str: def _get_git_head(path: Path) -> str:
"""Aux function to read HEAD from git. """Aux function to read HEAD from git.
@ -237,11 +291,51 @@ def log_versions(tbox_path: Optional[Path] = None) -> None:
pass pass
def _can_use_color(handler: logging.Handler) -> bool:
"""Check if color can be used in the logging output.
Parameters
----------
handler : logging.Handler
The logging handler to check for color support.
Returns
-------
bool
Whether color can be used in the logging output.
"""
if isinstance(handler, logging.FileHandler):
# Do not use colors in file handlers
return False
else:
stream = handler.stream
if hasattr(stream, "isatty") and stream.isatty():
valid_terms = [
"xterm-256color",
"xterm-kitty",
"xterm-color",
]
this_term = os.getenv("TERM", None)
if this_term is not None:
if this_term in valid_terms:
return True
if this_term.endswith("256color") or this_term.endswith("256"):
return True
if this_term == "dumb" and os.getenv("CI", False):
return True
if os.getenv("COLORTERM", False):
return True
# No TTY, no color
return False
def configure_logging( def configure_logging(
level: Union[int, str] = "WARNING", level: Union[int, str] = "WARNING",
fname: Optional[Union[str, Path]] = None, fname: Optional[Union[str, Path]] = None,
overwrite: Optional[bool] = None, overwrite: Optional[bool] = None,
output_format=None, output_format=None,
level_datalad: Union[int, str, None] = None,
) -> None: ) -> None:
"""Configure the logging functionality. """Configure the logging functionality.
@ -264,6 +358,10 @@ def configure_logging(
e.g., ``"%(asctime)s - %(levelname)s - %(message)s"``. e.g., ``"%(asctime)s - %(levelname)s - %(message)s"``.
If None, default string format is used If None, default string format is used
(default ``"%(asctime)s - %(name)s - %(levelname)s - %(message)s"``). (default ``"%(asctime)s - %(name)s - %(levelname)s - %(message)s"``).
level_datalad : int or {"DEBUG", "INFO", "WARNING", "ERROR"}, optional
The level of the messages to print for datalad. If string, it will be
interpreted as elements of logging. If None, it will be set as the
``level`` parameter (default None).
""" """
_close_handlers(logger) # close relevant logger handlers _close_handlers(logger) # close relevant logger handlers
@ -297,11 +395,22 @@ def configure_logging(
# "%(asctime)s [%(levelname)s] %(message)s " # "%(asctime)s [%(levelname)s] %(message)s "
# "(%(filename)s:%(lineno)s)" # "(%(filename)s:%(lineno)s)"
# ) # )
formatter = logging.Formatter(fmt=output_format) if _can_use_color(lh):
formatter = ColorFormatter(fmt=output_format)
else:
formatter = logging.Formatter(fmt=output_format)
lh.setFormatter(formatter) # set formatter lh.setFormatter(formatter) # set formatter
logger.setLevel(level) # set level logger.setLevel(level) # set level
datalad.log.lgr.setLevel(level) # set level for datalad
# Set datalad logging level accordingly
if level_datalad is not None:
if isinstance(level_datalad, str):
level_datalad = _logging_types[level_datalad]
else:
level_datalad = level
datalad.log.lgr.setLevel(level_datalad) # set level for datalad
logger.addHandler(lh) # set handler logger.addHandler(lh) # set handler
log_versions() # log versions of installed packages log_versions() # log versions of installed packages