ENH: More compact logging

docs/source/v1.5.md.inc

@@ -4,6 +4,7 @@
 
 - Added support for annotating bad segments based on head movement velocity (#757 by @larsoner)
 - Added examples of T1 and FLASH BEM to website (#758 by @larsoner)
+- Output logging spacing improved (#764 by @larsoner)
 
 [//]: # (### :warning: Behavior changes)
 

mne_bids_pipeline/_config_import.py

@@ -147,9 +147,7 @@ def _update_with_user_config(
             val = getattr(overrides, name)
             if log:
                 msg = f"Overriding config.{name} = {repr(val)}"
-                logger.info(
-                    **gen_log_kwargs(message=msg, step="", emoji="override", box="╶╴")
-                )
+                logger.info(**gen_log_kwargs(message=msg, emoji="override"))
             setattr(config, name, val)
 
     # 4. Env vars and other triaging
@@ -168,7 +166,7 @@ def _update_with_user_config(
     config.deriv_root = pathlib.Path(config.deriv_root).expanduser().resolve()
 
     # 5. Consistency
-    log_kwargs = dict(emoji="override", box="  ", step="")
+    log_kwargs = dict(emoji="override")
     if config.interactive:
         if log and config.on_error != "debug":
             msg = 'Setting config.on_error="debug" because of interactive mode'
@@ -427,4 +425,4 @@ def _handle_config_error(
         raise ValueError(msg)
     elif config.config_validation == "warn":
         if log:
-            logger.warning(**gen_log_kwargs(message=msg, step="", emoji="🛟"))
+            logger.warning(**gen_log_kwargs(message=msg, emoji="🛟"))

mne_bids_pipeline/_config_template.py

@@ -27,7 +27,7 @@ def create_template_config(
 
     target_path.write_text("".join(config), encoding="utf-8")
     message = f"Successfully created template configuration file at: " f"{target_path}"
-    logger.info(**gen_log_kwargs(message=message, emoji="✅", step=""))
+    logger.info(**gen_log_kwargs(message=message, emoji="✅"))
 
     message = "Please edit the file before running the pipeline."
-    logger.info(**gen_log_kwargs(message=message, emoji="💡", step=""))
+    logger.info(**gen_log_kwargs(message=message, emoji="💡"))

mne_bids_pipeline/_logging.py

@@ -31,21 +31,28 @@ def _console(self):
         kwargs["theme"] = rich.theme.Theme(
             dict(
                 default="white",
+                # Rule
+                title="bold green",
                 # Prefixes
                 asctime="green",
-                step="bold cyan",
+                prefix="bold cyan",
                 # Messages
                 debug="dim",
-                info="bold",
-                warning="bold magenta",
-                error="bold red",
+                info="",
+                warning="magenta",
+                error="red",
             )
         )
         self.__console = rich.console.Console(**kwargs)
         return self.__console
 
-    def rule(self, title="", *, align="center"):
-        self.__console.rule(title=title, characters="─", style="rule.line", align=align)
+    def title(self, title):
+        # Align left with ASCTIME offset
+        title = f"[title]┌────────┐ {title}[/]"
+        self._console.rule(title=title, characters="─", style="title", align="left")
+
+    def end(self, msg=""):
+        self._console.print(f"[title]└────────┘[/] {msg}")
 
     @property
     def level(self):
@@ -75,29 +82,18 @@ def _log_message(
         subject: Optional[Union[str, int]] = None,
         session: Optional[Union[str, int]] = None,
         run: Optional[Union[str, int]] = None,
-        step: Optional[str] = None,
         emoji: str = "",
-        box: str = "",
     ):
         this_level = getattr(logging, kind.upper())
         if this_level < self.level:
             return
-        if not subject:
-            subject = ""
-        if not session:
-            session = ""
-        if not run:
-            run = ""
-        if not step:
-            step = ""
-        if step and emoji:
-            step = f"{emoji} {step}"
-        asctime = datetime.datetime.now().strftime("[%H:%M:%S]")
-        msg = (
-            f"[asctime]{asctime}[/asctime] "
-            f"[step]{box}{step}{subject}{session}{run}[/step]"
-            f"[{kind}]{msg}[/{kind}]"
-        )
+        # Construct str
+        essr = [x for x in [emoji, subject, session, run] if x]
+        essr = " ".join(essr)
+        if essr:
+            essr += " "
+        asctime = datetime.datetime.now().strftime("│%H:%M:%S│")
+        msg = f"[asctime]{asctime} [/][prefix]{essr}[/][{kind}]{msg}[/]"
         self._console.print(msg)
 
 
@@ -111,12 +107,8 @@ def gen_log_kwargs(
     session: Optional[Union[str, int]] = None,
     run: Optional[Union[str, int]] = None,
     task: Optional[str] = None,
-    step: Optional[str] = None,
     emoji: str = "⏳️",
-    box: str = "│ ",
 ) -> LogKwargsT:
-    from ._run import _get_step_path, _short_step_path
-
     # Try to figure these out
     stack = inspect.stack()
     up_locals = stack[1].frame.f_locals
@@ -130,34 +122,22 @@ def gen_log_kwargs(
             task = task or up_locals.get("task", None)
             if task in ("noise", "rest"):
                 run = task
-    if step is None:
-        step_path = _get_step_path(stack)
-        if step_path:
-            step = _short_step_path(_get_step_path())
-        else:
-            step = ""
 
     # Do some nice formatting
     if subject is not None:
-        subject = f" sub-{subject}"
+        subject = f"sub-{subject}"
     if session is not None:
-        session = f" ses-{session}"
+        session = f"ses-{session}"
     if run is not None:
-        run = f" run-{run}"
-    if step != "":
-        # need an extra space
-        message = f" {message}"
+        run = f"run-{run}"
 
     # Choose some to be our standards
     emoji = dict(
         cache="✅",
         skip="⏩",
         override="❌",
     ).get(emoji, emoji)
-    extra = {
-        "step": f"{emoji} {step}",
-        "box": box,
-    }
+    extra = {"emoji": emoji}
     if subject:
         extra["subject"] = subject
     if session:
@@ -170,3 +150,7 @@ def gen_log_kwargs(
         "extra": extra,
     }
     return kwargs
+
+
+def _linkfile(uri):
+    return f"[link=file://{uri}]{uri}[/link]"

mne_bids_pipeline/_main.py

@@ -193,22 +193,19 @@ def main():
         # them twice.
         step_modules = [*STEP_MODULES["init"], *step_modules]
 
-    msg = "Welcome aboard the MNE BIDS Pipeline!"
-    logger.info(**gen_log_kwargs(message=msg, emoji="👋", box="╶╴", step=""))
+    logger.title("👋 Welcome aboard the MNE BIDS Pipeline! 👋")
     msg = f"Using configuration: {config}"
-    logger.info(**gen_log_kwargs(message=msg, emoji="🧾", box="╶╴", step=""))
+    logger.info(**gen_log_kwargs(message=msg, emoji="🧾"))
+    logger.end()
 
     config_imported = _import_config(
         config_path=config_path,
         overrides=overrides,
     )
-    for si, step_module in enumerate(step_modules):
+    for step_module in step_modules:
         start = time.time()
         step = _short_step_path(pathlib.Path(step_module.__file__))
-        if si == 0:
-            logger.rule()
-        msg = "Now running  👇"
-        logger.info(**gen_log_kwargs(message=msg, box="┌╴", emoji="🚀", step=step))
+        logger.title(title=f"🚀 {step}")
         step_module.main(config=config_imported)
         elapsed = time.time() - start
         hours, remainder = divmod(elapsed, 3600)
@@ -221,6 +218,4 @@ def main():
             elapsed = f"{minutes}m {elapsed}"
         if hours:
             elapsed = f"{hours}h {elapsed}"
-        msg = f"Done running  👆 [{elapsed}]"
-        logger.info(**gen_log_kwargs(message=msg, box="└╴", emoji="🎉", step=step))
-        logger.rule()
+        logger.end(f"[prefix]🎉 done[/] {elapsed}")

mne_bids_pipeline/_report.py

@@ -20,7 +20,7 @@
 
 from ._config_utils import sanitize_cond_name, get_subjects, _restrict_analyze_channels
 from ._decoding import _handle_csp_args
-from ._logging import logger, gen_log_kwargs
+from ._logging import logger, gen_log_kwargs, _linkfile
 
 
 @contextlib.contextmanager
@@ -83,7 +83,7 @@ def _open_report(
             except Exception as exc:
                 logger.warning(f"Failed: {exc}")
             fname_report_html = fname_report.with_suffix(".html")
-            msg = f"Saving report: {fname_report_html}"
+            msg = f"Saving report: {_linkfile(fname_report_html)}"
             logger.info(**gen_log_kwargs(message=msg))
             report.save(fname_report, overwrite=True)
             report.save(fname_report_html, overwrite=True, open_browser=False)

mne_bids_pipeline/_run.py

@@ -255,8 +255,7 @@ def wrapper(*args, **kwargs):
             del out_files
 
             if msg is not None:
-                step = _short_step_path(pathlib.Path(inspect.getfile(func)))
-                logger.info(**gen_log_kwargs(message=msg, emoji=emoji, step=step))
+                logger.info(**gen_log_kwargs(message=msg, emoji=emoji))
             if short_circuit:
                 return
 

mne_bids_pipeline/steps/init/_01_init_derivatives_dir.py

@@ -18,9 +18,9 @@ def init_dataset(cfg) -> None:
     """Prepare the pipeline directory in /derivatives."""
     fname_json = cfg.deriv_root / "dataset_description.json"
     if fname_json.is_file():
-        return  # already exists
-    msg = "Initializing output directories."
-    logger.info(**gen_log_kwargs(message=msg))
+        logger.info(**gen_log_kwargs(message="Output directories already exist …"))
+        return
+    logger.info(**gen_log_kwargs(message="Initializing output directories."))
 
     cfg.deriv_root.mkdir(exist_ok=True, parents=True)