feat(telemetry): record root cause on WinMLCLIError

src/winml/modelkit/telemetry/telemetry.py

@@ -24,7 +24,11 @@
 from . import consent as consent_mod
 from . import constants
 from .deviceid import get_or_create_device_id
-from .utils import _extract_exception_stack, _format_exception_message
+from .utils import (
+    _extract_exception_stack,
+    _format_exception_message,
+    _root_cause,
+)
 
 
 if TYPE_CHECKING:
@@ -43,6 +47,12 @@
 _ACTION_EVENT = "WinMLCLIAction"
 _ERROR_EVENT = "WinMLCLIError"
 
+# Root-cause messages get a larger cap than the outer exception message
+# (``_MESSAGE_CAP``): the root cause is the diagnostic payload, whereas the
+# outer message is often just a wrapper prefix. Initial value; tune from
+# real telemetry once truncation rates are known.
+_ROOT_CAUSE_MESSAGE_CAP = 500
+
 _ALLOWED_KEYS: dict[str, set[str]] = {
     _HEARTBEAT_EVENT: set(),
     _ACTION_EVENT: {
@@ -58,6 +68,8 @@
         "exception_type",
         "exception_message",
         "exception_stack",
+        "root_cause_type",
+        "root_cause_message",
     },
 }
 
@@ -214,10 +226,18 @@ def log_error(self, exc: BaseException) -> None:
         try:
             if self._logger is None:
                 return
+            root = _root_cause(exc)
+            has_root = root is not exc
             attrs = {
                 "exception_type": type(exc).__name__,
                 "exception_message": _format_exception_message(str(exc)),
                 "exception_stack": _extract_exception_stack(exc.__traceback__),
+                "root_cause_type": type(root).__name__ if has_root else None,
+                "root_cause_message": (
+                    _format_exception_message(str(root), cap=_ROOT_CAUSE_MESSAGE_CAP)
+                    if has_root
+                    else None
+                ),
             }
             self._emit(_ERROR_EVENT, attrs)
         except Exception:

src/winml/modelkit/telemetry/utils.py

@@ -116,14 +116,15 @@ def _scrub_pii(text: str) -> str:
 _MESSAGE_CAP = 200
 
 
-def _format_exception_message(message: str | None) -> str:
+def _format_exception_message(message: str | None, cap: int = _MESSAGE_CAP) -> str:
     """Run the scrubbing pipeline: path trim -> PII scrub -> length cap.
 
     Scrub runs *before* the length cap so PII straddling the cap boundary
     is still recognized by the regexes. Capping first would split a token
     or email mid-string and leak the surviving prefix (e.g. ``alice@exa…``
     leaves ``alice`` exposed because the cropped fragment no longer
-    matches the email pattern).
+    matches the email pattern). ``cap`` is parameterized so the root-cause
+    message can use a larger limit than the outer message.
     """
     if not message:
         return ""
@@ -134,8 +135,8 @@ def _format_exception_message(message: str | None) -> str:
     result = _scrub_pii(result)
     # Cap last - bounds final size even if scrub expanded the string
     # (each match becomes the 11-char ``<scrubbed>`` placeholder).
-    if len(result) > _MESSAGE_CAP:
-        result = result[: _MESSAGE_CAP - 1] + "…"
+    if len(result) > cap:
+        result = result[: cap - 1] + "…"
     return result
 
 
@@ -292,3 +293,27 @@ def _extract_exception_stack(tb: Any) -> list[dict[str, Any]]:
         }
         for frame in frames
     ]
+
+
+def _root_cause(exc: BaseException) -> BaseException:
+    """Return the innermost cause of an exception chain.
+
+    Follows ``__cause__`` (explicit ``raise ... from e``) in preference to
+    ``__context__`` (implicit, set when raising inside an ``except`` block),
+    repeatedly, until neither is set. A ``__context__`` explicitly suppressed
+    by ``raise ... from None`` (``__suppress_context__``) is honored — the
+    walk stops there, matching Python's own traceback printing and respecting
+    the developer's intent to hide that inner error. Returns ``exc`` itself
+    when there is no chain. Cycle-safe: a chain that loops back on itself
+    terminates rather than spinning forever.
+    """
+    seen: set[int] = {id(exc)}
+    current = exc
+    while True:
+        nxt = current.__cause__
+        if nxt is None and not current.__suppress_context__:
+            nxt = current.__context__
+        if nxt is None or id(nxt) in seen:
+            return current
+        seen.add(id(nxt))
+        current = nxt

tests/unit/telemetry/test_telemetry_emit.py

@@ -123,6 +123,59 @@ def test_log_error_scrubs_message_and_extracts_stack(running_telemetry):
         assert set(frame.keys()) == {"file", "line", "function"}
 
 
