Say why metadata failed to load and how to see the tracebacks

dandi/organize.py

@@ -94,6 +94,53 @@ class OrganizeInvalid(StrEnum):
 
 dandi_path = op.join("sub-{subject_id}", "{dandi_filename}")
 
+#: How many per-file metadata errors `format_metadata_load_failures()` spells
+#: out before deferring the rest to the log file
+MAX_METADATA_ERRORS_SHOWN = 5
+
+
+def format_metadata_load_failures(
+    metadata_excs: Sequence[tuple[dict, tuple | None]], npaths: int
+) -> str:
+    """Compose an actionable message about files whose metadata failed to load.
+
+    The message names each offending path together with the exception type and
+    the exception's own message, and it says how to get at the full tracebacks,
+    rather than only stating that they exist at DEBUG level.
+
+    Parameters
+    ----------
+    metadata_excs : sequence of (dict, tuple or None)
+        Pairs of a metadata record and, if loading it raised, a
+        ``(exception class, exception message, traceback)`` tuple
+    npaths : int
+        Total number of paths that were considered
+
+    Returns
+    -------
+    str
+        A multi-line message suitable for logging at WARNING level
+    """
+    failures = [(m["path"], e) for m, e in metadata_excs if e]
+    lines = [
+        f"Failed to load metadata for {len(failures)} out of "
+        f"{pluralize(npaths, 'file')}:"
+    ]
+    for path, exc in failures[:MAX_METADATA_ERRORS_SHOWN]:
+        exc_message = str(exc[1]).strip() or "<no message>"
+        lines.append(f"  {path}: {exc[0].__name__}: {exc_message}")
+    if len(failures) > MAX_METADATA_ERRORS_SHOWN:
+        lines.append(
+            f"  ... and {len(failures) - MAX_METADATA_ERRORS_SHOWN} more, see the "
+            "log file"
+        )
+    lines.append(
+        "Full tracebacks are recorded in the log file whose location is reported "
+        "at the end of this run.  To also see them on the console, re-run as "
+        "'dandi --log-level DEBUG organize ...'."
+    )
+    return "\n".join(lines)
+
 
 def filter_invalid_metadata_rows(metadata_rows):
     """Split into two lists - valid and invalid entries"""
@@ -891,14 +938,7 @@ def _get_metadata(path):
             metadata_excs = list(map(_get_metadata, paths))
         exceptions = [e for _, e in metadata_excs if e]
         if exceptions:
-            lgr.warning(
-                "Failed to load metadata for %d out of %d files "
-                "due to following types of exceptions: %s. "
-                "Details of the exceptions will be shown at DEBUG level",
-                len(exceptions),
-                len(paths),
-                ", ".join(e[0].__name__ for e in exceptions),
-            )
+            lgr.warning("%s", format_metadata_load_failures(metadata_excs, len(paths)))
             for m, e in metadata_excs:
                 if not e:
                     continue

dandi/tests/test_organize.py

@@ -15,12 +15,14 @@
 from ..cli.cmd_organize import organize
 from ..consts import dandiset_metadata_file
 from ..organize import (
+    MAX_METADATA_ERRORS_SHOWN,
     CopyMode,
     FileOperationMode,
     _sanitize_value,
     create_dataset_yml_template,
     create_unique_filenames_from_metadata,
     detect_link_type,
+    format_metadata_load_failures,
     get_obj_id,
     populate_dataset_yml,
     validate_organized_path,
@@ -434,3 +436,71 @@ def test_organize_required_field(simple2_nwb: Path, tmp_path: Path) -> None:
         tmp_path / dandiset_metadata_file,
         tmp_path / "sub-mouse001" / "sub-mouse001_ses-session-id1.nwb",
     ]
+
+
+@pytest.mark.ai_generated
+def test_format_metadata_load_failures() -> None:
+    metadata_excs = [
+        ({"path": "/data/ok.nwb"}, None),
+        (
+            {"path": "/data/bad.nwb"},
+            (ValueError, "Date is missing timezone information", None),
+        ),
+    ]
+    msg = format_metadata_load_failures(metadata_excs, 2)
+    assert "Failed to load metadata for 1 out of 2 files:" in msg
+    # the path and the actual reason are spelled out, not just the class name
+    assert "/data/bad.nwb: ValueError: Date is missing timezone information" in msg
+    # and the user is told where to look and what to run
+    assert "log file" in msg
+    assert "dandi --log-level DEBUG organize" in msg
+    # files that loaded fine are not mentioned
+    assert "/data/ok.nwb" not in msg
+
+
+@pytest.mark.ai_generated
+def test_format_metadata_load_failures_truncates() -> None:
+    metadata_excs: list[tuple[dict, Any]] = [
+        ({"path": f"/data/{i}.nwb"}, (ValueError, f"boom {i}", None))
+        for i in range(MAX_METADATA_ERRORS_SHOWN + 3)
+    ]
+    msg = format_metadata_load_failures(metadata_excs, len(metadata_excs))
+    assert msg.count("boom ") == MAX_METADATA_ERRORS_SHOWN
+    assert "... and 3 more, see the log file" in msg
+
+
+@pytest.mark.ai_generated
+@mark_xfail_windows_python313_posixsubprocess
+def test_organize_reports_metadata_exception_reason(
+    simple2_nwb: Path,
+    tmp_path: Path,
+    caplog: pytest.LogCaptureFixture,
+    monkeypatch: pytest.MonkeyPatch,
+) -> None:
+    # Regression test for https://github.com/dandi/dandi-cli/issues/1640 :
+    # the warning used to only say which exception *types* occurred and that
+    # details were available "at DEBUG level", without saying how to get them.
+    caplog.set_level(logging.INFO, logger="dandi")
+
+    def boom(path: Any, **kwargs: Any) -> NoReturn:
+        raise ValueError("Date is missing timezone information")
+
+    monkeypatch.setattr("dandi.metadata.nwb.get_metadata", boom)
+    r = CliRunner().invoke(
+        organize,
+        [
+            "--files-mode",
+            "dry",
+            "--invalid",
+            "warn",
+            "-d",
+            str(tmp_path / "organized"),
+            str(simple2_nwb),
+        ],
+    )
+    assert r.exit_code == 0
+    warnings = [rec[2] for rec in caplog.record_tuples if rec[1] == logging.WARNING]
+    matching = [w for w in warnings if "Date is missing timezone information" in w]
+    assert matching, f"reason not reported in warnings: {warnings}"
+    assert str(simple2_nwb) in matching[0]
+    assert "dandi --log-level DEBUG organize" in matching[0]