improve logging

mne_pipeline_hd/__main__.py

@@ -5,7 +5,6 @@
 Github: https://github.com/marsipu/mne-pipeline-hd
 """
 
-import logging
 import os
 import re
 import sys
@@ -21,14 +20,27 @@
 from mne_pipeline_hd.gui.gui_utils import StdoutStderrStream, UncaughtHook
 from mne_pipeline_hd.gui.welcome_window import WelcomeWindow
 from mne_pipeline_hd.pipeline.legacy import legacy_import_check
-from mne_pipeline_hd.pipeline.pipeline_utils import ismac, islin, QS, iswin
+from mne_pipeline_hd.pipeline.pipeline_utils import (
+    ismac,
+    islin,
+    QS,
+    iswin,
+    init_logging,
+    logger,
+)
 
 # Check for changes in required packages
 legacy_import_check()
 
 import qdarktheme  # noqa: E402
 
 
+def init_streams():
+    # Redirect stdout and stderr to capture it later in GUI
+    sys.stdout = StdoutStderrStream("stdout")
+    sys.stderr = StdoutStderrStream("stderr")
+
+
 def main():
     app_name = "mne-pipeline-hd"
     organization_name = "marsipu"
@@ -42,6 +54,8 @@ def main():
     app.setApplicationName(app_name)
     app.setOrganizationName(organization_name)
     app.setOrganizationDomain(domain_name)
+    # For Spyder to make console accessible again
+    app.lastWindowClosed.connect(app.quit)
 
     # Avoid file-dialog-problems with custom file-managers in linux
     if islin:
@@ -56,38 +70,21 @@ def main():
     # # Set multiprocessing method to spawn
     # multiprocessing.set_start_method('spawn')
 
-    # Redirect stdout to capture it later in GUI
-    sys.stdout = StdoutStderrStream("stdout")
-    # Redirect stderr to capture it later in GUI
-    sys.stderr = StdoutStderrStream("stderr")
-
     debug_mode = os.environ.get("MNEPHD_DEBUG", False) == "true"
+    init_logging(debug_mode)
 
-    # ToDo: log-level debug only for mne-pipeline-hd, not all apps
-    # Initialize Logger (root)
-    logger = logging.getLogger()
-    if debug_mode:
-        logger.setLevel(logging.DEBUG)
-    else:
-        logger.setLevel(QS().value("log_level", defaultValue=logging.INFO))
-    formatter = logging.Formatter(
-        "%(asctime)s: %(message)s", datefmt="%Y/%m/%d %H:%M:%S"
-    )
-    console_handler = logging.StreamHandler()
-    console_handler.setFormatter(formatter)
-    logger.addHandler(console_handler)
-    logger.info("Starting MNE-Pipeline HD")
+    logger().info("Starting MNE-Pipeline HD")
 
     # Show Qt-binding
     if any([qtpy.PYQT5, qtpy.PYQT6]):
         qt_version = qtpy.PYQT_VERSION
     else:
         qt_version = qtpy.PYSIDE_VERSION
-    logger.info(f"Using {qtpy.API_NAME} {qt_version}")
+    logger().info(f"Using {qtpy.API_NAME} {qt_version}")
 
     # Initialize Exception-Hook
     if debug_mode:
-        logger.info("Debug-Mode is activated")
+        logger().info("Debug-Mode is activated")
     else:
         qt_exception_hook = UncaughtHook()
         # this registers the exception_hook() function
@@ -129,19 +126,11 @@ def main():
     # Initiate WelcomeWindow
     WelcomeWindow()
 
-    # Redirect stdout to capture it later in GUI
-    sys.stdout = StdoutStderrStream("stdout")
-    # Redirect stderr to capture it later in GUI
-    sys.stderr = StdoutStderrStream("stderr")
-
     # Command-Line interrupt with Ctrl+C possible
     timer = QTimer()
     timer.timeout.connect(lambda: None)
     timer.start(500)
 
-    # For Spyder to make console accessible again
-    app.lastWindowClosed.connect(app.quit)
-
     sys.exit(app.exec())
 
 

mne_pipeline_hd/functions/operations.py

@@ -8,7 +8,6 @@
 from __future__ import print_function
 
 import gc
-import logging
 import os
 import shutil
 import subprocess
@@ -33,6 +32,7 @@
     ismac,
     iswin,
     get_n_jobs,
+    logger,
 )
 
 
@@ -54,7 +54,7 @@ def find_bads(meeg, n_jobs, **kwargs):
     noisy_chs, flat_chs = find_bad_channels_maxwell(
         raw, coord_frame=coord_frame, **kwargs
     )
-    logging.info(f"Noisy channels: {noisy_chs}\n" f"Flat channels: {flat_chs}")
+    logger().info(f"Noisy channels: {noisy_chs}\n" f"Flat channels: {flat_chs}")
     raw.info["bads"] = noisy_chs + flat_chs + raw.info["bads"]
     meeg.set_bad_channels(raw.info["bads"])
     meeg.save_raw(raw)
@@ -1201,7 +1201,7 @@ def morph_fsmri(meeg, morph_to):
         )
         meeg.save_source_morph(morph)
     else:
-        logging.info(
+        logger().info(
             f"There is no need to morph the source-space for {meeg.name}, "
             f'because the morph-destination "{morph_to}" '
             f"is the same as the associated FSMRI."
@@ -1488,7 +1488,7 @@ def apply_morph(meeg, morph_to):
             morphed_stcs[trial] = morph.apply(stcs[trial])
         meeg.save_morphed_source_estimates(morphed_stcs)
     else:
-        logging.info(
+        logger().info(
             f"{meeg.name} is already in source-space of {morph_to} "
             f"and won't be morphed"
         )

mne_pipeline_hd/gui/base_widgets.py

@@ -6,7 +6,6 @@
 """
 
 import itertools
