docs/changes/newsfragments/412.change

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

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`_

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:

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 = (

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

junifer/utils/logging.py

@@ -4,6 +4,7 @@
 #          Synchon Mandal <s.mandal@fz-juelich.de>
 # 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)"
         # )
+    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