diff --git a/CHANGELOG.md b/CHANGELOG.md index b0ff890..8f647e4 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,13 @@ ### Fixed +- **Two races in one file under the same name are two findings.** TSan reports were + deduplicated by rule, file and top symbols, without the line, so two different races + whose inlined frames share a name (two `Drop` impls, both `drop`) became one finding + and one of them was counted as a repeat of the other. The key now carries each + access's line; the same race reported again, from either side, is still one finding. + Findings are also no longer merged across classifications (a harness race with a race + outside the extension), nor at line 1 when their primary location has no line. - **A mutator refilling another library's buffer is a harness race.** A mutator writing into a numpy array (`arr[:] = ...`) reaches the memory through numpy's copy loop, not CPython's, and was filed as the extension's `certain` race, failing the run. A copy diff --git a/docs/ci.md b/docs/ci.md index 749702b..0617a10 100644 --- a/docs/ci.md +++ b/docs/ci.md @@ -54,6 +54,8 @@ $ docker run --rm --security-opt seccomp=unconfined \ module only with the GIL forced off. 5. **Collect.** TSan logs are parsed, each report is attributed, and repeats of the same race — from either side of the pair, from any threads — collapse into one finding. + A repeat is the same rule, the same top symbols and the same source line for each + access; two races in one file under the same inlined name (two `drop`s) stay two. 6. **Report.** Terminal summary, `--format json`, `--sarif`, `--junit`. The lint and the sanitizer write one SARIF format; only the rule id (`FT00x` vs `tsan/...`) and the `producer` property tell them apart. @@ -154,7 +156,9 @@ Each report is placed by looking at where each conflicting access actually happe Two refinements: when the *other* access is an allocation into reused memory (`new_dict`, `PyList_New`, `_PyFreeList_Pop`, …), your code touched an object after it was freed — **yours**, even though the frames look like CPython's. And reports -from many stacks that share one rule and one primary line are merged into one finding. +from many stacks that share one rule and one primary line are merged into one finding, +within one classification (a harness race never absorbs another). A primary location +with no line is not merged this way. **Crashes are findings.** A `SEGV` (or other fatal signal) with your code on the stack, or with no stack captured at all, fails the run: a process that died while being driven diff --git a/fixtures/racy/race-in-dependency-callbacks/expected.toml b/fixtures/racy/race-in-dependency-callbacks/expected.toml index 0bd4254..a56cc73 100644 --- a/fixtures/racy/race-in-dependency-callbacks/expected.toml +++ b/fixtures/racy/race-in-dependency-callbacks/expected.toml @@ -1,4 +1,4 @@ race = true rules = ["FT001"] -symbols = ["count_dropped", "deferred", "count_retired"] +symbols = ["drop", "deferred"] justification = "Unsynchronised read-modify-writes of shared counters in code the extension hands to a dependency: a message's Drop run by oneshot, a closure deferred to crossbeam-epoch's collector, and a thread-local destructor run at thread exit. The stacks pass through the same dependencies whose own reports ftcheck suppresses, so this pins that the suppressions stop at the dependency's code. FT001 sees only the closure, which is written inside the #[pyfunction]." diff --git a/fixtures/racy/race-in-dependency-callbacks/src/lib.rs b/fixtures/racy/race-in-dependency-callbacks/src/lib.rs index 0fcbb6b..f857ce6 100644 --- a/fixtures/racy/race-in-dependency-callbacks/src/lib.rs +++ b/fixtures/racy/race-in-dependency-callbacks/src/lib.rs @@ -22,19 +22,14 @@ static mut RETIRED: u64 = 0; /// Dropped by `oneshot` itself when the receiver goes away first. struct Receipt([u64; 32]); +// Both `Drop` impls in this file are symbolised as `drop`: only their lines +// tell the two races apart. impl Drop for Receipt { fn drop(&mut self) { - count_dropped(self.0[0]); + unsafe { DROPPED += self.0[0] }; } } -// The racy accesses are in functions of their own, so each race is reported -// under its own name rather than as another `drop`. -#[inline(never)] -fn count_dropped(n: u64) { - unsafe { DROPPED += n }; -} - #[pyfunction] fn undelivered(n: usize) -> usize { for _ in 0..n { @@ -59,15 +54,10 @@ struct Retire; impl Drop for Retire { fn drop(&mut self) { - count_retired(); + unsafe { RETIRED += 1 }; } } -#[inline(never)] -fn count_retired() { - unsafe { RETIRED += 1 }; -} - thread_local! { static ON_EXIT: Retire = const { Retire }; } diff --git a/fixtures/racy/two-drops-one-file/Cargo.lock b/fixtures/racy/two-drops-one-file/Cargo.lock new file mode 100644 index 0000000..43501ad --- /dev/null +++ b/fixtures/racy/two-drops-one-file/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 = "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 = "two-drops-one-file" +version = "0.0.0" +dependencies = [ + "pyo3", +] + +[[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/two-drops-one-file/Cargo.toml b/fixtures/racy/two-drops-one-file/Cargo.toml new file mode 100644 index 0000000..e897542 --- /dev/null +++ b/fixtures/racy/two-drops-one-file/Cargo.toml @@ -0,0 +1,12 @@ +[package] +name = "two-drops-one-file" +version = "0.0.0" +edition = "2021" +publish = false + +[lib] +name = "two_drops_one_file" +crate-type = ["cdylib", "rlib"] + +[dependencies] +pyo3 = { version = "0.29", features = ["extension-module"] } diff --git a/fixtures/racy/two-drops-one-file/expected.toml b/fixtures/racy/two-drops-one-file/expected.toml new file mode 100644 index 0000000..505634e --- /dev/null +++ b/fixtures/racy/two-drops-one-file/expected.toml @@ -0,0 +1,4 @@ +race = true +rules = [] +symbols = ["drop"] +justification = "Two `Drop` impls in one file each do an unsynchronised read-modify-write of a shared counter. Inlined, both accesses are symbolised as `drop` in `src/lib.rs`, so the file and the symbol cannot tell them apart: ThreadSanitizer must report two findings, one at each line (17 and 25). A deduplication key without the line merged them and hid one. The lint sees neither: the accesses are in `Drop` impls, not in a #[pyfunction]." diff --git a/fixtures/racy/two-drops-one-file/src/lib.rs b/fixtures/racy/two-drops-one-file/src/lib.rs new file mode 100644 index 0000000..6d86fce --- /dev/null +++ b/fixtures/racy/two-drops-one-file/src/lib.rs @@ -0,0 +1,49 @@ +//! Racy: two different races in one file under one inlined name. +//! +//! Each `Drop` impl below does an unsynchronised read-modify-write of its own +//! counter, shared by every thread. Inlined, both are symbolised as `drop` in +//! this file, so only their lines tell the two races apart: both must be +//! reported, each at its own line. + +use pyo3::prelude::*; + +static mut ADMITTED: u64 = 0; +static mut RELEASED: u64 = 0; + +struct Admit(u64); + +impl Drop for Admit { + fn drop(&mut self) { + unsafe { ADMITTED += self.0 }; + } +} + +struct Release(u64); + +impl Drop for Release { + fn drop(&mut self) { + unsafe { RELEASED += self.0 }; + } +} + +#[pyfunction] +fn admit(n: usize) -> usize { + for _ in 0..n { + drop(Admit(1)); + } + n +} + +#[pyfunction] +fn release(n: usize) -> usize { + for _ in 0..n { + drop(Release(1)); + } + n +} + +#[pymodule] +fn two_drops_one_file(m: &Bound<'_, PyModule>) -> PyResult<()> { + m.add_function(wrap_pyfunction!(admit, m)?)?; + m.add_function(wrap_pyfunction!(release, m)?) +} diff --git a/fixtures/racy/two-drops-one-file/tests/test_threads.py b/fixtures/racy/two-drops-one-file/tests/test_threads.py new file mode 100644 index 0000000..0f29ff6 --- /dev/null +++ b/fixtures/racy/two-drops-one-file/tests/test_threads.py @@ -0,0 +1,8 @@ +"""Run by `ftcheck ci` under pytest-run-parallel: this body runs in N threads at once.""" +import two_drops_one_file as m + + +def test_admit_and_release_from_many_threads(): + for _ in range(200): + m.admit(5) + m.release(5) diff --git a/python/ftcheck/ci/tsan.py b/python/ftcheck/ci/tsan.py index a3e6dd6..71beead 100644 --- a/python/ftcheck/ci/tsan.py +++ b/python/ftcheck/ci/tsan.py @@ -478,6 +478,31 @@ def _primary(report: Report, extension_modules: set[str], crate_root: str) -> tu return first, first.file or first.module or "" +def _anchor(section: Section, shown: list[Frame], placed_in_extension: bool, + extension_modules: set[str], crate_root: str) -> str: + """Where one access happened, as part of the deduplication key. + + The frame chosen is the one `_primary` would choose from this stack alone + (or, for a race placed where it happened, the stack's top), so the + finding's primary location is one of its anchors. Inlined frames + are named by their function alone — two `Drop` impls in one file are both + `drop` — so the line is what tells two races apart. A frame without one + (missing, or 0 for compiler-generated code) falls back to its file, which + is the key as it was before lines were part of it. + """ + frame = shown[0] if shown else None + if placed_in_extension: + in_crate = [f for f in section.frames if f.file and _relative(f.file, crate_root) is not None] + beyond_ffi = [f for f in in_crate if "/ffi/" not in f.file] # type: ignore[operator] + in_module = [f for f in section.frames if f.module in extension_modules] + located = [f for f in in_module if f.file] + frame = next(iter(beyond_ffi or in_crate or located or in_module), frame) + if frame is None: + return "" + where = frame.file or frame.module or "" + return f"{where}:{frame.line}" if frame.line else where + + def to_findings( reports: list[Report], extension_modules: set[str], crate_root: str ) -> tuple[list[dict], list[dict], list[dict]]: @@ -488,7 +513,9 @@ def to_findings( The same race reported from either side of the pair is one problem: stacks are ordered by their top frame before the signature is taken, so "write - races previous read" and "read races previous write" collapse. + races previous read" and "read races previous write" collapse. The + signature is the rule, the top symbols and each access's line (see + `_anchor`): the symbols alone cannot tell two inlined `drop`s apart. A report of yours is shown from your first frame; the others are shown from where the access actually happened, so a race inside CPython reads as one. @@ -531,11 +558,16 @@ def to_findings( frame, path = Frame("", None), "" rule = _rule(report.kind) tops = " / ".join(dict.fromkeys(s[1][0].symbol for s in stacks if s[1])) - signature = f"{rule}|{path}|{tops}" + # Sorted, so the same race reported from either side is one key. + anchors = sorted( + _anchor(section, frames, owner in (YOURS, HARNESS), extension_modules, crate_root) + for section, frames in stacks + ) + signature = f"{rule}|{tops}|{' / '.join(anchors)}" if stacks else f"{rule}|{path}" bucket = buckets[owner] if signature in bucket: - bucket[signature]["occurrences"] += 1 + bucket[signature][1]["occurrences"] += 1 continue # Addresses differ on every run; a message that changes when nothing @@ -558,7 +590,11 @@ def to_findings( HARNESS: "A mutator rewrote a buffer's contents while your extension read it — " "a race in the harness by the buffer protocol's contract, not in your code. ", }[owner] - bucket[signature] = { + # Findings merge on their primary line (below); a primary without a + # line would sit at line 1 and merge with anything else in the file, + # so it merges only on its own signature. + merge_key = (rule, path, frame.line) if frame.line else (rule, signature) + bucket[signature] = merge_key, { "rule": rule, "message": f"{prefix}ThreadSanitizer: {report.kind}. {described}".rstrip(), "confidence": "certain" if owner == YOURS else "likely", @@ -581,17 +617,18 @@ def to_findings( } # One root cause reported from many stacks is one finding: merge findings # sharing a rule and a primary line (one bug otherwise shows up as many). + # Never across classifications: a harness race and a race outside the + # extension at the same line stay two findings. return ( _merge(buckets[YOURS].values()), _merge(buckets[REACHED].values()), - _merge(list(buckets[EXTERNAL].values()) + list(buckets[HARNESS].values())), + _merge(buckets[EXTERNAL].values()) + _merge(buckets[HARNESS].values()), ) -def _merge(findings) -> list[dict]: +def _merge(keyed) -> list[dict]: merged: dict[tuple, dict] = {} - for f in findings: - key = (f["rule"], f["primary"]["file"], f["primary"]["line"]) + for key, f in keyed: if key in merged: merged[key]["occurrences"] += f["occurrences"] else: diff --git a/tests/test_tsan_ground_truth.py b/tests/test_tsan_ground_truth.py index f4915c7..c75d0b3 100644 --- a/tests/test_tsan_ground_truth.py +++ b/tests/test_tsan_ground_truth.py @@ -13,6 +13,7 @@ All fixtures run in one container sharing one Cargo target directory, so the instrumented standard library is built once rather than once per fixture. """ +import itertools import json import os import pathlib @@ -191,3 +192,16 @@ def test_two_panic_sites_with_one_message_are_reported_at_their_own_lines(result 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"] + + +def test_two_races_under_one_inlined_name_are_reported_at_their_own_lines(results): + """Two `Drop` impls in one file are both symbolised `drop`; a key without + the line merged them into one finding and hid a real race. Each fixture's + races are reported once, each at its own line.""" + cases = {"two-drops-one-file": [17, 25], "race-in-dependency-callbacks": [29, 47, 57]} + for (name, expected), mode in itertools.product(cases.items(), ("ci", "stress")): + report = results[(name, mode)] + races = [f for f in report["findings"] if f["rule"].startswith("tsan/")] + lines = sorted(f["primary"]["line"] for f in races) + assert lines == expected, (name, mode, [f["primary"] for f in races]) + assert all(f["primary"]["file"].endswith(f"{name}/src/lib.rs") for f in races), (name, mode) diff --git a/tests/test_tsan_parse.py b/tests/test_tsan_parse.py index 5d2f064..2b1aa7e 100644 --- a/tests/test_tsan_parse.py +++ b/tests/test_tsan_parse.py @@ -507,3 +507,74 @@ def test_the_text_summary_labels_stacks_with_thread_names(): _render_findings(outcome, out) assert "thread 1 (T1):" in out.getvalue() or "thread 2 (T1):" in out.getvalue() assert "(ftw-pair-3):" in out.getvalue() + + +# Deduplication keeps the line. Inlined frames are named by their function +# alone, so two `Drop` impls in one file both appear as `drop`: a signature of +# rule, file and top symbols made two different races one finding. +def _drop_race(line, other_line=None, fmt="{file}:{line}:9"): + other_line = line if other_line is None else other_line + at = fmt.format(file="/tmp/c/src/guards.rs", line=line) + other = fmt.format(file="/tmp/c/src/guards.rs", line=other_line) + return _race([f"drop {at} {EXT}"], [f"drop {other} {EXT}"]) + + +def test_two_races_with_the_same_symbols_in_one_file_are_two_findings(): + mine, _, _ = to_findings([_drop_race(25), _drop_race(40)], EXAMPLE, CRATE) + assert sorted(f["primary"]["line"] for f in mine) == [25, 40] + assert [f["occurrences"] for f in mine] == [1, 1] + + +def test_the_same_race_reported_again_is_still_one_finding(): + """The same pair of lines, in either order, is the same race.""" + reports = [_drop_race(25, 27), _drop_race(25, 27), _drop_race(27, 25)] + mine, _, _ = to_findings(reports, EXAMPLE, CRATE) + assert len(mine) == 1 and mine[0]["occurrences"] == 3 + + +def test_two_harness_races_at_nearby_lines_are_two_findings(): + """A mutator racing two different reads of the same function.""" + reports = [ + _race([f"scan /tmp/c/src/lib.rs:{line}:14 {EXT}"], + ["__tsan_memcpy (python3.14+0x9)", + f"bytearray_setslice_linear /cpython/Objects/bytearrayobject.c:500:5 {PY}"], + writer_name="ftm-churn") + for line in (117, 122) + ] # fmt: skip + _, _, other = to_findings(reports, EXAMPLE, CRATE) + assert sorted(f["primary"]["line"] for f in other) == [117, 122] + + +def test_findings_of_different_classifications_never_merge(): + """A harness race and a race of yours at the same line stay apart, and + so do a harness race and a race outside the extension.""" + harness = _race([f"scan /tmp/c/src/lib.rs:117:14 {EXT}"], + ["__tsan_memcpy (python3.14+0x9)", + f"bytearray_setslice_linear /cpython/Objects/bytearrayobject.c:500:5 {PY}"], + writer_name="ftm-churn") # fmt: skip + yours = _race([f"scan /tmp/c/src/lib.rs:117:14 {EXT}"], [f"fill /tmp/c/src/lib.rs:117:14 {EXT}"]) + other_so = "(otherlib.cpython-314t-x86_64-linux-gnu.so+0x5)" + external = _race([f"scan /tmp/c/src/lib.rs:117:14 {other_so}"], + [f"fill /tmp/c/src/lib.rs:117:14 {other_so}"]) # fmt: skip + mine, _, other = to_findings([harness, yours, external], EXAMPLE, CRATE) + assert len(mine) == 1 + assert len(other) == 2 + assert sum(f["message"].startswith("A mutator rewrote") for f in other) == 1 + + +def test_without_a_line_the_same_symbols_in_one_file_are_still_one_finding(): + """Frames with no line (missing, or 0 for compiler-generated code) cannot + tell two races apart: the file and symbols decide, as before.""" + for fmt in ("{file}", "{file}:0:0"): + mine, _, _ = to_findings( + [_drop_race(25, fmt=fmt), _drop_race(40, fmt=fmt)], EXAMPLE, CRATE + ) + assert len(mine) == 1 and mine[0]["occurrences"] == 2, fmt + + +def test_without_a_line_different_symbols_in_one_file_are_not_merged(): + """With no line to compare, every finding would sit at line 1 and merge.""" + a = _race([f"drop /tmp/c/src/guards.rs {EXT}"], [f"drop /tmp/c/src/guards.rs {EXT}"]) + b = _race([f"reset /tmp/c/src/guards.rs {EXT}"], [f"reset /tmp/c/src/guards.rs {EXT}"]) + mine, _, _ = to_findings([a, b], EXAMPLE, CRATE) + assert sorted(f["symbol"] for f in mine) == ["drop", "reset"]