-import logging
 import re
 import sys
 
@@ -49,7 +48,7 @@
     FileManagementModel,
     TreeModel,
 )
-from mne_pipeline_hd.pipeline.pipeline_utils import QS
+from mne_pipeline_hd.pipeline.pipeline_utils import QS, logger
 
 
 class Base(QWidget):
@@ -107,11 +106,13 @@ def get_current(self):
 
     def _current_changed(self, current_idx, previous_idx):
         current = self.model.getData(current_idx)
+        # ToDo: For ListWidget after removal,
+        #  there is a bug when previous_idx is too high
         previous = self.model.getData(previous_idx)
 
         self.currentChanged.emit(current, previous)
 
-        logging.debug(f"Current changed from {previous} to {current}")
+        logger().debug(f"Current changed from {previous} to {current}")
 
     def get_selected(self):
         try:
@@ -129,13 +130,13 @@ def _selection_changed(self):
 
         self.selectionChanged.emit(selected)
 
-        logging.debug(f"Selection changed to {selected}")
+        logger().debug(f"Selection changed to {selected}")
 
     def _data_changed(self, index, _):
         data = self.model.getData(index)
 
         self.dataChanged.emit(data, index)
-        logging.debug(f"{data} changed at {index}")
+        logger().debug(f"{data} changed at {index}")
 
     def content_changed(self):
         """Informs ModelView about external change made in data"""
@@ -427,7 +428,7 @@ def init_ui(self):
 
     def _checked_changed(self):
         self.checkedChanged.emit(self.model._checked)
-        logging.debug(f"Changed values: {self.model._checked}")
+        logger().debug(f"Changed values: {self.model._checked}")
 
     def replace_checked(self, new_checked):
         """Replaces model._checked with new checked list"""
@@ -645,7 +646,7 @@ def _current_changed(self, current_idx, previous_idx):
 
         self.currentChanged.emit(current_data, previous_data)
 
