fix(crashlog): build the crash context outside the lock

CHANGELOG.md

@@ -5,6 +5,14 @@ The format follows [Keep a Changelog](https://keepachangelog.com/); versions fol
 
 ## [Unreleased]
 
+### Fixed
+
+- **The program no longer freezes while it records an internal error.** Writing a crash
+  report used to read the Control page form. If a field held a value the program cannot
+  accept, such as a letter typed into Loss, or if a background task hit an error at the
+  wrong moment, the window stopped responding and STOP did nothing. Crash reports still
+  carry the settings. When a field is invalid, the report now says so instead.
+
 ## [0.7.0] - 2026-09-25
 
 ### Added

beantester/crashlog.py

@@ -54,6 +54,13 @@
   whatever broke last.
 * **Unbounded disk.** The log rotates and is capped, so a program left running for
   a fortnight with a repeating fault cannot fill the volume it is diagnosing.
+* **A logger that wedges the program.** Every thread reports here, the capture
+  thread and the watchdog included, so the one lock this module owns is never held
+  while code from OUTSIDE it runs. The context provider is the App's code, and it
+  used to run under that lock: a provider that recorded a fault of its own
+  deadlocked its thread on it, and one that waited for the Tk main loop deadlocked
+  against a main thread waiting for it. Every later report from every thread then
+  queued behind them - the GUI froze and the watchdog stopped watching.
 """
 import faulthandler
 import hashlib
@@ -90,6 +97,9 @@
 # makes room by dropping the fault nobody has seen for longest. See _record.
 _seen: OrderedDict[str, dict] = OrderedDict()   # fingerprint -> record (+ a count)
 _context_provider = None            # set by the App/CLI: returns a dict of state
+# Per thread: is this thread inside the context provider right now? A fault the
+# provider itself records must not ask the provider again (see _collect_context).
+_local = threading.local()
 _installed = False
 _enabled = True
 
@@ -113,9 +123,15 @@ def _ensure_dir():
 def set_context_provider(fn):
     """Register a callable returning a dict of app state to attach to every crash.
 
-    The App passes the seed, the settings, the counters and the open page; the CLI
-    passes the parsed configuration. Whatever it returns is best-effort: a context
-    provider that itself raises must not turn a crash into two.
+    The App passes the seed, the settings, the counters and the open page. Whatever
+    it returns is best-effort: a context provider that itself raises must not turn a
+    crash into two.
+
+    It runs on WHICHEVER thread recorded the fault - the capture thread, the
+    watchdog, a worker - so it must read plain data only: no GUI toolkit call (Tk
+    waits for its own main loop, which may be the thread waiting on us), and no lock
+    a recording thread may already hold. A fault it records itself is recorded
+    without asking it again.
     """
     global _context_provider
     _context_provider = fn
@@ -132,13 +148,23 @@ def _collect_context():
         "pydivert": _module_version("pydivert"),
         "threads": [t.name for t in threading.enumerate()],
     }
-    if _context_provider is not None:
-        try:
-            extra = _context_provider() or {}
-            if isinstance(extra, dict):
-                base.update(extra)
-        except Exception as exc:            # a broken provider must not mask the crash
-            base["context_provider_failed"] = f"{type(exc).__name__}: {exc}"
+    if _context_provider is None:
+        return base
+    if getattr(_local, "in_provider", False):
+        # The provider recorded a fault of its own. Asking it again would run the
+        # same failing code again, record again, ask again - recursion, and before
+        # the context moved out of the lock, a thread deadlocked on itself.
+        base["context_provider_skipped"] = "re-entered"
+        return base
+    _local.in_provider = True
+    try:
+        extra = _context_provider() or {}
+        if isinstance(extra, dict):
+            base.update(extra)
+    except Exception as exc:            # a broken provider must not mask the crash
+        base["context_provider_failed"] = f"{type(exc).__name__}: {exc}"
+    finally:
+        _local.in_provider = False
     return base
 
 
@@ -215,39 +241,48 @@ def _record(exc, source, subsystem, severity, note):
     with _lock:
         existing = _seen.get(fingerprint)
         if existing is not None:
-            existing["count"] += 1
-            existing["last_seen"] = _now_iso()
-            # Freshest last. The eviction below drops the OTHER end of the table,
-            # and a fault firing right now is the last thing it may drop.
-            _seen.move_to_end(fingerprint)
             # A repeating fault (a crash inside the tick loop fires 1.4x a second)
             # costs one integer from here on - not another disk write.
-            return existing
-
-        entry = {
-            "fingerprint": fingerprint,
-            "first_seen": _now_iso(),
-            "last_seen": _now_iso(),
-            "count": 1,
-            "severity": severity,
-            "source": source,
-            "subsystem": subsystem or _subsystem_of(frames),
-            "type": getattr(exc_type, "__name__", str(exc_type)),
-            "message": str(exc)[:500],
-            "note": note,
-            "traceback": "".join(
-                traceback.format_exception(exc_type, exc, tb))[:8000],
-            "context": _collect_context(),
-        }
+            return _count_again(existing, fingerprint)
+
+    # Built OUTSIDE the lock, and that is a deadlock fix, not tidiness (reproduced
+    # 2026-09-28, both ways). The context comes from the App's provider: the GUI's
+    # read a Tk variable and, on an invalid form field, recorded that ValueError -
+    # from inside the lock, into the lock, on the same thread. And a Tk call from a
+    # worker waits for the main loop, which could itself be waiting right here.
+    # Either way the lock stayed held, and every later report from every thread -
+    # the watchdog's too - queued behind it for good.
+    entry = {
+        "fingerprint": fingerprint,
+        "first_seen": _now_iso(),
+        "last_seen": _now_iso(),
+        "count": 1,
+        "severity": severity,
+        "source": source,
+        "subsystem": subsystem or _subsystem_of(frames),
+        "type": getattr(exc_type, "__name__", str(exc_type)),
+        "message": str(exc)[:500],
+        "note": note,
+        "traceback": "".join(
+            traceback.format_exception(exc_type, exc, tb))[:8000],
+        "context": _collect_context(),
+    }
+    with _lock:
+        existing = _seen.get(fingerprint)
+        if existing is not None:
+            # Another thread recorded this same NEW fault while this one was
+            # building its context: one record, one more occurrence, no second
+            # disk write. The context built here is simply dropped.
+            return _count_again(existing, fingerprint)
         # The table used to REFUSE a new fingerprint once it was full, and that
         # turned the ceiling into a cliff: a fault arriving late never got a slot,
         # so every one of its occurrences looked new, built a full context and
         # wrote to disk again. MEASURED on this machine (2026-09-03), the same
         # repeating fault: 137 us and zero writes with a slot, 1926 us and a write
-        # PER OCCURRENCE without one - 14x, with the expensive half built inside
-        # the lock every other caller of this module waits on. In other words the
-        # de-duplication this module is built around stopped working exactly when
-        # the program was failing most.
+        # PER OCCURRENCE without one - 14x, and back then the expensive half was
+        # built inside the lock every other caller of this module waits on. In
+        # other words the de-duplication this module is built around stopped
+        # working exactly when the program was failing most.
         #
         # So the table makes room instead of refusing: in a shipped build it is a
         # dedup CACHE and nothing else, since neither read-back helper at the
@@ -266,6 +301,16 @@ def _record(exc, source, subsystem, severity, note):
     return entry
 
 
+def _count_again(existing, fingerprint):
+    """One more occurrence of a fault already in the table. Caller holds ``_lock``."""
+    existing["count"] += 1
+    existing["last_seen"] = _now_iso()
+    # Freshest last. The eviction in _record drops the OTHER end of the table,
+    # and a fault firing right now is the last thing it may drop.
+    _seen.move_to_end(fingerprint)
+    return existing
+
+
 def _now_iso():
     return datetime.now(timezone.utc).isoformat(timespec="seconds")
 

beantester/gui/crash.py

@@ -6,7 +6,9 @@
 * **the report context** - rich, expensive, and PULLED at the moment a Python-level
   failure is recorded (``crashlog.set_context_provider``). It carries the seed and
   the settings, because a crash report should be one step away from a REPRO rather
-  than something to read.
+  than something to read. It is pulled on WHICHEVER thread failed, so it reads only
+  plain data: the form comes from a copy the main thread takes every tick, never
+  from a Tk variable (see ``context``).
 * **the breadcrumb** - three facts, cheap, and PUSHED to disk before anything goes
   wrong. A hard (C-level) crash writes a stack and nothing else: ``faulthandler``
   cannot ask a provider, so whatever the tool was doing has to already be on disk.
@@ -24,8 +26,17 @@
 alternative - widening five private attributes into a public surface so one
 neighbour can read them - would freeze more, not less.
 """
+import weakref
+
 from .. import crashlog
 from ..repro import settings_to_cli_string
+from ..settings import settings_from_raw
+
+# The raw form as the MAIN thread last read it, per App - the only way a report
+# written on another thread may learn what the form held. Kept here and not on
+# App, because App sits exactly on both class ratchets in tests/test_code_shape.py
+# (attributes and methods). Weak, so a test that builds many Apps keeps none alive.
+_FORMS: weakref.WeakKeyDictionary[object, dict] = weakref.WeakKeyDictionary()
 
 
 def install(app):
@@ -39,22 +50,45 @@ def context(app):
     The point is that a crash report should be one step away from a REPRO, not just
     something to read: the seed and the settings are what make the failure happen
     again.
+
+    This runs on whichever thread recorded the fault, so it touches PLAIN data only
+    - and each of the three things it no longer does deadlocked the program
+    (reproduced 2026-09-28): it read the form through Tk variables (a worker's Tcl
+    call waits for the main loop, which may be waiting on the crash log); it took
+    the engine's statistics lock (``last_snapshot`` is the same numbers, one tick
+    old, lock-free); and on an invalid field it recorded that error into the crash
+    log whose lock its caller held. An invalid field is now a fact in the report.
+
+    A real failure in here is still recorded, and that is safe now: the logger
+    holds no lock while this runs, and a fault recorded from inside it is written
+    without asking this function again (``crashlog._collect_context``). What is
+    filled in before the failure stays in the report.
     """
     state = {"page": app._page_id, "running": app.running}
-    try:
-        state["seed"] = app.engine.effective_seed()
-        state["counters"] = dict(app.engine.stats_snapshot())
-        settings = app._settings_from_widgets()
-        state["settings"] = settings
-        state["repro_command"] = settings_to_cli_string(
-            settings, seed=app.engine.effective_seed())
-        state["log_tail"] = list(app._log_lines[-crashlog.MAX_LOG_TAIL:])
-        state["open_windows"] = app.windows.open_ids()
-    except Exception as _exc:
-        crashlog.note(_exc, "gui.app")
+    with crashlog.quiet("gui.crash"):
+        _fill(app, state)
     return state
 
 
+def _fill(app, state):
+    state["seed"] = app.engine.effective_seed()
+    if app.last_snapshot is not None:
+        state["counters"] = dict(app.last_snapshot)
+    state["log_tail"] = list(app._log_lines[-crashlog.MAX_LOG_TAIL:])
+    state["open_windows"] = app.windows.open_ids()
+    raw = _FORMS.get(app)
+    if raw is None:
+        return                      # a fault before the first tick read the form
+    try:
+        settings = settings_from_raw(raw, app._lang)
+    except ValueError as exc:       # what a user mid-typing leaves in a field
+        state["settings_error"] = str(exc)
+        state["form"] = raw
+        return
+    state["settings"] = settings
+    state["repro_command"] = settings_to_cli_string(settings, seed=state["seed"])
+
+
 def leave_breadcrumb(app):
     """Put the three facts a NATIVE crash report cannot carry on disk.
 
@@ -68,6 +102,13 @@ def leave_breadcrumb(app):
 
     Deliberately SMALL. The seed and the settings belong to ``context`` above, not
     to a file rewritten whenever the user changes tab.
+
+    The same tick also copies the raw form for ``context`` - in memory, no disk -
+    for the same reason: it is the main thread, and it cannot be forgotten. The
+    read is the cheap one (no parsing, no regex); the parsing happens only when a
+    report is actually written.
     """
     crashlog.breadcrumb(page=app._page_id, running=app.running,
                         windows=app.windows.open_ids())
+    with crashlog.quiet("gui.crash"):   # a broken read must not cost the tick its rest
+        _FORMS[app] = app._raw_settings()