From 103c4bf87b1a6ab9622621c5e89e5751e73397c1 Mon Sep 17 00:00:00 2001 From: nimbrel <331679006+nimbrel@users.noreply.github.com> Date: Sat, 26 Sep 2026 10:06:18 +0000 Subject: [PATCH 1/5] fix(stress): locate each panic by its thread, not by its message Panic sites were matched to callables by message text, so two sites that panic with the same message were filed under whichever printed first, and the second site never appeared as a finding. The driver now records, per native thread, which callable panicked and in what order, and keeps every distinct panic message per callable with a count. Rust prints the same thread id in its panic line, so the two sequences are joined in order: each site gets exactly the calls that panicked there, and a callable that panicked at two sites is counted at each. When Rust prints no thread id, a panic is located by message and a finding names every site that shares it. Signed-off-by: nimbrel <331679006+nimbrel@users.noreply.github.com> --- python/ftcheck/stress/__init__.py | 200 ++++++++++++++++++++++-------- python/ftcheck/stress/driver.py | 44 ++++++- tests/test_stress_config.py | 90 ++++++++++++++ tests/test_stress_driver.py | 48 +++++++ 4 files changed, 327 insertions(+), 55 deletions(-) diff --git a/python/ftcheck/stress/__init__.py b/python/ftcheck/stress/__init__.py index a136e49..aeadb53 100644 --- a/python/ftcheck/stress/__init__.py +++ b/python/ftcheck/stress/__init__.py @@ -218,29 +218,85 @@ def _hang_finding(step: str, threads: int, seed: int) -> dict: } +# `thread '' () panicked at :::` then the +# message. Older Rust prints no thread id. _PANIC_AT = re.compile( + r"(?:thread '[^'\n]*'(?: \((?P\d+)\))? )?" r"panicked at (?P[^\n]+?):(?P\d+):(?P\d+):\n(?P[^\n]*)" ) +# How far past a thread's last matched panic line the next one is looked for. +# Extra lines on a thread (a panic the extension caught itself) are skipped. +_JOIN_WINDOW = 16 -def panic_locations(log_text: str) -> dict[str, dict]: - """Panic message -> where it panicked, from the Rust panic lines in the log. +def panic_locations(log_text: str) -> list[dict]: + """Every Rust panic line in the log, in order: where, and on which thread. `PanicException` carries the message but not the location; Rust prints - both to stderr (`thread '...' panicked at src/lib.rs:40:17:` then the - message), which the driver log captures. + both to stderr, which the driver log captures, with the native thread id + the driver also records for each panicking call. """ - found: dict[str, dict] = {} + found = [] for m in _PANIC_AT.finditer(log_text): - found.setdefault( - m.group("message").strip(), - {"file": m.group("file"), "line": int(m.group("line")), "column": int(m.group("column"))}, + found.append( + { + "tid": int(m.group("tid")) if m.group("tid") else None, + "file": m.group("file"), + "line": int(m.group("line")), + "column": int(m.group("column")), + "message": m.group("message").strip(), + } ) return found +def _same_message(logged: str, raised: str) -> bool: + # The log holds the first line of the message; the driver keeps 300 characters. + return logged[:300] == raised.split("\n", 1)[0].strip() + + +def _join(result: dict, events: list[dict], wanted: set[str]) -> tuple[dict, set[int]]: + """(qual -> {event index of the site: panics there}, consumed event indices). + + Each thread's panicking calls, in order, are matched to that thread's + panic lines, in order, so a site is known per call rather than guessed + from the message. + """ + by_tid: dict[int, list[int]] = {} + for i, e in enumerate(events): + if e["tid"] is not None: + by_tid.setdefault(e["tid"], []).append(i) + located: dict[str, dict[int, int]] = {} + consumed: set[int] = set() + for tid, runs in (result.get("panic_threads") or {}).items(): + mine = by_tid.get(int(tid), []) + k = 0 + for qual, message, count in runs: + for _ in range(count): + j = next( + ( + j + for j in range(k, min(k + _JOIN_WINDOW, len(mine))) + if _same_message(events[mine[j]]["message"], message) + ), + None, + ) + if j is None: + continue + k = j + 1 + consumed.add(mine[j]) + if qual in wanted: + site = located.setdefault(qual, {}) + site[mine[j]] = site.get(mine[j], 0) + 1 + return located, consumed + + +def _site_key(event: dict) -> str: + return f"{event['file']}:{event['line']}" + + def panic_findings( - result: dict | None, threads: int, seed: int, locations: dict[str, dict] | None = None + result: dict | None, threads: int, seed: int, locations: list[dict] | None = None ) -> list[dict]: """Rust panics a callable raised only when driven from many threads. @@ -250,56 +306,96 @@ def panic_findings( panic the baseline also raised is how the method behaves with those arguments, and is left alone. - Callables that panic at the same source location are one finding: one - `borrow()` shared by many methods produces the same panic in each of them. + One finding per source location, naming every callable that panicked + there with its own count: one `borrow()` shared by many methods produces + the same panic in each of them. The site of each panic comes from joining + the driver's per-thread record with the thread id in Rust's panic line. + Without thread ids (older Rust), a panic is located by its message, and + when several sites share the message the finding names them all. """ if not result: return [] - locations = locations or {} - groups: dict[str, dict] = {} + events = locations or [] + totals: dict[str, int] = {} for group in result.get("groups", []): serial = group.get("serial_exceptions", {}) for qual in group.get("driven", []): n = result.get("exceptions", {}).get(qual, {}).get("PanicException", 0) - if not n or "PanicException" in serial.get(qual, []): - continue - calls = result.get("calls", {}).get(qual, 0) - message = result.get("messages", {}).get(qual, {}).get("PanicException", "") - where = locations.get(message.strip()) - key = f"{where['file']}:{where['line']}" if where else f"message:{message}" - entry = groups.setdefault( - key, {"where": where, "message": message, "callables": [], "panics": 0, "calls": 0} - ) - entry["callables"].append(qual) - entry["panics"] += n - entry["calls"] += calls - out = [] - for entry in groups.values(): - callables = entry["callables"] - where = entry["where"] - named = ", ".join(f"`{q}`" for q in callables[:5]) + ( - f" and {len(callables) - 5} more" if len(callables) > 5 else "" - ) - at = f" at {where['file']}:{where['line']}" if where else "" - out.append( - { - "rule": "stress/panic", - "message": ( - f"Panicked{at} in {entry['panics']} of {entry['calls']} calls to {named} " - f"when driven from {threads} threads, and never in the single-threaded " - f"baseline: {entry['message'] or '(no message)'}. Replay with --replay {seed} " - f"--threads {threads}." - ), - "confidence": "certain", - "producer": "stress", - "symbol": callables[0], - "primary": where or {"file": "", "line": 1, "column": 1}, - "stacks": [], - "justification": None, - "occurrences": len(callables), - } - ) - return out + if n and "PanicException" not in serial.get(qual, []): + totals[qual] = n + located, consumed = _join(result, events, set(totals)) + + groups: dict[str, dict] = {} + + def add(key, sites, message, qual, n): + entry = groups.setdefault(key, {"sites": sites, "message": message, "callables": {}}) + entry["callables"][qual] = entry["callables"].get(qual, 0) + n + + for qual, n in totals.items(): + for index, count in located.get(qual, {}).items(): + event = events[index] + add(_site_key(event), [event], event["message"], qual, count) + rest = n - sum(located.get(qual, {}).values()) + if rest <= 0: + continue + # Not joined to a line: located by message, naming every candidate site. + raised = result.get("panics", {}).get(qual) or { + result.get("messages", {}).get(qual, {}).get("PanicException", ""): rest + } + pool = [e for i, e in enumerate(events) if i not in consumed] or events + sites = {} + for message in raised: + for e in pool: + if _same_message(e["message"], message): + sites.setdefault(_site_key(e), e) + first = next(iter(raised), "") + if not sites: + add(f"message:{first}", [], first, qual, rest) + else: + ordered = [sites[k] for k in sorted(sites)] + add(" | ".join(sorted(sites)), ordered, ordered[0]["message"] or first, qual, rest) + + calls = result.get("calls", {}) + return [_panic_finding(entry, calls, threads, seed) for entry in groups.values()] + + +def _panic_finding(entry: dict, calls: dict, threads: int, seed: int) -> dict: + callables = entry["callables"] + names = list(callables) + total = sum(callables.values()) + n_calls = sum(calls.get(q, 0) for q in names) + if len(names) == 1: + named = f"{total} of {n_calls} calls to `{names[0]}`" + else: + each = [f"`{q}` ({callables[q]} of {calls.get(q, 0)})" for q in names[:5]] + more = f" and {len(names) - 5} more" if len(names) > 5 else "" + named = f"{total} of {n_calls} calls to {', '.join(each)}{more}" + sites = entry["sites"] + if len(sites) == 1: + at = f" at {_site_key(sites[0])}" + elif sites: + at = f" at one of {', '.join(_site_key(e) for e in sites)} (the log does not say which)" + else: + at = "" + if sites: + primary = {k: sites[0][k] for k in ("file", "line", "column")} + else: + primary = {"file": "", "line": 1, "column": 1} + return { + "rule": "stress/panic", + "message": ( + f"Panicked{at} in {named} when driven from {threads} threads, and never in the " + f"single-threaded baseline: {entry['message'] or '(no message)'}. Replay with " + f"--replay {seed} --threads {threads}." + ), + "confidence": "certain", + "producer": "stress", + "symbol": names[0], + "primary": primary, + "stacks": [], + "justification": None, + "occurrences": len(names), + } def _crash_logged(tsan_dir: pathlib.Path) -> bool: diff --git a/python/ftcheck/stress/driver.py b/python/ftcheck/stress/driver.py index 3296cd7..336e1de 100644 --- a/python/ftcheck/stress/driver.py +++ b/python/ftcheck/stress/driver.py @@ -77,6 +77,9 @@ _MAX_COMBOS = 64 # derivation attempts per callable _MAX_ARGSETS = 3 # distinct argument tuples kept per callable +_MAX_PANIC_MESSAGES = 20 # distinct panic messages kept per callable +_MAX_PANIC_RUNS = 256 # changes of (callable, message) recorded per thread +_MAX_PANIC_RUNS_TOTAL = 20000 # and in the whole run, to bound the result file class Progress: @@ -610,9 +613,17 @@ def __init__(self): self.returned = {} self.exceptions = {} self.messages = {} # qual -> {exception name: first message} + self.panics = {} # qual -> {panic message: count} + # Native thread id -> [[qual, message, count], ...], in call order. Rust + # prints the same id in its panic line, so the orchestrator can tell + # which call panicked at which site: two sites with one message were + # otherwise indistinguishable (one was filed under the other). + self.panic_threads = {} + self._panic_full = set() + self._panic_runs = 0 self.total = 0 # every call, for progress: a hang is no call finishing - def record(self, qual, exc_name, message=None): + def record(self, qual, exc_name, message=None, tid=None): with self.lock: self.total += 1 self.calls[qual] = self.calls.get(qual, 0) + 1 @@ -623,9 +634,31 @@ def record(self, qual, exc_name, message=None): per[exc_name] = per.get(exc_name, 0) + 1 if message is not None: self.messages.setdefault(qual, {}).setdefault(exc_name, message[:300]) + if exc_name == "PanicException" and message is not None: + self._record_panic(qual, message[:300], tid) + + def _record_panic(self, qual, message, tid): + per = self.panics.setdefault(qual, {}) + if message in per or len(per) < _MAX_PANIC_MESSAGES: + per[message] = per.get(message, 0) + 1 + key = str(tid) + if tid is None or key in self._panic_full: + return + runs = self.panic_threads.setdefault(key, []) + if runs and runs[-1][0] == qual and runs[-1][1] == message: + runs[-1][2] += 1 + elif len(runs) < _MAX_PANIC_RUNS and self._panic_runs < _MAX_PANIC_RUNS_TOTAL: + self._panic_runs += 1 + runs.append([qual, message, 1]) + else: + # Past the cap the thread records nothing more, so what it did + # record stays in step with its panic lines. Its later panics are + # located by message, as when no thread id is known. + self._panic_full.add(key) def _worker(shared, work, rng, iterations, counters, barrier, errors, deadline): + tid = threading.get_native_id() try: barrier.wait() for _ in range(iterations): @@ -643,7 +676,7 @@ def _worker(shared, work, rng, iterations, counters, barrier, errors, deadline): except BaseException as exc: exc_name = type(exc).__name__ message = str(exc) - counters.record(qual, exc_name, message) + counters.record(qual, exc_name, message, tid) # Seeded yield points perturb the interleaving reproducibly. if rng.random() < 0.05: time.sleep(0) @@ -674,6 +707,7 @@ def _heartbeat(progress, step, counters, done, on_tick=None): def _mutator(name, mutate, counters, done): """Runs one declared mutator in a loop until the phase ends.""" + tid = threading.get_native_id() while not done.is_set(): exc_name = message = None try: @@ -682,7 +716,7 @@ def _mutator(name, mutate, counters, done): raise except BaseException as exc: exc_name, message = type(exc).__name__, str(exc) - counters.record(f"mutator:{name}", exc_name, message) + counters.record(f"mutator:{name}", exc_name, message, tid) time.sleep(0) @@ -891,6 +925,8 @@ def _write_result_locked(cfg, seed, started, surface, groups, counters, complete returned = dict(counters.returned) exceptions = {k: dict(v) for k, v in counters.exceptions.items()} messages = {k: dict(v) for k, v in counters.messages.items()} + panics = {k: dict(v) for k, v in counters.panics.items()} + panic_threads = {k: [list(r) for r in v] for k, v in counters.panic_threads.items()} for g in groups: g["raised_all"] = [q for q in g.get("driven", []) if calls.get(q) and not returned.get(q)] result = { @@ -906,6 +942,8 @@ def _write_result_locked(cfg, seed, started, surface, groups, counters, complete "returned": returned, "exceptions": exceptions, "messages": messages, + "panics": panics, + "panic_threads": panic_threads, } tmp = cfg["output_path"] + ".tmp" with open(tmp, "w") as fh: diff --git a/tests/test_stress_config.py b/tests/test_stress_config.py index 3c80c79..a0b279b 100644 --- a/tests/test_stress_config.py +++ b/tests/test_stress_config.py @@ -130,6 +130,96 @@ def test_panics_at_one_location_are_one_finding_located_there(): assert "`m.store.put`" in finding["message"] and "`m.store.get`" in finding["message"] +def _two_site_result(panic_threads, **extra): + """Two callables on one type, both panicking with the same message.""" + return { + "groups": [ + { + "driven": ["m.Shelf.left", "m.Shelf.right"], + "serial_exceptions": {"m.Shelf.left": [], "m.Shelf.right": []}, + } + ], + "calls": {"m.Shelf.left": 40, "m.Shelf.right": 60}, + "exceptions": { + "m.Shelf.left": {"PanicException": 2}, + "m.Shelf.right": {"PanicException": 1}, + }, + "messages": { + "m.Shelf.left": {"PanicException": "claim taken"}, + "m.Shelf.right": {"PanicException": "claim taken"}, + }, + "panic_threads": panic_threads, + **extra, + } + + +_TWO_SITES_LOG = ( + "thread '' (101) panicked at src/lib.rs:16:39:\n" + "claim taken\n" + "note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace\n" + "\n" + "thread '' (102) panicked at src/lib.rs:22:39:\n" + "claim taken\n" + "\n" + "thread '' (101) panicked at src/lib.rs:16:39:\n" + "claim taken\n" +) + + +def test_two_sites_sharing_one_message_are_two_findings_joined_by_thread(): + """Matched by message alone, both callables were filed at whichever site + panicked first, and the second site never appeared.""" + from ftcheck.stress import panic_findings, panic_locations + + result = _two_site_result( + {"101": [["m.Shelf.left", "claim taken", 2]], "102": [["m.Shelf.right", "claim taken", 1]]} + ) + findings = panic_findings(result, threads=8, seed=1, locations=panic_locations(_TWO_SITES_LOG)) + by_line = {f["primary"]["line"]: f for f in findings} + assert sorted(by_line) == [16, 22] + assert by_line[16]["symbol"] == "m.Shelf.left" + assert "2 of 40 calls to `m.Shelf.left`" in by_line[16]["message"] + assert "m.Shelf.right" not in by_line[16]["message"] + assert "1 of 60 calls to `m.Shelf.right`" in by_line[22]["message"] + + +def test_a_callable_that_panicked_at_two_sites_is_counted_at_each(): + """One thread that ran both callables (the mix phase): its panics are + joined in order, so each site gets exactly the calls that panicked there.""" + from ftcheck.stress import panic_findings, panic_locations + + log = ( + "thread '' (103) panicked at src/lib.rs:16:39:\nclaim taken\n" + "thread '' (103) panicked at src/lib.rs:22:39:\nclaim taken\n" + "thread '' (103) panicked at src/lib.rs:22:39:\nclaim taken\n" + ) + result = _two_site_result( + {"103": [["m.Shelf.left", "claim taken", 1], ["m.Shelf.left", "claim taken", 1]]}, + ) + result["exceptions"] = {"m.Shelf.left": {"PanicException": 2}} + result["panic_threads"]["103"].insert(1, ["m.Shelf.right", "claim taken", 1]) + result["exceptions"]["m.Shelf.right"] = {"PanicException": 1} + findings = panic_findings(result, threads=8, seed=1, locations=panic_locations(log)) + by_line = {f["primary"]["line"]: f for f in findings} + assert sorted(by_line) == [16, 22] + assert "1 of 40 calls to `m.Shelf.left`" in by_line[16]["message"] + assert "`m.Shelf.right`" in by_line[22]["message"] + assert "`m.Shelf.left`" in by_line[22]["message"] + + +def test_without_thread_ids_every_site_with_the_message_is_listed(): + """Older Rust prints no thread id. The site cannot be told apart then, so + the finding names every candidate instead of picking one silently.""" + from ftcheck.stress import panic_findings, panic_locations + + log = _TWO_SITES_LOG.replace(" (101)", "").replace(" (102)", "") + result = _two_site_result({}) + del result["panic_threads"] + (finding,) = panic_findings(result, threads=8, seed=1, locations=panic_locations(log)) + assert "src/lib.rs:16" in finding["message"] and "src/lib.rs:22" in finding["message"] + assert "3 of 100 calls" in finding["message"] + + def test_declared_test_dependencies_are_found_in_the_usual_places(tmp_path): """A first user's two projects both failed test collection: the venv held only the wheel and the runner.""" diff --git a/tests/test_stress_driver.py b/tests/test_stress_driver.py index 47201e8..3cfb323 100644 --- a/tests/test_stress_driver.py +++ b/tests/test_stress_driver.py @@ -507,3 +507,51 @@ def test_mutator_threads_keep_their_name_within_fifteen_characters(tmp_path): def test_json_groups_list_what_raised_on_every_call(tmp_path): g = group(run_driver(tmp_path), "standin.Counter") assert "standin.Counter.reject" in g["raised_all"] + + +def test_each_panic_is_recorded_with_its_thread_and_every_message(tmp_path): + """The log's panic lines carry the native thread id; the driver records + which callable panicked on which thread, in order, so the two can be + joined. Every distinct message is kept, with a count, not only the first.""" + (tmp_path / "panicky.py").write_text(textwrap.dedent( + ''' + import threading + + class PanicException(BaseException): + """Named like pyo3_runtime.PanicException.""" + + class Shelf: + def __init__(self): + self.n = 0 + def left(self): + self.n += 1 + raise PanicException("left " + ("odd" if self.n % 2 else "even")) + def right(self): + return 1 + ''' + )) + result = run_driver(tmp_path, modules=["panicky"], skip={}, threads=2, iterations=10) + left = "panicky.Shelf.left" + assert set(result["panics"][left]) == {"left odd", "left even"} + assert sum(result["panics"][left].values()) == result["exceptions"][left]["PanicException"] + recorded = [run for runs in result["panic_threads"].values() for run in runs] + assert {q for q, _, _ in recorded} == {left}, "only panicking calls are recorded" + assert sum(n for _, _, n in recorded) == result["exceptions"][left]["PanicException"] + assert all(tid.isdigit() for tid in result["panic_threads"]) + + +def test_a_thread_past_the_record_cap_records_nothing_more(monkeypatch): + """Regression: merging a later panic into the last run after the cap made + the record skip calls the log still had, and the join then filed one + callable's panics at the other's site.""" + import importlib.util + + spec = importlib.util.spec_from_file_location("ftcheck_driver", DRIVER) + driver = importlib.util.module_from_spec(spec) + spec.loader.exec_module(driver) + monkeypatch.setattr(driver, "_MAX_PANIC_RUNS", 2) + counters = driver.Counters() + for qual in ("a", "b", "a", "b", "a"): + counters.record(qual, "PanicException", "boom", tid=7) + assert counters.panic_threads == {"7": [["a", "boom", 1], ["b", "boom", 1]]} + assert counters.panics == {"a": {"boom": 3}, "b": {"boom": 2}} From ba188176a46f0fa827f61e9290572a21a23b535f Mon Sep 17 00:00:00 2001 From: nimbrel <331679006+nimbrel@users.noreply.github.com> Date: Sat, 26 Sep 2026 10:06:51 +0000 Subject: [PATCH 2/5] fix(stress): say when a panic is inside a dependency, and find your frame A panic inside a dependency (PyO3's conversions, any other crate, or the standard library) was located at the dependency's line with no stack, and the headline called it a panic "in your extension". The finding now says which dependency and version the site is in, names PyO3's argument conversion when it is there, and carries a `dependency` field; the headline counts such panics as "inside a dependency, reached from your extension". When the log holds a Rust backtrace, the first frame in the crate's own code becomes the location and the frames down to it become the stack; otherwise the message says to replay with RUST_BACKTRACE=1. Backtraces stay off by default: turned on for a whole run they slow each panicking call about tenfold, which changes the schedule being tested. Signed-off-by: nimbrel <331679006+nimbrel@users.noreply.github.com> --- python/ftcheck/ci/__init__.py | 20 ++++-- python/ftcheck/stress/__init__.py | 111 +++++++++++++++++++++++++++--- tests/test_ci_verdict.py | 14 ++++ tests/test_stress_config.py | 72 +++++++++++++++++++ 4 files changed, 205 insertions(+), 12 deletions(-) diff --git a/python/ftcheck/ci/__init__.py b/python/ftcheck/ci/__init__.py index 0aa23f6..9770bea 100644 --- a/python/ftcheck/ci/__init__.py +++ b/python/ftcheck/ci/__init__.py @@ -24,16 +24,28 @@ def describe_findings(findings: list[dict]) -> str: ("stress/panic", "panic under concurrency", "panics under concurrency"), ("stress/hang", "hang under concurrency", "hangs under concurrency"), ] + # A panic inside a dependency's code is reached through the extension's + # surface, but calling it "in your extension" sent users to the wrong code. + dependency = sum(1 for f in findings if f["rule"] == "stress/panic" and f.get("dependency")) + yours = [f for f in findings if not (f["rule"] == "stress/panic" and f.get("dependency"))] parts = [] for prefix, one, many in kinds: - n = sum(1 for f in findings if f["rule"].startswith(prefix)) + n = sum(1 for f in yours if f["rule"].startswith(prefix)) if n: parts.append(f"{n} {one if n == 1 else many}") - other = len(findings) - sum(int(p.split()[0]) for p in parts) + other = len(yours) - sum(int(p.split()[0]) for p in parts) if other: parts.append(f"{other} other finding{'s' if other != 1 else ''}") - joined = parts[0] if len(parts) == 1 else ", ".join(parts[:-1]) + " and " + parts[-1] - return f"{joined} in your extension" + described = [] + if parts: + joined = parts[0] if len(parts) == 1 else ", ".join(parts[:-1]) + " and " + parts[-1] + described.append(f"{joined} in your extension") + if dependency: + noun = "panic" if dependency == 1 else "panics" + described.append( + f"{dependency} {noun} under concurrency inside a dependency, reached from your extension" + ) + return " and ".join(described) # pytest exit statuses that mean the suite itself never ran properly. _PYTEST_BROKEN = {2: "interrupted", 3: "internal error", 4: "usage error", 5: "no tests collected"} diff --git a/python/ftcheck/stress/__init__.py b/python/ftcheck/stress/__init__.py index aeadb53..7d465b7 100644 --- a/python/ftcheck/stress/__init__.py +++ b/python/ftcheck/stress/__init__.py @@ -224,20 +224,28 @@ def _hang_finding(step: str, threads: int, seed: int) -> dict: r"(?:thread '[^'\n]*'(?: \((?P\d+)\))? )?" r"panicked at (?P[^\n]+?):(?P\d+):(?P\d+):\n(?P[^\n]*)" ) +_BACKTRACE_FRAME = re.compile(r"^\s+\d+: (?P\S.*)$") +_BACKTRACE_AT = re.compile(r"^\s+at (?P.+?):(?P\d+)(?::(?P\d+))?$") +_REGISTRY = re.compile(r"/registry/src/[^/]+/(?P[A-Za-z0-9_.-]+?)-(?P\d+\.\d+\.\d+[^/]*)/") +_GIT_CHECKOUT = re.compile(r"/git/checkouts/(?P[^/]+?)-[0-9a-f]+/") +_STD = re.compile(r"^/rustc/|/lib/rustlib/src/rust/library/") # How far past a thread's last matched panic line the next one is looked for. # Extra lines on a thread (a panic the extension caught itself) are skipped. _JOIN_WINDOW = 16 def panic_locations(log_text: str) -> list[dict]: - """Every Rust panic line in the log, in order: where, and on which thread. + """Every Rust panic line in the log, in order: where, on which thread, and + the frames if a backtrace follows (only when RUST_BACKTRACE is set). `PanicException` carries the message but not the location; Rust prints both to stderr, which the driver log captures, with the native thread id the driver also records for each panicking call. """ found = [] - for m in _PANIC_AT.finditer(log_text): + matches = list(_PANIC_AT.finditer(log_text)) + for i, m in enumerate(matches): + tail = log_text[m.end() : matches[i + 1].start() if i + 1 < len(matches) else len(log_text)] found.append( { "tid": int(m.group("tid")) if m.group("tid") else None, @@ -245,11 +253,52 @@ def panic_locations(log_text: str) -> list[dict]: "line": int(m.group("line")), "column": int(m.group("column")), "message": m.group("message").strip(), + "frames": _backtrace(tail), } ) return found +def _backtrace(tail: str) -> list[dict]: + lines = tail.splitlines() + try: + start = next(i for i, ln in enumerate(lines[:4]) if ln.strip() == "stack backtrace:") + except StopIteration: + return [] + frames = [] + for line in lines[start + 1 :]: + frame, at = _BACKTRACE_FRAME.match(line), _BACKTRACE_AT.match(line) + if frame: + frames.append({"symbol": frame.group("symbol").strip(), "location": None}) + elif at and frames: + file = at.group("file") + frames[-1]["location"] = { + "file": file.removeprefix("./"), + "line": int(at.group("line")), + "column": int(at.group("column") or 1), + } + else: + break + return frames + + +def _dependency(path: str) -> str | None: + """"pyo3 0.29.2" when `path` is a dependency's source, else None (yours).""" + if m := _REGISTRY.search(path): + return f"{m.group('crate')} {m.group('ver')}" + if m := _GIT_CHECKOUT.search(path): + return m.group("crate") + if _STD.search(path): + return "the Rust standard library" + return None + + +def _short(path: str) -> str: + """A dependency's file from its crate directory on: `pyo3-0.29.2/src/x.rs`.""" + m = _REGISTRY.search(path) or _GIT_CHECKOUT.search(path) + return path[m.start("crate") :] if m else path + + def _same_message(logged: str, raised: str) -> bool: # The log holds the first line of the message; the driver keeps 300 characters. return logged[:300] == raised.split("\n", 1)[0].strip() @@ -359,6 +408,37 @@ def add(key, sites, message, qual, n): return [_panic_finding(entry, calls, threads, seed) for entry in groups.values()] +def _inside(dependency: str, site: dict) -> str: + where = f"{_short(site['file'])}:{site['line']}" + if dependency.startswith("pyo3 ") and ( + "/conversions/" in site["file"] or "extract_argument" in site["file"] + ): + return f" inside PyO3's argument conversion ({dependency}, a dependency) at {where}" + if dependency.startswith("the Rust"): + return f" inside {dependency} at {where}" + return f" inside the dependency {dependency} at {where}" + + +def _your_frame(frames: list[dict]) -> tuple[dict | None, list[dict]]: + """The first backtrace frame in the crate's own Rust code, and the stack + from the first frame outside the standard library down to it.""" + mine = [ + i + for i, fr in enumerate(frames) + if fr["location"] + and fr["location"]["file"].endswith(".rs") + and _dependency(fr["location"]["file"]) is None + ] + if not mine: + return None, [] + first = mine[0] + start = next( + (i for i, fr in enumerate(frames) if fr["location"] and not _STD.search(fr["location"]["file"])), + first, + ) + return frames[first], [{"frames": frames[start : first + 1]}] + + def _panic_finding(entry: dict, calls: dict, threads: int, seed: int) -> dict: callables = entry["callables"] names = list(callables) @@ -371,31 +451,46 @@ def _panic_finding(entry: dict, calls: dict, threads: int, seed: int) -> dict: more = f" and {len(names) - 5} more" if len(names) > 5 else "" named = f"{total} of {n_calls} calls to {', '.join(each)}{more}" sites = entry["sites"] - if len(sites) == 1: + dependency = _dependency(sites[0]["file"]) if len(sites) == 1 else None + yours, stacks, reached, hint = None, [], "", "" + if dependency: + at = _inside(dependency, sites[0]) + yours, stacks = _your_frame(sites[0]["frames"]) + if yours: + where = yours["location"] + reached = f" It was reached from `{yours['symbol']}` at {where['file']}:{where['line']}." + else: + hint = " (with RUST_BACKTRACE=1 set, to see which of your frames led there)" + elif len(sites) == 1: at = f" at {_site_key(sites[0])}" elif sites: at = f" at one of {', '.join(_site_key(e) for e in sites)} (the log does not say which)" else: at = "" - if sites: + if yours: + primary = dict(yours["location"]) + elif sites: primary = {k: sites[0][k] for k in ("file", "line", "column")} else: primary = {"file": "", "line": 1, "column": 1} - return { + finding = { "rule": "stress/panic", "message": ( f"Panicked{at} in {named} when driven from {threads} threads, and never in the " - f"single-threaded baseline: {entry['message'] or '(no message)'}. Replay with " - f"--replay {seed} --threads {threads}." + f"single-threaded baseline: {entry['message'] or '(no message)'}.{reached}" + f" Replay with --replay {seed} --threads {threads}{hint}." ), "confidence": "certain", "producer": "stress", "symbol": names[0], "primary": primary, - "stacks": [], + "stacks": stacks, "justification": None, "occurrences": len(names), } + if dependency: + finding["dependency"] = dependency + return finding def _crash_logged(tsan_dir: pathlib.Path) -> bool: diff --git a/tests/test_ci_verdict.py b/tests/test_ci_verdict.py index e998fc8..bfbe8d3 100644 --- a/tests/test_ci_verdict.py +++ b/tests/test_ci_verdict.py @@ -93,3 +93,17 @@ def test_the_headline_names_each_kind_of_finding(): assert describe_findings([tsan, tsan, panic]) == ( "2 ThreadSanitizer reports and 1 panic under concurrency in your extension" ) + + +def test_a_panic_inside_a_dependency_is_not_called_yours(): + from ftcheck.ci import describe_findings + + tsan = {"rule": "tsan/data-race"} + dep = {"rule": "stress/panic", "dependency": "tinyqueue 1.2.3"} + assert describe_findings([dep, dep]) == ( + "2 panics under concurrency inside a dependency, reached from your extension" + ) + assert describe_findings([tsan, dep]) == ( + "1 ThreadSanitizer report in your extension and 1 panic under concurrency " + "inside a dependency, reached from your extension" + ) diff --git a/tests/test_stress_config.py b/tests/test_stress_config.py index a0b279b..ef9dff2 100644 --- a/tests/test_stress_config.py +++ b/tests/test_stress_config.py @@ -220,6 +220,78 @@ def test_without_thread_ids_every_site_with_the_message_is_listed(): assert "3 of 100 calls" in finding["message"] +_DEP = "/opt/cargo/registry/src/index.crates.io-0000000000000000" + + +def test_a_panic_inside_a_dependency_says_so_and_names_the_callable(): + from ftcheck.ci import describe_findings + from ftcheck.stress import panic_findings, panic_locations + + log = ( + f"thread '' (101) panicked at {_DEP}/tinyqueue-1.2.3/src/lib.rs:88:13:\n" + "queue closed\n" + ) + result = _two_site_result({"101": [["m.Shelf.left", "queue closed", 2]]}) + result["exceptions"] = {"m.Shelf.left": {"PanicException": 2}} + result["messages"] = {"m.Shelf.left": {"PanicException": "queue closed"}} + (finding,) = panic_findings(result, threads=8, seed=1, locations=panic_locations(log)) + assert finding["dependency"] == "tinyqueue 1.2.3" + assert "inside the dependency tinyqueue 1.2.3" in finding["message"] + assert "`m.Shelf.left`" in finding["message"] + assert "RUST_BACKTRACE=1" in finding["message"], "the way to see your frame is named" + assert describe_findings([finding]) == ( + "1 panic under concurrency inside a dependency, reached from your extension" + ) + + +def test_a_panic_in_pyo3_argument_conversion_is_named_as_such(): + from ftcheck.stress import panic_findings, panic_locations + + log = ( + f"thread '' (101) panicked at {_DEP}/pyo3-0.29.2/src/conversions/std/num.rs:" + "31:9:\nconversion failed\n" + ) + result = _two_site_result({"101": [["m.Shelf.left", "conversion failed", 2]]}) + result["exceptions"] = {"m.Shelf.left": {"PanicException": 2}} + result["messages"] = {"m.Shelf.left": {"PanicException": "conversion failed"}} + (finding,) = panic_findings(result, threads=8, seed=1, locations=panic_locations(log)) + assert finding["dependency"] == "pyo3 0.29.2" + assert "inside PyO3's argument conversion (pyo3 0.29.2, a dependency)" in finding["message"] + + +def test_a_backtrace_in_the_log_locates_the_panic_at_your_frame(): + """With RUST_BACKTRACE=1 set (a replay), the first frame in your crate is + the location, and the dependency's line is kept in the message.""" + from ftcheck.stress import panic_findings, panic_locations + + log = ( + f"thread '' (101) panicked at {_DEP}/tinyqueue-1.2.3/src/lib.rs:88:13:\n" + "queue closed\n" + "stack backtrace:\n" + " 0: __rustc::rust_begin_unwind\n" + " at /rustc/0000/library/std/src/panicking.rs:689:5\n" + " 1: core::panicking::panic_fmt\n" + " at /rustc/0000/library/core/src/panicking.rs:80:14\n" + " 2: tinyqueue::Queue::pop\n" + f" at {_DEP}/tinyqueue-1.2.3/src/lib.rs:88:13\n" + " 3: examplelib::Shelf::left\n" + " at ./src/lib.rs:16:39\n" + " 4: examplelib::Shelf::__pymethod_left__\n" + " at ./src/lib.rs:9:1\n" + " 5: _PyFunction_Vectorcall\n" + "note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.\n" + ) + result = _two_site_result({"101": [["m.Shelf.left", "queue closed", 2]]}) + result["exceptions"] = {"m.Shelf.left": {"PanicException": 2}} + result["messages"] = {"m.Shelf.left": {"PanicException": "queue closed"}} + (finding,) = panic_findings(result, threads=8, seed=1, locations=panic_locations(log)) + assert finding["primary"] == {"file": "src/lib.rs", "line": 16, "column": 39} + assert "tinyqueue-1.2.3/src/lib.rs:88" in finding["message"] + assert "reached from `examplelib::Shelf::left`" in finding["message"] + symbols = [fr["symbol"] for fr in finding["stacks"][0]["frames"]] + assert symbols == ["tinyqueue::Queue::pop", "examplelib::Shelf::left"] + + def test_declared_test_dependencies_are_found_in_the_usual_places(tmp_path): """A first user's two projects both failed test collection: the venv held only the wheel and the runner.""" From 3619e88e5054d97b84d42509b752e575be634683 Mon Sep 17 00:00:00 2001 From: nimbrel <331679006+nimbrel@users.noreply.github.com> Date: Sat, 26 Sep 2026 10:07:14 +0000 Subject: [PATCH 3/5] fix(stress): say when mutators were running in a panic finding The single-threaded baseline never sees a mutator's transient state, so a call that panics on input a mutator made invalid read as a plain concurrency panic. When mutators ran, the stress/panic message now names them and restates the rule they must follow: keep the shared inputs valid at every instant. Signed-off-by: nimbrel <331679006+nimbrel@users.noreply.github.com> --- python/ftcheck/stress/__init__.py | 16 +++++++++++++--- tests/test_stress_config.py | 18 ++++++++++++++++++ 2 files changed, 31 insertions(+), 3 deletions(-) diff --git a/python/ftcheck/stress/__init__.py b/python/ftcheck/stress/__init__.py index 7d465b7..db2d762 100644 --- a/python/ftcheck/stress/__init__.py +++ b/python/ftcheck/stress/__init__.py @@ -405,7 +405,10 @@ def add(key, sites, message, qual, n): add(" | ".join(sorted(sites)), ordered, ordered[0]["message"] or first, qual, rest) calls = result.get("calls", {}) - return [_panic_finding(entry, calls, threads, seed) for entry in groups.values()] + mutators = result.get("mutators") or [] + return [ + _panic_finding(entry, calls, mutators, threads, seed) for entry in groups.values() + ] def _inside(dependency: str, site: dict) -> str: @@ -439,7 +442,7 @@ def _your_frame(frames: list[dict]) -> tuple[dict | None, list[dict]]: return frames[first], [{"frames": frames[start : first + 1]}] -def _panic_finding(entry: dict, calls: dict, threads: int, seed: int) -> dict: +def _panic_finding(entry: dict, calls: dict, mutators: list, threads: int, seed: int) -> dict: callables = entry["callables"] names = list(callables) total = sum(callables.values()) @@ -467,6 +470,13 @@ def _panic_finding(entry: dict, calls: dict, threads: int, seed: int) -> dict: at = f" at one of {', '.join(_site_key(e) for e in sites)} (the log does not say which)" else: at = "" + mutated = "" + if mutators: + mutated = ( + f" Mutators were running ({', '.join(mutators)}): if one can leave the shared " + "inputs invalid, this panic may be its doing rather than contention. Mutators " + "must keep the inputs valid at every instant." + ) if yours: primary = dict(yours["location"]) elif sites: @@ -478,7 +488,7 @@ def _panic_finding(entry: dict, calls: dict, threads: int, seed: int) -> dict: "message": ( f"Panicked{at} in {named} when driven from {threads} threads, and never in the " f"single-threaded baseline: {entry['message'] or '(no message)'}.{reached}" - f" Replay with --replay {seed} --threads {threads}{hint}." + f"{mutated} Replay with --replay {seed} --threads {threads}{hint}." ), "confidence": "certain", "producer": "stress", diff --git a/tests/test_stress_config.py b/tests/test_stress_config.py index ef9dff2..c25ce01 100644 --- a/tests/test_stress_config.py +++ b/tests/test_stress_config.py @@ -292,6 +292,24 @@ def test_a_backtrace_in_the_log_locates_the_panic_at_your_frame(): assert symbols == ["tinyqueue::Queue::pop", "examplelib::Shelf::left"] +def test_a_panic_while_mutators_ran_says_so(): + """The baseline never sees a mutator's transient state: the message must + say mutators were running, and point at the rule they must follow.""" + from ftcheck.stress import panic_findings, panic_locations + + result = _two_site_result( + {"101": [["m.Shelf.left", "claim taken", 2]], "102": [["m.Shelf.right", "claim taken", 1]]}, + mutators=["churn"], + ) + findings = panic_findings(result, threads=8, seed=1, locations=panic_locations(_TWO_SITES_LOG)) + for f in findings: + assert "Mutators were running (churn)" in f["message"] + assert "valid at every instant" in f["message"] + quiet = _two_site_result({"101": [["m.Shelf.left", "claim taken", 2]]}, mutators=[]) + for f in panic_findings(quiet, threads=8, seed=1, locations=panic_locations(_TWO_SITES_LOG)): + assert "Mutators" not in f["message"] + + def test_declared_test_dependencies_are_found_in_the_usual_places(tmp_path): """A first user's two projects both failed test collection: the venv held only the wheel and the runner.""" From 2b62bde0e06d5f326784bb18d6c70c8c32c592a0 Mon Sep 17 00:00:00 2001 From: nimbrel <331679006+nimbrel@users.noreply.github.com> Date: Sat, 26 Sep 2026 10:10:04 +0000 Subject: [PATCH 4/5] test: a racy fixture with two panic sites that share one message Neither method panics on one thread; each panics at its own line once two threads overlap, with the same message. The sanitizer ground truth asserts one stress/panic finding per line, each naming only its own method. Signed-off-by: nimbrel <331679006+nimbrel@users.noreply.github.com> --- .../racy/stress-panic-two-sites/Cargo.lock | 132 ++++++++++++++++++ .../racy/stress-panic-two-sites/Cargo.toml | 12 ++ .../racy/stress-panic-two-sites/expected.toml | 5 + .../racy/stress-panic-two-sites/src/lib.rs | 43 ++++++ .../tests/test_threads.py | 10 ++ tests/test_tsan_ground_truth.py | 12 ++ 6 files changed, 214 insertions(+) create mode 100644 fixtures/racy/stress-panic-two-sites/Cargo.lock create mode 100644 fixtures/racy/stress-panic-two-sites/Cargo.toml create mode 100644 fixtures/racy/stress-panic-two-sites/expected.toml create mode 100644 fixtures/racy/stress-panic-two-sites/src/lib.rs create mode 100644 fixtures/racy/stress-panic-two-sites/tests/test_threads.py diff --git a/fixtures/racy/stress-panic-two-sites/Cargo.lock b/fixtures/racy/stress-panic-two-sites/Cargo.lock new file mode 100644 index 0000000..35d755f --- /dev/null +++ b/fixtures/racy/stress-panic-two-sites/Cargo.lock @@ -0,0 +1,132 @@ +# This file is automatically @generated by Cargo. +# It is not intended for manual editing. +version = 4 + +[[package]] +name = "heck" +version = "0.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2304e00983f87ffb38b55b444b5e3b60a884b5d30c0fca7d82fe33449bbe55ea" + +[[package]] +name = "libc" +version = "0.2.189" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3eaf3ede3fee6db1a4c2ee091bf8a8b4dccdc6d17f656fb07896ee72867612f2" + +[[package]] +name = "once_cell" +version = "1.21.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9f7c3e4beb33f85d45ae3e3a1792185706c8e16d043238c593331cc7cd313b50" + +[[package]] +name = "portable-atomic" +version = "1.15.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "05c8b63e8d9609db387f0324918f81d68fe27748f084ef092fb35954d0539a85" + +[[package]] +name = "proc-macro2" +version = "1.0.107" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "985e7ec9bb745e6ce6535b544d84d6cd6f7ad8bd711c398938ae983b91a766d9" +dependencies = [ + "unicode-ident", +] + +[[package]] +name = "pyo3" +version = "0.29.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4688ddedf473e32662b9b067670129a8afb8c18e351482c70d62ba4a88171e8b" +dependencies = [ + "libc", + "once_cell", + "portable-atomic", + "pyo3-build-config", + "pyo3-ffi", + "pyo3-macros", +] + +[[package]] +name = "pyo3-build-config" +version = "0.29.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f41027e41b4bd03f6e60f9f417fe24a6341a6bb744edd62b6f709f2a52ea30e9" +dependencies = [ + "target-lexicon", +] + +[[package]] +name = "pyo3-ffi" +version = "0.29.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e591a95526fead067432c3b3a33fc74770b87b1e04e73671090d9c2055a2b327" +dependencies = [ + "libc", + "pyo3-build-config", +] + +[[package]] +name = "pyo3-macros" +version = "0.29.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "73225868fc1cd84eef2c3c230ddb91273bf1de46aeb8a4248da76d32a0924a1c" +dependencies = [ + "proc-macro2", + "pyo3-macros-backend", + "quote", + "syn", +] + +[[package]] +name = "pyo3-macros-backend" +version = "0.29.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "571575aa3749fa6216757dd47d2a3e7ef360f329a40f0666a9fbd14889024952" +dependencies = [ + "heck", + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "quote" +version = "1.0.47" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1fbf4db142a473a8d80c26bbf18454ed458bf8d26c8219c331daecfdbd079001" +dependencies = [ + "proc-macro2", +] + +[[package]] +name = "stress-panic-two-sites" +version = "0.0.0" +dependencies = [ + "pyo3", +] + +[[package]] +name = "syn" +version = "2.0.119" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "872831b642d1a07999a962a351ed35b955ea2cfc8f3862091e2a240a84f17297" +dependencies = [ + "proc-macro2", + "quote", + "unicode-ident", +] + +[[package]] +name = "target-lexicon" +version = "0.13.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "adb6935a6f5c20170eeceb1a3835a49e12e19d792f6dd344ccc76a985ca5a6ca" + +[[package]] +name = "unicode-ident" +version = "1.0.26" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d245f478577f809a851594d02313b640fb437e0bb33866753cff937863096954" diff --git a/fixtures/racy/stress-panic-two-sites/Cargo.toml b/fixtures/racy/stress-panic-two-sites/Cargo.toml new file mode 100644 index 0000000..8ce0500 --- /dev/null +++ b/fixtures/racy/stress-panic-two-sites/Cargo.toml @@ -0,0 +1,12 @@ +[package] +name = "stress-panic-two-sites" +version = "0.0.0" +edition = "2021" +publish = false + +[lib] +name = "stress_panic_two_sites" +crate-type = ["cdylib", "rlib"] + +[dependencies] +pyo3 = { version = "0.29", features = ["extension-module"] } diff --git a/fixtures/racy/stress-panic-two-sites/expected.toml b/fixtures/racy/stress-panic-two-sites/expected.toml new file mode 100644 index 0000000..6d7583d --- /dev/null +++ b/fixtures/racy/stress-panic-two-sites/expected.toml @@ -0,0 +1,5 @@ +race = false +rules = [] +stress_rules = ["stress/panic"] +symbols = ["head", "tail"] +justification = "Two `try_lock().expect()` sites with the same message on one shared instance: neither panics on one thread, each panics at its own line once two threads overlap. Not a data race (a real mutex guards the data), so TSan must stay silent. `stress` must report two stress/panic findings, one per line, each naming only the method that panicked there. Matching panics to sites by message text filed both under one line." diff --git a/fixtures/racy/stress-panic-two-sites/src/lib.rs b/fixtures/racy/stress-panic-two-sites/src/lib.rs new file mode 100644 index 0000000..c254f7d --- /dev/null +++ b/fixtures/racy/stress-panic-two-sites/src/lib.rs @@ -0,0 +1,43 @@ +//! Two panic sites with one message — not a data race. +//! +//! `head` and `tail` each take the same exclusive claim with `try_lock` and +//! `expect` it, with the same message. On one thread neither panics; as soon +//! as two threads overlap, each panics at its own line. The two sites print +//! identical messages, so a tool that locates panics by message alone files +//! both under one line and loses the other. Each must be reported at its own +//! line, naming the method that panicked there. + +use pyo3::prelude::*; +use std::sync::Mutex; + +#[pyclass] +struct Queue { + items: Mutex>, +} + +#[pymethods] +impl Queue { + #[new] + fn new() -> Self { + Queue { + items: Mutex::new((0..64).collect()), + } + } + + fn head(&self) -> u32 { + let guard = self.items.try_lock().expect("queue is busy"); + std::thread::sleep(std::time::Duration::from_micros(50)); + guard[0] + } + + fn tail(&self) -> u32 { + let guard = self.items.try_lock().expect("queue is busy"); + std::thread::sleep(std::time::Duration::from_micros(50)); + guard[guard.len() - 1] + } +} + +#[pymodule] +fn stress_panic_two_sites(m: &Bound<'_, PyModule>) -> PyResult<()> { + m.add_class::() +} diff --git a/fixtures/racy/stress-panic-two-sites/tests/test_threads.py b/fixtures/racy/stress-panic-two-sites/tests/test_threads.py new file mode 100644 index 0000000..c441f00 --- /dev/null +++ b/fixtures/racy/stress-panic-two-sites/tests/test_threads.py @@ -0,0 +1,10 @@ +"""Each test builds its own object, so under `ftcheck ci` no instance is +shared and neither site panics.""" +import stress_panic_two_sites as m + + +def test_head_and_tail(): + queue = m.Queue() + for _ in range(100): + assert queue.head() == 0 + assert queue.tail() == 63 diff --git a/tests/test_tsan_ground_truth.py b/tests/test_tsan_ground_truth.py index b70b2fe..f4915c7 100644 --- a/tests/test_tsan_ground_truth.py +++ b/tests/test_tsan_ground_truth.py @@ -179,3 +179,15 @@ def test_the_gap_fixture_is_invisible_to_ci_and_caught_by_stress(results): stress = results[("stress-unshared-state", "stress")] assert ci["exit_code"] == 0 and ci["findings"] == [] assert stress["exit_code"] == 1 and stress["findings"] + + +def test_two_panic_sites_with_one_message_are_reported_at_their_own_lines(results): + """Matched by message, both methods were filed under one line.""" + report = results[("stress-panic-two-sites", "stress")] + panics = [f for f in report["findings"] if f["rule"] == "stress/panic"] + by_line = {f["primary"]["line"]: f for f in panics} + assert sorted(by_line) == [28, 34], [f["primary"] for f in panics] + assert by_line[28]["symbol"].endswith("Queue.head") + assert "Queue.tail" not in by_line[28]["message"] + assert by_line[34]["symbol"].endswith("Queue.tail") + assert "Queue.head" not in by_line[34]["message"] From 9357b0b30d3a81e2c0f55ce56d32b2f0c940729c Mon Sep 17 00:00:00 2001 From: nimbrel <331679006+nimbrel@users.noreply.github.com> Date: Sat, 26 Sep 2026 10:10:04 +0000 Subject: [PATCH 5/5] docs: panic sites, dependency panics and mutator notes in stress output Remove the message-matching limitation, describe the dependency label and the RUST_BACKTRACE replay, and add an Unreleased CHANGELOG section with the new JSON fields. Signed-off-by: nimbrel <331679006+nimbrel@users.noreply.github.com> --- CHANGELOG.md | 18 ++++++++++++++++++ docs/limitations.md | 20 ++++++++++++-------- docs/stress.md | 21 +++++++++++++-------- 3 files changed, 43 insertions(+), 16 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index ef4076d..54d37ba 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -21,6 +21,24 @@ - Race messages name the threads (`by thread T5 (ftm-refill)`), the text summary labels each stack with its thread, and JSON stacks carry a `thread` field. - A race whose access is in PyO3's own source says so, with the PyO3 version and line. +- **`stress/panic` is located per call, not per message.** The driver records the native + thread of each panic and Rust prints the same id in its panic line, so two sites that + panic with the same message are two findings, each naming the callables that panicked + there with their own counts. When Rust prints no thread id, a finding lists every + site that shares the message. +- **A panic inside a dependency says so.** The message names the dependency and its + version (and PyO3's argument conversion when the site is there), and the headline + counts it as "inside a dependency, reached from your extension". When the log holds a + Rust backtrace, the first frame in the crate's own code is the location. +- A `stress/panic` message says when mutators were running. + +### JSON + +- `stress.panics`: every distinct panic message per callable, with a count. +- `stress.panic_threads`: per native thread id, the panicking calls in order, as + `[callable, message, count]` runs. +- A `stress/panic` finding inside a dependency carries `dependency` (for example + `"pyo3 0.29.2"`). ## 0.1.0 — 2026-09-25 diff --git a/docs/limitations.md b/docs/limitations.md index 4186dd8..d7d8bb6 100644 --- a/docs/limitations.md +++ b/docs/limitations.md @@ -47,15 +47,19 @@ Known gaps, each still open: invisible to it. - **Exceptions raised only under concurrency**, other than Rust panics, are counted in the JSON output (`stress.exceptions`) but not surfaced in the text summary. -- **A panic raised inside a dependency's code** is located at the dependency's source - line, not at the frame of yours that led there. The finding's symbol is the only pointer - to your callable. -- **Panic locations are matched by message text.** When two sites panic with the same - message, a finding can be filed at the other site, and the second site may not appear - as a finding of its own. +- **A panic raised inside a dependency's code** is labelled with the dependency and + located at its source line. The frame of yours that led there is found only when the + log holds a Rust backtrace: replay with `RUST_BACKTRACE=1` set. Backtraces are off by + default because printing one for every panic slows each panicking call about tenfold, + which changes the schedule under test. +- **Panic sites are told apart by thread id**, which current Rust prints in its panic + line. With a toolchain that prints none, a panic is located by its message, and when + two sites share the message the finding lists both without saying which call panicked + where. - **A panic on input a mutator made invalid reads as a concurrency panic**, because the - single-threaded baseline never sees the mutator's transient state. A mutator must keep - the shared inputs valid at every instant. + single-threaded baseline never sees the mutator's transient state. The finding says + when mutators were running, but does not check whether one caused it. A mutator must + keep the shared inputs valid at every instant. - **Some dependency-internal TSan reports still fail runs.** Beyond the suppressed crossbeam-deque race, reports inside dependencies' fence-based synchronisation (which TSan does not model) and glibc's thread-local teardown can be filed as "in your diff --git a/docs/stress.md b/docs/stress.md index 65f79b9..601071a 100644 --- a/docs/stress.md +++ b/docs/stress.md @@ -134,7 +134,7 @@ was, so that shows mutators reach this class of bug, not that they find it unaid A mutator must keep the shared inputs **valid at every instant**. The baseline never sees a mutator's transient state, so a call that panics on input the mutator made invalid is -reported as a panic under concurrency. +reported as a panic under concurrency. The finding says that mutators were running. A mutator that only **rewrites a buffer's contents** in place (a slice assignment into a `bytearray` the extension is reading, or a numpy array refilled with `arr[:] = ...`) races @@ -199,10 +199,15 @@ across Python threads, so they are neither driven nor counted as a coverage hole **Panics under contention are findings.** A Rust panic (`PanicException`) that a callable raises under concurrency but never in its baseline is -reported as `stress/panic`, with the count, the first panic message and — from Rust's +reported as `stress/panic`, with the count, the panic message and — from Rust's own panic output — the source line that panicked. Callables panicking at the same line are -one finding. The line is matched by panic message, so two sites panicking with the same -message can be filed under one of them (see Limits). It is not a data +one finding, with each callable's own count. The driver records the thread each panic +happened on, and Rust prints the same thread id in its panic line, so two sites panicking +with the same message are two findings. A panic inside a dependency (PyO3, another crate, +the standard library) says so and carries a `dependency` field, and the headline counts it +as inside a dependency rather than in your extension. When the log holds a Rust +backtrace (replay with `RUST_BACKTRACE=1` set), the first frame in your own code becomes +the location. It is not a data race and TSan may see nothing, but it is contention the code does not handle — and since `PanicException` is a `BaseException`, callers' `except Exception` will not catch it. A panic the baseline also raised is how the method treats those arguments, and @@ -289,9 +294,9 @@ relative to that directory. Every run prints the complete command that replays i - **Wrong results are not checked.** A call that returns a wrong value under concurrency without raising is invisible; exceptions other than panics that occur only under concurrency are counted in the JSON output but not surfaced in the summary. -- **Panic attribution is coarse.** A panic inside a dependency is located at the - dependency's source line, not at your frame that led there; panic sites are matched by - message text, so one site can hide another with the same message. +- **A panic inside a dependency is located at the dependency's line** unless the log holds + a backtrace (replay with `RUST_BACKTRACE=1`). When the toolchain prints no thread + id in its panic lines, sites that share a message are listed together. - **Mutators must keep inputs valid** (above), or their transient state reads as a - concurrency panic. + concurrency panic; the finding says mutators were running, nothing more. - See [limitations.md](limitations.md#what-stress-does-not-report-yet) for the full list.