diff --git a/docs/changes/newsfragments/412.change b/docs/changes/newsfragments/412.change new file mode 100644 index 000000000..d8406817e --- /dev/null +++ b/docs/changes/newsfragments/412.change @@ -0,0 +1 @@ +Introduce new CLI parameter ``--verbose-datalad`` to control ``datalad``'s logging handler by `Fede Raimondo`_ diff --git a/docs/changes/newsfragments/412.feature b/docs/changes/newsfragments/412.feature new file mode 100644 index 000000000..5f1bb7cf2 --- /dev/null +++ b/docs/changes/newsfragments/412.feature @@ -0,0 +1 @@ +Add support for coloured :class:`logging.Formatter` to use with ``junifer``'s :class:`logging.StreamHandler` based on environment by `Fede Raimondo`_ diff --git a/junifer/api/queue_context/gnu_parallel_local_adapter.py b/junifer/api/queue_context/gnu_parallel_local_adapter.py index b1cf0d2dd..a14b29057 100644 --- a/junifer/api/queue_context/gnu_parallel_local_adapter.py +++ b/junifer/api/queue_context/gnu_parallel_local_adapter.py @@ -37,6 +37,9 @@ class GnuParallelLocalAdapter(QueueContextAdapter): virtual environment of any kind (default None). verbose : str, optional 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 Whether to submit the jobs (default False). @@ -65,6 +68,7 @@ class GnuParallelLocalAdapter(QueueContextAdapter): pre_collect: Optional[str] = None, env: Optional[dict[str, str]] = None, verbose: str = "info", + verbose_datalad: Optional[str] = None, submit: bool = False, ) -> None: """Initialize the class.""" @@ -76,6 +80,7 @@ class GnuParallelLocalAdapter(QueueContextAdapter): self._pre_collect = pre_collect self._check_env(env) self._verbose = verbose + self._verbose_datalad = verbose_datalad self._submit = submit self._log_dir = self._job_dir / "logs" @@ -155,6 +160,11 @@ class GnuParallelLocalAdapter(QueueContextAdapter): def run(self) -> str: """Return run commands.""" + verbose_args = f"--verbose {self._verbose}" + if self._verbose_datalad: + verbose_args = ( + f"{verbose_args} --verbose-datalad {self._verbose_datalad}" + ) return ( f"#!/usr/bin/env {self._shell}\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._arguments} run " f"{self._yaml_config_path.resolve()!s} " - f"--verbose {self._verbose} " + f"{verbose_args} " f"--element" ) @@ -184,6 +194,11 @@ class GnuParallelLocalAdapter(QueueContextAdapter): def collect(self) -> str: """Return collect commands.""" + verbose_args = f"--verbose {self._verbose}" + if self._verbose_datalad: + verbose_args = ( + f"{verbose_args} --verbose-datalad {self._verbose_datalad}" + ) return ( f"#!/usr/bin/env {self._shell}\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._arguments} collect " f"{self._yaml_config_path.resolve()!s} " - f"--verbose {self._verbose}" + f"{verbose_args}" ) def prepare(self) -> None: diff --git a/junifer/api/queue_context/htcondor_adapter.py b/junifer/api/queue_context/htcondor_adapter.py index 5e01e64f2..d3a004d04 100644 --- a/junifer/api/queue_context/htcondor_adapter.py +++ b/junifer/api/queue_context/htcondor_adapter.py @@ -37,6 +37,9 @@ class HTCondorAdapter(QueueContextAdapter): virtual environment of any kind (default None). verbose : str, optional 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 The number of CPU cores to use (default 1). mem : str, optional @@ -83,6 +86,7 @@ class HTCondorAdapter(QueueContextAdapter): pre_collect: Optional[str] = None, env: Optional[dict[str, str]] = None, verbose: str = "info", + verbose_datalad: Optional[str] = None, cpus: int = 1, mem: str = "8G", disk: str = "1G", @@ -99,6 +103,7 @@ class HTCondorAdapter(QueueContextAdapter): self._pre_collect = pre_collect self._check_env(env) self._verbose = verbose + self._verbose_datalad = verbose_datalad self._cpus = cpus self._mem = mem self._disk = disk @@ -201,10 +206,15 @@ class HTCondorAdapter(QueueContextAdapter): def run(self) -> str: """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 = ( "run " f"{self._yaml_config_path.resolve()!s} " - f"--verbose {self._verbose} " + f"{verbose_args}" "--element $(element)" ) log_dir_prefix = ( @@ -246,10 +256,16 @@ class HTCondorAdapter(QueueContextAdapter): def collect(self) -> str: """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 = ( "collect " 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" fixed = ( diff --git a/junifer/cli/cli.py b/junifer/cli/cli.py index b7733b86d..b7081daa2 100644 --- a/junifer/cli/cli.py +++ b/junifer/cli/cli.py @@ -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( ctx: click.Context, param: str, value: str ) -> Union[str, int]: @@ -105,8 +131,17 @@ def cli() -> None: # pragma: no cover callback=_validate_verbose, default="info", ) +@click.option( + "--verbose-datalad", + type=click.UNPROCESSED, + callback=_validate_optional_verbose, + default=None, +) 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: """Run feature extraction. @@ -120,10 +155,12 @@ def run( The element(s) to operate on. verbose : click.Choice 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 - configure_logging(level=verbose) + configure_logging(level=verbose, level_datalad=verbose_datalad) # TODO(synchon): add validation # Parse YAML config = parse_yaml(filepath) @@ -167,7 +204,17 @@ def run( callback=_validate_verbose, 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. \f @@ -178,10 +225,12 @@ def collect(filepath: click.Path, verbose: Union[str, int]) -> None: The filepath to the configuration file. verbose : click.Choice 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 - configure_logging(level=verbose) + configure_logging(level=verbose, level_datalad=verbose_datalad) # TODO: add validation # Parse YAML config = parse_yaml(filepath) @@ -208,12 +257,19 @@ def collect(filepath: click.Path, verbose: Union[str, int]) -> None: callback=_validate_verbose, default="info", ) +@click.option( + "--verbose-datalad", + type=click.UNPROCESSED, + callback=_validate_optional_verbose, + default=None, +) def queue( filepath: click.Path, element: tuple[str], overwrite: bool, submit: bool, verbose: Union[str, int], + verbose_datalad: Union[str, int, None], ) -> None: """Queue feature extraction. @@ -231,6 +287,8 @@ def queue( Whether to submit the job. verbose : click.Choice 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 ------ @@ -239,7 +297,7 @@ def queue( """ # Setup logging - configure_logging(level=verbose) + configure_logging(level=verbose, level_datalad=verbose_datalad) # TODO: add validation # Parse YAML config = parse_yaml(filepath) # type: ignore @@ -365,9 +423,16 @@ def selftest(subpkg: str) -> None: callback=_validate_verbose, default="info", ) +@click.option( + "--verbose-datalad", + type=click.UNPROCESSED, + callback=_validate_optional_verbose, + default=None, +) def reset( filepath: click.Path, verbose: Union[str, int], + verbose_datalad: Union[str, int, None], ) -> None: """Reset generated assets. @@ -379,10 +444,12 @@ def reset( The filepath to the configuration file. verbose : click.Choice 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 - configure_logging(level=verbose) + configure_logging(level=verbose, level_datalad=verbose_datalad) # Parse YAML config = parse_yaml(filepath) # Perform operation @@ -409,11 +476,18 @@ def reset( callback=_validate_verbose, default="info", ) +@click.option( + "--verbose-datalad", + type=click.UNPROCESSED, + callback=_validate_optional_verbose, + default=None, +) def list_elements( filepath: click.Path, element: tuple[str], output_file: Optional[click.Path], verbose: Union[str, int], + verbose_datalad: Union[str, int, None], ) -> None: """List elements of a dataset. @@ -430,10 +504,12 @@ def list_elements( stdout is not performed. verbose : click.Choice 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 - configure_logging(level=verbose) + configure_logging(level=verbose, level_datalad=verbose_datalad) # Parse YAML config = parse_yaml(filepath) # Fetch datagrabber diff --git a/junifer/utils/logging.py b/junifer/utils/logging.py index 93ff8618f..ecaccadca 100644 --- a/junifer/utils/logging.py +++ b/junifer/utils/logging.py @@ -4,6 +4,7 @@ # Synchon Mandal # License: AGPL +import os import sys @@ -16,7 +17,7 @@ import logging import warnings from pathlib import Path from subprocess import PIPE, Popen, TimeoutExpired -from typing import NoReturn, Optional, Union +from typing import ClassVar, NoReturn, Optional, Union from warnings import warn import datalad @@ -80,6 +81,59 @@ class WrapStdOut(logging.StreamHandler): 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) + + 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: """Aux function to read HEAD from git. @@ -237,11 +291,51 @@ def log_versions(tbox_path: Optional[Path] = None) -> None: 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( level: Union[int, str] = "WARNING", fname: Optional[Union[str, Path]] = None, overwrite: Optional[bool] = None, output_format=None, + level_datalad: Union[int, str, None] = None, ) -> None: """Configure the logging functionality. @@ -264,6 +358,10 @@ def configure_logging( e.g., ``"%(asctime)s - %(levelname)s - %(message)s"``. If None, default string format is used (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 @@ -297,11 +395,22 @@ def configure_logging( # "%(asctime)s [%(levelname)s] %(message)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 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 log_versions() # log versions of installed packages