+def test_root_cause_message_cap_is_500():
+    from winml.modelkit.telemetry.telemetry import _ROOT_CAUSE_MESSAGE_CAP
+
+    assert _ROOT_CAUSE_MESSAGE_CAP == 500
+
+
+def test_log_error_records_root_cause_for_chained(running_telemetry):
+    logger = _with_mock_logger(running_telemetry)
+    try:
+        try:
+            raise ValueError("qwen3_5 not recognized")
+        except ValueError as e:
+            raise RuntimeError("Inspection error") from e
+    except RuntimeError as outer:
+        running_telemetry.log_error(outer)
+
+    log_record = logger.emit.call_args.args[0]
+    attrs = dict(log_record.attributes)
+    assert attrs["exception_type"] == "RuntimeError"
+    assert attrs["root_cause_type"] == "ValueError"
+    assert "qwen3_5 not recognized" in attrs["root_cause_message"]
+
+
+def test_log_error_unchained_has_null_root_cause(running_telemetry):
+    logger = _with_mock_logger(running_telemetry)
+    try:
+        raise RuntimeError("Quantization failed")
+    except RuntimeError as exc:
+        running_telemetry.log_error(exc)
+
+    log_record = logger.emit.call_args.args[0]
+    attrs = dict(log_record.attributes)
+    assert attrs["exception_type"] == "RuntimeError"
+    assert attrs["root_cause_type"] is None
+    assert attrs["root_cause_message"] is None
+
+
+def test_log_error_scrubs_root_cause_message(running_telemetry):
+    logger = _with_mock_logger(running_telemetry)
+    try:
+        try:
+            raise ValueError("leaked alice@example.com in root")
+        except ValueError as e:
+            raise RuntimeError("wrapper") from e
+    except RuntimeError as outer:
+        running_telemetry.log_error(outer)
+
+    log_record = logger.emit.call_args.args[0]
+    attrs = dict(log_record.attributes)
+    assert "alice@example.com" not in attrs["root_cause_message"]
+    assert "<scrubbed>" in attrs["root_cause_message"]
+
+
 def test_disabled_telemetry_noops_all_emits(monkeypatch):
     monkeypatch.setattr("winml.modelkit.telemetry.constants.INSTRUMENTATION_KEY", "")
     t = Telemetry.get_or_init()

tests/unit/telemetry/test_utils_scrubbing.py

@@ -156,6 +156,37 @@ def test_format_exception_message_scrubs_long_token_at_cap_boundary():
     assert len(result) <= 200
 
 
+def test_format_exception_message_default_cap_is_200():
+    msg = "y" * 400
+    result = _format_exception_message(msg)
+    assert len(result) <= 200
+
+
+def test_format_exception_message_custom_cap_allows_longer():
+    msg = "y" * 400
+    result = _format_exception_message(msg, cap=500)
+    # 400 < 500, so nothing is truncated.
+    assert result == msg
+    assert not result.endswith("…")
+
+
+def test_format_exception_message_custom_cap_still_truncates_beyond():
+    msg = "y" * 600
+    result = _format_exception_message(msg, cap=500)
+    assert len(result) <= 500
+    assert result.endswith("…")
+
+
+def test_format_exception_message_custom_cap_scrubs_pii_before_cap():
+    # Email lands just before the 500 boundary; must be scrubbed, not split.
+    prefix = "y" * 495
+    msg = prefix + " alice@example.com"
+    result = _format_exception_message(msg, cap=500)
+    assert "alice" not in result
+    assert "@" not in result
+    assert len(result) <= 500
+
+
 @pytest.mark.parametrize(
     "value,expected",
     [

tests/unit/telemetry/test_utils_stack.py

@@ -3,7 +3,7 @@
 # Licensed under the MIT License.
 # --------------------------------------------------------------------------
 
-from winml.modelkit.telemetry.utils import _extract_exception_stack
+from winml.modelkit.telemetry.utils import _extract_exception_stack, _root_cause
 
 
 def _raise_chain():
@@ -58,3 +58,80 @@ def test_extract_exception_stack_contains_no_message_or_locals():
 
 def test_extract_exception_stack_on_none_returns_empty():
     assert _extract_exception_stack(None) == []
+
+
+def test_root_cause_no_chain_returns_self():
+    exc = ValueError("boom")
+    assert _root_cause(exc) is exc
+
+
+def test_root_cause_follows_explicit_cause():
+    root = ValueError("root")
+    try:
+        try:
+            raise root
+        except ValueError as e:
+            raise RuntimeError("wrapper") from e
+    except RuntimeError as outer:
+        assert _root_cause(outer) is root
+
+
+def test_root_cause_follows_implicit_context():
+    root = ValueError("root")
+    try:
+        try:
+            raise root
+        except ValueError:
+            # No `from` — Python sets __context__ implicitly. B904 is the
+            # exact pattern under test here, so the lint is suppressed.
+            raise RuntimeError("wrapper")  # noqa: B904
+    except RuntimeError as outer:
+        assert _root_cause(outer) is root
+
+
+def test_root_cause_honors_suppressed_context():
+    # `raise ... from None` sets __suppress_context__=True and __cause__=None.
+    # The suppressed inner exception must NOT be walked into — matching
+    # Python's own traceback printing and the developer's intent to hide it.
+    try:
+        try:
+            raise ValueError("suppressed inner")
+        except ValueError:
+            raise RuntimeError("clean outer") from None
+    except RuntimeError as outer:
+        # No chain surfaces: the outer exception is its own root cause.
+        assert _root_cause(outer) is outer
+
+
+def test_root_cause_walks_multiple_levels_to_innermost():
+    innermost = OSError("disk full")
+    try:
+        try:
+            try:
+                raise innermost
+            except OSError as e1:
+                raise RuntimeError("mid") from e1
+        except RuntimeError as e2:
+            raise ValueError("top") from e2
+    except ValueError as outer:
+        assert _root_cause(outer) is innermost
+
+
+def test_root_cause_prefers_cause_over_context():
+    cause = ValueError("the cause")
+    context = KeyError("the context")
+    outer = RuntimeError("outer")
+    # Simulate: raised inside handling `context`, but `from cause`.
+    outer.__context__ = context
+    outer.__cause__ = cause
+    assert _root_cause(outer) is cause
+
+
+def test_root_cause_cycle_guard_terminates():
+    a = ValueError("a")
+    b = RuntimeError("b")
+    a.__cause__ = b
+    b.__cause__ = a  # cycle
+    # Must terminate and return one of the two, not loop forever.
+    result = _root_cause(a)
+    assert result in (a, b)