Quiet the notebook output: no debug flood from ImageJ TIFFs

CHANGELOG.md

@@ -8,6 +8,15 @@ v0.5.1: no run before v0.5.1 is read.)
 
 ## Unreleased (v0.5.1)
 
+### Fixed: the notebook output is no longer flooded with debug messages
+
+ImageJ TIFFs have a plain-text description, so reading it as OME-XML failed for every image and
+logged a debug message with a traceback; and the notebook's own log capture set the package
+logger to DEBUG while records still reached the root logger, which Colab prints. Now only an
+OME-XML description is parsed (which images are marked is unchanged; a malformed one logs one
+debug line without a traceback), and while the capture is attached the package's DEBUG records
+go to the "Technical details" panel only, with WARNING and above still reaching the root handlers.
+
 ### Normalization pinned at v0.4.0 (#262)
 
 - **`morphobricks-normalization` moves from v0.3.4 to v0.4.0** (tag `c952263`). It is

src/morphobricks_preprocessing/notebook_ui.py

@@ -488,18 +488,39 @@ def attached(self):  # noqa: ANN202
         return _Attached(self)
 
 
+class _ToRootWarnings(logging.Handler):
+    """Hands WARNING and above to the root logger's handlers (as propagation would)."""
+
+    def __init__(self) -> None:
+        super().__init__(logging.WARNING)
+
+    def emit(self, record: logging.LogRecord) -> None:
+        # With no root handler (plain Jupyter), propagation would reach logging.lastResort.
+        handlers = logging.getLogger().handlers or [logging.lastResort]
+        for handler in handlers:
+            if handler is not None and record.levelno >= handler.level:
+                handler.handle(record)
+
+
 class _Attached:
     def __init__(self, handler: logging.Handler):  # noqa: ANN204
         self.handler = handler
         self.logger = logging.getLogger(_PACKAGE_LOGGER)
 
     def __enter__(self):  # noqa: ANN204
         self.level = self.logger.level
+        self.propagate = self.logger.propagate
         self.logger.addHandler(self.handler)
         self.logger.setLevel(logging.DEBUG)
+        # DEBUG is for the panel only: a root handler (Colab's) would print every record.
+        self.logger.propagate = False
+        self.forward = _ToRootWarnings()
+        self.logger.addHandler(self.forward)
         return self.handler
 
     def __exit__(self, *exc):  # noqa: ANN002, ANN204
         self.logger.removeHandler(self.handler)
+        self.logger.removeHandler(self.forward)
+        self.logger.propagate = self.propagate
         self.logger.setLevel(self.level)
         return False

src/morphobricks_preprocessing/projection_marker.py

@@ -35,10 +35,16 @@ def is_projected_copy(path: Path) -> bool:
     try:
         with tifffile.TiffFile(path) as tif:
             text = tif.pages.first.description
-        root = ElementTree.fromstring(text)
-    except (OSError, ValueError, ElementTree.ParseError, tifffile.TiffFileError, AttributeError):
+    except (OSError, ValueError, tifffile.TiffFileError, AttributeError):
         logger.debug("Cannot read the description of %s", path, exc_info=True)
         return False
+    if not text.lstrip().startswith("<"):
+        return False  # plain text (ImageJ, none): not OME-XML, so not marked; nothing to report
+    try:
+        root = ElementTree.fromstring(text)
+    except ElementTree.ParseError as exc:
+        logger.debug("The OME description of %s is not well-formed XML (%s)", path, exc)
+        return False
     for image in root:
         if image.tag.rsplit("}", 1)[-1] != "Image":
             continue

tests/test_notebook_log_capture.py

@@ -0,0 +1,47 @@
+"""The notebook's log capture keeps DEBUG off the root handlers (Colab prints them)."""
+
+import io
+import logging
+
+import pytest
+
+pytest.importorskip("ipywidgets")
+pytest.importorskip("matplotlib")
+
+from morphobricks_preprocessing import notebook_ui  # noqa: E402
+
+
+def test_attached_log_capture_keeps_debug_off_the_root_handlers_but_not_warnings():
+    root_stream = io.StringIO()
+    root_handler = logging.StreamHandler(root_stream)
+    root_handler.setLevel(logging.NOTSET)
+    root = logging.getLogger()
+    root.addHandler(root_handler)
+    package = logging.getLogger("morphobricks_preprocessing")
+    before = (package.level, package.propagate, list(package.handlers))
+    try:
+        capture = notebook_ui._LogCapture()
+        with capture.attached():
+            child = logging.getLogger("morphobricks_preprocessing.projection_marker")
+            child.debug("quiet detail")
+            child.warning("loud warning")
+        assert "quiet detail" not in root_stream.getvalue()
+        assert "loud warning" in root_stream.getvalue()
+        assert any("quiet detail" in line for line in capture.lines)
+        assert (package.level, package.propagate, list(package.handlers)) == before
+    finally:
+        root.removeHandler(root_handler)
+
+
+def test_a_warning_still_reaches_the_last_resort_handler_without_root_handlers(monkeypatch):
+    stream = io.StringIO()
+    monkeypatch.setattr(logging, "lastResort", logging.StreamHandler(stream))
+    root = logging.getLogger()
+    monkeypatch.setattr(root, "handlers", [])
+    capture = notebook_ui._LogCapture()
+    with capture.attached():
+        child = logging.getLogger("morphobricks_preprocessing.projection_marker")
+        child.debug("quiet detail")
+        child.warning("loud warning")
+    assert "loud warning" in stream.getvalue()
+    assert "quiet detail" not in stream.getvalue()

tests/test_projection_marker.py

@@ -80,3 +80,34 @@ def no_pixels(self, *args, **kwargs):
     from morphobricks_preprocessing.projection_marker import marked_images
 
     assert marked_images(copies, NAMES) == sorted(NAMES)
+
+
+def _record_marker_logs(caplog):
+    caplog.set_level("DEBUG", logger="morphobricks_preprocessing")
+
+
+def test_an_imagej_tiff_is_not_marked_and_logs_nothing(tmp_path, caplog):
+    from morphobricks_preprocessing.projection_marker import is_projected_copy
+
+    path = tmp_path / "a.tif"
+    tifffile.imwrite(path, np.zeros((2, 4, 4), np.uint8), imagej=True)
+    _record_marker_logs(caplog)
+    assert is_projected_copy(path) is False
+    assert caplog.records == []
+
+
+def test_a_malformed_ome_description_is_not_marked_and_logs_no_traceback(tmp_path, caplog):
+    from morphobricks_preprocessing.projection_marker import is_projected_copy
+
+    path = tmp_path / "b.tif"
+    tifffile.imwrite(path, np.zeros((4, 4), np.uint8), description="<OME><Image>")
+    _record_marker_logs(caplog)
+    assert is_projected_copy(path) is False
+    assert len(caplog.records) == 1 and not caplog.records[0].exc_info
+
+
+def test_a_marked_projection_is_still_marked(tmp_path):
+    from morphobricks_preprocessing.projection_marker import marked_images
+
+    copies = projected_tree(tmp_path)
+    assert set(marked_images(copies, NAMES)) == set(NAMES)