-        logging.debug(f"Current changed from {current_data} to {previous_data}")
+        logger().debug(f"Current changed from {current_data} to {previous_data}")
 
     def _selected_keyvalue(self, indexes):
         try:
@@ -661,7 +662,7 @@ def _selection_changed(self):
 
         self.selectionChanged.emit(selected_data)
 
-        logging.debug(f"Selection to {selected_data}")
+        logger().debug(f"Selection to {selected_data}")
 
     def select(self, keys, values, clear_selection=True):
         key_indices = [i for i, x in enumerate(self.model._data.keys()) if x in keys]
@@ -909,7 +910,7 @@ def _current_changed(self, current_idx, previous_idx):
 
         self.currentChanged.emit(current_list, previous_list)
 
-        logging.debug(f"Current changed from {previous_list} to {current_list}")
+        logger().debug(f"Current changed from {previous_list} to {current_list}")
 
     def get_selected(self):
         # Somehow, the indexes got from selectionChanged
@@ -924,7 +925,7 @@ def _selection_changed(self):
         selection_list = self.get_selected()
         self.selectionChanged.emit(selection_list)
 
-        logging.debug(f"Selection changed to {selection_list}")
+        logger().debug(f"Selection changed to {selection_list}")
 
     def select(self, values=None, rows=None, columns=None, clear_selection=True):
         """

mne_pipeline_hd/gui/gui_utils.py

@@ -40,7 +40,7 @@
 )
 
 from mne_pipeline_hd import _object_refs
-from mne_pipeline_hd.pipeline.pipeline_utils import QS
+from mne_pipeline_hd.pipeline.pipeline_utils import QS, logger
 
 
 def center(widget):
@@ -151,7 +151,7 @@ def show_error_dialog(exc_str):
     if QApplication.instance() is not None:
         ErrorDialog(exc_str, title="A unexpected error occurred")
     else:
-        logging.debug("No QApplication instance available.")
+        logger().debug("No QApplication instance available.")
 
 
 def gui_error_decorator(func):
@@ -204,7 +204,7 @@ def exception_hook(self, exc_type, exc_value, exc_traceback):
                 exc_value,
                 "".join(traceback.format_tb(exc_traceback)),
             )
-            logging.critical(
+            logger().critical(
                 f"Uncaught exception:\n"
                 f"{exc_str[0]}: {exc_str[1]}\n"
                 f"{exc_str[2]}",
@@ -287,7 +287,10 @@ def write_stdout(self, text):
 
     def write_stderr(self, text):
         text = self._html_compatible(text)
-        text = f'<font color="red">{text}</font>'
+        if text[-4:] == "<br>":
+            text = f'<font color="red">{text[:-4]}</font><br>'
+        else:
+            text = f'<font color="red">{text}</font>'
         self.buffer.append(text)
 
     # Make sure cursor is not moved
@@ -318,19 +321,24 @@ class StdoutStderrStream(io.TextIOBase):
     def __init__(self, kind):
         super().__init__()
         self.signal = StreamSignals()
-        if kind == "stdout":
+        self.kind = kind
+        if self.kind == "stdout":
             self.original_stream = sys.__stdout__
-        else:
+        elif self.kind == "stderr":
             self.original_stream = sys.__stderr__
+        else:
+            self.original_stream = None
 
     def write(self, text):
-        # Still send output to the command-line
-        self.original_stream.write(text)
+        if self.original_stream is not None:
+            # Still send output to the command-line
+            self.original_stream.write(text)
         # Emit signal to display in GUI
         self.signal.text_written.emit(text)
 
     def flush(self):
-        self.original_stream.flush()
+        if self.original_stream is not None:
+            self.original_stream.flush()
 
 
 class WorkerSignals(QObject):
@@ -723,7 +731,7 @@ def get_user_input_string(prompt, title="Input required!", force=False):
                     "You need to provide an appropriate input to proceed!",
                 )
             else:
-                logging.warning(
+                logger().warning(
                     "Input required! You need to provide "
                     "an appropriate input to proceed!"
                 )