diff --git a/CHANGELOG.md b/CHANGELOG.md index 5d0bc07..fb79697 100644 --- a/CHANGELOG.md +++ b/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 diff --git a/src/morphobricks_preprocessing/notebook_ui.py b/src/morphobricks_preprocessing/notebook_ui.py index 26c7628..ad250ec 100644 --- a/src/morphobricks_preprocessing/notebook_ui.py +++ b/src/morphobricks_preprocessing/notebook_ui.py @@ -488,6 +488,20 @@ 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 @@ -495,11 +509,18 @@ def __init__(self, handler: logging.Handler): # noqa: ANN204 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 diff --git a/src/morphobricks_preprocessing/projection_marker.py b/src/morphobricks_preprocessing/projection_marker.py index aa34b06..6c07cea 100644 --- a/src/morphobricks_preprocessing/projection_marker.py +++ b/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 diff --git a/tests/test_notebook_log_capture.py b/tests/test_notebook_log_capture.py new file mode 100644 index 0000000..5a500bb --- /dev/null +++ b/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() diff --git a/tests/test_projection_marker.py b/tests/test_projection_marker.py index cc60bf0..fa6450d 100644 --- a/tests/test_projection_marker.py +++ b/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="") + _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)