diff --git a/.github/copilot-instructions.md b/.github/copilot-instructions.md index 3daee0576..e864099ba 100644 --- a/.github/copilot-instructions.md +++ b/.github/copilot-instructions.md @@ -2252,6 +2252,13 @@ The data does not have to be necessarily stable. A guideline might be that small a separate file or somehow encoded in source files. Larger data sets may be generated at run time, whether exhaustively or via random techniques. +### Test tiers + +A test too slow for every push is `#[ignore = "long-haul: "]` in a module named `long_haul`; one not yet +trusted is `#[ignore = "probation: "]` in a module named `probation`. A tier's run selects by the module +name and the reason names the tier, so the two must agree, and `tools/check-test-tiers.ps1` refuses a test where +they do not. The convention, what an integration test does, how the tiers run and where probation results are kept are in [DEVELOPMENT.md](../DEVELOPMENT.md#test-tiers). + ## Architectural pre-steps **Never call `stdout`/`stderr`/`print`/`eprintln` (or the language equivalent) from diff --git a/.github/release/workflows.test.cjs b/.github/release/workflows.test.cjs new file mode 100644 index 000000000..937fe9930 --- /dev/null +++ b/.github/release/workflows.test.cjs @@ -0,0 +1,36 @@ +// Copyright (c) Mike Grier. + +// Every workflow file is valid YAML. GitHub does not run a workflow it cannot parse, and says so only as a failed +// run with no jobs: the pull request's checks simply never appear, so a required one is missing and nothing says why. +// An unquoted `run:` value holding `: ` is enough (`--skip long_haul:: --skip probation::`), and no other check here +// reads a workflow as YAML. + +const test = require('node:test'); +const assert = require('node:assert/strict'); +const fs = require('node:fs'); +const path = require('node:path'); +const YAML = require('yaml'); + +const workflows = path.join(__dirname, '..', 'workflows'); + +function problems(text) { + const document = YAML.parseDocument(text); + return [...document.errors, ...document.warnings].map((e) => e.message); +} + +test('the check reports a plain scalar that holds ": "', () => { + const broken = 'jobs:\n t:\n steps:\n - run: cargo test -- --skip long_haul:: --skip probation::\n'; + assert.notEqual(problems(broken).length, 0); +}); + +test('the check accepts the same command quoted', () => { + const quoted = "jobs:\n t:\n steps:\n - run: 'cargo test -- --skip long_haul:: --skip probation::'\n"; + assert.deepEqual(problems(quoted), []); +}); + +for (const file of fs.readdirSync(workflows).filter((f) => /\.ya?ml$/.test(f))) { + test(`${file} is valid YAML`, () => { + const found = problems(fs.readFileSync(path.join(workflows, file), 'utf8')); + assert.deepEqual(found, [], `${file}: ${found.join('; ')}`); + }); +} diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index fe56e1bde..dca1ca084 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -218,6 +218,36 @@ jobs: - name: Run test-sabotage-records.ps1 (Windows PowerShell 5.1) shell: powershell run: ./tools/test-sabotage-records.ps1 + # The check that a test's ignore reason and its module agree about its tier, driven + # both from recorded listings and against a real fixture workspace, because the + # JSON libtest writes is what it reads and is not always valid JSON. Both hosts: + # an ordinary script a developer may run under either. + - name: Run test-check-test-tiers.ps1 + shell: pwsh + run: ./tools/test-check-test-tiers.ps1 + - name: Run test-check-test-tiers.ps1 (Windows PowerShell 5.1) + shell: powershell + run: ./tools/test-check-test-tiers.ps1 + # The planner that decides whether the long-haul workflow runs: a defect in it is quiet + # in both directions, the tier never running while the schedule stays green or running + # daily on an unchanged main. Both hosts, as above. + - name: Run test-plan-long-haul.ps1 + shell: pwsh + run: ./tools/test-plan-long-haul.ps1 + - name: Run test-plan-long-haul.ps1 (Windows PowerShell 5.1) + shell: powershell + run: ./tools/test-plan-long-haul.ps1 + # The scripts that run a tier, keep what each probation test did on a branch, and report + # it. A defect in them is quiet: a test counted as passing that did not, a run counted + # twice, or a test that killed its process counted as never having run. The publisher + # runs against a bare repository, and the runner against real one-crate workspaces. Both + # hosts, as above. + - name: Run test-probation.ps1 + shell: pwsh + run: ./tools/test-probation.ps1 + - name: Run test-probation.ps1 (Windows PowerShell 5.1) + shell: powershell + run: ./tools/test-probation.ps1 # pwsh only, and deliberately not repeated under 5.1 like the step above: # check-encoding.ps1 carries curated mojibake with no BOM, so 5.1 decodes # it as ANSI and cannot parse it. The suite says so and refuses to run @@ -327,6 +357,15 @@ jobs: RUST_BACKTRACE: 1 RUST_LIB_BACKTRACE: 1 run: cargo test --workspace ${{ matrix.flags }} --locked --no-fail-fast + # A test's ignore reason and the module it sits in must agree about its tier, because + # the long-haul and probation runs select by module name: a test that disagrees is one + # nothing runs, and nothing else says so. It asks every test executable for its list, + # so it needs the all-features build above and nothing more. See DEVELOPMENT.md, + # "Test tiers". + - name: check test tiers + if: ${{ matrix.variant == 'all features' }} + shell: pwsh + run: ./tools/check-test-tiers.ps1 # The UNC current-directory test is ignored by default because it needs a # reachable administrative share (`\\localhost\C$`), which an ordinary # developer account does not have -- running it by default would report an @@ -560,7 +599,7 @@ jobs: env: RUST_BACKTRACE: 1 RUST_LIB_BACKTRACE: 1 - run: cargo test -p windows-platform-probes --locked --no-fail-fast -- --include-ignored + run: 'cargo test -p windows-platform-probes --locked --no-fail-fast -- --include-ignored --skip long_haul:: --skip probation::' - name: cargo test (windows-platform-probes oracle-in-renderer integration target) env: RUST_BACKTRACE: 1 diff --git a/.github/workflows/long-haul.yml b/.github/workflows/long-haul.yml new file mode 100644 index 000000000..f3ad07ee6 --- /dev/null +++ b/.github/workflows/long-haul.yml @@ -0,0 +1,163 @@ +# Copyright (c) Mike Grier. +# +# The long-haul and probation test tiers. See DEVELOPMENT.md, "Test tiers", and +# DESIGN-NOTES.md, "long-haul-tier". +# +# A test whose scale is the point rather than the claim is `#[ignore = "long-haul: ..."]` +# in a module named `long_haul`, so ci.yml and every sabotage entry skip it and this +# workflow runs it. A test that has never run anywhere is the same with `probation`. +# libtest selects by name and not by ignore reason, which is why the module is part of +# the convention and why tools/check-test-tiers.ps1 holds the two in step. +# +# WHEN IT RUNS. Daily, and only when `main` has moved since the last run that +# completed: on an unchanged `main` a run would repeat the last one's result at the cost +# of a workspace build and every long test. tools/plan-long-haul.ps1 decides, and has +# tests of its own. A manual dispatch always runs, on the branch it is dispatched from. +# +# WHAT FAILS IT. The long-haul tier: a failure there fails the run, since those tests +# are the full-scale form of claims the push-time suites hold at a small size. The +# probation tier does not: its tests have no record yet, and a failure is data rather +# than a verdict. It runs after the long-haul tier, and whatever the long-haul tier did. +# Its results are kept across runs on the probation-results branch, by the last job, and +# reported in the run's summary (DESIGN-NOTES.md, "probation-results"). +# +# WHY IT IS NOT PART OF THE SABOTAGE SWEEP. A sweep runs a crate's whole suite once per +# entry, so a tier that costs minutes would be paid for hundreds of times. A sweep never +# passes `--ignored` and so never pays for either tier. +name: long-haul + +on: + schedule: + # Off the hour, when scheduled runs are least delayed. + - cron: '47 8 * * *' + workflow_dispatch: + +permissions: + contents: read + +# One at a time, never cancelling: a run cancelled by the next one would count as not +# completed, and the commit it was on would be run again. +concurrency: + group: long-haul + cancel-in-progress: false + +jobs: + # Asks whether `main` has moved. Needs `actions: read` to list the earlier runs. + plan: + name: plan + runs-on: windows-latest + permissions: + contents: read + actions: read + outputs: + run: ${{ steps.plan.outputs.run }} + steps: + - uses: actions/checkout@v7 + - name: Decide whether main has moved + id: plan + shell: pwsh + env: + GH_TOKEN: ${{ github.token }} + GH_REPO: ${{ github.repository }} + EVENT_NAME: ${{ github.event_name }} + RUN_SHA: ${{ github.sha }} + RUN_ID: ${{ github.run_id }} + run: ./tools/plan-long-haul.ps1 -EventName "${env:EVENT_NAME}" -Sha "${env:RUN_SHA}" -CurrentRunId "${env:RUN_ID}" -GitHubOutput "${env:GITHUB_OUTPUT}" + + tiers: + name: long-haul and probation + needs: plan + if: ${{ needs.plan.outputs.run == 'true' }} + runs-on: windows-latest + # The long tier's tests cost seconds each, not hours; a run past this has stalled. + timeout-minutes: 120 + # See ci.yml: without this, rustup's directory-scoped toolchain file would win over + # the toolchain just installed. + env: + RUSTUP_TOOLCHAIN: stable + RUST_BACKTRACE: 1 + RUST_LIB_BACKTRACE: 1 + steps: + - uses: actions/checkout@v7 + - uses: dtolnay/rust-toolchain@stable + - uses: Swatinem/rust-cache@v2 + with: + key: long-haul + # tools/run-tier.ps1 owns the command that selects a tier: the library, binary, + # integration and example test targets with `--ignored` and the tier's module + # filter, and not the doctests, since a doctest cannot sit in a `long_haul` + # module. `--no-fail-fast` so every crate's tier reports rather than the first + # to fail. It writes what each test did, and exits with cargo's own code. + - name: Run the long-haul tier + shell: pwsh + run: ./tools/run-tier.ps1 -Module long_haul -OutputDirectory .scratch/tiers/long_haul + # After the long-haul tier, and whether or not it passed, but never cancelled. + - name: Run the probation tier + id: probation + if: ${{ !cancelled() }} + continue-on-error: true + shell: pwsh + run: ./tools/run-tier.ps1 -Module probation -OutputDirectory .scratch/tiers/probation + # The id of the run and attempt that ran the tests, kept beside what they did. The job + # below that keeps the results can be re-run alone, which is a new attempt of that job + # and not another run of the tests, so it must not name the run by its own attempt. + - name: Name the run that produced these results + if: ${{ !cancelled() && hashFiles('.scratch/tiers/probation/outcomes.json') != '' }} + shell: pwsh + env: + RUN_ID: ${{ github.run_id }}.${{ github.run_attempt }} + run: ' [System.IO.File]::WriteAllText(".scratch/tiers/probation/run-id.txt", $env:RUN_ID) ' + # What each probation test did, for the job below that keeps it. Passed on as an + # artifact so that the job holding write access never runs the tests, which run + # here with read-only access. + - name: Upload what each probation test did + if: ${{ !cancelled() }} + uses: actions/upload-artifact@v7 + with: + name: probation-outcomes + path: | + .scratch/tiers/probation/outcomes.json + .scratch/tiers/probation/run-id.txt + if-no-files-found: warn + retention-days: 1 + overwrite: true + + # Keeps what each probation test did, across runs, on the `probation-results` branch, + # and reports it (DESIGN-NOTES.md, "probation-results"). The only job here that writes + # to the repository, and it writes one branch, which holds nothing but this record. It + # runs the scripts of the checkout this run is for and none of the tests, which ran in + # the job above with read-only access. + # + # Not fatal, as the sweep's equivalent is not: the record only ever gains or misses a + # run, and a red run for a publish that failed would be read as a test that did. + record: + name: keep the probation results + needs: [plan, tiers] + if: ${{ always() && needs.plan.outputs.run == 'true' }} + runs-on: windows-latest + permissions: + contents: write + steps: + - uses: actions/checkout@v7 + - name: Download what each probation test did + continue-on-error: true + uses: actions/download-artifact@v8 + with: + name: probation-outcomes + path: .scratch/probation + # The run is named by the id the job that ran the tests wrote beside the outcomes, not + # by this job's own attempt: a re-run of this job alone has the same outcomes, and + # applying the same id twice is applying it once. + - name: Publish the results to the probation-results branch + if: ${{ hashFiles('.scratch/probation/outcomes.json') != '' && hashFiles('.scratch/probation/run-id.txt') != '' }} + continue-on-error: true + shell: pwsh + env: + RUN_SHA: ${{ github.sha }} + run: ./tools/publish-probation-results.ps1 -Outcomes .scratch/probation/outcomes.json -RunId (Get-Content -Raw .scratch/probation/run-id.txt).Trim() -Commit "${env:RUN_SHA}" + # Read back from the branch, so what is reported is what is kept, and so that a + # run that could not publish still reports what the branch holds. + - name: Report the probation tier + continue-on-error: true + shell: pwsh + run: ./tools/report-probation.ps1 -SummaryPath "${env:GITHUB_STEP_SUMMARY}" diff --git a/CHECKLIST.md b/CHECKLIST.md index 135244ff0..f0ddc5ac5 100644 --- a/CHECKLIST.md +++ b/CHECKLIST.md @@ -603,3 +603,35 @@ yanks are needed, is [DE-D-8](crates/durable-ioring-events/DESIGN-NOTES.md#de-d- The engineer's own step, with their crates.io login: `cargo yank --version 0.1.1 durable-ioring-events`, then `cargo yank --version 0.5.0 win-durable-ioring` and `cargo yank --version 0.5.1 win-durable-ioring`. Both driver releases require the events crate at 0.1.1 or later within 0.1, so all three go, and the replacements must exist first. + +## M45 -- A long-haul tier, a probation tier, and suites that do only what their claims need + +Each pull request's CI, and each sabotage entry, runs a crate's whole suite, so every test pays its cost +on every one of them. Measured locally, 22 of the workspace's tests take a second or more and account +for nearly half of its serial test time; on GitHub runners, tests doing real file I/O have stalled for +many seconds while idle, which failed sabotage controls on the post-merge sweeps of `c714e83b` and +`13f06742`. So a test's scale is kept only where the claim needs it, and the scale for its own sake moves +to a long-haul tier that runs daily. Tests that have never run anywhere start on probation. The decision +is [DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier); the measurements behind it are in +[DESIGN-RATIONALE.md](DESIGN-RATIONALE.md#why-a-long-haul-tier). + +- [x] **M45.1** -- The tiers' convention and its census: `tools/check-test-tiers.ps1` refuses a test whose ignore reason and module disagree about its tier, in CI on every push. -> [completed 2026-11-03](COMPLETED-CHECKLIST.md#m451) + +- [x] **M45.2** -- `long-haul.yml`: daily when `main` has moved, plus dispatch; the long-haul tier fails the run, the probation tier does not. -> [completed 2026-11-03](COMPLETED-CHECKLIST.md#m452) + + +- [x] **M45.3** -- Probation results are kept on the `probation-results` branch and reported; the promotion threshold stays a working position. -> [completed 2026-11-03](COMPLETED-CHECKLIST.md#m453) + +- [x] **M45.4** -- The six never-run tests (five flush-barrier stress instruments and the 4 GiB buffer test) are on probation, and a tier runs one test at a time. -> [completed 2026-11-03](COMPLETED-CHECKLIST.md#m454) + +- [x] **M45.5** -- `blocking_push`'s capacity test writes past a declared capacity of 32 and its full-scale form is long-haul. -> [completed 2026-11-03](COMPLETED-CHECKLIST.md#m455) + +- [x] **M45.6** -- `windows-file-enumeration-sys`'s three large-directory tests run over 600 files with the minimum buffer, and their full-scale forms are long-haul. -> [completed 2026-11-03](COMPLETED-CHECKLIST.md#m456) + +- [x] **M45.7** -- `win-multi-file-tail-watcher`'s seven scale-bearing tests run smaller with their full-scale forms long-haul; the quiet-between-bursts waits are left and say why. -> [completed 2026-11-03](COMPLETED-CHECKLIST.md#m457) + +- [x] **M45.8** -- The census and the cost-probe tests run the cost probes at a twentieth of their workload through a new `--iteration-divisor`, with full-length forms long-haul. -> [completed 2026-11-04](COMPLETED-CHECKLIST.md#m458) + +- [x] **M45.9** -- The four waits that are their claim were measured, none was shortened, and each says why beside its constant. -> [completed 2026-11-04](COMPLETED-CHECKLIST.md#m459) + +- [x] **M45.10** -- The workspace was re-measured: 17 file-watcher stress tests that never ran are on probation, and the 13 tests still over a second are each left with a reason. -> [completed 2026-11-04](COMPLETED-CHECKLIST.md#m4510) diff --git a/COMPLETED-CHECKLIST.md b/COMPLETED-CHECKLIST.md index cd899a2d3..c6e260814 100644 --- a/COMPLETED-CHECKLIST.md +++ b/COMPLETED-CHECKLIST.md @@ -4183,3 +4183,336 @@ crates' checklists; this is only the order and the links, and each item's own ch - [x] **M44.3** -- `windows-waitable-queues`: its doorbell's `duplicate` becomes `duplicate_handle`, and the crate depends on `win-handles-sys`. - [x] **M44.4** -- `win-job-launcher`: `duplicate_inheritable` becomes `duplicate_handle`, and the crate depends on `win-handles-sys`. + +## Moved 2026-11-03 18:41:21 -05:00 -- M45.1: the test tiers' convention and its census + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier). + +### M45.1 -- The tiers' convention and its census: `tools/check-test-tiers.ps1` refuses a test whose ignore reason and module disagree about its tier, in CI on every push. *(completed 2026-11-03 18:41:21 -05:00)* + +- [x] **M45.1** -- The tiers' convention and its census. A long-haul test is + `#[ignore = "long-haul: "]` and sits in a module named `long_haul`; a probation test is + `#[ignore = "probation: "]` in a module named `probation`, since libtest filters by name + and not by ignore reason. A census script fails when a reason and its module path disagree in either + direction, so a test cannot be marked into a tier that never selects it; it runs in CI on every push, + with tests of its own for both directions. DEVELOPMENT.md states the convention. + +**Done.** [tools/check-test-tiers.ps1](tools/check-test-tiers.ps1) asks every test executable for its list +(`--list --format json`, which carries each test's ignore reason) and exits 0 consistent, 1 for a test that +breaks a rule, 2 when the census could not be taken: a `harness = false` target, a build that failed, or a +missing listing. It runs in the all-features `build + test` job after `cargo test`. +[tools/test-check-test-tiers.ps1](tools/test-check-test-tiers.ps1) tests each rule in both directions from +recorded listings, and against a fixture workspace whose real executable is asked, on PowerShell 7 and +Windows PowerShell 5.1; [tools/sabotage-tiers.json](tools/sabotage-tiers.json) re-injects each rule's +defect. The convention is in [DEVELOPMENT.md](DEVELOPMENT.md#test-tiers). + +libtest writes an ignore reason into its JSON without escaping a backslash, so the reason of the +administrative-share tests (`\\localhost\C$`) is not valid JSON and a strict parse refuses the line. The +census reads such a line by its shape. The branch that refuses a line that is neither is not reached by any +test, because no executable the suite can build writes one. + +## Moved 2026-11-03 19:18:51 -05:00 -- M45.2: the long-haul workflow + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier). + +### M45.2 -- `long-haul.yml`: daily when `main` has moved, plus dispatch; the long-haul tier fails the run, the probation tier does not. *(completed 2026-11-03 19:18:51 -05:00)* + +- [x] **M45.2** -- `long-haul.yml`: daily, and only when `main` has moved since the last completed run, + plus manual dispatch. It runs `--ignored long_haul` across the workspace, and a failure there fails the + run. Then it runs `--ignored probation`, whose failures do not fail the run. Separate from the + sabotage sweep, which never passes `--ignored` and so never pays for either tier. + +**Done.** [.github/workflows/long-haul.yml](.github/workflows/long-haul.yml) has a `plan` job and a `tiers` job. +`plan` runs [tools/plan-long-haul.ps1](tools/plan-long-haul.ps1): a dispatch always runs, and a schedule runs unless +the most recent earlier run that completed (succeeded, failed or timed out; a cancelled run did not complete) was on +the commit being run now. When the earlier runs cannot be listed it runs, with a warning, since not being able to ask +is not evidence that nothing changed. `tiers` runs the long-haul tier and then the probation tier, which is +`continue-on-error` and reports its outcome in the run summary, after the long-haul tier whether or not that passed. +The commands select the library, binary, integration and example test targets and not the doctests, since a doctest +cannot sit in a `long_haul` module. + +[tools/test-plan-long-haul.ps1](tools/test-plan-long-haul.ps1) tests each rule in both directions on PowerShell 7 and +Windows PowerShell 5.1, in CI with the other harness suites, including the path that asks GitHub through a fake `gh` and +the arguments it was given. [tools/sabotage-long-haul.json](tools/sabotage-long-haul.json) re-injects each rule's defect. +Windows PowerShell 5.1 returns a parsed JSON array as one object, which the planner enumerates; the suite found that on +its first 5.1 run, and the real `gh` output would have hit it. + +One entry is a declared equivalent mutant: a dispatch never has the earlier runs loaded, so the decision's own check for +a non-schedule event gives the same answer as the rule for a schedule with no earlier run. The entry is expected to +survive and says it will come back caught if the loader's check is ever removed. + +The workflow itself has never run: nothing in the repository can run a GitHub schedule, so the first dispatch after it +reaches `main` is the first time its two jobs and the `gh` call run on a runner. The commands were run locally, on the +workspace, where nothing is tiered yet and every executable reports no tests selected, and on a fixture crate whose +long-haul tests were selected and whose other ignored tests were not. + +## Moved 2026-11-03 21:35:43 -05:00 -- M45.3: the probation tier's results + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#probation-results). + +### M45.3 -- Probation results are kept on the `probation-results` branch and reported; the promotion threshold stays a working position. *(completed 2026-11-03 21:35:43 -05:00)* + +- [x] **M45.3** -- Keep each probation test's results across runs, and report them. The report gives each + probation test's runs, passes and current run of passes, which is what promoting it from `probation` + to `long_haul` -- a code change -- is decided on. Where the results live is this item's to decide + (artifacts expire; the sabotage record's branch is the pattern that does not), and so is the + promotion threshold, which is a working position until the first results exist. + +**Done.** Where the results live is decided: a branch of their own, `probation-results`, holding one generated +`results.json`, written by a `record` job in [long-haul.yml](.github/workflows/long-haul.yml) and read by +[report-probation.ps1](tools/report-probation.ps1). The tests run in a job with read-only access and hand what each +did to the `record` job as an artifact, so the job that can write never runs a test. +[run-tier.ps1](tools/run-tier.ps1) now owns the command that selects a tier, and both of the workflow's tiers go through +it; it reads each test's outcome from libtest's JSON events, keys it by the source path of the target its executable was +built from, and counts a test that started and never reported (its executable aborted) as a failure. +[publish-probation-results.ps1](tools/publish-probation-results.ps1) applies a run once, whatever the number of retries, +and never forces. The reasoning is in [DESIGN-NOTES.md](DESIGN-NOTES.md#probation-results) and +[DESIGN-RATIONALE.md](DESIGN-RATIONALE.md#how-probation-results-are-kept). + +The promotion threshold is **not decided**: the report takes it as `-Threshold` and labels its default a working +position, because there is no result yet to suggest a number. It is the one part of this item left open on purpose, and +nothing is scheduled for it: the first results are what settle it. + +[tools/test-probation.ps1](tools/test-probation.ps1) tests the parse, the record, the report, the publisher against a bare +repository (including a race and a branch whose name merely ends the same) and the runner against real one-crate +workspaces, one of which has an executable that aborts, on PowerShell 7 and Windows PowerShell 5.1, in CI with the other +harness suites. [tools/sabotage-probation.json](tools/sabotage-probation.json) re-injects 31 defects and a control, and all +behave as declared. Its sweep found two things: a surviving entry showed that `[ordered]@{}` compares keys without regard to +case, so the record would have merged two tests that differ only by case (it is now a list on disk and an ordinal dictionary +in memory); and `RUSTC_BOOTSTRAP=0` still turns on libtest's unstable options, because libtest only checks that the +variable is set, so the entry that was meant to switch them off removes the variable instead. + +The workflow has not run on a runner, so the first dispatch after it reaches `main` is the first time the `record` job, its +artifact hand-off and the push to the new branch run for real. Nothing is on probation yet (`M45.4` puts the first tests +there), so that run will publish nothing and report an empty record. The `record` job's publisher is a copy of the sabotage +record's, on purpose; the merge-or-delete decision is parked as `M45+.2`. + +## Moved 2026-11-03 21:52:41 -05:00 -- M45.4: the never-run tests on probation + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier). + +### M45.4 -- The six never-run tests (five flush-barrier stress instruments and the 4 GiB buffer test) are on probation, and a tier runs one test at a time. *(completed 2026-11-03 21:52:41 -05:00)* + +- [x] **M45.4** -- Put the never-run tests on probation: `windows-ioring-sys`' five flush-barrier stress + tests ("saturates a disk with background writers"; "writes tens of MiB per trial") and + `win-durable-ioring`'s test that allocates a buffer of more than 4 GiB. + +**Done.** The five instruments in [flush_barrier_stress.rs](crates/windows-ioring-sys/tests/flush_barrier_stress.rs) sit in +a `mod probation` with reasons that start `probation:`, and the 4 GiB test in `win-durable-ioring`'s +`windows_backend::tests` does the same; the census reports six probation tests and no disagreement. Their names are +unchanged, so a filter by name still finds them, but their libtest path gained `probation::`, so +[soak-flush-barrier.ps1](tools/soak-flush-barrier.ps1), which runs them with `--exact`, now passes the module path. + +Putting them on probation found something the tier had to do: [run-tier.ps1](tools/run-tier.ps1) ran a tier's tests in +parallel, and the stress instruments' own docs say `--test-threads 1` "is not optional decoration" (three of them start +contention writers, and two once collided on a temp file under a parallel harness). It now passes `--test-threads`, one by +default, with `-TestThreads` to raise it; a test with an overlap-detecting fixture covers both directions, and a sabotage +entry removes the argument. That is a choice made here, recorded as one in the decision, and not one the engineer was asked. + +All six were run for the first time here, through `run-tier.ps1` for the two crates with `IORING_STRESS_TRIALS=5`, and +all passed; the 4 GiB test allocated and passed on this machine. The default trial budget was not run, so what the tier costs +at that size on a runner is not known; the workflow's timeout bounds it, and the first results will say. + +## Moved 2026-11-03 22:12:12 -05:00 -- M45.5: the blocking_push example at the size its claim needs + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier). + +### M45.5 -- `blocking_push`'s capacity test writes past a declared capacity of 32 and its full-scale form is long-haul. *(completed 2026-11-03 22:12:12 -05:00)* + +- [x] **M45.5** -- `win-durable-ioring`'s `blocking_push` example: write past a small declared capacity, not + three times 256 writes, and keep the full scale as a long-haul test. + +**Done.** [blocking_push](crates/win-durable-ioring/examples/blocking_push/main.rs) takes the instance's declared operations +as a parameter (`build` and a new `run_with`; `run` keeps the demonstration's 256), and seals an epoch every eighth of +them. The test that writes past the declared capacity now does it at 32, with 96 writes under each delivery, and its +full-scale form, three times 256 under each, is `tests::long_haul::...`, which passed through the long-haul tier. The other +tests that wrote 200 writes through a queue of 4 now write 40, which is ten times what the queue holds, as their claim needs. +The example's tests take about a tenth of a second. + +The smaller size lost a detection, and the sabotage sweep is what showed it. At 16 operations an epoch is two writes, below the +queue of four, so a seal never meets a completion queue it cannot drain into and a pop is never refused for want of room: the +entry "a pop refused for want of room is a fault" survived. It was caught at 24 and at 32, and 32 is kept for margin; the +reasoning is on the constant. All 9 entries that patch the example behave as declared. The two entries' find strings that named +`EPOCH_WRITES` follow it to `epoch_writes`. + +## Moved 2026-11-03 22:44:38 -05:00 -- M45.6: the large-directory tests at the size their claims need + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier). + +### M45.6 -- `windows-file-enumeration-sys`'s three large-directory tests run over 600 files with the minimum buffer, and their full-scale forms are long-haul. *(completed 2026-11-03 22:44:38 -05:00)* + +- [x] **M45.6** -- `windows-file-enumeration-sys`: the directory of thousands of entries and the two large + running enumerations that are cancelled or dropped. Each to the size its claim needs, the full size + long-haul. + +**Done.** What these tests need of a directory is many refills of the native buffer and several quanta (a quantum is at most 256 +records), not thousands of files: the 1 KiB minimum buffer gives many refills from a few hundred entries, and creating the files +is what each test cost. Each of the three now takes a count and a buffer size, runs over 600 files with the minimum buffer, and +keeps its original form, 4000 files through the default buffer, as `long_haul::` beside it under its original name. The +integration suite now takes under a second, and the three long-haul forms passed through the long-haul tier. + +All 28 entries of the crate's sabotage manifest behave as declared on the changed tests. None of them needed the large size, which +is the answer to whether the shrink lost a detection; the entries were swept whole and not by diff because the tests changed and +not the code they judge. The cancellation test accepts `Completed` as well as `Cancelled`, so it never asserted the +enumeration was still running; that is unchanged, and is why a smaller count loses nothing there. + +## Moved 2026-11-03 23:13:51 -05:00 -- M45.7: the tail watcher's tests at the size their claims need + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier). + +### M45.7 -- `win-multi-file-tail-watcher`'s seven scale-bearing tests run smaller with their full-scale forms long-haul; the quiet-between-bursts waits are left and say why. *(completed 2026-11-03 23:13:51 -05:00)* + +- [x] **M45.7** -- `win-multi-file-tail-watcher`: the large roster dropped during a poll, the job log under the + tiny and default options, the children whose output is reassembled, and the real-writer tests. Shrink + where the scale is not the claim; where it is a timing claim (a reader quiet between bursts), say so + and leave it. + +**Done.** Each of these now takes its size as a parameter, runs small, and keeps its original size as a `long_haul::` test beside +it; all seven long-haul forms passed through the long-haul tier. The sizes, and what each claim needs of one: + +- **The two roster tests** (a request during a poll of 20000 files; a drop during it) assert a ratio, one step against a pass, and + skip the comparison when a pass is under 10 ms. So the size they need is one whose pass is measurable, not one that is large. A + pass cost about 4.4 microseconds a file here, so 5000 gives about 22 ms, twice the floor; 2000 gave 8 ms, under it, which would + have made the claim vacuous on this machine. 5000 is used and the full 20000, with ten times the floor, is long-haul. Registering + the files was most of what each cost. +- **The two job logs** (default and tiny options) write 36 loop steps in three bursts instead of 360. A burst still crosses many + buffers and exhausts the tiny options' pool, which is the claim; the silences are not shortened. +- **The children whose output is reassembled** (the engine's, and the layer's) use 24 child processes where they used 200 and 150: more + than three times the layer's queue of eight and many times the four buffers. A child process each was most of what they cost. +- **The real-writer park-and-resume test** registers 100 files, 20 of them written, where it registered 300 with 60. The constants + it asserted against were tied to 60 writers (a writer at index 40, more than 20 rounds a pass), so both are now derived from the + writer count; the strict inequality it had is kept. + +**What is left, and why.** `a_command_that_is_silent_then_writes_a_burst_is_delivered_at_once_and_the_reader_is_quiet_between` +takes a second and a half and is not shortened, with a comment saying so: its claim is that the reader is quiet across a silence, +a claim about time, and a shorter silence is a window in which a reader that wakes by itself is less likely to be seen. The 200 ms +quiet checks in the job-log tests and the 300 ms one after the real-writer test are the same kind and are left. Tests of under a +second, the watcher engine's child tests among them, are `M45.10`'s. + +**Sabotage.** The published catcher record names the entries each of these tests caught; 20 entries across the crate's two +manifests were caught by one of the seven, and all 20 behave as declared on the smaller tests. The record names no entry caught by +the two roster tests, so nothing the shrink could lose was recorded for them. The record is at a commit before this change and is +a hint, not a proof; the rest of the crate's entries are caught by tests this did not touch. + +## Moved 2026-11-04 09:28:29 -05:00 -- M45.8: the platform probes' tests at the workload their claims need + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier); the probes' own is in [crates/windows-platform-probes/DESIGN-NOTES.md](crates/windows-platform-probes/DESIGN-NOTES.md). + +### M45.8 -- The census and the cost-probe tests run the cost probes at a twentieth of their workload through a new `--iteration-divisor`, with full-length forms long-haul. *(completed 2026-11-04 09:28:29 -05:00)* + +- [x] **M45.8** -- `windows-platform-probes`: the tests that run every registered probe, or a cost probe at a + multiplier, at full workload. Run the probes at the smallest workload that still shows what each test + checks, with full workload long-haul. + +**Done.** The probes had no way to run lighter: the cost probes took only a whole-number multiplier of at least one, and the +multiplier test ran the request probe at twice its workload. So the cost probes gain `--iteration-divisor N`, the counterpart +of `--iteration-multiplier`: each loop runs a Nth of its usual count and at least once, so a shortened run goes round every loop +and its report has every line a full one has. A run is lengthened or shortened, never both; it says so beside its banner like a +lengthened run, and every row now carries `"iteration_divisor"` (1 by default). The census, the table-matches-row tests and the +multiplier test then use it: the census runs the cost probes at a twentieth, the two both-readers tests at a twentieth, and the +multiplier test runs the doorbell probe (the quick one) where it ran the request probe. Each keeps its full-length form as a +`long_haul::` test, the request probe at twice its workload among them; all four passed through the long-haul tier. + +The request probe's run went from about 5.5 s to 0.3 s, and the census from about 12 s to about 6 s. + +**What is left, and the blocker.** The census still takes about 6 s, and most of that is the peer-index-cache probe (3.9 s) and +the core-affinity probe (1.5 s), which measure through `windows-placement-probe` where the workload is a `pub const` of two +million baked into both `measure()` functions and into the run-plan arithmetic. A setting there changes the public signature of +a function in a second published crate, which was the engineer's decision to make and not this item's; it became +M45.8.1 and was withdrawn the same day, below. Nothing else in the crate costs a second or more except the capture-script test +(1.7 s), which is `M45.10`'s. + +**Sabotage.** Nine new entries cover the divisor (not shortening, shortening to zero, starting a loop that did not run, allowing +both settings, refusing the no-op value beside a multiplier, a huge divisor read as one, the report line, and each probe's row). +The 16 entries whose patched file changed, among them those nine and two controls that survive by design, and the 15 the published +catcher record names as caught by a test this changed, all behave as declared. Two existing entries followed the code: the request +row's find string gained the new field, and the control that shortens the queue probe's run moved with its constant. + +## Moved 2026-11-04 12:14:16 -05:00 -- M45.8.1: withdrawn + +### M45.8.1 -- Withdrawn: a setting for the size of the peer-index-cache and core-affinity probes is not worth a second crate's public API change for about six seconds. *(withdrawn 2026-11-04 12:14:16 -05:00)* + +- [x] **M45.8.1** -- `windows-placement-probe`: a setting for how many items its peer-index-cache and core-affinity + measurements move, so the census in `windows-platform-probes` can run those two probes short as it does the + others. **Withdrawn, and not done.** + +The engineer, 2026-11-04, after the cost was set out (those two probes are most of what the census still takes, about 3.9 s and +1.5 s of the six or so it takes, on debug builds): "6s is not a huge problem in terms of the time, IMO". The setting would have +meant a `measure_with(items)` in two modules of `windows-placement-probe`, a count carried in each observation, and the figures +that divide by the `ITEMS` constant dividing by it, which is a change of public API in a second published crate. The census +keeps running both probes at their normal length. Nothing is scheduled. + +## Moved 2026-11-04 13:07:34 -05:00 -- M45.9: the tests whose wait is their claim + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier). + +### M45.9 -- The four waits that are their claim were measured, none was shortened, and each says why beside its constant. *(completed 2026-11-04 13:07:34 -05:00)* + +- [x] **M45.9** -- The tests whose wait is their claim: `win-job-launcher`'s bound killing a descendant or a + grandchild, `win-debugging-sys`' process that outlives its bound, and the registration bounds in + `win-durable-ioring`. Shorten a bound only where the claim holds at the shorter one; otherwise leave it + and say why. + +**Done, by leaving them.** The item asks for a bound to be shortened only where the claim holds at the shorter one, and for these it +does not hold with the margin that keeps it from flaking on the stalled runners that prompted M45. Each is now a named constant with +the reasoning and the measurement beside it, so the next reader who asks why a test waits three seconds finds out in the file. + +- **`win-job-launcher`, the grandchild and the orphan** (3 s each, side by side, so one bound of wall time). The bound may fire + only after the descendant holds the marker. Measured: about 60 ms for the grandchild and 160 ms for the orphan, behind a middle + script that exits, on an idle machine; about 0.35 s and 1.0 s with every processor busy. Three seconds is three times the loaded + figure, and one and a half would be one and a half times it, to save a second and a half. +- **`win-debugging-sys`, a process that outlives its bound** (1.5 s). The assertion, no exit code, also holds for a process ended before it + started, so a shorter bound would still pass, but without showing that the process was running when the bound arrived. The margin is + what keeps the evidence real. The weaker evidence was left alone, since the stronger form would turn a slow start into a failure. +- **`win-durable-ioring`, the three registration bounds** (a 600 ms stall against a 50 ms bound, 0.6 s each). The stall is twelve times + the bound and far below the 30 s default, which is what lets the test tell a bound that is honoured from one that is ignored. It is also + what each test waits for while the ring runs down. The crate's longest test is about as long, so shortening these would not shorten + the suite. + +Nothing about the tests changed but names and comments, so no sabotage sweep was run: the values are identical. + +## Moved 2026-11-04 14:51:18 -05:00 -- M45.10, the re-measurement + +### M45.10 -- The workspace was re-measured: 17 file-watcher stress tests that never ran are on probation, and the 13 tests still over a second are each left with a reason. *(completed 2026-11-04 14:51:18 -05:00)* + +Run serially (`--test-threads 1`) over the whole workspace, with libtest's JSON timings. + +| | At M45's planning | After M45.1 to M45.9 | +|---|---|---| +| Tests run | 7185 | 6865 (96 ignored) | +| Serial time | 140 s | 101.6 s | +| Tests of a second or more | 22, totalling 65 s | 13, totalling 31.5 s | + +**A suite that tested nothing.** `windows-file-watcher`'s `tests/stress.rs` (4 tests) and `tests/scenario_stress.rs` +(13 tests) returned at once unless `WINDOWS_FILE_WATCHER_STRESS` was set. Nothing in CI sets it, so each +reported as passing in 0.00 s while running nothing, and because none was `#[ignore]`d the census of +`tools/check-test-tiers.ps1` could not see them. Run for real they take about 237 s serially (one test, the +churn burst, is 133 s of it) and all 17 pass. The guards are removed; each test is now in a `mod probation` +with a `probation:` ignore reason carrying its measured cost, so they run in the daily workflow and are +recorded, and a plain `cargo test` says they are ignored and not that they passed. Run through +`tools/run-tier.ps1 -Module probation`, 17 passed, 0 failed, each keyed +`crates/windows-file-watcher/tests/.rs::probation::`. The ungated unit tests in both files stay +where they were, and `WINDOWS_FILE_WATCHER_STRESS_SEED` still seeds the generator (D-66). The census reports +probation 23 (the six of M45.4 and these 17). + +**The 13 tests still over a second, left as they are, each for the reason its claim gives:** + +- The census (8.2 s): the engineer ruled the time acceptable. +- The three waits of M45.9 (two job-launcher bounds, 3.1 s each; the debugger test, 2.0 s): measured, and each says why beside its constant. +- `azure_shape` (1.9 s) and the two `runner_log` tests (1.3 s each) of M45.7: timing claims. +- The barrier-pair test in `scenario_stress` (2.0 s): a two-second timeout is what it asserts. +- The doorbell multiplier-2 test (1.4 s): the setting under test is the multiplier, and the divisor that shrinks the other + probe tests is refused beside it ("not both"), so the smallest non-default run is twice the workload. +- `runs_of_different_builds_are_refused` (1.7 s): it starts `node` once per committed copy of each capture script and per case, + and running every committed copy is its claim. +- `the_listed_streams_reach_the_commands_own_children` (1.1 s): the grandchild has to outlive its command, and `ping -n 2` is + the smallest delay a batch file has that needs no console; the test returns as soon as the grandchild's line appears. +- `properties_under_every_resolution` (1.3 s): its coverage thresholds are fractions of `PLANS`, so the scale is + the claim; the generator is clock-seeded, which a design note records as approved. +- `win-durable-ioring`'s remote-path test (0.7 s to 3.0 s between runs): the variance is the loopback share's, not the test's scale. + +No sabotage entry names a moved test, and the tests' bodies are unchanged, so no sweep was run. + +The two parked items this unblocked are not ready to be graduated: what each waits for is a run on a runner +after the branch merges (the post-merge sweeps for `M45+.1`, the first scheduled long-haul runs for +`M45+.2`), so each has a restated gate in [PARKED.md](PARKED.md). \ No newline at end of file diff --git a/DESIGN-NOTES.md b/DESIGN-NOTES.md index 4f635d4e4..a94effcfa 100644 --- a/DESIGN-NOTES.md +++ b/DESIGN-NOTES.md @@ -3028,6 +3028,91 @@ last learned and not from nothing, which is what a clone's first scoped sweep ot The alternatives and what building it found are in [DESIGN-RATIONALE.md](DESIGN-RATIONALE.md#how-the-record-came-to-a-branch). +**A test's scale is kept where its claim needs it; scale for its own sake runs daily in a long-haul tier, and a test that has never run starts on probation.** +The engineer, 2026-11-03, on the sabotage controls that timed out because a runner stalled under a +suite doing real file I/O: "do less in each of these tests", since a lighter suite helps all of CI, and +"perhaps we should have some heavy / long-haul runs for post-merge runs ... (but not as part of the +sabotage full runs)". Every pull request's CI and every sabotage entry runs a crate's whole suite, so a +test's cost is paid on each; a test whose claim holds at a small size is written at that size. + +- **The tiers are named, not inferred.** A long-haul test is `#[ignore = "long-haul: "]` + in a module named `long_haul`; a probation test is `#[ignore = "probation: "]` in a + module named `probation`. libtest selects by name, not by ignore reason, so the module path is what + runs a tier and the reason is what tells a reader why; a census fails when the two disagree, since a + test marked into a tier its name does not select would never run. The cost in the reason is + documentation (the engineer: "I don't know what the value of the 'cost' is other than pure + documentation but that's ok"). +- **The scale is moved, not dropped.** A test reduced to the size its claim needs keeps its full-scale + form as a long-haul test, so nothing that ran before stops running; it runs daily instead of on every + push. +- **A tier runs one test at a time.** [run-tier.ps1](tools/run-tier.ps1) passes `--test-threads 1` by default. + These are the tests whose scale or timing is the point, so under a parallel harness each is measured under + the others' load, and for the flush-barrier stress instruments that is not a quibble: their own module docs + call the flag "not optional decoration", and two of them once collided on a temp file under the parallel + harness. `-TestThreads` raises it for a tier whose tests are known to be independent. This was found by + putting those instruments on probation, which is what the tier is for. It was chosen while implementing + `M45.4` and the engineer was not asked; it costs wall time, which the workflow's timeout bounds. +- **Cadence: daily, and only when `main` has moved** (the engineer), plus manual dispatch, in a workflow + of its own. Not part of the sabotage sweep, which never passes `--ignored` and so never pays for either + tier. +- **Probation is for a test that has never run in CI** (the engineer: a set "which run after the main + tests which don't fail the run but we gather data on whether they succeed or fail and we can promote + them to non-probationary once they succeed for enough runs"). It runs after the long-haul tier, its + failures do not fail the run, and its results are kept across runs. Promotion is a code change, moving + the test to `long_haul`. Where the results are kept is [probation-results](#probation-results). + **A working position, not a decision:** how many passes are enough, which is `M45.3`'s to settle once + there are results to look at. + +The work is [CHECKLIST.md](CHECKLIST.md) `M45`. What prompted it, and the measurements, are in +[DESIGN-RATIONALE.md](DESIGN-RATIONALE.md#why-a-long-haul-tier). +**Each probation test's results are kept across runs on a branch of their own, `probation-results`, and reported; how many passes are enough is a working position.** +`M45.3` left this to its own work, having said only that artifacts expire and that the sabotage record's +branch is the pattern that does not. The record, `results.json`, is derived data in the same sense as the +[sabotage record](#sabotage-records), so it has the same home and the same reasons: a branch that shares no +history with `main`, written by the `record` job of +[long-haul.yml](.github/workflows/long-haul.yml) with +[publish-probation-results.ps1](tools/publish-probation-results.ps1), and read by +[report-probation.ps1](tools/report-probation.ps1), which prints each test's runs, passes, current run of +passes and latest result. The tests run in a job with read-only access and hand what each did to the `record` +job as an artifact, so the job that can write never runs a test. + +- **What a result is.** [run-tier.ps1](tools/run-tier.ps1) runs a tier through libtest's JSON events, which are + unstable and are asked for as [check-test-tiers.ps1](tools/check-test-tiers.ps1) asks for them, and reads + what each test did from them and not from text meant for a person. A test is keyed by the source path of the + target its executable was built from, relative to the workspace, and its path inside it: cargo's own + `Running` header names a path relative to the package, which two crates share, so the executable is mapped + to its target from the build's JSON. An executable that cargo ran and the build did not produce is an error. + cargo's output and the events are one file by one redirect, because the header says which executable the + events after it belong to and two pipes read on two threads do not keep that order. +- **A test's key is case-sensitive.** Two Rust tests can differ only by case, and PowerShell's ordered + dictionaries and object properties both treat those as one, which would merge two tests' counts. The record + is a list on disk and an ordinal-keyed dictionary in memory for that reason. +- **A test that started and was never reported is a failure.** The executable stopped under it, by a crash or + an abort; counting that as a pass, or as nothing, would promote exactly the test probation is for. A test + of an executable that stopped before it started is not known to exist and is not counted. +- **A run is applied once.** Each run has an id (the workflow's run and its attempt, since a re-run of the + jobs is another run of the tests), and a record that has had that id applied, as its latest run or an earlier one, is left as it is, + so a retry from a fresh fetch cannot count a run twice and a replay of an old run cannot put its results over a + newer one's (the record keeps every applied id, one a day). The id is the one the job that ran the tests wrote beside + the outcomes, not the keeping job's own attempt: that job can be re-run alone over the same outcomes, + and naming them by its new attempt would count tests that did not run again. The record's latest run moving on is also how a test that was + not in it is known: it was promoted, renamed or deleted, and the report says so and does not call it a + candidate for what it no longer is. Its counts are kept; nothing prunes the record. +- **The threshold is the report's, and is a working position.** The report calls a test a candidate when its + latest result is a pass and its current run of passes has reached `-Threshold`. The + default is a guess made before a result exists, it decides nothing -- promotion is a change to the test -- + and it is a parameter so that what the first results suggest can be tried without a code change. It has no + decision ID and nothing binds to it. +- **Not fatal.** The publish and the report are `continue-on-error`, as the sweep's record is: a result the + record misses is a run it lacks, and a red run for a publish that failed would be read as a test that did. +- **The plumbing is a copy, deliberately.** [publish-probation-results.ps1](tools/publish-probation-results.ps1) + and `Get-ProbationBranch` follow [publish-sabotage-catchers.ps1](tools/publish-sabotage-catchers.ps1) and + `Get-SabotageRecordBranch` rather than generalising them, so that building this did not touch the sabotage + harness, which a change to `common.ps1` would have re-swept in full. Whether to merge them is parked, in + [PARKED.md](PARKED.md#m45-plus-publishers), for when the new one has been shown to work. + +What was weighed is in [DESIGN-RATIONALE.md](DESIGN-RATIONALE.md#how-probation-results-are-kept). + **An entry whose result depends on the machine declares `hardware-dependent`.** The engineer, 2026-11-03, choosing among taking such an entry out of its manifest into documentation, a new expectation, and leaving it to fail at random. The case was `windows-ioring-sys`' entry that drops a flush's diff --git a/DESIGN-RATIONALE.md b/DESIGN-RATIONALE.md index 13738e04b..4d55b7225 100644 --- a/DESIGN-RATIONALE.md +++ b/DESIGN-RATIONALE.md @@ -1057,3 +1057,46 @@ select fewer entries than a full one would. **Not decided.** Whether the cache should be removed once the branch is shown to work. It is kept beside the branch on purpose, so a defect in the new path cannot cost a run its record, and the merge-or-delete decision is parked with the post-merge observation that would settle it. + +## Why a long-haul tier, and what it was measured from + +The post-merge sabotage sweeps of `c714e83b` and `13f06742` each failed on a `win-durable-ioring` control +that timed out. Neither was a hang. The failed shards' transcripts showed the same code on the same runner +taking far longer than its own baseline: the library tests in one, the `blocking_push` example in the other, +with almost no CPU used while they waited. The stall moved between test binaries, so it was the runner and +not one test; but a suite doing less real file I/O gives a stall fewer places to land. + +Measured locally on 2026-11-03 by timing every test in the workspace one at a time: 22 tests take a second +or more and account for nearly half of the serial total. They fall into three kinds. Scale for its own sake +(a directory of thousands of entries, large running enumerations, a large roster), whose claims hold at a +size just past one batch. Probes run at full workload where the test checks the shape of their output. And +waits that are the claim, such as a bound that must kill a process, which shrink only if the bound can. + +**Alternatives not taken.** Raising the sweep's timeout for the crate, or re-running a control that times +out: both answer the symptom, and are parked behind the reduction (`M45+.1`) until it is known how often a +stall still reaches a control. Deleting the heavy tests: the scale is evidence the smaller form does not +give, so it moves to a daily tier instead. Running the heavy tier inside the sabotage sweep: the sweep runs +the whole suite once per entry, which is exactly the cost this removes. + +## How probation results are kept, and what was weighed + +The decision is [DESIGN-NOTES.md](DESIGN-NOTES.md#probation-results). The engineer asked for tests that have never +run to run after the main tests, not fail the run, and be promoted "once they succeed for enough runs", which needs a +count that outlives a run. + +- **An artifact** expires, which is the whole objection to it, and is why it carries a run's outcomes to the job that + keeps them and no further. +- **The cache** evicts and no clone can read it, the reasons the sabotage record left it for a branch. +- **The `sabotage-records` branch itself** holds one generated file about a different kind of fact, and a second file + there would couple two unrelated publishers to one history and one retry loop. A branch of its own costs a readme. +- **Reading the human-readable test output** was the first thing tried and gives up what matters: a test's printed + line says it passed or failed and nothing of which executable, and a test that kills its process prints nothing at + all, which is the case that must not read as a pass. libtest's JSON names the test when it starts and again when it + finishes, so a start with no finish is visible. Its format is unstable; the census already depends on it, and a + change to it fails the run of this script loudly where a parse of text would quietly find nothing. +- **Running the executables directly** would give the JSON and the executable together, and lose what `cargo test` + sets for a test: its working directory and the variables it reads. A test would then pass or fail by how it was + started. +- **What building it found.** The tests caught two things a reading would not have: `@()` over an empty generic list + throws on PowerShell 7 here, so the empty case of every parse failed; and PowerShell 7 reads an ISO 8601 string out + of JSON as a DateTime, and written back it differs from the branch's text, so every publish would have committed. diff --git a/DEVELOPMENT.md b/DEVELOPMENT.md index 4b831f8ea..38632dd88 100644 --- a/DEVELOPMENT.md +++ b/DEVELOPMENT.md @@ -53,6 +53,60 @@ the directory override in `rustup`'s resolution order and forces those jobs onto the actual floating toolchain. The `msrv` job intentionally has no such override, since it is meant to run the pinned version. +## Test tiers + +A test too slow for every push, or not yet trusted, is `#[ignore]`d with a reason that names its tier and +sits in a module of the same name. The two spellings are what a run selects by, so they must agree: + +| Tier | Ignore reason starts with | Module | A run selects it with | +|---|---|---|---| +| long-haul | `long-haul:` | `long_haul` | `--ignored long_haul::` | +| probation | `probation:` | `probation` | `--ignored probation::` | + +```rust +mod long_haul { + #[test] + #[ignore = "long-haul: about 3s, a roster of 4096 files"] + fn the_whole_roster() { /* ... */ } +} +``` + +The text after the marker says what the test costs. Nothing reads it but a person deciding whether to run +the tier, so it is documentation, and it should say something. + +An integration test (a file under a crate's `tests/`) puts its tiered tests in a `mod long_haul` or +`mod probation` inside that file, the same as a unit test does. + +libtest filters by name and cannot filter by ignore reason, which is why the module is part of the +convention. [tools/check-test-tiers.ps1](tools/check-test-tiers.ps1) asks every test executable for its +list and refuses a test whose reason and module disagree: marked but not in the module (nothing would run +it), in the module but not marked (it would run on every push, or be swept into the tier for another +reason), a path that contains `long_haul::` without a module of that name, and a reason that reads like a +marker but is not spelled as one. It also reads the workflows' `cargo test` commands that run ignored tests +(`--include-ignored`, `--ignored`) and refuses one that would select a tier test, by its packages, targets, name +filters and `--skip`s: a tier never runs on a push, so such a command skips both tiers +(`--skip long_haul:: --skip probation::`) or names the tests it is for. CI runs it after the all-features `cargo test`, and +[tools/test-check-test-tiers.ps1](tools/test-check-test-tiers.ps1) tests it. The reasoning is in +[DESIGN-NOTES.md](DESIGN-NOTES.md#long-haul-tier). + +[.github/workflows/long-haul.yml](.github/workflows/long-haul.yml) runs the tiers, the long-haul tier and then the +probation tier, each through [tools/run-tier.ps1](tools/run-tier.ps1), which owns the command that selects a tier. +It runs daily when `main` has moved since the last run that completed, and on a manual dispatch (from any branch, +always). A failure in the long-haul tier fails the run. A failure in the probation tier does not: that step is +`continue-on-error`. The decision whether `main` has moved is [tools/plan-long-haul.ps1](tools/plan-long-haul.ps1), +tested by [tools/test-plan-long-haul.ps1](tools/test-plan-long-haul.ps1). A tier runs one test at a time (`-TestThreads`, 1 by +default), since its tests are the ones whose scale or timing is the point and each should not be measured +under the others' load. To run a tier locally: +`./tools/run-tier.ps1 -Module long_haul -OutputDirectory .scratch/tiers/long_haul`, or for one crate, +`cargo test -p --all-features -- --ignored long_haul:: --test-threads 1`. + +What each probation test did is kept across runs on the `probation-results` branch, which holds one generated file and +shares no history with `main`. To read it, run `./tools/report-probation.ps1`: each test's runs, passes, current run of +passes and latest result, and which tests have passed enough runs in a row (`-Threshold`) to be candidates for promotion. +Promoting one is a change to the test, moving it from the `probation` module to `long_haul`; the report decides nothing, +and the threshold is a working position (see [DESIGN-NOTES.md](DESIGN-NOTES.md#probation-results)). The scripts are +tested by [tools/test-probation.ps1](tools/test-probation.ps1). + ## Release process `release-please` owns version changes, tags, and changelog updates. Each crate diff --git a/PARKED.md b/PARKED.md index 2b3732e5e..41d3f9fc3 100644 --- a/PARKED.md +++ b/PARKED.md @@ -19,3 +19,34 @@ milestone of [CHECKLIST.md](CHECKLIST.md), and the file is deleted when it is em `record` job's dependence on two stores; keeping it costs a second copy that can disagree with the first, which the merge by latest result already tolerates. Either way, the merge-or-delete is made when the new path is proven and is not pre-empted by a testing or efficiency shortcut. + +## M45+ -- What a sabotage sweep does with a control that times out (parked behind the first post-merge sweeps after M45) + +- [ ] **M45+.1** -- Decide whether a sabotage entry declared `survives` that times out is run again once before + it is reported caught, or whether a crate whose suite does real I/O gets a manifest `timeoutSeconds` well + above its baseline, or neither. + + **Gate:** the post-merge sabotage sweeps that run after the M45 branch has landed on `main`. [M45.10](COMPLETED-CHECKLIST.md#m4510) + re-measured the suites (and cut the serial run from 140 s to 101.6 s), but a stall reaching a control is a property of a + runner, so only sweeps on runners can show how often it still happens. The question arose from controls in + `win-durable-ioring` timing out on runners whose tests stalled while idle (post-merge sweeps of + `c714e83b` and `13f06742`); the engineer, 2026-11-03, chose first to make the suites do less, and this + is left until it is known how often a stall still reaches a control once they do. One data point is already + in, from before M45 landed: the post-merge sweep of `main` after the `hardware-dependent` change had a control ("the abandoned-through bound takes its operands in the other order", shard + `durable-ioring` 25/49) hang past its 21 s bound inside `win-durable-ioring`'s `blocking_push` capacity test, which [M45.5](COMPLETED-CHECKLIST.md#m455) + is the item that made smaller. Whether a stall still reaches a control after M45 is what the next sweeps show. A control's patch + changes nothing, so a timeout on one cannot be a detection; a timeout on an entry declared `caught` + can be, and stays one either way. + +## M45+ -- The two publishers of a record to a branch (parked behind the first scheduled long-haul runs) + +- [ ] **M45+.2** -- Merge or delete the copy. `tools/publish-probation-results.ps1` and `Get-ProbationBranch` in + `tools/probation-common.ps1` repeat the approach of `tools/publish-sabotage-catchers.ps1` and + `Get-SabotageRecordBranch` in `tools/common.ps1`: ask the remote for the branch, build a blob, a tree and a + commit with plumbing in an index of its own, push a fast-forward, retry from a fresh fetch. Decide whether + one parameterised publisher serves both, or whether the two stay apart. + + **Gate:** the first scheduled `long-haul.yml` runs on `main`. The probation publisher is a copy so that building it + left the sabotage harness alone (`DESIGN-NOTES.md`, "probation-results"), and it is to be judged after the scheduled + workflow has run it against the real remote, which nothing in M45, [M45.10](COMPLETED-CHECKLIST.md#m4510) included, does. A merge edits `tools/common.ps1`, which every + sabotage sweep takes as an input. diff --git a/PLANS.md b/PLANS.md index 5b1de1ca2..ad4a94a8d 100644 --- a/PLANS.md +++ b/PLANS.md @@ -40,7 +40,7 @@ plans tracker: [crates/durable-ioring/PLANS.md](crates/durable-ioring/PLANS.md), | [CHECKLIST-mutation-survivors.md](CHECKLIST-mutation-survivors.md) | not started | Work queued from the workspace-wide cargo-mutants sweep of 2026-09-02, whose findings are kept in [mutation-sweeps/2026-09-02/](mutation-sweeps/2026-09-02/README.md) rather than re-derived -- the run took roughly fourteen hours. 2,792 caught, 1,112 survived, 198 timed out. **The headline numbers mislead in three ways and the README says how**: a timeout in a blocking-API crate is usually a detection that lost its name rather than a gap (measured: one of `windows-waitable-queues`' 120 timeouts fails four tests in 0.00s when re-injected alone), a low score on an executable probe crate is measuring the wrong thing, and three kinds of survivor -- equivalent mutants, unreachable code, and constants that want a `const` assertion -- are not missing tests at all. M1 covers the shipping crates; M2 holds the two crates that are not libraries and whose scope is an engineer's decision; M3 re-runs and prunes rather than hand-editing the tool's output into a second source of truth. | [mutation-sweeps/2026-09-02/README.md](mutation-sweeps/2026-09-02/README.md) | | [crates/topology-planner/CHECKLIST.md](crates/topology-planner/CHECKLIST.md) | in progress | **Planned, not built** -- the directory holds a plan and no code, and becomes a crate when M2 begins. Owns the mapping from a **dataflow description of an application** -- its input, output and processing code paths, the shape settled 2026-09-23 as `EP-D-6` and discharging the deferral `EP-D-4` named -- plus an abstracted idealized machine description, to **one or more suggested** sets of execution domains: which processors host a domain, where each thread pins, which memory node it allocates from, what channel connects each pair, and where each channel's buffer lives. `EP-D-6` also split planning into two stages -- connectivity inferred with no machine in hand, then realization against a machine model -- which adds `EP-1+.5` (the connectivity graph is a value and needs a type and a home) and `EP-1+.6` (the answer is a set, so what a caller receives and what `M2+.2` renders are sets). Filed because that mapping was **unowned**: [CHECKLIST-io-domains.md](CHECKLIST-io-domains.md) M32 lists the contracts "the runtime cannot be written without" and all of them concern the queue, while M33+.1 opens with "one pinned thread, its `IoRing`, its node-local registered pool, its shard" -- presupposing a plan nothing computed. Separate from `windows-topology-sys` because that crate states **facts** and this one applies **policy**; fusing them is what produced `outermost_partitioning_cache`, a policy answer sitting in the facts crate that three consumers then re-derived differently (SH-16.9). M1 was a *requirements* milestone -- it states what the topology must answer, and it fed the locality-model session, which has since concluded as `D-13`..`D-21`. **The component was deferred past PR #56 by direction**, contributing only planning documents there; #56 then closed unmerged on 2026-09-15 and its content is landing in peeled pieces instead, so the component is still unlanded and goes in its own pull request. Per `D-21` the topology reshape lands without it, since `windows-topology-sys` publishes a refined view of what the platform publishes and an adapter absorbs the rest. M2+ and M3+ are parked on that session concluding, and are additionally **awaiting a re-cut**: EP-D-4 and EP-D-5 re-scoped the component into four parts (`topology-model` holding the abstract machine description, the planner's traits and the plan type; `topology-planner`; an inward Windows adapter; an outward realizer), and only M1 has been reconciled with that. EP-1.1 is done and already earned its keep: checking the shard-set query against the model found `Processor::capacity` using `0` as both a valid efficiency class and a "not known" sentinel, which collide on every non-hybrid machine (filed as SH-16.12). | [crates/topology-planner/DESIGN-NOTES.md](crates/topology-planner/DESIGN-NOTES.md), [design-sessions/DESIGN-SESSION-2026-09-02-cache-locality-model.md](design-sessions/DESIGN-SESSION-2026-09-02-cache-locality-model.md) | | [CHECKLIST-io-domains.md](CHECKLIST-io-domains.md) | in progress | **M30 is complete and archived** in [COMPLETED-CHECKLIST.md](COMPLETED-CHECKLIST.md): the queue crate's name, skeleton and SPSC shape. M31 built the bounded-array MPSC (with a lazily created manual-reset doorbell whose reset cannot be separated from the observation that there is nothing to take -- achieved by ordering plus a re-check rather than by a lock, per D-9 and D-15) and is done but for `M31.6`, the `loom` verification, which is re-homed as `M30.4` in [CHECKLIST.md](CHECKLIST.md). M32 remains: the contract decisions -- ordering, correlation, backpressure among them -- the domain runtime cannot be written without. M33+ parks the runtime itself, the creation-time-affinity thread builder, the namespace `Outcome` extension, and the client-side `ThreadpoolWait` fan-in helper; the durability crate it also parked (`M33+.5`) was transferred on 2026-10-05 to [crates/durable-ioring](crates/durable-ioring/COMPONENT.md), reshaped to build on `IoRing` directly. M-inf holds items each gated on a specific measurement rather than on taste. The N=1 path is the whole first deliverable and depends on no NUMA hardware. | [DESIGN-NOTES.md](DESIGN-NOTES.md), [DESIGN-SESSION-2026-08-30-numa-sharded-io-execution-domains.md](design-sessions/DESIGN-SESSION-2026-08-30-numa-sharded-io-execution-domains.md) | -| [CHECKLIST.md](CHECKLIST.md) | in progress | M42: apply the documented-contract rule to the refusals made ahead of platform calls that already exist. M19: propagate the 2026-08-27 platform measurements (IoRing registration replaces the table; the completion-port/`IoRing` fork; `runs_long` as the growth mechanism; the measured 512 default maximum) into the crates whose code or documentation currently assumes otherwise. M20: decide the session-independent path form, now that path resolution is measured to follow the impersonated token's logon session. M21: reconcile with the impersonation and enumeration crates that landed during the session. M34 carries the review-driven repairs raised while shipping the placement tool: M34.1 (the reusable sabotage harness) is done, and M34.2 (route the placement tool's output through a sink rather than writing to stdout from many sites) and M34.3 (archive the completed item bodies still carried by the three root checklists) are open. M37: discharge the failable-call standard across the workspace. M30: find out how much of this workspace's algorithm correctness can be machine-checked -- a survey matching each argued-but-unchecked algorithm to a class of tool (TLA+/PlusCal, loom, bounded proof, `const` assertions), one pilot chosen because parameter shrinking makes an untestable property exhaustive, and a named list of what the pilot could not reach, which is the deliverable. Scoped as an instrument for narrowing hand-inspection rather than replacing it, and explicitly not a reversal of [D-31](crates/windows-waitable-queues/DESIGN-NOTES.md#d-31). Also re-homes `M31.6`, the `loom` verification the queue crate promises adopters before 1.0: it was previously untracked, referenced from that crate's design notes, a source file and its sabotage manifest with no live checklist item anywhere, and is now queued as M30.4. M30's rationale is in [DESIGN-RATIONALE.md](DESIGN-RATIONALE.md#machine-checking-what-is-argued) -- Tier 2, because no decision is taken yet; M30.5 is what produces one. M38 labels Model A and Model B at their first use in live files. M39 builds a locality helper that derives a file's flush domains from Windows' storage topology for durable-ioring. M43 corrects the `durable-ioring-events` 0.1.1 release, which should have been 0.2.0: release it, then yank 0.1.1 and `win-durable-ioring` 0.5.0 ([DE-D-8](crates/durable-ioring-events/DESIGN-NOTES.md#de-d-8)). | [DESIGN-NOTES.md](DESIGN-NOTES.md#remoting-synchronous-namespace-operations) for M19-M21 and M37; N/A for M30 | +| [CHECKLIST.md](CHECKLIST.md) | in progress | M42: apply the documented-contract rule to the refusals made ahead of platform calls that already exist. M19: propagate the 2026-08-27 platform measurements (IoRing registration replaces the table; the completion-port/`IoRing` fork; `runs_long` as the growth mechanism; the measured 512 default maximum) into the crates whose code or documentation currently assumes otherwise. M20: decide the session-independent path form, now that path resolution is measured to follow the impersonated token's logon session. M21: reconcile with the impersonation and enumeration crates that landed during the session. M34 carries the review-driven repairs raised while shipping the placement tool: M34.1 (the reusable sabotage harness) is done, and M34.2 (route the placement tool's output through a sink rather than writing to stdout from many sites) and M34.3 (archive the completed item bodies still carried by the three root checklists) are open. M37: discharge the failable-call standard across the workspace. M30: find out how much of this workspace's algorithm correctness can be machine-checked -- a survey matching each argued-but-unchecked algorithm to a class of tool (TLA+/PlusCal, loom, bounded proof, `const` assertions), one pilot chosen because parameter shrinking makes an untestable property exhaustive, and a named list of what the pilot could not reach, which is the deliverable. Scoped as an instrument for narrowing hand-inspection rather than replacing it, and explicitly not a reversal of [D-31](crates/windows-waitable-queues/DESIGN-NOTES.md#d-31). Also re-homes `M31.6`, the `loom` verification the queue crate promises adopters before 1.0: it was previously untracked, referenced from that crate's design notes, a source file and its sabotage manifest with no live checklist item anywhere, and is now queued as M30.4. M30's rationale is in [DESIGN-RATIONALE.md](DESIGN-RATIONALE.md#machine-checking-what-is-argued) -- Tier 2, because no decision is taken yet; M30.5 is what produces one. M38 labels Model A and Model B at their first use in live files. M39 builds a locality helper that derives a file's flush domains from Windows' storage topology for durable-ioring. M43 corrects the `durable-ioring-events` 0.1.1 release, which should have been 0.2.0: release it, then yank 0.1.1 and `win-durable-ioring` 0.5.0 ([DE-D-8](crates/durable-ioring-events/DESIGN-NOTES.md#de-d-8)). M45 adds a daily long-haul tier and a probation tier, and reduces each heavy test to the size its claim needs ([long-haul-tier](DESIGN-NOTES.md#long-haul-tier)). | [DESIGN-NOTES.md](DESIGN-NOTES.md#remoting-synchronous-namespace-operations) for M19-M21 and M37; N/A for M30 | | [CHECKLIST-ship-topology-and-queues.md](CHECKLIST-ship-topology-and-queues.md) | in progress | Release `windows-topology-sys` 0.2.0 and `windows-waitable-queues` 0.1.0, which everything shorter-term depends on. **Both reached crates.io on 2026-09-05**, by a route this file does not describe, since PR #56 closed unmerged; `SH-4.15` owns reconciling M4 with what shipped. Deliberately redundant with [CHECKLIST-io-domains.md](CHECKLIST-io-domains.md): that file plans the design, this one plans the release, and a release has failure modes a design checklist does not surface. Two were found while writing it -- `windows-waitable-queues-v*` is missing from the publish workflow's tag list, so release-please would tag it and nothing would publish it, silently; and `windows-ioring-sys` is published against `windows-topology-sys = "0.1.0"`. (That second finding was later **corrected at SH-2.2**: the pin is a *dev*-dependency, which consumers never resolve, so it obliges a pin update but no release.) M1 settled the public surface before it was public (done, archived); M2 repairs the plumbing; M3 lands the branch; M4 releases; M5 verifies from outside the workspace; M6 is long-running validation and gates the queue crate's release specifically. M7-M13 were seven PR #56 review rounds (done, archived); M14, M15 and M16 are the three later rounds and carry the file's open work -- M15 owns the fix for an ABA hole that ships **disclosed rather than fixed**, so it does not block the release. M16 is the SH-3.1.1 diff review, the first to read the branch as a diff rather than react to a comment: seven findings, six fixed, including a publish-workflow regression this branch had introduced two commits earlier and a soundness hole in the crate about to freeze its API. Its remaining four are blocked on [design-sessions/DESIGN-SESSION-2026-09-02-cache-locality-model.md](design-sessions/DESIGN-SESSION-2026-09-02-cache-locality-model.md), which began by asking whether collapsing a seven-kind, any-depth topology onto a single cache boundary is the right projection and has since settled that presence and observation must be modeled rather than collapsed into an `Option`. **That work gated the merge, and has since discharged**: unlike M14 and M15, which concern a defect in an implementation that can ship disclosed, M16 concerned the shape of the public model `windows-topology-sys` 0.2.0 would publish, and a published model cannot be reshaped without another break. It became the `MMT-*` plan, which has landed; the session has concluded and 0.2.0 shipped the new model, so M3 no longer waits on M16. The file opens with a status table. | [crates/windows-topology-sys/DESIGN-NOTES.md](crates/windows-topology-sys/DESIGN-NOTES.md), [crates/windows-waitable-queues/DESIGN-NOTES.md](crates/windows-waitable-queues/DESIGN-NOTES.md) | | [CHECKLIST-placement-tool.md](CHECKLIST-placement-tool.md) | in progress | A small Windows tool a stranger can download, run once, and send back one structured result -- distributed as a GitHub release binary, never to a registry, per `PT-5.6` -- so this workspace can collect placement and NUMA-hop measurements from hardware it does not own. The gap is concrete: every host available here has one NUMA node, so the whole `cross NUMA node` row and the inter-node hop matrix are unmeasured and no local work will change that. Extracted rather than published in place, because [crates/windows-platform-probes](crates/windows-platform-probes) is deliberately "an experiment, not a component". **M1-M4 and M36 are complete and archived** in [COMPLETED-CHECKLIST.md](COMPLETED-CHECKLIST.md): the name and what the record says about a machine, `(group, number)` processor identity so a machine with more than 64 of them is not silently miscounted, each NUMA hop measured in both directions with the ring placed deliberately, the move of the measurement modules, a schema-versioned submission record, the runner's experience and trust, and redaction of the secondary metadata by default. What remains is M5 (distribute the binary), M6 (are "equivalent" processors actually equivalent?) and M7 (report what Windows contradicts about itself). **M5+ is WITHDRAWN**: the canonical artifact is a CI-built binary compiled from this repository through `path` dependencies, so it needs nothing published, and an earlier version of this row wrongly gated the whole tool on releasing `windows-topology-sys` and `windows-waitable-queues`. | [crates/windows-placement-probe/DESIGN-NOTES.md](crates/windows-placement-probe/DESIGN-NOTES.md), [crates/windows-platform-probes/DESIGN-NOTES.md](crates/windows-platform-probes/DESIGN-NOTES.md) | | [CHECKLIST-thread-ambient.md](CHECKLIST-thread-ambient.md) | in progress | **M22-M29 are complete and archived** in [COMPLETED-CHECKLIST.md](COMPLETED-CHECKLIST.md): `windows-thread-ambient-sys` (a standalone layer that captures a thread's ambient state and applies it on another thread), `windows-namespace-request-sys` (marshalable Win32 namespace call parameter sets, over an entry list audited from three real consumers rather than guessed), `windows-platform-probes` (a durable home for the measurements this workspace's designs rest on), and the defects the audit of those three found. What remains is **pending**: the three `M26+` items were each gated on the namespace-facility design branch reaching `main`, and it has, so the gate has lifted -- reconciling the imported design background, applying the M22.2 narrowing to M21.2, and making the merge-or-delete decision on the duplicated path preparation. The file is deleted outright once those land. | [crates/windows-thread-ambient-sys/DESIGN-NOTES.md](crates/windows-thread-ambient-sys/DESIGN-NOTES.md) | @@ -60,6 +60,6 @@ plans tracker: [crates/durable-ioring/PLANS.md](crates/durable-ioring/PLANS.md), | [crates/windows-file-watcher/PARKED.md](crates/windows-file-watcher/PARKED.md) | parked | The `M-inf` horizon: `ReadDirectoryChangesExW` extended records, digest-based change verification, and a per-volume capability cache, outside v1 by D-19. | [DESIGN-NOTES.md](crates/windows-file-watcher/DESIGN-NOTES.md) (D-19) | | [crates/wtf-string/PARKED.md](crates/wtf-string/PARKED.md) | parked | The `M-inf` horizon: a checked no-interior-NUL C-string companion type, optional by D-7. | [DESIGN-NOTES.md](crates/wtf-string/DESIGN-NOTES.md) (D-7) | | [crates/windows-file-enumeration-sys/PARKED.md](crates/windows-file-enumeration-sys/PARKED.md) | parked | REVIEW-1: re-read against that contract, which no longer caps ordinary paths or rewrites any to `\\?\` form, and review it against a traversal layer before one is built. Raised from the `windows-file-watcher` side; schedules no change of its own. | [DESIGN-NOTES.md](crates/windows-file-enumeration-sys/DESIGN-NOTES.md), [workspace DESIGN-NOTES.md](DESIGN-NOTES.md#path-contracts-follow-path-construction) | -| [PARKED.md](PARKED.md) | parked | M34.25: keep or remove the Actions cache path for the sabotage catcher record once the `sabotage-records` branch is shown to work, gated on M34.24. | [DESIGN-NOTES.md](DESIGN-NOTES.md#sabotage-records) | +| [PARKED.md](PARKED.md) | parked | M34.25: keep or remove the Actions cache path for the sabotage catcher record once the `sabotage-records` branch is shown to work, gated on M34.24. M45+.1: what a sweep does with a control that times out, gated on M45.10. | [DESIGN-NOTES.md](DESIGN-NOTES.md#sabotage-records) | Add a row here when new work is planned, against [CHECKLIST.md](CHECKLIST.md) or any crate's. diff --git a/crates/win-debugging-sys/tests/debugger.rs b/crates/win-debugging-sys/tests/debugger.rs index 268b8ebe9..684c0447a 100644 --- a/crates/win-debugging-sys/tests/debugger.rs +++ b/crates/win-debugging-sys/tests/debugger.rs @@ -95,6 +95,16 @@ fn a_program_that_is_not_there_is_an_error_and_not_a_capture() { assert!(run_debugged(missing, &[], Duration::from_secs(1)).is_err()); } +/// How long the process that waits is given, which is most of what this file costs and is not shortened. +/// +/// The claim is about a process that is still running when the bound arrives, so the bound has to be longer +/// than it takes the process to start and be debugged: the whole exchange of the tests above, start to +/// exit, takes well under half a second on an idle machine, and several times that on a busy one. A bound +/// near that would still pass, since a process ended before it started has no exit code either, but it would +/// pass without having shown anything, which is the weaker evidence of the two to be sparing with. The +/// margin costs a second and a half of wall time beside the other tests. +const OUTLIVED_BOUND: Duration = Duration::from_millis(1_500); + #[test] fn a_process_that_outlives_the_bound_is_ended_and_has_no_exit_code() { let exe = std::env::current_exe().expect("the test binary's path"); @@ -106,7 +116,7 @@ fn a_process_that_outlives_the_bound_is_ended_and_has_no_exit_code() { "--ignored", "--test-threads=1", ], - Duration::from_millis(1_500), + OUTLIVED_BOUND, ) .expect("the process was debugged"); assert_eq!(observed.exit_code, None); diff --git a/crates/win-durable-ioring/examples/blocking_push/main.rs b/crates/win-durable-ioring/examples/blocking_push/main.rs index 80fc297f4..cbeaa68d2 100644 --- a/crates/win-durable-ioring/examples/blocking_push/main.rs +++ b/crates/win-durable-ioring/examples/blocking_push/main.rs @@ -212,8 +212,9 @@ impl Drop for Scratch { /// are measured against: a consumer that writes past it without sealing is refused. pub const OPERATIONS: usize = 256; -/// An instance over `scratch`, delivered as `delivery`, with queues of `queue` entries. -pub fn build(delivery: Delivery, scratch: &Scratch, queue: u32) -> Ring { +/// An instance over `scratch`, delivered as `delivery`, with queues of `queue` entries and built for +/// `operations` operations at once. +pub fn build(delivery: Delivery, scratch: &Scratch, queue: u32, operations: usize) -> Ring { Ring::new(Setup { submission_queue_size: queue, completion_queue_size: queue, @@ -221,7 +222,7 @@ pub fn build(delivery: Delivery, scratch: &Scratch, queue: u32) -> Ring { buffers: Vec::new(), provider: None, capacity: Capacity { - operations: OPERATIONS, + operations, lineages: 4, imports: 4, targets: 4, @@ -265,10 +266,13 @@ pub struct Report { pub sealed: usize, } -/// How many writes go into one epoch before it is sealed. Well under [`OPERATIONS`]: an epoch's -/// writes hold their places until it is sealed and the seal is durable, so the instance has to be -/// able to hold several epochs' worth while their seals complete. -const EPOCH_WRITES: usize = 32; +/// How many writes go into one epoch before it is sealed, for an instance built for `operations`: an +/// eighth of them, so well under. An epoch's writes hold their places until it is sealed and the +/// seal is durable, so the instance has to be able to hold several epochs' worth while their seals +/// complete. +fn epoch_writes(operations: usize) -> usize { + (operations / 8).max(1) +} /// The next entry, or `None` when there is none yet. That includes a pop the backend refused for /// want of room: popping rings for what a seal queued, and the backend will not take it until its @@ -314,12 +318,20 @@ fn settle( /// that, blocking whenever the ring will not take one, then collect every completion. /// /// The instance holds a write's place until its completion is popped and a seal has covered it, so -/// this does both as it goes: it seals an epoch every [`EPOCH_WRITES`] writes, and its `make_room` +/// this does both as it goes: it seals an epoch every [`epoch_writes`] writes, and its `make_room` /// pops what is waiting as well as draining. That is what lets it push more writes than the /// instance is built to hold at once ([`OPERATIONS`]). pub fn run(delivery: Delivery, writes: usize, queue: u32) -> Report { + run_with(delivery, writes, queue, OPERATIONS) +} + +/// [`run`] for an instance built for `operations` operations, which is what the writes are measured +/// against: the claim is that a consumer that seals and pops gets through more than that, and it +/// holds at any size, so a test can use a small one. +pub fn run_with(delivery: Delivery, writes: usize, queue: u32, operations: usize) -> Report { let scratch = Scratch::new(&format!("{delivery:?}")); - let mut ring = build(delivery, &scratch, queue); + let mut ring = build(delivery, &scratch, queue, operations); + let epoch_writes = epoch_writes(operations); let lineage = ring.default_lineage(); let seal = |ring: &mut Ring, epoch: u64| { ring.make_durable_through(lineage.at(epoch)) @@ -354,7 +366,7 @@ pub fn run(delivery: Delivery, writes: usize, queue: u32) -> Report { Err(blocked) => panic!("a push gave up: {:?}", blocked.why), } in_epoch += 1; - if in_epoch == EPOCH_WRITES { + if in_epoch == epoch_writes { seal(&mut ring, epoch); (sealed, last_sealed) = (sealed + 1, Some(epoch)); (epoch, in_epoch) = (epoch + 1, 0); diff --git a/crates/win-durable-ioring/examples/blocking_push/tests.rs b/crates/win-durable-ioring/examples/blocking_push/tests.rs index dd169f933..e5df6ec15 100644 --- a/crates/win-durable-ioring/examples/blocking_push/tests.rs +++ b/crates/win-durable-ioring/examples/blocking_push/tests.rs @@ -7,28 +7,40 @@ use std::time::{Duration, Instant}; use win_durable_ioring::{DurableRing, IoTargetKey, PushRefusal}; use super::{ - Blocked, Delivery, FILE, GaveUp, OPERATIONS, Scratch, build, push_blocking, run, write_at, + Blocked, Delivery, FILE, GaveUp, OPERATIONS, Scratch, build, push_blocking, run, run_with, + write_at, }; -/// Far more writes than the queues hold, so a push the ring will not take is certain. -const WRITES: usize = 200; +/// Ten times the entries the queues hold, so a push the ring will not take is certain. +const WRITES: usize = 40; const QUEUE: u32 = 4; -/// More writes than the instance is built for, so the declared capacity is certain to be reached. -const PAST_CAPACITY: usize = 3 * OPERATIONS; +/// A small declared capacity, which the writes below are measured against. The claim is that a +/// consumer that seals and pops gets through more than it, and that holds at any size -- but not +/// every defect is reachable at any size: an epoch is an eighth of the capacity, and below about +/// 24 operations an epoch is smaller than the queue, so a seal never meets a completion queue it +/// cannot drain into and a pop refused for want of room never happens, which the sabotage entry +/// "a pop refused for want of room is a fault" needs. Measured, not derived: 16 let it through, +/// 24 and 32 caught it. +const SMALL_OPERATIONS: usize = 32; + +/// Three times the capacity a run is built for, so that capacity is certain to be reached. +fn past(operations: usize) -> usize { + 3 * operations +} fn block() -> Vec { vec![7; 8] } -#[test] -fn writes_past_the_declared_capacity_are_taken_by_sealing_and_popping() { - // The instance holds a write's place until its completion is popped and a seal has covered it, - // so a consumer that never seals is refused at its declared operations however fast it pops. - // Every delivery has to get through, and has to have sealed to do it. +/// The instance holds a write's place until its completion is popped and a seal has covered it, +/// so a consumer that never seals is refused at its declared operations however fast it pops. +/// Every delivery has to get through, and has to have sealed to do it. +fn writes_past_the_declared_capacity(operations: usize) { for delivery in [Delivery::Pool, Delivery::Pumped, Delivery::Signalled] { - let report = run(delivery, PAST_CAPACITY, QUEUE); - assert_eq!(report.pushed, PAST_CAPACITY, "{delivery:?}: {report:?}"); - assert_eq!(report.completed, PAST_CAPACITY, "{delivery:?}: {report:?}"); + let writes = past(operations); + let report = run_with(delivery, writes, QUEUE, operations); + assert_eq!(report.pushed, writes, "{delivery:?}: {report:?}"); + assert_eq!(report.completed, writes, "{delivery:?}: {report:?}"); assert!( report.sealed > 1, "{delivery:?} sealed as it went: {report:?}" @@ -36,6 +48,24 @@ fn writes_past_the_declared_capacity_are_taken_by_sealing_and_popping() { } } +#[test] +fn writes_past_a_small_declared_capacity_are_taken_by_sealing_and_popping() { + writes_past_the_declared_capacity(SMALL_OPERATIONS); +} + +/// The same claim at the size the demonstration is built for, which is the full scale: three times +/// its declared operations, under each delivery. Nothing about it differs from the small one but +/// the size. +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: three deliveries of three times the 256 operations the example is built for"] + fn writes_past_the_demonstrations_declared_capacity_are_taken_by_sealing_and_popping() { + writes_past_the_declared_capacity(OPERATIONS); + } +} + #[test] fn a_pumped_instance_takes_far_more_writes_than_its_queues_hold_by_pumping() { let report = run(Delivery::Pumped, WRITES, QUEUE); @@ -67,7 +97,7 @@ fn a_pool_instance_takes_them_by_waiting_for_the_pool() { #[test] fn a_refusal_waiting_cannot_clear_is_returned_at_once_with_its_buffer() { let scratch = Scratch::new("unknown-file"); - let mut ring = build(Delivery::Pumped, &scratch, 8); + let mut ring = build(Delivery::Pumped, &scratch, 8, OPERATIONS); let lineage = ring.default_lineage(); let mut rooms = 0; let Err(Blocked { refused, why }) = push_blocking( @@ -116,7 +146,7 @@ fn fill(ring: &mut super::Ring, lineage: &win_durable_ioring::LineageHandle) -> #[test] fn a_push_that_never_gets_room_times_out_and_hands_its_buffer_back() { let scratch = Scratch::new("times-out"); - let mut ring = build(Delivery::Pumped, &scratch, QUEUE); + let mut ring = build(Delivery::Pumped, &scratch, QUEUE, OPERATIONS); let lineage = ring.default_lineage(); let filled = fill(&mut ring, &lineage); let mut rooms = 0; @@ -150,7 +180,7 @@ fn a_push_that_never_gets_room_times_out_and_hands_its_buffer_back() { #[test] fn a_make_room_that_fails_is_reported_and_hands_the_push_back() { let scratch = Scratch::new("room-fails"); - let mut ring = build(Delivery::Pumped, &scratch, QUEUE); + let mut ring = build(Delivery::Pumped, &scratch, QUEUE, OPERATIONS); let lineage = ring.default_lineage(); let filled = fill(&mut ring, &lineage); let Err(Blocked { refused, why }) = push_blocking( @@ -173,7 +203,7 @@ fn a_make_room_that_fails_is_reported_and_hands_the_push_back() { #[test] fn a_push_the_ring_takes_never_calls_make_room() { let scratch = Scratch::new("takes-it"); - let mut ring = build(Delivery::Pumped, &scratch, 8); + let mut ring = build(Delivery::Pumped, &scratch, 8, OPERATIONS); let lineage = ring.default_lineage(); let mut rooms = 0; let id = push_blocking( diff --git a/crates/win-durable-ioring/sabotage.json b/crates/win-durable-ioring/sabotage.json index 15105f7e0..e25cfe1ac 100644 --- a/crates/win-durable-ioring/sabotage.json +++ b/crates/win-durable-ioring/sabotage.json @@ -2283,7 +2283,7 @@ "file": "examples/blocking_push/main.rs", "expect": "caught", "why": "A write keeps its place until its completion is popped and a seal has covered it, so a run that seals only at the end is refused at the declared operations however fast it pops, and its push times out. This is the defect the review found: writes past 256 panicked.", - "find": [" if in_epoch == EPOCH_WRITES {"], + "find": [" if in_epoch == epoch_writes {"], "replace": [" if false {"] }, { diff --git a/crates/win-durable-ioring/src/dioring/tests/construction.rs b/crates/win-durable-ioring/src/dioring/tests/construction.rs index ab76a8228..655e0c7f5 100644 --- a/crates/win-durable-ioring/src/dioring/tests/construction.rs +++ b/crates/win-durable-ioring/src/dioring/tests/construction.rs @@ -166,6 +166,10 @@ fn a_buffer_registration_whose_completion_fails_keeps_the_buffers_with_the_ring( refused.assert_everything_but_the_buffers_came_back(&[]); } +/// The stall, twelve times the 50 ms bound it is held against and far short of the 30 s default; see `STALL` in +/// the backend's construction tests for why it is not shortened. +const STALL: Duration = Duration::from_millis(600); + #[test] fn a_registration_that_does_not_complete_within_the_bound_fails_construction() { let temp = TempFile::new("dc-stall"); @@ -173,7 +177,7 @@ fn a_registration_that_does_not_complete_within_the_bound_fails_construction() { &[&temp], vec![vec![7; 4]], Duration::from_millis(50), - |control| control.stall_submits(Duration::from_millis(600)), + |control| control.stall_submits(STALL), ); let error = refused.ring_error(); assert_eq!(error.kind(), io::ErrorKind::TimedOut); diff --git a/crates/win-durable-ioring/src/windows_backend/tests.rs b/crates/win-durable-ioring/src/windows_backend/tests.rs index 1fc82b00c..dcf0661d9 100644 --- a/crates/win-durable-ioring/src/windows_backend/tests.rs +++ b/crates/win-durable-ioring/src/windows_backend/tests.rs @@ -363,29 +363,35 @@ fn the_targets_geometry_is_enforced_before_the_ring_is_asked() { run(&mut backend, write(2, IoTargetKey(3), 512, &[0; 512])); } -/// Allocates a buffer of more than 4 GiB, which a machine without that commit available cannot, so -/// it is run on request: `cargo test -- --ignored a_buffer_the_ring_cannot_carry`. -#[test] -#[ignore = "allocates a buffer of more than 4 GiB"] -fn a_buffer_the_ring_cannot_carry_is_refused_by_check_and_by_push() { - let (given, added) = (TempFile::new("wb-given"), TempFile::new("wb-added")); - let mut backend = backend(&given, &added); - let length = usize::try_from(u64::from(u32::MAX) + 1).expect("a 64-bit target"); - let submission = Submission { - token: SubmissionToken(1), - target: ADDED, - op: SubmissionOp::Write { - offset: 0, - data: SubmissionData::Owned(vec![0; length]), - caching: WriteCaching::Cached, - }, - }; - assert_eq!( - backend.check(submission.target, &submission.op), - Err(RefusalCause::Invalid) - ); - let refused = backend.push(submission).expect_err("beyond a u32"); - assert_eq!(refused.cause, RefusalCause::Invalid); +mod probation { + use super::*; + + /// Allocates a buffer of more than 4 GiB, which a machine without that commit available cannot, so + /// it is run on request: `cargo test -- --ignored a_buffer_the_ring_cannot_carry`. + /// + /// On probation: it has never run in CI, so it sits in the module the probation tier selects by. + #[test] + #[ignore = "probation: allocates a buffer of more than 4 GiB"] + fn a_buffer_the_ring_cannot_carry_is_refused_by_check_and_by_push() { + let (given, added) = (TempFile::new("wb-given"), TempFile::new("wb-added")); + let mut backend = backend(&given, &added); + let length = usize::try_from(u64::from(u32::MAX) + 1).expect("a 64-bit target"); + let submission = Submission { + token: SubmissionToken(1), + target: ADDED, + op: SubmissionOp::Write { + offset: 0, + data: SubmissionData::Owned(vec![0; length]), + caching: WriteCaching::Cached, + }, + }; + assert_eq!( + backend.check(submission.target, &submission.op), + Err(RefusalCause::Invalid) + ); + let refused = backend.push(submission).expect_err("beyond a u32"); + assert_eq!(refused.cause, RefusalCause::Invalid); + } } #[test] diff --git a/crates/win-durable-ioring/src/windows_backend/tests/construction.rs b/crates/win-durable-ioring/src/windows_backend/tests/construction.rs index 862b6bdd7..8457364f0 100644 --- a/crates/win-durable-ioring/src/windows_backend/tests/construction.rs +++ b/crates/win-durable-ioring/src/windows_backend/tests/construction.rs @@ -169,12 +169,21 @@ fn a_failed_buffer_registration_completion_does_not_hand_the_buffers_back() { ); } +/// How long the registration tests stall a submit for, against a bound of 50 ms: twelve times it, so the +/// bound is certain to be what ends the wait, and far short of the default of 30 s, so a construction that +/// ignored the bound would wait for the stall to end and succeed instead. The stall is also what the test +/// waits for after it, while the ring runs down, so it is most of what each of these costs, about 0.6 s. +/// It is not shortened: the bound has to be reached before the stall ends however slowly the thread that +/// waits on it is scheduled, and a stall of a few times the bound would leave that margin to chance on a +/// busy machine. The crate's longest test is about as long, so shortening these saves no wall time. +const STALL: Duration = Duration::from_millis(600); + #[test] fn a_registration_that_does_not_complete_within_the_bound_fails_construction_on_that_bound() { let file = TempFile::new("wbc-stall"); let bound = Duration::from_millis(50); let (refused, _control) = refused_with(&[&file], vec![vec![7; 4]], bound, |control| { - control.stall_submits(Duration::from_millis(600)); + control.stall_submits(STALL); }); let error = ring_error(&refused); assert_eq!(error.kind(), io::ErrorKind::TimedOut); @@ -199,7 +208,7 @@ fn a_buffer_registration_that_does_not_complete_within_the_bound_fails_on_that_b &[], vec![vec![7; 4]], Duration::from_millis(50), - |control| control.stall_submits(Duration::from_millis(600)), + |control| control.stall_submits(STALL), ); let error = ring_error(&refused); assert_eq!(error.kind(), io::ErrorKind::TimedOut); diff --git a/crates/win-job-launcher/tests/launch.rs b/crates/win-job-launcher/tests/launch.rs index 8613ee512..71c6cae0f 100644 --- a/crates/win-job-launcher/tests/launch.rs +++ b/crates/win-job-launcher/tests/launch.rs @@ -27,6 +27,18 @@ const LAUNCHER: &str = env!("CARGO_BIN_EXE_win-job-launcher"); /// A long-running command: `ping` waits about a second between echoes. const LONG: [&str; 4] = ["ping", "-n", "60", "127.0.0.1"]; +/// The bound, in milliseconds, of the two tests that start a descendant and wait for the bound to kill it. +/// +/// **It is the claim, and it is not shortened.** Each test waits for its descendant to hold the marker before +/// the bound may fire, and a bound that fires first is a test that never saw what it claims to. Setting a +/// descendant up takes a chain of `cmd` starts: measured, the grandchild holds the marker after about 60 ms +/// and the orphan, behind a middle script that exits, after about 160 ms on an idle machine, and about 0.35 s +/// and 1.0 s with every processor busy, which is what a stalled runner looks like. A bound of three seconds +/// is three times the loaded figure; a bound of one and a half would be one and a half times it, and the +/// price of saving a second and a half would be a test that fails when the machine is slow. The two run +/// side by side, so together they cost one bound of wall time. +const DESCENDANT_BOUND_MS: u32 = 3_000; + /// A scratch directory unique to one test, removed when dropped. struct Scratch(PathBuf); @@ -280,7 +292,7 @@ fn the_bound_kills_a_grandchild() { // The script's cmd holds the marker; its ping is the grandchild. let s = Scratch::new("grandchild"); let script = holder(&s); - let (child, start) = spawn(&s, 3_000, &[script.to_str().unwrap()]); + let (child, start) = spawn(&s, DESCENDANT_BOUND_MS, &[script.to_str().unwrap()]); let marker = s.path("marker.txt"); wait_until_held(&marker); let run = finish(&s, start, child.wait_with_output().unwrap()); @@ -310,7 +322,7 @@ fn the_bound_kills_a_descendant_whose_parent_has_exited() { "top.cmd", "start \"\" /b cmd /d /c \"{dir}\\middle.cmd\"\nping -n 60 127.0.0.1 >nul", ); - let (child, start) = spawn(&s, 3_000, &[top.to_str().unwrap()]); + let (child, start) = spawn(&s, DESCENDANT_BOUND_MS, &[top.to_str().unwrap()]); let marker = s.path("marker.txt"); wait_until_held(&marker); let run = finish(&s, start, child.wait_with_output().unwrap()); diff --git a/crates/win-multi-file-tail-watcher/src/read_engine/child_tests.rs b/crates/win-multi-file-tail-watcher/src/read_engine/child_tests.rs index 46ecaa17e..248fd0803 100644 --- a/crates/win-multi-file-tail-watcher/src/read_engine/child_tests.rs +++ b/crates/win-multi-file-tail-watcher/src/read_engine/child_tests.rs @@ -144,12 +144,17 @@ impl Fixture { } } -#[test] -fn what_children_write_is_reassembled_by_range_each_byte_delivered_once() { - const COUNT: u32 = 200; +/// Several times the four buffers the engine reads through, so most files wait for one while others +/// are being read. A child process each is most of what the test costs. +const CHILDREN: u32 = 24; + +/// The count the test was first written at. See [`long_haul`]. +const MANY_CHILDREN: u32 = 200; + +fn what_children_write_is_reassembled_by_range(count: u32) { const PASSES: u64 = 30; let dir = TempDir::new("re-child-whole"); - let mut fixture = Fixture::new(&dir, COUNT, PASSES, 4); + let mut fixture = Fixture::new(&dir, count, PASSES, 4); let mut taken = Taken::default(); let deadline = Instant::now() + Duration::from_secs(120); let mut polls = 0; @@ -176,6 +181,21 @@ fn what_children_write_is_reassembled_by_range_each_byte_delivered_once() { } } +#[test] +fn what_children_write_is_reassembled_by_range_each_byte_delivered_once() { + what_children_write_is_reassembled_by_range(CHILDREN); +} + +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: starts 200 child processes"] + fn what_many_children_write_is_reassembled_by_range_each_byte_delivered_once() { + what_children_write_is_reassembled_by_range(MANY_CHILDREN); + } +} + #[test] fn chunks_the_client_keeps_stop_the_reads_and_dropping_them_resumes_them() { const PASSES: u64 = 20; diff --git a/crates/win-multi-file-tail-watcher/src/read_layer/child_tests.rs b/crates/win-multi-file-tail-watcher/src/read_layer/child_tests.rs index f63a3a779..770735b2a 100644 --- a/crates/win-multi-file-tail-watcher/src/read_layer/child_tests.rs +++ b/crates/win-multi-file-tail-watcher/src/read_layer/child_tests.rs @@ -68,15 +68,20 @@ impl Writers { } } -#[test] -fn polls_on_the_thread_pool_deliver_what_children_write_each_byte_once() { - const COUNT: u32 = 150; +/// Three times the watcher SQ of eight, so polls park and are continued, and many times the four +/// buffers. A child process each is most of what the test costs. +const CHILDREN: u32 = 24; + +/// The count the test was first written at. See [`long_haul`]. +const MANY_CHILDREN: u32 = 150; + +fn polls_on_the_thread_pool_deliver_what_children_write(count: u32) { const PASSES: u64 = 30; let dir = TempDir::new("rl-child-polls"); // A watcher SQ of eight, so polls park and are continued, a pool of four buffers of eight // bytes, and a client SQ of two. let layer = layer_with(8, 4, 2); - let mut writers = Writers::start(&dir, &layer, COUNT, PASSES); + let mut writers = Writers::start(&dir, &layer, count, PASSES); let mut taken = Taken::default(); let deadline = Instant::now() + Duration::from_secs(120); let mut polls = 0; @@ -104,6 +109,21 @@ fn polls_on_the_thread_pool_deliver_what_children_write_each_byte_once() { assert!(layer.take_failure().is_none()); } +#[test] +fn polls_on_the_thread_pool_deliver_what_children_write_each_byte_once() { + polls_on_the_thread_pool_deliver_what_children_write(CHILDREN); +} + +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: starts 150 child processes"] + fn polls_on_the_thread_pool_deliver_what_many_children_write_each_byte_once() { + polls_on_the_thread_pool_deliver_what_children_write(MANY_CHILDREN); + } +} + #[test] fn chunks_the_client_keeps_stall_the_layer_and_dropping_them_continues_it() { const COUNT: u32 = 12; diff --git a/crates/win-multi-file-tail-watcher/tests/poll_real_writers.rs b/crates/win-multi-file-tail-watcher/tests/poll_real_writers.rs index d87fc9cc9..cd7e9ca7e 100644 --- a/crates/win-multi-file-tail-watcher/tests/poll_real_writers.rs +++ b/crates/win-multi-file-tail-watcher/tests/poll_real_writers.rs @@ -225,14 +225,25 @@ fn attentions(entries: &[SqEntry]) -> Vec<(u32, u64, u64)> { .collect() } -#[test] -fn children_writing_to_inherited_handles_are_reported_across_many_parks_and_resumes() { +/// Registrations, every fifth a file a child writes, so a pass reports a few times more writers than +/// the two slots hold and the poll parks and resumes between them. A child process each is most of +/// what the test costs. +const ROSTER: u32 = 100; + +/// The roster the test was first written at: sixty writers. See [`long_haul`]. +const FULL_ROSTER: u32 = 300; + +fn children_writing_to_inherited_handles_are_reported_across_parks_and_resumes(total: u32) { const PASSES: u64 = 5; let dir = TempDir::new("steps"); - let mut fixture = Fixture::new(&dir, 300, 5, PASSES, true); + let mut fixture = Fixture::new(&dir, total, 5, PASSES, true); let late_path = dir.file("late.log", &[b'y'; 40]); let mut live: Vec = fixture.writers.iter().map(|(value, _)| *value).collect(); - let dropped = live[40]; + // Two thirds of the way along, so it is a writer in the middle of the poll whatever the roster. + let dropped = live[live.len() * 2 / 3]; + // Parks and resumes: every two writers fill the slots once, and a pass takes more than two + // thirds of that many rounds. + let least_rounds = live.len() / SLOTS * 2 / 3; let mut late = None; let (entries, _) = poll_to_end(&fixture.watcher); @@ -270,7 +281,10 @@ fn children_writing_to_inherited_handles_are_reported_across_many_parks_and_resu } assert_eq!(attentions(&entries), expected, "pass {pass}"); assert_eq!(entries.last(), Some(&SqEntry::PollDone)); - assert!(rounds > 20, "pass {pass} took {rounds} rounds"); + assert!( + rounds > least_rounds, + "pass {pass} took {rounds} rounds, and a roster of {total} takes more than {least_rounds}" + ); } drop(late); fixture.finish(); @@ -291,6 +305,21 @@ fn children_writing_to_inherited_handles_are_reported_across_many_parks_and_resu round(&fixture.watcher); } +#[test] +fn children_writing_to_inherited_handles_are_reported_across_many_parks_and_resumes() { + children_writing_to_inherited_handles_are_reported_across_parks_and_resumes(ROSTER); +} + +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: starts sixty child processes among 300 registrations"] + fn many_children_writing_to_inherited_handles_are_reported_across_many_parks_and_resumes() { + children_writing_to_inherited_handles_are_reported_across_parks_and_resumes(FULL_ROSTER); + } +} + #[test] fn polling_through_two_slots_while_children_write_and_registrations_come_and_go() { const WRITES: u64 = 300; diff --git a/crates/win-multi-file-tail-watcher/tests/reader_real_writers/azure_shape.rs b/crates/win-multi-file-tail-watcher/tests/reader_real_writers/azure_shape.rs index f8d3eb094..4f690cffe 100644 --- a/crates/win-multi-file-tail-watcher/tests/reader_real_writers/azure_shape.rs +++ b/crates/win-multi-file-tail-watcher/tests/reader_real_writers/azure_shape.rs @@ -42,6 +42,10 @@ fn lines(of: &[&str]) -> Vec { of.iter().map(|l| (*l).to_owned()).collect() } +// Not shortened, though it takes over a second: the claim is that the reader is quiet between a +// silence and a burst, which is a claim about time. Three polls with 500 ms between them is the +// silence, and a shorter one is a shorter window in which a reader that wakes on its own could be +// seen to. #[test] fn a_command_that_is_silent_then_writes_a_burst_is_delivered_at_once_and_the_reader_is_quiet_between() { diff --git a/crates/win-multi-file-tail-watcher/tests/reader_real_writers/runner_log.rs b/crates/win-multi-file-tail-watcher/tests/reader_real_writers/runner_log.rs index 505df3d50..4316d86f7 100644 --- a/crates/win-multi-file-tail-watcher/tests/reader_real_writers/runner_log.rs +++ b/crates/win-multi-file-tail-watcher/tests/reader_real_writers/runner_log.rs @@ -49,12 +49,21 @@ fn loop_body() -> String { .join("&") } -fn run(options: &TailReaderOptions) { +/// Three bursts with a silence before each, as the capture has them, in steps of the script's +/// loop. Enough that each burst crosses many buffers and exhausts the tiny options' pool, which is +/// what the claim needs; the child writing them is most of what the test costs. +const BURSTS: [(u64, u64); 3] = [(1, 12), (13, 16), (17, 36)]; + +/// The same shape ten times over, the size the test was first written at: 120, 40 and 200 steps. +const FULL_BURSTS: [(u64, u64); 3] = [(1, 120), (121, 160), (161, 360)]; + +/// The silence before each burst is not shortened: that nothing is delivered and nothing rings +/// while a log is quiet is a claim about time, and a window shorter than a wake-up of the reader +/// would stop being able to see one. +fn run(options: &TailReaderOptions, bursts: [(u64, u64); 3]) { let dir = TempDir::new("runner"); let path = dir.path("job.log"); - // Three bursts with a silence before each: 120, 40 and 200 steps. - let bursts = [(1, 120), (121, 160), (161, 360)]; let mut parts = Vec::new(); for (from, to) in bursts { parts.push(gate()); @@ -130,20 +139,41 @@ fn run(options: &TailReaderOptions) { assert!(crossed > 0, "the log has lines longer than the buffer"); } -#[test] -fn a_job_log_is_delivered_whole_under_the_default_options() { - run(&TailReaderOptions::default()); -} - -#[test] -fn a_job_log_is_delivered_whole_under_the_tiny_options() { - // Eight-byte buffers: every line is cut across chunks, the pool and the client queue are - // exhausted by each burst, and the log is still whole. +/// Eight-byte buffers: every line is cut across chunks, the pool and the client queue are exhausted +/// by each burst, and the log is still whole. +fn tiny_options() -> TailReaderOptions { let mut options = TailReaderOptions::default(); options.buffer_len = 8; options.buffer_count = 4; options.client_sq_capacity = 2; options.ring_sq_size = 8; options.ring_cq_size = 16; - run(&options); + options +} + +#[test] +fn a_job_log_is_delivered_whole_under_the_default_options() { + run(&TailReaderOptions::default(), BURSTS); +} + +#[test] +fn a_job_log_is_delivered_whole_under_the_tiny_options() { + run(&tiny_options(), BURSTS); +} + +/// The same two logs at the size they were first written at. +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: a child writes 360 loop steps of four lines, in three bursts"] + fn a_job_log_of_many_steps_is_delivered_whole_under_the_default_options() { + run(&TailReaderOptions::default(), FULL_BURSTS); + } + + #[test] + #[ignore = "long-haul: a child writes 360 loop steps of four lines, in three bursts"] + fn a_job_log_of_many_steps_is_delivered_whole_under_the_tiny_options() { + run(&tiny_options(), FULL_BURSTS); + } } diff --git a/crates/win-multi-file-tail-watcher/tests/shutdown_every_state.rs b/crates/win-multi-file-tail-watcher/tests/shutdown_every_state.rs index d8a52d6ba..d78514212 100644 --- a/crates/win-multi-file-tail-watcher/tests/shutdown_every_state.rs +++ b/crates/win-multi-file-tail-watcher/tests/shutdown_every_state.rs @@ -148,14 +148,21 @@ fn a_request_from_the_callers_wait_while_a_poll_is_parked_stops_it_and_poll_done wait.stop_and_drain(); } -#[test] -fn a_request_from_the_callers_wait_while_a_poll_is_inside_its_probe_returns_at_once() { - const FILES: u32 = 20_000; +/// The roster size at which a pass over it is long enough to measure against, with room to spare: +/// the two claims below are ratios of one step to a pass, and each skips the comparison when a pass +/// is under 10 ms, which a roster this size is about twice over on the machine it was measured on. +/// Registering the files is what the tests cost, so this is no larger than that needs. +const MEASURABLE: u32 = 5_000; + +/// The size the claims were first made at, with about ten times the floor. See [`long_haul`]. +const FULL: u32 = 20_000; + +fn a_request_while_a_poll_is_inside_its_probe_returns_at_once(files: u32) { let dir = TempDir::new("probe"); let path = dir.file("a.log", b"0123456789"); // Registered at their length, so a poll is all probe and reports nothing. let watcher = Arc::new(Watcher::new(4).expect("watcher")); - let _registrations: Vec<_> = (0..FILES) + let _registrations: Vec<_> = (0..files) .map(|n| watcher.register(&wtf(&path), 10, n).expect("register")) .collect(); let start = Instant::now(); @@ -168,8 +175,8 @@ fn a_request_from_the_callers_wait_while_a_poll_is_inside_its_probe_returns_at_o let bell = doorbell_copy(&watcher); let start = Instant::now(); watcher.poll().expect("poll"); - // The poll is probing twenty thousand files, which does not ring the doorbell; ring it for the - // caller's wait. + // The poll is probing every file, which does not ring the doorbell; ring it for the caller's + // wait. ring(&bell); let took = requested .recv_timeout(Duration::from_secs(10)) @@ -190,6 +197,11 @@ fn a_request_from_the_callers_wait_while_a_poll_is_inside_its_probe_returns_at_o wait.stop_and_drain(); } +#[test] +fn a_request_from_the_callers_wait_while_a_poll_is_inside_its_probe_returns_at_once() { + a_request_while_a_poll_is_inside_its_probe_returns_at_once(MEASURABLE); +} + // A value whose clone waits for `release`, so a poll can be held inside the report. struct Gate { state: Mutex<(bool, bool)>, @@ -283,15 +295,13 @@ fn repeated_requests_from_the_callers_wait_and_from_other_threads_are_harmless() wait.stop_and_drain(); } -#[test] -fn dropping_during_a_poll_over_a_large_roster_takes_a_step_not_a_pass() { - const FILES: u32 = 20_000; +fn dropping_during_a_poll_takes_a_step_not_a_pass(files: u32) { let dir = TempDir::new("drop-large"); let path = dir.file("a.log", b"0123456789"); // Registered at their length, so a poll is all probe and reports nothing. let build = || { let watcher = Watcher::::new(4).expect("watcher"); - let registrations: Vec<_> = (0..FILES) + let registrations: Vec<_> = (0..files) .map(|n| watcher.register(&wtf(&path), 10, n).expect("register")) .collect(); (watcher, registrations) @@ -330,6 +340,31 @@ fn dropping_during_a_poll_over_a_large_roster_takes_a_step_not_a_pass() { } } +#[test] +fn dropping_during_a_poll_over_a_measurable_roster_takes_a_step_not_a_pass() { + dropping_during_a_poll_takes_a_step_not_a_pass(MEASURABLE); +} + +/// The two ratio claims at the size they were first made at, whose pass is long enough that the +/// comparison is made on any machine. Nothing about either differs from its small form but the +/// size, and registering twenty thousand files is most of what each costs. +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: registers 20000 files, twice for the drop"] + fn a_request_from_the_callers_wait_while_a_poll_is_inside_its_probe_of_a_large_roster_returns_at_once() + { + a_request_while_a_poll_is_inside_its_probe_returns_at_once(FULL); + } + + #[test] + #[ignore = "long-haul: registers 20000 files, twice"] + fn dropping_during_a_poll_over_a_large_roster_takes_a_step_not_a_pass() { + dropping_during_a_poll_takes_a_step_not_a_pass(FULL); + } +} + #[test] fn no_callback_of_the_crate_runs_after_a_watcher_with_a_parked_poll_is_dropped() { let dir = TempDir::new("quiet"); diff --git a/crates/windows-file-enumeration-sys/tests/integration/cancellation.rs b/crates/windows-file-enumeration-sys/tests/integration/cancellation.rs index 0c07388d0..a81eb88ed 100644 --- a/crates/windows-file-enumeration-sys/tests/integration/cancellation.rs +++ b/crates/windows-file-enumeration-sys/tests/integration/cancellation.rs @@ -4,7 +4,10 @@ use std::time::{Duration, Instant}; -use windows_file_enumeration_sys::{Completion, EnumerationRequest, Session, TerminalOutcome}; +use windows_file_enumeration_sys::{ + Completion, DEFAULT_BUFFER_CAPACITY, EnumerationRequest, MINIMUM_BUFFER_CAPACITY, Session, + TerminalOutcome, +}; use crate::support::{Scratch, borrow_all, many_file_names}; @@ -36,17 +39,38 @@ fn cancelling_before_any_quantum_runs_still_yields_one_terminal() { assert!(receiver.try_recv().is_none(), "exactly one terminal"); } -#[test] -fn cancelling_a_large_running_enumeration_ends_it_with_no_entry_after_the_terminal() { - // Thousands of entries keep a real worker busy for many quanta, giving - // the cancellation a real chance to land on a running, not yet finished, - // enumeration -- proof against the live engine, not a scripted one. - let names = many_file_names(4_000); +/// A directory of `count` files, which a request with a native buffer of +/// `buffer` bytes enumerates over many refills and quanta, so that an +/// enumeration is still running when the test acts on it. +fn running_enumeration(count: usize, buffer: usize) -> (Scratch, EnumerationRequest) { + let names = many_file_names(count); let borrowed = borrow_all(&names); let scratch = Scratch::with_files(&borrowed); + let request = EnumerationRequest::for_path(scratch.path()) + .expect("resolvable") + .with_buffer_capacity(buffer) + .expect("representable"); + (scratch, request) +} + +/// More than two quanta of records (a quantum is at most 256), which with the +/// minimum buffer is also many refills. Creating the files is what a test +/// here costs, so this is as few as keeps an enumeration running for many +/// quanta; [`FULL`] is the scale the claims were first made at. +const SPANNING: usize = 600; + +/// Thousands of entries through the default buffer. See [`long_haul`]. +const FULL: usize = 4_000; + +/// Cancelling an enumeration of `count` entries ends it with exactly one +/// terminal and no entry after it. +fn cancelling_ends_it_with_no_entry_after_the_terminal(count: usize, buffer: usize) { + // Many quanta keep a real worker busy, giving the cancellation a real + // chance to land on a running, not yet finished, enumeration -- proof + // against the live engine, not a scripted one. + let (_scratch, request) = running_enumeration(count, buffer); let (session, receiver) = Session::new(8, 64).expect("room"); - let request = EnumerationRequest::for_path(scratch.path()).expect("resolvable"); let handle = session.try_begin(request).expect("room"); let enumeration = handle.id(); handle.cancel(); @@ -86,6 +110,11 @@ fn cancelling_a_large_running_enumeration_ends_it_with_no_entry_after_the_termin let _ = entries_seen; } +#[test] +fn cancelling_a_running_enumeration_over_many_refills_ends_it_with_no_entry_after_the_terminal() { + cancelling_ends_it_with_no_entry_after_the_terminal(SPANNING, MINIMUM_BUFFER_CAPACITY); +} + #[test] fn cancelling_an_already_completed_enumeration_adds_no_second_terminal() { let scratch = Scratch::empty(); @@ -119,14 +148,12 @@ fn cancelling_an_already_completed_enumeration_adds_no_second_terminal() { ); } -#[test] -fn dropping_the_receiver_ends_a_large_running_enumeration_promptly() { - let names = many_file_names(4_000); - let borrowed = borrow_all(&names); - let scratch = Scratch::with_files(&borrowed); +/// Dropping the receiver of an enumeration of `count` entries returns at once +/// and releases the enumeration. +fn dropping_the_receiver_ends_it_promptly(count: usize, buffer: usize) { + let (_scratch, request) = running_enumeration(count, buffer); let (session, receiver) = Session::new(8, 64).expect("room"); - let request = EnumerationRequest::for_path(scratch.path()).expect("resolvable"); let handle = session.try_begin(request).expect("room"); handle.detach(); @@ -146,3 +173,27 @@ fn dropping_the_receiver_ends_a_large_running_enumeration_promptly() { } panic!("the abandoned enumeration was never released"); } + +#[test] +fn dropping_the_receiver_ends_an_enumeration_running_over_many_refills_promptly() { + dropping_the_receiver_ends_it_promptly(SPANNING, MINIMUM_BUFFER_CAPACITY); +} + +/// The two claims above at the scale they were first made at: thousands of +/// entries through the default buffer, which is mostly the time to create +/// them. Nothing about either differs from its small form but the size. +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: creates 4000 files and cancels an enumeration of them"] + fn cancelling_a_large_running_enumeration_ends_it_with_no_entry_after_the_terminal() { + cancelling_ends_it_with_no_entry_after_the_terminal(FULL, DEFAULT_BUFFER_CAPACITY); + } + + #[test] + #[ignore = "long-haul: creates 4000 files and drops the receiver of an enumeration of them"] + fn dropping_the_receiver_ends_a_large_running_enumeration_promptly() { + dropping_the_receiver_ends_it_promptly(FULL, DEFAULT_BUFFER_CAPACITY); + } +} diff --git a/crates/windows-file-enumeration-sys/tests/integration/scale.rs b/crates/windows-file-enumeration-sys/tests/integration/scale.rs index 13adc3dcc..14b1072cc 100644 --- a/crates/windows-file-enumeration-sys/tests/integration/scale.rs +++ b/crates/windows-file-enumeration-sys/tests/integration/scale.rs @@ -13,17 +13,27 @@ use crate::support::{Scratch, borrow_all, drain_to_terminal, entry_names, many_f /// Large enough that no single native buffer holds every record in one /// refill, and large enough that the record/time quantum budget spans -/// several quanta even with the default buffer. +/// several quanta even with the default buffer. The full scale; see +/// [`long_haul`]. const MANY: usize = 4_000; -#[test] -fn a_directory_with_thousands_of_entries_delivers_every_one_exactly_once() { - let names = many_file_names(MANY); +/// More than two quanta of records (a quantum is at most 256), which with the +/// minimum buffer is also many refills: the same two things [`MANY`] exists to +/// force, from far fewer files, since creating them is what the test costs. +const SPANNING: usize = 600; + +/// Every entry of a directory of `count` files arrives exactly once when the +/// request uses a native buffer of `buffer` bytes. +fn delivers_every_entry_exactly_once(count: usize, buffer: usize) { + let names = many_file_names(count); let borrowed = borrow_all(&names); let scratch = Scratch::with_files(&borrowed); let (session, receiver) = Session::new(16, 256).expect("room"); - let request = EnumerationRequest::for_path(scratch.path()).expect("resolvable"); + let request = EnumerationRequest::for_path(scratch.path()) + .expect("resolvable") + .with_buffer_capacity(buffer) + .expect("representable"); let handle = session.try_begin(request).expect("room"); let enumeration = handle.id(); handle.detach(); @@ -37,6 +47,24 @@ fn a_directory_with_thousands_of_entries_delivers_every_one_exactly_once() { assert_eq!(delivered, expected, "no entry lost or duplicated at scale"); } +#[test] +fn a_directory_spanning_many_refills_and_quanta_delivers_every_entry_exactly_once() { + delivers_every_entry_exactly_once(SPANNING, MINIMUM_BUFFER_CAPACITY); +} + +/// The same claim at the scale the module is named for: thousands of entries +/// through the default buffer. Nothing about it differs from the test above +/// but the size, which is why it is the long-haul form of it. +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: creates 4000 files and enumerates them through the default buffer"] + fn a_directory_with_thousands_of_entries_delivers_every_one_exactly_once() { + delivers_every_entry_exactly_once(MANY, DEFAULT_BUFFER_CAPACITY); + } +} + #[test] fn a_completion_ring_far_smaller_than_the_directory_still_delivers_everything() { // The smallest ring the contract allows: every entry beyond the first diff --git a/crates/windows-file-watcher/tests/scenario_stress.rs b/crates/windows-file-watcher/tests/scenario_stress.rs index 16eed494c..ead737c91 100644 --- a/crates/windows-file-watcher/tests/scenario_stress.rs +++ b/crates/windows-file-watcher/tests/scenario_stress.rs @@ -17,13 +17,6 @@ use windows_file_watcher::scenario::{ run_scenario_keep_dir, seed, }; -/// Whether the stress tests below should actually run: they exercise a live -/// `Monitor`, so they are gated the same way as [`stress.rs`](stress.rs) -/// rather than running on every plain `cargo test`. -fn stress_enabled() -> bool { - std::env::var_os("WINDOWS_FILE_WATCHER_STRESS").is_some() -} - #[test] fn a_barrier_pair_that_can_never_run_concurrently_fails_fast_instead_of_hanging() { // PR #20 review response: passing `validate_barriers`'s exactly-two-uses @@ -155,34 +148,6 @@ fn repeat_counts_hundreds_of_thousands_of_operations_without_materializing_them( assert_eq!(scenario.operation_count(), 250_000); } -#[test] -fn a_small_scenario_runs_through_the_harness_and_is_fully_accounted_for() { - if !stress_enabled() { - return; - } - let scenario = Scenario::new("harness-smoke") - .then(Operation::CreateFile { - path: PathBuf::from("a.txt"), - }) - .then(Operation::CreateFile { - path: PathBuf::from("b.txt"), - }) - .then(Operation::Rename { - from: PathBuf::from("a.txt"), - to: PathBuf::from("c.txt"), - }) - .then(Operation::RemoveFile { - path: PathBuf::from("b.txt"), - }); - - let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); - assert!( - outcome.batches > 0, - "expected at least one batch from {} operations", - scenario.operation_count() - ); -} - // --------------------------------------------------------------------------- // M9.3: the basic scenario library. Each function below returns a `Scenario` // -- a value -- built from the M9.1 model; none of them contains @@ -282,94 +247,6 @@ fn fast_two_entity_swap_scenario() -> Scenario { }) } -#[test] -fn a_burst_of_churn_across_a_few_files_is_observed() { - if !stress_enabled() { - return; - } - let files = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_CHURN_FILES", 5); - let touches = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_CHURN_TOUCHES", 50_000); - let scenario = churn_scenario(files, touches); - let params = HarnessParams::for_operation_count(scenario.operation_count()); - let outcome = run_scenario(&scenario, seed(), ¶ms); - assert!( - outcome.batches > 0, - "expected at least one batch from {} operations", - scenario.operation_count() - ); -} - -#[test] -fn delete_wait_reintroduce_survives_irregular_timing() { - if !stress_enabled() { - return; - } - let rounds = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_REINTRODUCE_ROUNDS", 25); - // Bounds above Windows's ~23ms scheduling floor (D-73): a (1, 40) range - // would round every draw up to the same one tick, silently degrading - // "irregular" timing into a fixed delay. - let scenario = delete_wait_reintroduce_scenario( - rounds, - Duration::from_millis(25), - Duration::from_millis(250), - ); - let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); - assert!( - outcome.batches > 0, - "expected at least one batch from {rounds} delete/reintroduce rounds" - ); -} - -#[test] -fn plain_renames_are_observed() { - if !stress_enabled() { - return; - } - let count = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_RENAME_COUNT", 500); - let scenario = rename_scenario(count); - let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); - assert!( - outcome.batches > 0, - "expected at least one batch from {count} renames" - ); -} - -#[test] -fn a_directory_can_reuse_a_removed_files_name_and_back() { - if !stress_enabled() { - return; - } - let scenario = cross_type_name_reuse_scenario(); - let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); - assert!( - outcome.batches > 0, - "expected at least one batch from the cross-type name-reuse sequence" - ); -} - -#[test] -fn a_fast_two_entity_swap_leaves_the_filesystem_in_the_expected_end_state() { - if !stress_enabled() { - return; - } - let scenario = fast_two_entity_swap_scenario(); - let (outcome, dir) = run_scenario_keep_dir(&scenario, seed(), &HarnessParams::default()); - - // Whatever the watcher reported, the OS itself must have applied both - // renames without the second clobbering the first: the real end state is - // what actually answers "did the swap confuse anything" independent of - // the notification stream. - assert!(dir.path().join("y").is_file(), "x -> y did not land"); - assert!(dir.path().join("x").is_dir(), "z -> x did not land"); - assert!(!dir.path().join("z").exists(), "z should no longer exist"); - assert!( - outcome.batches > 0, - "expected at least one batch from the swap" - ); - - dir.cleanup(); -} - // --------------------------------------------------------------------------- // M9.4: session/watch lifecycle operations. A scenario can now open/close // named sessions and subscribe/cancel named watches mid-run, not just churn @@ -446,76 +323,6 @@ fn session_watch_churn_with_delays_scenario( ) } -#[test] -fn sessions_and_watches_enter_and_exit_with_delays_between_transitions() { - if !stress_enabled() { - return; - } - let rounds = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_LIFECYCLE_ROUNDS", 25); - // Bounds above Windows's ~23ms scheduling floor (D-73); see the - // back-to-back variant below for the intentionally near-zero posture. - let scenario = session_watch_churn_with_delays_scenario( - rounds, - Duration::from_millis(25), - Duration::from_millis(250), - ); - let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); - assert!( - outcome.batches > 0, - "expected at least one batch from {rounds} session/watch churn rounds" - ); -} - -/// The same churn, but with no delay between transitions at all -- the -/// "hit it hard, continuously" posture, kept alongside the delayed one above -/// so both timing postures are exercised, not just the spaced-out one. -#[test] -fn sessions_and_watches_enter_and_exit_back_to_back() { - if !stress_enabled() { - return; - } - let rounds = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_LIFECYCLE_ROUNDS", 25); - let scenario = - session_watch_churn_with_delays_scenario(rounds, Duration::ZERO, Duration::from_micros(1)); - let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); - assert!( - outcome.batches > 0, - "expected at least one batch from {rounds} back-to-back session/watch churn rounds" - ); -} - -#[test] -fn multiple_sessions_can_be_open_at_once_and_each_is_drained() { - if !stress_enabled() { - return; - } - let scenario = Scenario::new("two-sessions") - .then(Operation::OpenSession { - name: "second".to_string(), - }) - .then(Operation::Subscribe { - session: "second".to_string(), - watch: "second-watch".to_string(), - path: PathBuf::new(), - subtree: true, - }) - .then(Operation::CreateFile { - path: PathBuf::from("seen-by-both.txt"), - }) - .then(Operation::CancelWatch { - watch: "second-watch".to_string(), - }) - .then(Operation::CloseSession { - name: "second".to_string(), - }); - let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); - assert!( - outcome.batches >= 2, - "expected the initial watch and the second session's watch to each report the same file create, got {} batches", - outcome.batches - ); -} - // --------------------------------------------------------------------------- // M9+: concurrent modifiers, spoilers, nesting, and queue overwhelm. All four // share one prerequisite -- `Fleet` moving behind a `Mutex` so @@ -523,153 +330,323 @@ fn multiple_sessions_can_be_open_at_once_and_each_is_drained() { // together rather than as four artificially separated commits. // --------------------------------------------------------------------------- -#[test] -fn concurrent_branches_run_at_the_same_time_and_are_all_accounted_for() { - if !stress_enabled() { - return; +// --------------------------------------------------------------------------- +// M9.5: the scenario library above is also persisted as JSON fixtures under +// `tests/scenarios/`. This test is the generic, data-driven runner: it does +// not know about any particular scenario, only how to load and execute one. +// --------------------------------------------------------------------------- + +/// Tests that have never run in CI: they returned early unless `WINDOWS_FILE_WATCHER_STRESS` was set, which nothing sets, +/// so they reported as passing without running. They are ignored with a `probation:` reason instead, which is what +/// the probation tier selects by (DEVELOPMENT.md, "Test tiers"). Run by hand with `-- --ignored`. +mod probation { + use super::*; + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; under a second"] + fn a_small_scenario_runs_through_the_harness_and_is_fully_accounted_for() { + let scenario = Scenario::new("harness-smoke") + .then(Operation::CreateFile { + path: PathBuf::from("a.txt"), + }) + .then(Operation::CreateFile { + path: PathBuf::from("b.txt"), + }) + .then(Operation::Rename { + from: PathBuf::from("a.txt"), + to: PathBuf::from("c.txt"), + }) + .then(Operation::RemoveFile { + path: PathBuf::from("b.txt"), + }); + + let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); + assert!( + outcome.batches > 0, + "expected at least one batch from {} operations", + scenario.operation_count() + ); } - let scenario = Scenario::new("concurrent-branches").then(Operation::Concurrent { - branches: vec![ - vec![ - Operation::CreateFile { - path: PathBuf::from("a.txt"), - }, - Operation::CreateFile { - path: PathBuf::from("b.txt"), - }, - ], - vec![ - Operation::CreateFile { - path: PathBuf::from("c.txt"), - }, - Operation::CreateFile { - path: PathBuf::from("d.txt"), - }, - ], - ], - }); - let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); - assert!( - outcome.batches > 0, - "expected at least one batch from two concurrent branches" - ); -} -#[test] -fn a_held_open_file_blocks_a_concurrent_delete_with_a_real_sharing_violation() { - if !stress_enabled() { - return; + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; about 133 s"] + fn a_burst_of_churn_across_a_few_files_is_observed() { + let files = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_CHURN_FILES", 5); + let touches = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_CHURN_TOUCHES", 50_000); + let scenario = churn_scenario(files, touches); + let params = HarnessParams::for_operation_count(scenario.operation_count()); + let outcome = run_scenario(&scenario, seed(), ¶ms); + assert!( + outcome.batches > 0, + "expected at least one batch from {} operations", + scenario.operation_count() + ); } - // `ready_barrier` is the deterministic replacement for a fixed sleep - // guessing the hold has already opened its handle: the delete branch - // cannot even attempt `RemoveFile` until `HoldOpen` has genuinely opened - // the file and rendezvoused on the same barrier name. - let scenario = Scenario::new("spoiler-blocks-delete") - .then(Operation::CreateFile { - path: PathBuf::from("spoiled.txt"), - }) - .then(Operation::Concurrent { + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; about 7 s"] + fn delete_wait_reintroduce_survives_irregular_timing() { + let rounds = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_REINTRODUCE_ROUNDS", 25); + // Bounds above Windows's ~23ms scheduling floor (D-73): a (1, 40) range + // would round every draw up to the same one tick, silently degrading + // "irregular" timing into a fixed delay. + let scenario = delete_wait_reintroduce_scenario( + rounds, + Duration::from_millis(25), + Duration::from_millis(250), + ); + let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); + assert!( + outcome.batches > 0, + "expected at least one batch from {rounds} delete/reintroduce rounds" + ); + } + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; about 1 s"] + fn plain_renames_are_observed() { + let count = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_RENAME_COUNT", 500); + let scenario = rename_scenario(count); + let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); + assert!( + outcome.batches > 0, + "expected at least one batch from {count} renames" + ); + } + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; under a second"] + fn a_directory_can_reuse_a_removed_files_name_and_back() { + let scenario = cross_type_name_reuse_scenario(); + let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); + assert!( + outcome.batches > 0, + "expected at least one batch from the cross-type name-reuse sequence" + ); + } + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; under a second"] + fn a_fast_two_entity_swap_leaves_the_filesystem_in_the_expected_end_state() { + let scenario = fast_two_entity_swap_scenario(); + let (outcome, dir) = run_scenario_keep_dir(&scenario, seed(), &HarnessParams::default()); + + // Whatever the watcher reported, the OS itself must have applied both + // renames without the second clobbering the first: the real end state is + // what actually answers "did the swap confuse anything" independent of + // the notification stream. + assert!(dir.path().join("y").is_file(), "x -> y did not land"); + assert!(dir.path().join("x").is_dir(), "z -> x did not land"); + assert!(!dir.path().join("z").exists(), "z should no longer exist"); + assert!( + outcome.batches > 0, + "expected at least one batch from the swap" + ); + + dir.cleanup(); + } + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; about 18 s"] + fn sessions_and_watches_enter_and_exit_with_delays_between_transitions() { + let rounds = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_LIFECYCLE_ROUNDS", 25); + // Bounds above Windows's ~23ms scheduling floor (D-73); see the + // back-to-back variant below for the intentionally near-zero posture. + let scenario = session_watch_churn_with_delays_scenario( + rounds, + Duration::from_millis(25), + Duration::from_millis(250), + ); + let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); + assert!( + outcome.batches > 0, + "expected at least one batch from {rounds} session/watch churn rounds" + ); + } + + /// The same churn, but with no delay between transitions at all -- the + /// "hit it hard, continuously" posture, kept alongside the delayed one above + /// so both timing postures are exercised, not just the spaced-out one. + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; under a second"] + fn sessions_and_watches_enter_and_exit_back_to_back() { + let rounds = env_u64("WINDOWS_FILE_WATCHER_SCENARIO_LIFECYCLE_ROUNDS", 25); + let scenario = session_watch_churn_with_delays_scenario( + rounds, + Duration::ZERO, + Duration::from_micros(1), + ); + let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); + assert!( + outcome.batches > 0, + "expected at least one batch from {rounds} back-to-back session/watch churn rounds" + ); + } + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; under a second"] + fn multiple_sessions_can_be_open_at_once_and_each_is_drained() { + let scenario = Scenario::new("two-sessions") + .then(Operation::OpenSession { + name: "second".to_string(), + }) + .then(Operation::Subscribe { + session: "second".to_string(), + watch: "second-watch".to_string(), + path: PathBuf::new(), + subtree: true, + }) + .then(Operation::CreateFile { + path: PathBuf::from("seen-by-both.txt"), + }) + .then(Operation::CancelWatch { + watch: "second-watch".to_string(), + }) + .then(Operation::CloseSession { + name: "second".to_string(), + }); + let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); + assert!( + outcome.batches >= 2, + "expected the initial watch and the second session's watch to each report the same file create, got {} batches", + outcome.batches + ); + } + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; under a second"] + fn concurrent_branches_run_at_the_same_time_and_are_all_accounted_for() { + let scenario = Scenario::new("concurrent-branches").then(Operation::Concurrent { branches: vec![ - vec![Operation::HoldOpen { - path: PathBuf::from("spoiled.txt"), - duration: Duration::from_millis(100), - ready_barrier: Some("spoiler-open".to_string()), - }], vec![ - Operation::Barrier { - name: "spoiler-open".to_string(), + Operation::CreateFile { + path: PathBuf::from("a.txt"), }, - Operation::RemoveFile { - path: PathBuf::from("spoiled.txt"), + Operation::CreateFile { + path: PathBuf::from("b.txt"), + }, + ], + vec![ + Operation::CreateFile { + path: PathBuf::from("c.txt"), + }, + Operation::CreateFile { + path: PathBuf::from("d.txt"), }, ], ], }); - let (_outcome, dir) = run_scenario_keep_dir(&scenario, seed(), &HarnessParams::default()); + let outcome = run_scenario(&scenario, seed(), &HarnessParams::default()); + assert!( + outcome.batches > 0, + "expected at least one batch from two concurrent branches" + ); + } - // The held-open handle has no `FILE_SHARE_DELETE`, so the concurrent - // `RemoveFile` -- unblocked only once the hold is confirmed open -- must - // fail with a real sharing violation: the file is still here, not merely - // "probably" spoiled. - assert!( - dir.path().join("spoiled.txt").exists(), - "the spoiler should have blocked the concurrent delete" - ); + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; under a second"] + fn a_held_open_file_blocks_a_concurrent_delete_with_a_real_sharing_violation() { + // `ready_barrier` is the deterministic replacement for a fixed sleep + // guessing the hold has already opened its handle: the delete branch + // cannot even attempt `RemoveFile` until `HoldOpen` has genuinely opened + // the file and rendezvoused on the same barrier name. + let scenario = Scenario::new("spoiler-blocks-delete") + .then(Operation::CreateFile { + path: PathBuf::from("spoiled.txt"), + }) + .then(Operation::Concurrent { + branches: vec![ + vec![Operation::HoldOpen { + path: PathBuf::from("spoiled.txt"), + duration: Duration::from_millis(100), + ready_barrier: Some("spoiler-open".to_string()), + }], + vec![ + Operation::Barrier { + name: "spoiler-open".to_string(), + }, + Operation::RemoveFile { + path: PathBuf::from("spoiled.txt"), + }, + ], + ], + }); + let (_outcome, dir) = run_scenario_keep_dir(&scenario, seed(), &HarnessParams::default()); - dir.cleanup(); -} + // The held-open handle has no `FILE_SHARE_DELETE`, so the concurrent + // `RemoveFile` -- unblocked only once the hold is confirmed open -- must + // fail with a real sharing violation: the file is still here, not merely + // "probably" spoiled. + assert!( + dir.path().join("spoiled.txt").exists(), + "the spoiler should have blocked the concurrent delete" + ); -#[test] -fn a_deliberately_tiny_queue_bound_never_wedges_under_overwhelming_load() { - if !stress_enabled() { - return; + dir.cleanup(); } - let scenario = Scenario::new("queue-overwhelm") - .then(Operation::OpenSessionBounded { - name: "tiny".to_string(), - bound: 2, - }) - .then(Operation::Subscribe { - session: "tiny".to_string(), - watch: "tiny-watch".to_string(), - path: PathBuf::new(), - subtree: true, - }) - .then_repeated( - 5_000, - vec![Operation::CreateFile { - path: PathBuf::from("overwhelmed.txt"), - }], - ) - .then(Operation::CancelWatch { - watch: "tiny-watch".to_string(), - }) - .then(Operation::CloseSession { - name: "tiny".to_string(), - }); - let params = HarnessParams::for_operation_count(scenario.operation_count()); - // A bound this small, hit this hard, is expected to force backpressure - // (D-11/D-29) -- the point of this test is that the harness's own - // deadline assertion inside `run_scenario` never trips, not that zero - // desyncs occur. - let outcome = run_scenario(&scenario, seed(), ¶ms); - assert!( - outcome.batches > 0, - "expected at least one batch despite the tiny queue bound" - ); -} -// --------------------------------------------------------------------------- -// M9.5: the scenario library above is also persisted as JSON fixtures under -// `tests/scenarios/`. This test is the generic, data-driven runner: it does -// not know about any particular scenario, only how to load and execute one. -// --------------------------------------------------------------------------- - -#[test] -fn every_persisted_json_fixture_runs_through_the_harness() { - if !stress_enabled() { - return; - } - let dir = std::path::Path::new(env!("CARGO_MANIFEST_DIR")).join("tests/scenarios"); - let mut ran = 0; - for entry in std::fs::read_dir(&dir).expect("read tests/scenarios") { - let entry = entry.expect("read dir entry"); - let path = entry.path(); - if path.extension().and_then(|ext| ext.to_str()) != Some("json") { - continue; - } - let contents = std::fs::read_to_string(&path) - .unwrap_or_else(|error| panic!("read {}: {error}", path.display())); - let scenario: Scenario = serde_json::from_str(&contents) - .unwrap_or_else(|error| panic!("parse {}: {error}", path.display())); + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; about 3 s"] + fn a_deliberately_tiny_queue_bound_never_wedges_under_overwhelming_load() { + let scenario = Scenario::new("queue-overwhelm") + .then(Operation::OpenSessionBounded { + name: "tiny".to_string(), + bound: 2, + }) + .then(Operation::Subscribe { + session: "tiny".to_string(), + watch: "tiny-watch".to_string(), + path: PathBuf::new(), + subtree: true, + }) + .then_repeated( + 5_000, + vec![Operation::CreateFile { + path: PathBuf::from("overwhelmed.txt"), + }], + ) + .then(Operation::CancelWatch { + watch: "tiny-watch".to_string(), + }) + .then(Operation::CloseSession { + name: "tiny".to_string(), + }); let params = HarnessParams::for_operation_count(scenario.operation_count()); + // A bound this small, hit this hard, is expected to force backpressure + // (D-11/D-29) -- the point of this test is that the harness's own + // deadline assertion inside `run_scenario` never trips, not that zero + // desyncs occur. let outcome = run_scenario(&scenario, seed(), ¶ms); assert!( outcome.batches > 0, - "fixture {} produced no batches", - path.display() + "expected at least one batch despite the tiny queue bound" ); - ran += 1; } - assert!(ran > 0, "no JSON fixtures found under {}", dir.display()); + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; about 21 s"] + fn every_persisted_json_fixture_runs_through_the_harness() { + let dir = std::path::Path::new(env!("CARGO_MANIFEST_DIR")).join("tests/scenarios"); + let mut ran = 0; + for entry in std::fs::read_dir(&dir).expect("read tests/scenarios") { + let entry = entry.expect("read dir entry"); + let path = entry.path(); + if path.extension().and_then(|ext| ext.to_str()) != Some("json") { + continue; + } + let contents = std::fs::read_to_string(&path) + .unwrap_or_else(|error| panic!("read {}: {error}", path.display())); + let scenario: Scenario = serde_json::from_str(&contents) + .unwrap_or_else(|error| panic!("parse {}: {error}", path.display())); + let params = HarnessParams::for_operation_count(scenario.operation_count()); + let outcome = run_scenario(&scenario, seed(), ¶ms); + assert!( + outcome.batches > 0, + "fixture {} produced no batches", + path.display() + ); + ran += 1; + } + assert!(ran > 0, "no JSON fixtures found under {}", dir.display()); + } } diff --git a/crates/windows-file-watcher/tests/stress.rs b/crates/windows-file-watcher/tests/stress.rs index 39dc34ac1..76fcf8bbd 100644 --- a/crates/windows-file-watcher/tests/stress.rs +++ b/crates/windows-file-watcher/tests/stress.rs @@ -3,15 +3,18 @@ //! coalesced multi-subscription load, at volumes well beyond what the //! ordinary integration suite exercises. //! -//! Gated behind the `WINDOWS_FILE_WATCHER_STRESS` environment variable rather -//! than `#[ignore]`, so a normal `cargo test`/`cargo nextest run` still -//! compiles and enumerates every test here (catching a build break), but each -//! one returns immediately unless a caller opts in: +//! Ignored, on the probation tier (`mod probation`), so a normal `cargo test` +//! still compiles and enumerates every test here (catching a build break) but +//! does not run them, and the long-haul workflow does. Run them by hand with: //! //! ```text -//! $env:WINDOWS_FILE_WATCHER_STRESS = "1" -//! cargo test --test stress -- --test-threads=1 +//! cargo test --test stress -- --ignored --test-threads=1 //! ``` +//! +//! They used to be gated behind the `WINDOWS_FILE_WATCHER_STRESS` environment +//! variable instead, each returning at once unless it was set. Nothing set it, +//! so a plain run reported them as passing without running them, which is the +//! false signal the ignore reason now replaces. #![cfg(windows)] use std::path::{Path, PathBuf}; @@ -19,13 +22,6 @@ use std::time::{Duration, Instant}; use windows_file_watcher::{Monitor, Notification, WatchOptions}; -/// Whether the stress suite should actually run. Checked at the top of every -/// test, which is what makes this opt-in rather than `#[ignore]`: the tests -/// still compile and are still visible to `cargo test --list`. -fn stress_enabled() -> bool { - std::env::var_os("WINDOWS_FILE_WATCHER_STRESS").is_some() -} - /// Upper bound generous enough for a loaded CI runner; a genuine wedge still /// fails the run rather than hanging it forever. const STRESS_TIMEOUT: Duration = Duration::from_secs(120); @@ -104,220 +100,219 @@ fn wait_for bool>(what: &str, mut predicate: F) { } } -#[test] -fn change_churn_is_never_silently_lost() { - if !stress_enabled() { - return; - } - let dir = TempDir::new("churn"); - let monitor = Monitor::new().expect("create the monitor"); - let (session, receiver) = monitor.session(); - let watch = session - .subscribe(dir.path(), WatchOptions::new()) - .expect("register"); - - const FILES: usize = 20_000; - let writer = { - let target = dir.path().to_path_buf(); - std::thread::spawn(move || { - for index in 0..FILES { - std::fs::write(target.join(format!("churn-{index}.txt")), b"x") - .expect("create a file"); - } - }) - }; - - // Every batch and every desync is accounted for by construction (D-12): the - // property under test is that the watch never wedges (stops delivering - // anything at all) under sustained load, not that zero desyncs occur -- a - // burst this large is expected to overflow the kernel's own buffer at least - // once, and that is a correctly reported loss, not a bug. - let mut seen_any = false; - let mut settled = false; - let mut checker = Guard::new(); - let deadline = Instant::now() + STRESS_TIMEOUT; - while !settled { - assert!(Instant::now() < deadline, "the watch stalled under churn"); - if let Some(notification) = - check!(checker, receiver.recv_timeout(Duration::from_millis(200))) - { - seen_any = true; - if matches!(notification, Notification::Desync { .. }) { - // A desync is an explicit, honest "you may have missed - // something" -- exactly what this crate promises never to hide. +/// Tests that have never run in CI: they returned early unless `WINDOWS_FILE_WATCHER_STRESS` was set, which nothing sets, +/// so they reported as passing without running. They are ignored with a `probation:` reason instead, which is what +/// the probation tier selects by (DEVELOPMENT.md, "Test tiers"). Run by hand with `-- --ignored`. +mod probation { + use super::*; + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; about 16 s"] + fn change_churn_is_never_silently_lost() { + let dir = TempDir::new("churn"); + let monitor = Monitor::new().expect("create the monitor"); + let (session, receiver) = monitor.session(); + let watch = session + .subscribe(dir.path(), WatchOptions::new()) + .expect("register"); + + const FILES: usize = 20_000; + let writer = { + let target = dir.path().to_path_buf(); + std::thread::spawn(move || { + for index in 0..FILES { + std::fs::write(target.join(format!("churn-{index}.txt")), b"x") + .expect("create a file"); + } + }) + }; + + // Every batch and every desync is accounted for by construction (D-12): the + // property under test is that the watch never wedges (stops delivering + // anything at all) under sustained load, not that zero desyncs occur -- a + // burst this large is expected to overflow the kernel's own buffer at least + // once, and that is a correctly reported loss, not a bug. + let mut seen_any = false; + let mut settled = false; + let mut checker = Guard::new(); + let deadline = Instant::now() + STRESS_TIMEOUT; + while !settled { + assert!(Instant::now() < deadline, "the watch stalled under churn"); + if let Some(notification) = + check!(checker, receiver.recv_timeout(Duration::from_millis(200))) + { + seen_any = true; + if matches!(notification, Notification::Desync { .. }) { + // A desync is an explicit, honest "you may have missed + // something" -- exactly what this crate promises never to hide. + } + } else if writer.is_finished() { + settled = true; } - } else if writer.is_finished() { - settled = true; } - } - writer.join().expect("writer thread"); - assert!( - seen_any, - "no notification arrived during a 20,000-file churn" - ); - - drop(watch); - drop(monitor); - dir.cleanup(); -} + writer.join().expect("writer thread"); + assert!( + seen_any, + "no notification arrived during a 20,000-file churn" + ); -#[test] -fn a_fault_storm_of_repeated_delete_recreate_always_reestablishes() { - if !stress_enabled() { - return; + drop(watch); + drop(monitor); + dir.cleanup(); } - let dir = TempDir::new("fault-storm"); - let monitor = Monitor::new().expect("create the monitor"); - let (session, receiver) = monitor.session(); - let watch = session - .subscribe(dir.path(), WatchOptions::new().report_liveness(true)) - .expect("register"); - - const ROUNDS: usize = 25; - let mut checker = Guard::new(); - for round in 0..ROUNDS { - std::fs::write(dir.path().join("marker.txt"), b"x").expect("mark the round"); - wait_for(&format!("round {round}'s marker"), || !receiver.is_empty()); - // Drain whatever arrived so the queue never saturates across 25 rounds. - while check!(checker, receiver.try_recv()).is_some() {} - - std::fs::remove_dir_all(dir.path()).expect("delete the watched directory"); - wait_for(&format!("round {round}'s suspension"), || { - let mut suspended = false; - while let Some(notification) = check!(checker, receiver.try_recv()) { - if matches!(notification, Notification::Suspended { .. }) { - suspended = true; + + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; about 13 s"] + fn a_fault_storm_of_repeated_delete_recreate_always_reestablishes() { + let dir = TempDir::new("fault-storm"); + let monitor = Monitor::new().expect("create the monitor"); + let (session, receiver) = monitor.session(); + let watch = session + .subscribe(dir.path(), WatchOptions::new().report_liveness(true)) + .expect("register"); + + const ROUNDS: usize = 25; + let mut checker = Guard::new(); + for round in 0..ROUNDS { + std::fs::write(dir.path().join("marker.txt"), b"x").expect("mark the round"); + wait_for(&format!("round {round}'s marker"), || !receiver.is_empty()); + // Drain whatever arrived so the queue never saturates across 25 rounds. + while check!(checker, receiver.try_recv()).is_some() {} + + std::fs::remove_dir_all(dir.path()).expect("delete the watched directory"); + wait_for(&format!("round {round}'s suspension"), || { + let mut suspended = false; + while let Some(notification) = check!(checker, receiver.try_recv()) { + if matches!(notification, Notification::Suspended { .. }) { + suspended = true; + } } - } - suspended - }); - - std::fs::create_dir_all(dir.path()).expect("recreate the watched directory"); - wait_for(&format!("round {round}'s resumption"), || { - let mut resumed = false; - while let Some(notification) = check!(checker, receiver.try_recv()) { - if matches!(notification, Notification::Resumed { .. }) { - resumed = true; + suspended + }); + + std::fs::create_dir_all(dir.path()).expect("recreate the watched directory"); + wait_for(&format!("round {round}'s resumption"), || { + let mut resumed = false; + while let Some(notification) = check!(checker, receiver.try_recv()) { + if matches!(notification, Notification::Resumed { .. }) { + resumed = true; + } } - } - resumed - }); - } - - drop(watch); - drop(monitor); - dir.cleanup(); -} + resumed + }); + } -#[test] -fn many_watchers_tear_down_concurrently_under_sustained_churn() { - if !stress_enabled() { - return; - } - const WATCHERS: usize = 64; - - let dir = TempDir::new("teardown-race"); - let monitor = Monitor::new().expect("create the monitor"); - let (session, receiver) = monitor.session(); - - let mut watches = Vec::with_capacity(WATCHERS); - for _ in 0..WATCHERS { - watches.push( - session - .subscribe(dir.path(), WatchOptions::new()) - .expect("register"), - ); + drop(watch); + drop(monitor); + dir.cleanup(); } - monitor.quiesce(); - assert_eq!(monitor.watcher_count(), WATCHERS); - - let stop = std::sync::Arc::new(std::sync::atomic::AtomicBool::new(false)); - let churn = { - let target = dir.path().to_path_buf(); - let stop = std::sync::Arc::clone(&stop); - std::thread::spawn(move || { - let mut index = 0; - while !stop.load(std::sync::atomic::Ordering::Relaxed) { - let _ = std::fs::write(target.join(format!("churn-{index}.txt")), b"x"); - index += 1; - } - }) - }; - - // Drop every watch concurrently, from several threads, while completions - // are actively arriving -- the scenario D-23's gate exists to make safe. - let started = Instant::now(); - let handles: Vec<_> = watches - .into_iter() - .map(|watch| std::thread::spawn(move || drop(watch))) - .collect(); - for handle in handles { - handle.join().expect("teardown thread"); - } - assert!( - started.elapsed() < Duration::from_secs(30), - "concurrent teardown of {WATCHERS} watchers wedged" - ); - stop.store(true, std::sync::atomic::Ordering::Relaxed); - churn.join().expect("churn thread"); + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; under a second"] + fn many_watchers_tear_down_concurrently_under_sustained_churn() { + const WATCHERS: usize = 64; + + let dir = TempDir::new("teardown-race"); + let monitor = Monitor::new().expect("create the monitor"); + let (session, receiver) = monitor.session(); + + let mut watches = Vec::with_capacity(WATCHERS); + for _ in 0..WATCHERS { + watches.push( + session + .subscribe(dir.path(), WatchOptions::new()) + .expect("register"), + ); + } + monitor.quiesce(); + assert_eq!(monitor.watcher_count(), WATCHERS); + + let stop = std::sync::Arc::new(std::sync::atomic::AtomicBool::new(false)); + let churn = { + let target = dir.path().to_path_buf(); + let stop = std::sync::Arc::clone(&stop); + std::thread::spawn(move || { + let mut index = 0; + while !stop.load(std::sync::atomic::Ordering::Relaxed) { + let _ = std::fs::write(target.join(format!("churn-{index}.txt")), b"x"); + index += 1; + } + }) + }; + + // Drop every watch concurrently, from several threads, while completions + // are actively arriving -- the scenario D-23's gate exists to make safe. + let started = Instant::now(); + let handles: Vec<_> = watches + .into_iter() + .map(|watch| std::thread::spawn(move || drop(watch))) + .collect(); + for handle in handles { + handle.join().expect("teardown thread"); + } + assert!( + started.elapsed() < Duration::from_secs(30), + "concurrent teardown of {WATCHERS} watchers wedged" + ); - drop(receiver); - drop(monitor); - dir.cleanup(); -} + stop.store(true, std::sync::atomic::Ordering::Relaxed); + churn.join().expect("churn thread"); -#[test] -fn a_deeply_coalesced_directory_delivers_to_every_subscription_under_load() { - if !stress_enabled() { - return; - } - const SUBSCRIPTIONS: usize = 128; - const FILES: usize = 2_000; - - let dir = TempDir::new("coalesced-load"); - let monitor = Monitor::new().expect("create the monitor"); - let (session, receiver) = monitor.session(); - - let mut watches = Vec::with_capacity(SUBSCRIPTIONS); - for _ in 0..SUBSCRIPTIONS { - watches.push( - session - .subscribe(dir.path(), WatchOptions::new()) - .expect("register"), - ); - } - monitor.quiesce(); - assert_eq!( - monitor.watcher_count(), - SUBSCRIPTIONS, - "every subscription is registered, whether or not its watcher is coalesced (D-6)" - ); - - for index in 0..FILES { - std::fs::write(dir.path().join(format!("f-{index}.txt")), b"x").expect("create"); + drop(receiver); + drop(monitor); + dir.cleanup(); } - let mut seen: std::collections::HashSet = - std::collections::HashSet::new(); - let mut checker = Guard::new(); - let deadline = Instant::now() + STRESS_TIMEOUT; - while seen.len() < SUBSCRIPTIONS { - assert!( - Instant::now() < deadline, - "only {} of {SUBSCRIPTIONS} subscriptions ever saw a change", - seen.len() + #[test] + #[ignore = "probation: was gated on WINDOWS_FILE_WATCHER_STRESS and so never run in CI; about 1.4 s"] + fn a_deeply_coalesced_directory_delivers_to_every_subscription_under_load() { + const SUBSCRIPTIONS: usize = 128; + const FILES: usize = 2_000; + + let dir = TempDir::new("coalesced-load"); + let monitor = Monitor::new().expect("create the monitor"); + let (session, receiver) = monitor.session(); + + let mut watches = Vec::with_capacity(SUBSCRIPTIONS); + for _ in 0..SUBSCRIPTIONS { + watches.push( + session + .subscribe(dir.path(), WatchOptions::new()) + .expect("register"), + ); + } + monitor.quiesce(); + assert_eq!( + monitor.watcher_count(), + SUBSCRIPTIONS, + "every subscription is registered, whether or not its watcher is coalesced (D-6)" ); - if let Some(notification) = - check!(checker, receiver.recv_timeout(Duration::from_millis(200))) - && let Notification::Batch { watch, changes } = notification - && !changes.is_empty() - { - seen.insert(watch); + + for index in 0..FILES { + std::fs::write(dir.path().join(format!("f-{index}.txt")), b"x").expect("create"); } - } - drop(watches); - drop(monitor); - dir.cleanup(); + let mut seen: std::collections::HashSet = + std::collections::HashSet::new(); + let mut checker = Guard::new(); + let deadline = Instant::now() + STRESS_TIMEOUT; + while seen.len() < SUBSCRIPTIONS { + assert!( + Instant::now() < deadline, + "only {} of {SUBSCRIPTIONS} subscriptions ever saw a change", + seen.len() + ); + if let Some(notification) = + check!(checker, receiver.recv_timeout(Duration::from_millis(200))) + && let Notification::Batch { watch, changes } = notification + && !changes.is_empty() + { + seen.insert(watch); + } + } + + drop(watches); + drop(monitor); + dir.cleanup(); + } } diff --git a/crates/windows-ioring-sys/tests/flush_barrier_stress.rs b/crates/windows-ioring-sys/tests/flush_barrier_stress.rs index 0d9c079a9..bd0cf25b6 100644 --- a/crates/windows-ioring-sys/tests/flush_barrier_stress.rs +++ b/crates/windows-ioring-sys/tests/flush_barrier_stress.rs @@ -45,7 +45,9 @@ //! //! # Why these are `#[ignore]` //! -//! Each trial writes tens of MiB of unbuffered device I/O, and the contended +//! They are on the probation tier (`probation::`): they have never run in CI, and +//! their results are kept across runs until they have passed enough of them to be +//! promoted. Each trial writes tens of MiB of unbuffered device I/O, and the contended //! tests deliberately saturate a disk. That belongs nowhere near an ordinary //! `cargo test`. Run them explicitly: //! @@ -939,203 +941,210 @@ fn campaign(tag: &str, coverage: FlushCoverage, count: usize) -> Campaign { result } -// --------------------------------------------------------------------------- -// The instruments. -// --------------------------------------------------------------------------- - -/// Does the drain hold, and how often is the one-sidedness visible, on an idle disk? -/// -/// This is the baseline the contended run is compared against. A violation here -/// would mean contention is not the trigger at all, which would point at the -/// barrier's guarantee rather than at load. -#[test] -#[ignore = "writes tens of MiB per trial; run explicitly"] -fn the_drain_holds_across_many_quiet_trials() { - let count = trials(); - let result = campaign("quiet", FlushCoverage::CoversPrecedingOperations, count); - - eprintln!("{}", result.report("quiet")); - if let Some(clean) = &result.first_clean { - eprintln!("A CLEAN TRIAL, for comparison:\n{clean}"); - } - if let Some(reordered) = &result.first_reordered { - eprintln!("THE FIRST TRIAL WHERE A COMPLETION CROSSED THE FLUSH:\n{reordered}"); - } +// The instruments are on probation: each has never run in CI (see `Why these are #[ignore]`), +// so they sit in a module of that name, which is what the probation tier selects by. Their +// results are kept across runs, and promoting one to `long_haul` is a change to the test. +mod probation { + use super::*; + // --------------------------------------------------------------------------- + // The instruments. + // --------------------------------------------------------------------------- - // Only D-23 is asserted. A phase-B write completing early is the documented - // one-sided behaviour (D-47), not a failure -- this very instrument is what - // established it, at about 0.03% on an idle ring, so asserting it to be zero - // would make the test fail on the platform behaving as documented. - assert_eq!( - result.d23_failures, - 0, - "{}", - result.report("a write queued BEFORE the flush completed after it, with no competing load") - ); -} + /// Does the drain hold, and how often is the one-sidedness visible, on an idle disk? + /// + /// This is the baseline the contended run is compared against. A violation here + /// would mean contention is not the trigger at all, which would point at the + /// barrier's guarantee rather than at load. + #[test] + #[ignore = "probation: writes tens of MiB per trial; run explicitly"] + fn the_drain_holds_across_many_quiet_trials() { + let count = trials(); + let result = campaign("quiet", FlushCoverage::CoversPrecedingOperations, count); + + eprintln!("{}", result.report("quiet")); + if let Some(clean) = &result.first_clean { + eprintln!("A CLEAN TRIAL, for comparison:\n{clean}"); + } + if let Some(reordered) = &result.first_reordered { + eprintln!("THE FIRST TRIAL WHERE A COMPLETION CROSSED THE FLUSH:\n{reordered}"); + } -/// Does the drain hold while the disk is deliberately saturated? -/// -/// This is the one built to reproduce the observed failure. It is expected to -/// be the test that fails; when it does, the log it prints is the evidence the -/// two readings in the module docs have to be decided on. -#[test] -#[ignore = "saturates a disk with background writers; run explicitly"] -fn the_drain_holds_under_deliberate_disk_contention() { - let count = trials(); - let _load = Contention::start(4); - let result = campaign("contended", FlushCoverage::CoversPrecedingOperations, count); - - eprintln!("{}", result.report("contended")); - if let Some(clean) = &result.first_clean { - eprintln!("A CLEAN TRIAL, for comparison:\n{clean}"); - } - if let Some(reordered) = &result.first_reordered { - eprintln!("THE FIRST TRIAL WHERE A COMPLETION CROSSED THE FLUSH:\n{reordered}"); + // Only D-23 is asserted. A phase-B write completing early is the documented + // one-sided behaviour (D-47), not a failure -- this very instrument is what + // established it, at about 0.03% on an idle ring, so asserting it to be zero + // would make the test fail on the platform behaving as documented. + assert_eq!( + result.d23_failures, + 0, + "{}", + result.report( + "a write queued BEFORE the flush completed after it, with no competing load" + ) + ); } - // D-23 only; see the quiet instrument for why D-24 is reported, not asserted. - assert_eq!( - result.d23_failures, - 0, - "{}", - result.report("a write queued BEFORE the flush completed after it, under contention") - ); -} + /// Does the drain hold while the disk is deliberately saturated? + /// + /// This is the one built to reproduce the observed failure. It is expected to + /// be the test that fails; when it does, the log it prints is the evidence the + /// two readings in the module docs have to be decided on. + #[test] + #[ignore = "probation: saturates a disk with background writers; run explicitly"] + fn the_drain_holds_under_deliberate_disk_contention() { + let count = trials(); + let _load = Contention::start(4); + let result = campaign("contended", FlushCoverage::CoversPrecedingOperations, count); + + eprintln!("{}", result.report("contended")); + if let Some(clean) = &result.first_clean { + eprintln!("A CLEAN TRIAL, for comparison:\n{clean}"); + } + if let Some(reordered) = &result.first_reordered { + eprintln!("THE FIRST TRIAL WHERE A COMPLETION CROSSED THE FLUSH:\n{reordered}"); + } -/// Under the same contention, can the control still tell a barrier from none? -/// -/// This guards the whole comparison rather than the contract. If load makes an -/// *unordered* flush stop reordering -- or makes everything reorder -- then the -/// contended covering result means nothing either way, and that is a finding -/// about the instrument rather than about the kernel. -/// -/// It asserts nothing about the barrier on purpose. It reports, and fails only -/// if the control has lost its ability to discriminate. -#[test] -#[ignore = "saturates a disk with background writers; run explicitly"] -fn the_unordered_control_still_discriminates_under_contention() { - let count = trials(); - let _load = Contention::start(4); - let result = campaign("control", FlushCoverage::Unordered, count); - - eprintln!("{}", result.report("unordered control under contention")); - if let Some(sample) = &result.first_reordered { - eprintln!("A REORDERED CONTROL TRIAL:\n{sample}"); + // D-23 only; see the quiet instrument for why D-24 is reported, not asserted. + assert_eq!( + result.d23_failures, + 0, + "{}", + result.report("a write queued BEFORE the flush completed after it, under contention") + ); } - assert!( - result.reordered_trials > 0, - "an unordered flush produced completions in strict submission order in all {count} \ + /// Under the same contention, can the control still tell a barrier from none? + /// + /// This guards the whole comparison rather than the contract. If load makes an + /// *unordered* flush stop reordering -- or makes everything reorder -- then the + /// contended covering result means nothing either way, and that is a finding + /// about the instrument rather than about the kernel. + /// + /// It asserts nothing about the barrier on purpose. It reports, and fails only + /// if the control has lost its ability to discriminate. + #[test] + #[ignore = "probation: saturates a disk with background writers; run explicitly"] + fn the_unordered_control_still_discriminates_under_contention() { + let count = trials(); + let _load = Contention::start(4); + let result = campaign("control", FlushCoverage::Unordered, count); + + eprintln!("{}", result.report("unordered control under contention")); + if let Some(sample) = &result.first_reordered { + eprintln!("A REORDERED CONTROL TRIAL:\n{sample}"); + } + + assert!( + result.reordered_trials > 0, + "an unordered flush produced completions in strict submission order in all {count} \ contended trials. The covering assertion would then pass for the wrong reason under \ contention, so a contended covering result proves nothing until this is understood.", - ); -} + ); + } -/// Does the drain hold when several rings are working the device at once? -/// -/// This is a **different and probably better** pressure than -/// [`the_drain_holds_under_deliberate_disk_contention`], and worth -/// having as well rather than instead. -/// -/// That test loads the *device*, with background threads doing ordinary -/// buffered writes. This one loads the **IoRing subsystem itself**: every -/// competing thread is submitting to its own ring, waiting, and draining, so -/// whatever kernel machinery implements `IOSQE_FLAGS_DRAIN_PRECEDING_OPS` is -/// under contention rather than merely the disk beneath it. If the drain has a -/// defect that contention exposes, this is the shape most likely to find it, -/// because it competes with the drain rather than around it. -/// -/// **Each thread gets its own ring and its own file, deliberately.** The drain's -/// *reach* is ring-wide -- that half of D-24 survived D-47, which withdrew only -/// the hold-back claim -- so a per-thread ring keeps each assertion a -/// statement about its own ring and nothing else; and separate files keep the -/// filesystem's own write serialisation -- one of the three failure modes the -/// contract test had to design around -- out of the result. Sharing either -/// would produce a livelier test whose failures could not be attributed. -/// -/// No background load is added on top: here the other rings *are* the load, and -/// stacking both would confound the two variables this pair exists to separate. -#[test] -#[ignore = "saturates a disk from several rings at once; run explicitly"] -fn the_drain_holds_with_concurrent_rings() { - let threads = std::thread::available_parallelism() - .map(|n| n.get().clamp(2, 8)) - .unwrap_or(4); - let count = (trials() / threads).max(5); - - eprintln!("Concurrent rings: {threads} thread(s), {count} trial(s) each."); - - let workers: Vec<_> = (0..threads) - .map(|worker| { - std::thread::spawn(move || { - // Built inside the thread so each ring and handle belongs to - // the thread that uses it. - campaign( - &format!("concurrent-{worker}"), - FlushCoverage::CoversPrecedingOperations, - count, - ) + /// Does the drain hold when several rings are working the device at once? + /// + /// This is a **different and probably better** pressure than + /// [`the_drain_holds_under_deliberate_disk_contention`], and worth + /// having as well rather than instead. + /// + /// That test loads the *device*, with background threads doing ordinary + /// buffered writes. This one loads the **IoRing subsystem itself**: every + /// competing thread is submitting to its own ring, waiting, and draining, so + /// whatever kernel machinery implements `IOSQE_FLAGS_DRAIN_PRECEDING_OPS` is + /// under contention rather than merely the disk beneath it. If the drain has a + /// defect that contention exposes, this is the shape most likely to find it, + /// because it competes with the drain rather than around it. + /// + /// **Each thread gets its own ring and its own file, deliberately.** The drain's + /// *reach* is ring-wide -- that half of D-24 survived D-47, which withdrew only + /// the hold-back claim -- so a per-thread ring keeps each assertion a + /// statement about its own ring and nothing else; and separate files keep the + /// filesystem's own write serialisation -- one of the three failure modes the + /// contract test had to design around -- out of the result. Sharing either + /// would produce a livelier test whose failures could not be attributed. + /// + /// No background load is added on top: here the other rings *are* the load, and + /// stacking both would confound the two variables this pair exists to separate. + #[test] + #[ignore = "probation: saturates a disk from several rings at once; run explicitly"] + fn the_drain_holds_with_concurrent_rings() { + let threads = std::thread::available_parallelism() + .map(|n| n.get().clamp(2, 8)) + .unwrap_or(4); + let count = (trials() / threads).max(5); + + eprintln!("Concurrent rings: {threads} thread(s), {count} trial(s) each."); + + let workers: Vec<_> = (0..threads) + .map(|worker| { + std::thread::spawn(move || { + // Built inside the thread so each ring and handle belongs to + // the thread that uses it. + campaign( + &format!("concurrent-{worker}"), + FlushCoverage::CoversPrecedingOperations, + count, + ) + }) }) - }) - .collect(); + .collect(); - let mut total = Campaign::new(0); - let mut first_reordered = None; - let mut first_clean = None; - - // Collected rather than printed here, so the TOTAL can be emitted first; see - // the note below the loop. - let mut per_worker = Vec::with_capacity(threads); - - for (worker, handle) in workers.into_iter().enumerate() { - let result = handle.join().expect("a worker thread panicked"); - per_worker.push(result.report(&format!("worker {worker}"))); - total.trials += result.trials; - total.reordered_trials += result.reordered_trials; - total.d23_failures += result.d23_failures; - total.d24_overtakes += result.d24_overtakes; - total.d24_total_overtakers += result.d24_total_overtakers; - total.d24_worst = total.d24_worst.max(result.d24_worst); - total.same_round += result.same_round; - if first_reordered.is_none() { - first_reordered = result.first_reordered; - } - if first_clean.is_none() { - first_clean = result.first_clean; + let mut total = Campaign::new(0); + let mut first_reordered = None; + let mut first_clean = None; + + // Collected rather than printed here, so the TOTAL can be emitted first; see + // the note below the loop. + let mut per_worker = Vec::with_capacity(threads); + + for (worker, handle) in workers.into_iter().enumerate() { + let result = handle.join().expect("a worker thread panicked"); + per_worker.push(result.report(&format!("worker {worker}"))); + total.trials += result.trials; + total.reordered_trials += result.reordered_trials; + total.d23_failures += result.d23_failures; + total.d24_overtakes += result.d24_overtakes; + total.d24_total_overtakers += result.d24_total_overtakers; + total.d24_worst = total.d24_worst.max(result.d24_worst); + total.same_round += result.same_round; + if first_reordered.is_none() { + first_reordered = result.first_reordered; + } + if first_clean.is_none() { + first_clean = result.first_clean; + } } - } - // The TOTAL first, then the per-worker breakdown. - // - // Ordering matters because it is scraped, not just read: - // `tools/soak-flush-barrier.ps1` takes the *first* line matching `D-23` as - // the CSV's detail column. With the per-worker lines printed as each thread - // was joined, the CSV recorded worker 0 -- one thread of `threads` -- while - // being labelled with the instrument's name, which is a quietly wrong number - // rather than a missing one. - // - // The total was also not printed at all on a passing run: it existed only - // inside the assertion message below, which renders on failure. So the - // figure a reader most wants was the one they could never get. - eprintln!( - "{}", - total.report(&format!("{threads} concurrent rings TOTAL")) - ); - for line in &per_worker { - eprintln!(" {line}"); - } + // The TOTAL first, then the per-worker breakdown. + // + // Ordering matters because it is scraped, not just read: + // `tools/soak-flush-barrier.ps1` takes the *first* line matching `D-23` as + // the CSV's detail column. With the per-worker lines printed as each thread + // was joined, the CSV recorded worker 0 -- one thread of `threads` -- while + // being labelled with the instrument's name, which is a quietly wrong number + // rather than a missing one. + // + // The total was also not printed at all on a passing run: it existed only + // inside the assertion message below, which renders on failure. So the + // figure a reader most wants was the one they could never get. + eprintln!( + "{}", + total.report(&format!("{threads} concurrent rings TOTAL")) + ); + for line in &per_worker { + eprintln!(" {line}"); + } - if let Some(clean) = &first_clean { - eprintln!("A CLEAN TRIAL, for comparison:\n{clean}"); - } - if let Some(reordered) = &first_reordered { - eprintln!("THE FIRST TRIAL WHERE A COMPLETION CROSSED THE FLUSH:\n{reordered}"); - } + if let Some(clean) = &first_clean { + eprintln!("A CLEAN TRIAL, for comparison:\n{clean}"); + } + if let Some(reordered) = &first_reordered { + eprintln!("THE FIRST TRIAL WHERE A COMPLETION CROSSED THE FLUSH:\n{reordered}"); + } - // D-23 only, as in the single-ring instruments. D-24 failures are expected - // here -- this is the condition that produced the highest rate of them. - assert_eq!( + // D-23 only, as in the single-ring instruments. D-24 failures are expected + // here -- this is the condition that produced the highest rate of them. + assert_eq!( total.d23_failures, 0, "{}", @@ -1143,76 +1152,77 @@ fn the_drain_holds_with_concurrent_rings() { "a write queued BEFORE the flush completed after it, across {threads} concurrent rings" )) ); -} + } -/// Does the overtake rate track queue depth? -/// -/// Reports rather than asserts. If reordered_trials appear only at depth, that is a -/// different shape of answer from a fixed per-trial probability, and it is -/// cheap to find out while the instrument is already built. -#[test] -#[ignore = "writes tens of MiB per trial; run explicitly"] -fn reordering_rate_by_ring_depth_is_reported() { - let count = (trials() / 4).max(5); - let _load = Contention::start(4); - - // A trial submits PHASE_OPS writes, one flush, and PHASE_OPS more as a - // single batch, so the submission queue must hold all 65 at once -- the - // contract test says so, and a depth of 64 does not: it fails with - // IORING_E_SUBMISSION_QUEUE_FULL (0x80460002) rather than measuring - // anything. Found by running this sweep, which originally started at 64. - // - // So what varies here is the ring's *headroom* over a fixed shape, not the - // shape itself. That is still the interesting axis: if reordered_trials need - // slack in the queue, the rate should move across these. - const PER_TRIAL_OPS: u32 = (PHASE_OPS * 2 + 1) as u32; - - // Collected before anything is printed, for the same scraping reason as the - // concurrent-rings instrument: the soak runner takes the *first* `D-23` line - // as the CSV's detail, so the first line an instrument prints must be the one - // that represents it. Printing per-depth lines as they were produced put - // `depth 128` in a column labelled with the whole sweep's name. - let mut per_depth = Vec::new(); - let mut combined = Campaign::new(0); - - for depth in [128_u32, 256, 512] { - assert!( - depth >= PER_TRIAL_OPS, - "a depth of {depth} cannot hold one trial's {PER_TRIAL_OPS} entries" - ); - let mut fixture = Fixture::new(&format!("depth-{depth}")); - fixture.ring = TrialRing::with_inventory(depth, depth).expect("create ring"); - let mut result = Campaign::new(count); - for _ in 0..count { - let (observed, _log) = run_trial( - &mut fixture.ring, - fixture.handle, - FlushCoverage::CoversPrecedingOperations, + /// Does the overtake rate track queue depth? + /// + /// Reports rather than asserts. If reordered_trials appear only at depth, that is a + /// different shape of answer from a fixed per-trial probability, and it is + /// cheap to find out while the instrument is already built. + #[test] + #[ignore = "probation: writes tens of MiB per trial; run explicitly"] + fn reordering_rate_by_ring_depth_is_reported() { + let count = (trials() / 4).max(5); + let _load = Contention::start(4); + + // A trial submits PHASE_OPS writes, one flush, and PHASE_OPS more as a + // single batch, so the submission queue must hold all 65 at once -- the + // contract test says so, and a depth of 64 does not: it fails with + // IORING_E_SUBMISSION_QUEUE_FULL (0x80460002) rather than measuring + // anything. Found by running this sweep, which originally started at 64. + // + // So what varies here is the ring's *headroom* over a fixed shape, not the + // shape itself. That is still the interesting axis: if reordered_trials need + // slack in the queue, the rate should move across these. + const PER_TRIAL_OPS: u32 = (PHASE_OPS * 2 + 1) as u32; + + // Collected before anything is printed, for the same scraping reason as the + // concurrent-rings instrument: the soak runner takes the *first* `D-23` line + // as the CSV's detail, so the first line an instrument prints must be the one + // that represents it. Printing per-depth lines as they were produced put + // `depth 128` in a column labelled with the whole sweep's name. + let mut per_depth = Vec::new(); + let mut combined = Campaign::new(0); + + for depth in [128_u32, 256, 512] { + assert!( + depth >= PER_TRIAL_OPS, + "a depth of {depth} cannot hold one trial's {PER_TRIAL_OPS} entries" ); - result.absorb(&observed); - } + let mut fixture = Fixture::new(&format!("depth-{depth}")); + fixture.ring = TrialRing::with_inventory(depth, depth).expect("create ring"); + let mut result = Campaign::new(count); + for _ in 0..count { + let (observed, _log) = run_trial( + &mut fixture.ring, + fixture.handle, + FlushCoverage::CoversPrecedingOperations, + ); + result.absorb(&observed); + } - combined.trials += result.trials; - combined.reordered_trials += result.reordered_trials; - combined.d23_failures += result.d23_failures; - combined.d24_overtakes += result.d24_overtakes; - combined.d24_total_overtakers += result.d24_total_overtakers; - combined.d24_worst = combined.d24_worst.max(result.d24_worst); - combined.same_round += result.same_round; + combined.trials += result.trials; + combined.reordered_trials += result.reordered_trials; + combined.d23_failures += result.d23_failures; + combined.d24_overtakes += result.d24_overtakes; + combined.d24_total_overtakers += result.d24_total_overtakers; + combined.d24_worst = combined.d24_worst.max(result.d24_worst); + combined.same_round += result.same_round; - per_depth.push(result.report(&format!("depth {depth}"))); - } + per_depth.push(result.report(&format!("depth {depth}"))); + } - // The combined figure is the headline because it is the one that is - // comparable **across soak rounds** -- which is what the CSV is for. It is - // explicitly not the instrument's finding: pooling the depths averages away - // the very axis this measures, so the per-depth breakdown follows - // immediately and is what a reader should actually compare. - eprintln!( - "Ring depth sweep, {count} trial(s) each, under contention -- {}", - combined.report("ALL DEPTHS COMBINED") - ); - for line in &per_depth { - eprintln!(" {line}"); + // The combined figure is the headline because it is the one that is + // comparable **across soak rounds** -- which is what the CSV is for. It is + // explicitly not the instrument's finding: pooling the depths averages away + // the very axis this measures, so the per-depth breakdown follows + // immediately and is what a reader should actually compare. + eprintln!( + "Ring depth sweep, {count} trial(s) each, under contention -- {}", + combined.report("ALL DEPTHS COMBINED") + ); + for line in &per_depth { + eprintln!(" {line}"); + } } } diff --git a/crates/windows-platform-probes/DESIGN-NOTES.md b/crates/windows-platform-probes/DESIGN-NOTES.md index eb156e180..c5159d666 100644 --- a/crates/windows-platform-probes/DESIGN-NOTES.md +++ b/crates/windows-platform-probes/DESIGN-NOTES.md @@ -2455,12 +2455,21 @@ on the unchanged configuration. Before `M4.2` that was a source edit and a rebui - **`probe-queue-contention` takes `--pushes-per-producer N`, `--repetitions N` and `--producers a,b,...`.** The three axes the item named -- duration, repetitions, concurrency -- are these three. -- **The cost probes, `probe-request-cost` and `probe-doorbell-cost`, take one setting, - `--iteration-multiplier N`.** Each times fixed loops and divides; neither repeats a measurement - nor varies a thread count, so lengthening the loops is the whole of +- **The cost probes, `probe-request-cost` and `probe-doorbell-cost`, take one setting for the span, + `--iteration-multiplier N`** (and its counterpart, below). Each times fixed loops and divides; + neither repeats a measurement nor varies a thread count, so lengthening the loops is the whole of "more of the same" for them. One multiplier scales every loop the probe runs, the doorbell probe's park-and-wake rounds included, so the loops keep the lengths relative to each other that they were written with. +- **`--iteration-divisor N` shortens the span the same way, and is not for figures.** Each loop + runs a Nth of its usual count, and at least once, so a shortened run still goes round every loop + and its report has every line a full one has. It exists because a test of what a probe *says* -- + that its table and its row agree, that it reports the setting it used, that a census finds its + row -- does not need the figures, and a cost probe's default run is seconds long; the queue + probe already had settings to run short, and the census used them. A run is lengthened or + shortened and never both: a multiplier and a divisor both above one is refused. A shortened run + says so beside its banner, `iteration divisor: N (NOT the default ...)`, as a lengthened one + does, and adds `"iteration_divisor":N` to the row, which every run carries (1 by default). - **A value is given as `--name value` or `--name=value`**, parsed by [src/probe_args.rs](src/probe_args.rs), shared so that every probe that takes settings parses and refuses the same way. @@ -2477,8 +2486,8 @@ on the unchanged configuration. Before `M4.2` that was a source edit and a rebui probe counts its loop in `u32`. These are this crate's limits, not a platform's. - **A run reports what it used, beside the banner, and says when that was not the default.** The queue probe's sampling line ends `(the defaults)` or `(NOT the defaults: ...)`; the cost probes - print `iteration multiplier: N` followed by the same distinction, and add - `"iteration_multiplier":N` to their NDJSON line. This is + print `iteration multiplier: N` (or the divisor's line) followed by the same distinction, and + add `"iteration_multiplier":N` and `"iteration_divisor":N` to their NDJSON line. This is [A probe reports observations parameterized by their capture](#d-observations-not-verdicts) applied to settings that are now part of the capture. - **The sampling is carried in the observation, not beside it.** `Observation.sampling` is what diff --git a/crates/windows-platform-probes/sabotage.json b/crates/windows-platform-probes/sabotage.json index 294cc8dd4..2d5233ed2 100644 --- a/crates/windows-platform-probes/sabotage.json +++ b/crates/windows-platform-probes/sabotage.json @@ -255,10 +255,10 @@ "expect": "caught", "why": "A machine reader would see a scaled run's figures with nothing saying they were not the default's.", "find": [ - " r#\"{{\"reason\":\"x-probe-request-cost\",\"arch\":\"{}\",\"iteration_multiplier\":{},{fields}}}\"#," + " r#\"{{\"reason\":\"x-probe-request-cost\",\"arch\":\"{}\",\"iteration_multiplier\":{},\"iteration_divisor\":{},{fields}}}\"#," ], "replace": [ - " r#\"{{\"reason\":\"x-probe-request-cost\",\"arch\":\"{}\",\"ignored\":{},{fields}}}\"#," + " r#\"{{\"reason\":\"x-probe-request-cost\",\"arch\":\"{}\",\"ignored\":{},\"iteration_divisor\":{},{fields}}}\"#," ] }, { @@ -1430,10 +1430,10 @@ "expect": "survives", "why": "A control: how much a short run measures is incidental to which lines its report carries.", "find": [ - " \"1000\"," + " \"1000\"," ], "replace": [ - " \"998\"," + " \"998\"," ] }, { @@ -1586,6 +1586,114 @@ "replace": [ " .max(1)\n" ] + }, + { + "name": "M45.8 divisor: a divided loop is not shortened", + "file": "src/probe_args.rs", + "expect": "caught", + "why": "The divisor exists so a test of what a cost probe says does not run its full workload. A divisor that changes nothing leaves that test as long as the one it replaced.", + "find": [ + " (lengthened / self.divisor).max(1)" + ], + "replace": [ + " lengthened.max(1)" + ] + }, + { + "name": "M45.8 divisor: a divided loop can run no iterations", + "file": "src/probe_args.rs", + "expect": "caught", + "why": "A shortened run still goes round every loop, so its report has every line a full one has. A loop divided to zero iterations measures nothing and divides by it.", + "find": [ + " (lengthened / self.divisor).max(1)" + ], + "replace": [ + " lengthened / self.divisor" + ] + }, + { + "name": "M45.8 divisor: a loop that did not run is made to", + "file": "src/probe_args.rs", + "expect": "caught", + "why": "The floor of one iteration is for a loop that ran; a loop the probe gave no iterations is not one the setting should start.", + "find": [ + " if lengthened == 0 {" + ], + "replace": [ + " if false {" + ] + }, + { + "name": "M45.8 divisor: a run is lengthened and shortened at once", + "file": "src/probe_args.rs", + "expect": "caught", + "why": "A run that did both would have a length no single setting names, and its report line could say only one of them.", + "find": [ + " if chosen.divisor > 1 && chosen.times > 1 {" + ], + "replace": [ + " if false {" + ] + }, + { + "name": "M45.8 divisor: a divisor of one is refused beside a multiplier", + "file": "src/probe_args.rs", + "expect": "caught", + "why": "A divisor of one shortens nothing, so a multiplier beside it is a lengthened run and not both.", + "find": [ + " if chosen.divisor > 1 && chosen.times > 1 {" + ], + "replace": [ + " if chosen.divisor >= 1 && chosen.times >= 1 {" + ] + }, + { + "name": "M45.8 divisor: a divisor too large for a u32 is read as one", + "file": "src/probe_args.rs", + "expect": "caught", + "why": "A divisor past every loop shortens each to its one iteration, as u32::MAX does. Read as one it would be the default, and a run asked to be as short as possible would be as long as can be.", + "find": [ + ".unwrap_or(u32::MAX);" + ], + "replace": [ + ".unwrap_or(1);" + ] + }, + { + "name": "M45.8 divisor: a shortened run reports itself as a multiplied one", + "file": "src/probe_args.rs", + "expect": "caught", + "why": "A shortened run says so beside its banner. Reported as a multiplier of one it would read as a run that was not shortened, so its figures would pass for the published ones.", + "find": [ + " } else if self.divisor > 1 {" + ], + "replace": [ + " } else if false {" + ] + }, + { + "name": "M45.8 divisor: the doorbell probe's row drops the divisor", + "file": "src/bin/doorbell_cost.rs", + "expect": "caught", + "why": "A machine reader would see a shortened run's figures with nothing in the row saying they were not the default's.", + "find": [ + "\"iteration_multiplier\":{},\"iteration_divisor\":{},{}\"#," + ], + "replace": [ + "\"iteration_multiplier\":{},\"ignored\":{},{}\"#," + ] + }, + { + "name": "M45.8 divisor: the request probe's row drops the divisor", + "file": "src/bin/request_cost.rs", + "expect": "caught", + "why": "The same for the request probe, whose full run is the slow one a reader is most likely to shorten.", + "find": [ + "\"iteration_multiplier\":{},\"iteration_divisor\":{},{fields}" + ], + "replace": [ + "\"iteration_multiplier\":{},\"ignored\":{},{fields}" + ] } ] } diff --git a/crates/windows-platform-probes/src/bin/doorbell_cost.rs b/crates/windows-platform-probes/src/bin/doorbell_cost.rs index f62fde15a..7a86ce10a 100644 --- a/crates/windows-platform-probes/src/bin/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/bin/doorbell_cost.rs @@ -380,11 +380,12 @@ fn render(out: &mut dyn std::fmt::Write, multiplier: IterationMultiplier) { let _ = writeln!( out, concat!( - r#"{{"reason":"x-probe-doorbell-cost","arch":"{}","iteration_multiplier":{},{}"#, + r#"{{"reason":"x-probe-doorbell-cost","arch":"{}","iteration_multiplier":{},"iteration_divisor":{},{}"#, r#""park_and_wake_round_trip_ns":{},"doorbell_over_empty_submit":{}}}"# ), std::env::consts::ARCH, multiplier.get(), + multiplier.divisor(), fields, park.map_or("null".to_string(), |n| format!("{n:.1}")), observation diff --git a/crates/windows-platform-probes/src/bin/request_cost.rs b/crates/windows-platform-probes/src/bin/request_cost.rs index 19e416b83..0ea1e1538 100644 --- a/crates/windows-platform-probes/src/bin/request_cost.rs +++ b/crates/windows-platform-probes/src/bin/request_cost.rs @@ -393,8 +393,9 @@ fn render(out: &mut dyn std::fmt::Write, multiplier: IterationMultiplier) { let _ = writeln!( out, - r#"{{"reason":"x-probe-request-cost","arch":"{}","iteration_multiplier":{},{fields}}}"#, + r#"{{"reason":"x-probe-request-cost","arch":"{}","iteration_multiplier":{},"iteration_divisor":{},{fields}}}"#, std::env::consts::ARCH, multiplier.get(), + multiplier.divisor(), ); } diff --git a/crates/windows-platform-probes/src/probe_args.rs b/crates/windows-platform-probes/src/probe_args.rs index af6d062c6..177547f74 100644 --- a/crates/windows-platform-probes/src/probe_args.rs +++ b/crates/windows-platform-probes/src/probe_args.rs @@ -22,7 +22,8 @@ //! //! Only the axes a stated diagnostic step varies are reachable: the length of a timed span, and, //! for the probe that repeats, the repetitions and the producer counts. The cost probes neither -//! repeat nor vary concurrency, so their one setting is the span. +//! repeat nor vary concurrency, so their settings are the span: lengthened by a multiplier or +//! shortened by a divisor. use std::fmt; @@ -157,67 +158,112 @@ pub fn usage(probe: &str, flags: &[Flag]) -> String { text } -/// How many times its usual count each timed loop of a cost probe runs: the length of the span -/// (`M4.2`). +/// How many times its usual count each timed loop of a cost probe runs, or what fraction of it: +/// the length of the span (`M4.2`). /// /// One multiplier for every loop, rather than a count per loop, so the loops keep the proportions /// they were given -- those that make a kernel call run fewer iterations than those that do not -- -/// and lengthening the span is one decision. The default is 1, the run the published figures came +/// and changing the span is one decision. The default is 1, the run the published figures came /// from. +/// +/// The span is lengthened by a multiplier or shortened by a divisor, never both: a run that did +/// both would have a length no single setting names. A shortened run is for a caller that wants +/// the probe's report and not its figures, a test of what the report says among them, and says so +/// in the report like a lengthened one. #[derive(Debug, Clone, Copy, PartialEq, Eq)] -pub struct IterationMultiplier(u32); +pub struct IterationMultiplier { + times: u32, + divisor: u32, +} impl Default for IterationMultiplier { fn default() -> Self { - Self(1) + Self { + times: 1, + divisor: 1, + } } } impl IterationMultiplier { - /// The one setting the cost probes take. - pub const FLAGS: [Flag; 1] = [Flag { - name: "iteration-multiplier", - value: "N", - help: "each timed loop runs N times its usual count, lengthening the span; 1 when not given", - }]; + /// The settings the cost probes take. + pub const FLAGS: [Flag; 2] = [ + Flag { + name: "iteration-multiplier", + value: "N", + help: "each timed loop runs N times its usual count, lengthening the span; 1 when not given", + }, + Flag { + name: "iteration-divisor", + value: "N", + help: "each timed loop runs a Nth of its usual count, at least once, shortening the span; \ + not with --iteration-multiplier; 1 when not given", + }, + ]; /// The multiplier a command line asks for, given that the probe's longest loop runs /// `largest` iterations at the default. /// /// # Errors /// - /// What [`parse`] refuses, a value that is not a whole number of at least one, and a - /// multiplier that would take the longest loop past `u32::MAX` iterations, which is what a - /// loop counts in. + /// What [`parse`] refuses, a value that is not a whole number of at least one, a multiplier + /// that would take the longest loop past `u32::MAX` iterations, which is what a loop counts + /// in, and a multiplier and a divisor both given and both above one. pub fn from_args( args: impl IntoIterator, largest: u32, ) -> Result { let given = parse(args, &Self::FLAGS)?; - let Some(value) = given.get("iteration-multiplier") else { - return Ok(Self::default()); - }; - let multiplier = u32::try_from(positive("iteration-multiplier", value)?).ok(); - match multiplier { - Some(multiplier) if largest.checked_mul(multiplier).is_some() => Ok(Self(multiplier)), - _ => Err(ArgError::Invalid { - flag: "iteration-multiplier", - value: value.to_owned(), - reason: format!( - "takes the longest loop, {largest} iterations at the default, past {} iterations", - u32::MAX - ), - }), + let mut chosen = Self::default(); + if let Some(value) = given.get("iteration-multiplier") { + let multiplier = u32::try_from(positive("iteration-multiplier", value)?).ok(); + chosen.times = match multiplier { + Some(multiplier) if largest.checked_mul(multiplier).is_some() => multiplier, + _ => { + return Err(ArgError::Invalid { + flag: "iteration-multiplier", + value: value.to_owned(), + reason: format!( + "takes the longest loop, {largest} iterations at the default, past {} \ + iterations", + u32::MAX + ), + }); + } + }; + } + if let Some(value) = given.get("iteration-divisor") { + // Past `u32::MAX` a divisor shortens every loop to its one iteration, as `u32::MAX` + // does, so it is saturated and not refused. + chosen.divisor = + u32::try_from(positive("iteration-divisor", value)?).unwrap_or(u32::MAX); + if chosen.divisor > 1 && chosen.times > 1 { + return Err(ArgError::Invalid { + flag: "iteration-divisor", + value: value.to_owned(), + reason: "a run is lengthened or shortened, not both, and \ + --iteration-multiplier is also given" + .to_owned(), + }); + } } + Ok(chosen) } - /// The multiplier. + /// The multiplier, 1 when the run is not lengthened. #[must_use] pub const fn get(self) -> u32 { - self.0 + self.times + } + + /// The divisor, 1 when the run is not shortened. + #[must_use] + pub const fn divisor(self) -> u32 { + self.divisor } - /// `iterations` times the multiplier. + /// `iterations` times the multiplier, over the divisor, and never fewer than one for a loop + /// that ran at all: a shortened run still goes round every loop. /// /// # Panics /// @@ -226,16 +272,21 @@ impl IterationMultiplier { /// mistake. #[must_use] pub fn scale(self, iterations: u32) -> u32 { - iterations.checked_mul(self.0).unwrap_or_else(|| { + let lengthened = iterations.checked_mul(self.times).unwrap_or_else(|| { panic!( "{iterations} iterations times {} passes u32::MAX; the probe gave \ `from_args` a smaller longest loop than it runs", - self.0 + self.times ) - }) + }); + if lengthened == 0 { + 0 + } else { + (lengthened / self.divisor).max(1) + } } - /// Whether this is the multiplier a run given no settings uses. + /// Whether this is the setting a run given no settings uses. #[must_use] pub fn is_default(self) -> bool { self == Self::default() @@ -248,12 +299,18 @@ impl IterationMultiplier { #[must_use] pub fn report_line(self) -> String { if self.is_default() { - format!("iteration multiplier: {} (the default)", self.0) + "iteration multiplier: 1 (the default)".to_owned() + } else if self.divisor > 1 { + format!( + "iteration divisor: {} (NOT the default: set on the command line, so these \ + figures are not the published ones)", + self.divisor + ) } else { format!( "iteration multiplier: {} (NOT the default: set on the command line, so these \ figures are not the published ones)", - self.0 + self.times ) } } diff --git a/crates/windows-platform-probes/src/probe_args/tests.rs b/crates/windows-platform-probes/src/probe_args/tests.rs index ea4c42d0e..1656d0d41 100644 --- a/crates/windows-platform-probes/src/probe_args/tests.rs +++ b/crates/windows-platform-probes/src/probe_args/tests.rs @@ -252,3 +252,99 @@ fn the_report_line_says_the_multiplier_and_whether_it_is_the_default() { assert!(second.parse::().is_err(), "{line}"); } } + +// --- The divisor, which shortens the span -------------------------------------------------------- + +#[test] +fn a_divisor_shortens_every_loop_by_the_same_factor_and_never_below_one_iteration() { + let divided = IterationMultiplier::from_args(args(&["--iteration-divisor", "10"]), 100_000) + .expect("valid"); + assert_eq!(divided.divisor(), 10); + assert_eq!(divided.get(), 1, "a shortened run is not a lengthened one"); + assert!(!divided.is_default()); + assert_eq!(divided.scale(100_000), 10_000); + assert_eq!(divided.scale(20_000), 2_000); + assert_eq!(divided.scale(5), 1, "a loop still goes round once"); + assert_eq!(divided.scale(1), 1); + assert_eq!( + divided.scale(0), + 0, + "a loop that did not run is not made to" + ); +} + +#[test] +fn a_divisor_of_one_is_the_default_and_a_divisor_alone_does_not_lengthen() { + let one = + IterationMultiplier::from_args(args(&["--iteration-divisor", "1"]), 10).expect("valid"); + assert_eq!(one, IterationMultiplier::default()); + assert!(one.is_default()); + assert_eq!(IterationMultiplier::default().divisor(), 1); +} + +#[test] +fn a_run_is_lengthened_or_shortened_and_not_both() { + let error = IterationMultiplier::from_args( + args(&["--iteration-multiplier", "2", "--iteration-divisor", "2"]), + 10, + ) + .expect_err("both"); + assert!( + matches!( + &error, + ArgError::Invalid { + flag: "iteration-divisor", + .. + } + ), + "{error:?}" + ); + assert!(error.to_string().contains("not both"), "{error}"); + // One of them being the no-op value is not both. + let lengthened = IterationMultiplier::from_args( + args(&["--iteration-multiplier", "2", "--iteration-divisor", "1"]), + 10, + ) + .expect("a divisor of one shortens nothing"); + assert_eq!((lengthened.get(), lengthened.divisor()), (2, 1)); + let shortened = IterationMultiplier::from_args( + args(&["--iteration-multiplier", "1", "--iteration-divisor", "2"]), + 10, + ) + .expect("a multiplier of one lengthens nothing"); + assert_eq!((shortened.get(), shortened.divisor()), (1, 2)); +} + +#[test] +fn a_divisor_of_zero_or_text_is_refused_and_one_past_u32_is_taken_as_the_largest() { + for refused in ["0", "two", "-3"] { + assert!( + IterationMultiplier::from_args(args(&["--iteration-divisor", refused]), 10).is_err(), + "{refused}" + ); + } + let beyond_u32 = (u64::from(u32::MAX) + 1).to_string(); + let huge = IterationMultiplier::from_args(args(&["--iteration-divisor", &beyond_u32]), 10) + .expect("a divisor past every loop shortens each to one iteration, as the largest does"); + assert_eq!(huge.scale(1_000_000), 1); +} + +#[test] +fn the_report_line_says_a_divisor_and_that_it_is_not_the_default() { + let divided = IterationMultiplier::from_args(args(&["--iteration-divisor=8"]), 10) + .expect("valid") + .report_line(); + assert!( + divided.starts_with("iteration divisor: 8 (NOT the default"), + "{divided}" + ); + let second = divided.split_whitespace().nth(1).expect("two words"); + assert!(second.parse::().is_err(), "{divided}"); +} + +#[test] +fn the_usage_of_the_cost_probes_names_both_settings() { + let text = usage("probe-example", &IterationMultiplier::FLAGS); + assert!(text.contains("--iteration-multiplier N"), "{text}"); + assert!(text.contains("--iteration-divisor N"), "{text}"); +} diff --git a/crates/windows-platform-probes/tests/a_cost_probe_tells_both_readers_the_same_thing.rs b/crates/windows-platform-probes/tests/a_cost_probe_tells_both_readers_the_same_thing.rs index 934286b58..7fa00afc9 100644 --- a/crates/windows-platform-probes/tests/a_cost_probe_tells_both_readers_the_same_thing.rs +++ b/crates/windows-platform-probes/tests/a_cost_probe_tells_both_readers_the_same_thing.rs @@ -29,9 +29,17 @@ use std::process::Command; +/// What the short runs ask of a probe: a twentieth of its loops, which still goes round each of them, so +/// the table has every row it has at full length. The figures are not the published ones and the test +/// does not read them as such: it compares the table with the row, digit for digit. +const SHORT: &[&str] = &["--iteration-divisor", "20"]; + /// Every `label value` row of a probe's table, and its NDJSON line. -fn run(binary: &str) -> (Vec<(String, f64)>, String) { - let output = Command::new(binary).output().expect("run the probe"); +fn run(binary: &str, args: &[&str]) -> (Vec<(String, f64)>, String) { + let output = Command::new(binary) + .args(args) + .output() + .expect("run the probe"); assert!( output.status.success(), "the probe exited with {:?}; stderr: {}", @@ -80,10 +88,11 @@ fn ndjson_number(line: &str, key: &str) -> Option { fn assert_table_matches_ndjson( binary: &str, + args: &[&str], key_for: impl Fn(&str) -> &'static str, every_label: &[&str], ) { - let (rows, ndjson) = run(binary); + let (rows, ndjson) = run(binary, args); // **`!rows.is_empty()` was the only guard on the recovery, and one row // satisfies it.** The filter above recovers rows heuristically -- column-0 @@ -135,8 +144,7 @@ fn assert_table_matches_ndjson( } } -#[test] -fn the_doorbell_probe_prints_every_figure_to_both_readers() { +fn the_doorbell_probe_prints_every_figure(args: &[&str]) { // Every label, not just the unconditional ones: the census asks the NDJSON // which of them were measured, so a conditional label is required exactly on // the hosts that measured it. @@ -146,16 +154,45 @@ fn the_doorbell_probe_prints_every_figure_to_both_readers() { .collect(); assert_table_matches_ndjson( env!("CARGO_BIN_EXE_probe-doorbell-cost"), + args, windows_platform_probes::doorbell_cost::json_key, &every, ); } -#[test] -fn the_request_probe_prints_every_figure_to_both_readers() { +fn the_request_probe_prints_every_figure(args: &[&str]) { assert_table_matches_ndjson( env!("CARGO_BIN_EXE_probe-request-cost"), + args, windows_platform_probes::request_cost::json_key, &windows_platform_probes::request_cost::EVERY_LABEL, ); } + +#[test] +fn the_doorbell_probe_prints_every_figure_to_both_readers() { + the_doorbell_probe_prints_every_figure(SHORT); +} + +#[test] +fn the_request_probe_prints_every_figure_to_both_readers() { + the_request_probe_prints_every_figure(SHORT); +} + +/// The same two checks over the probes' normal runs, which are seconds long. Nothing about them differs +/// from the short runs but the length, which is what a figure printed to the digit is not about. +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: runs the doorbell probe at its usual workload"] + fn the_doorbell_probe_prints_every_figure_to_both_readers_at_full_length() { + the_doorbell_probe_prints_every_figure(&[]); + } + + #[test] + #[ignore = "long-haul: runs the request probe at its usual workload"] + fn the_request_probe_prints_every_figure_to_both_readers_at_full_length() { + the_request_probe_prints_every_figure(&[]); + } +} diff --git a/crates/windows-platform-probes/tests/a_probe_takes_its_settings_or_refuses_them.rs b/crates/windows-platform-probes/tests/a_probe_takes_its_settings_or_refuses_them.rs index 7f58edf18..57c022735 100644 --- a/crates/windows-platform-probes/tests/a_probe_takes_its_settings_or_refuses_them.rs +++ b/crates/windows-platform-probes/tests/a_probe_takes_its_settings_or_refuses_them.rs @@ -132,9 +132,11 @@ fn a_queue_run_of_one_producer_making_one_push_is_measured() { ); } -#[test] -fn a_cost_probe_given_a_multiplier_reports_it_beside_its_banner_and_in_its_row() { - let output = run(REQUEST, &["--iteration-multiplier", "2"]); +/// What a cost probe given `--iteration-multiplier 2` reports: the setting beside its banner and in its +/// row, which is a claim about the report and not about the figures, so any cost probe shows it. The +/// doorbell probe is the quick one; the request probe's run is [`long_haul`]. +fn a_cost_probe_given_a_multiplier_reports_it(binary: &str) { + let output = run(binary, &["--iteration-multiplier", "2"]); let stdout = String::from_utf8(output.stdout).expect("a probe's report is UTF-8"); assert!( output.status.success(), @@ -151,6 +153,64 @@ fn a_cost_probe_given_a_multiplier_reports_it_beside_its_banner_and_in_its_row() .find(|line| line.starts_with('{')) .expect("the NDJSON row"); assert!(row.contains(r#""iteration_multiplier":2,"#), "{row}"); + assert!(row.contains(r#""iteration_divisor":1,"#), "{row}"); +} + +#[test] +fn a_cost_probe_given_a_multiplier_reports_it_beside_its_banner_and_in_its_row() { + a_cost_probe_given_a_multiplier_reports_it(DOORBELL); +} + +/// The same for the request probe, shortened: the probe takes a divisor so that a test of what its report +/// says does not run its full workload. +#[test] +fn a_cost_probe_given_a_divisor_reports_it_beside_its_banner_and_in_its_row() { + let output = run(REQUEST, &["--iteration-divisor", "20"]); + let stdout = String::from_utf8(output.stdout).expect("a probe's report is UTF-8"); + assert!( + output.status.success(), + "{}", + String::from_utf8_lossy(&output.stderr) + ); + let lines: Vec<&str> = stdout.lines().collect(); + assert!( + lines[1].starts_with("iteration divisor: 20 (NOT the default"), + "the line after the banner says what the run used: {stdout}" + ); + let row = lines + .iter() + .find(|line| line.starts_with('{')) + .expect("the NDJSON row"); + assert!( + row.contains(r#""iteration_multiplier":1,"iteration_divisor":20,"#), + "{row}" + ); +} + +#[test] +fn a_cost_probe_refuses_to_be_both_lengthened_and_shortened() { + assert_refused( + REQUEST, + &["--iteration-multiplier", "2", "--iteration-divisor", "2"], + "not both", + ); + assert_refused( + DOORBELL, + &["--iteration-divisor", "0"], + "must be at least 1", + ); +} + +/// The request probe at twice its usual length, which is most of what this file costs. Nothing about it +/// differs from the doorbell probe's run but the probe and the time. +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: runs the request probe at twice its usual workload"] + fn the_request_probe_given_a_multiplier_reports_it_beside_its_banner_and_in_its_row() { + a_cost_probe_given_a_multiplier_reports_it(REQUEST); + } } #[test] diff --git a/crates/windows-platform-probes/tests/the_probes_that_emit_a_machine_readable_row.rs b/crates/windows-platform-probes/tests/the_probes_that_emit_a_machine_readable_row.rs index d0a48011e..8e8b2bc40 100644 --- a/crates/windows-platform-probes/tests/the_probes_that_emit_a_machine_readable_row.rs +++ b/crates/windows-platform-probes/tests/the_probes_that_emit_a_machine_readable_row.rs @@ -61,23 +61,35 @@ const DEADLINE: Duration = Duration::from_secs(120); /// built with `Row::new` answers falsely. const MAY_NOT_EXIT: [&str; 1] = ["probe-cancel-io"]; +/// The queue probe's short command line: one producer, one repetition and a thousand pushes take a +/// fraction of a second against the default's minute. +const QUEUE_SHORT: &[&str] = &[ + "--producers", + "1", + "--repetitions", + "1", + "--pushes-per-producer", + "1000", +]; + +/// A cost probe's short command line: a twentieth of each loop, which still goes round every one. +const COST_SHORT: &[&str] = &["--iteration-divisor", "20"]; + /// Probes run with a command line that keeps them short, and that command line. /// /// The settings change how much is measured, never which lines the report /// carries, so a short run answers the census's question as well as a full -/// one. One producer, one repetition and a thousand pushes take a fraction of a -/// second against the default's minute. -const SHORT_RUNS: [(&str, &[&str]); 1] = [( - "probe-queue-contention", - &[ - "--producers", - "1", - "--repetitions", - "1", - "--pushes-per-producer", - "1000", - ], -)]; +/// one. The probes that take no setting are run as they are. +const SHORT_RUNS: [(&str, &[&str]); 3] = [ + ("probe-queue-contention", QUEUE_SHORT), + ("probe-request-cost", COST_SHORT), + ("probe-doorbell-cost", COST_SHORT), +]; + +/// What the census keeps short whatever its length: the queue probe's normal run is a minute and a half, +/// which is not a thing to wait for in any tier. The census at full length runs every other probe +/// as it is. See [`long_haul`]. +const ALWAYS_SHORT: [(&str, &[&str]); 1] = [("probe-queue-contention", QUEUE_SHORT)]; /// Every `[[bin]]` name the manifest registers. fn registered_binaries(manifest: &str) -> Vec { @@ -204,8 +216,7 @@ fn emits_a_row(name: &str, mut command: Command, may_not_exit: bool, deadline: D } } -#[test] -fn every_registered_probe_emits_a_machine_readable_row() { +fn every_registered_probe_emits_a_row(short_runs: &[(&str, &[&str])]) { let manifest = std::fs::read_to_string(crate_root().join("Cargo.toml")) .expect("the crate's manifest is readable"); let registered = registered_binaries(&manifest); @@ -222,7 +233,7 @@ fn every_registered_probe_emits_a_machine_readable_row() { waited on, which is the hang the excuse exists to avoid" ); } - for (name, _) in SHORT_RUNS { + for (name, _) in short_runs { assert!( registered.iter().any(|registered| registered == name), "`{name}` is given a short command line by name, so it must still be \ @@ -235,7 +246,7 @@ fn every_registered_probe_emits_a_machine_readable_row() { let mut without_a_row: Vec<&str> = Vec::new(); for name in ®istered { let executable = directory.join(format!("{name}{}", std::env::consts::EXE_SUFFIX)); - let arguments = SHORT_RUNS + let arguments = short_runs .iter() .find(|(short, _)| short == name) .map_or(&[][..], |(_, arguments)| *arguments); @@ -254,6 +265,23 @@ fn every_registered_probe_emits_a_machine_readable_row() { ); } +#[test] +fn every_registered_probe_emits_a_machine_readable_row() { + every_registered_probe_emits_a_row(&SHORT_RUNS); +} + +/// The census with the cost probes at their normal length, which is what "normal run" says. The probes +/// that take a setting to run short are the only difference from the test above. +mod long_haul { + use super::*; + + #[test] + #[ignore = "long-haul: runs every probe, the cost probes at their usual workload"] + fn every_registered_probe_emits_a_machine_readable_row_at_full_length() { + every_registered_probe_emits_a_row(&ALWAYS_SHORT); + } +} + /// A `cmd.exe` running `script`, with a stdin it can wait on forever. /// /// The census's deadline paths need a child that does not finish, and `set /p` diff --git a/tools/README-sabotage.md b/tools/README-sabotage.md index fc811a29a..c672d20e4 100644 --- a/tools/README-sabotage.md +++ b/tools/README-sabotage.md @@ -215,6 +215,37 @@ must stamp the file with the current time. The entry is caught. That is the argument for this file in one paragraph. A test suite cannot tell you what it fails to look at; only injecting the defect can. +[sabotage-tiers.json](sabotage-tiers.json) is the same arrangement for +[check-test-tiers.ps1](check-test-tiers.ps1), judged by +[test-check-test-tiers.ps1](test-check-test-tiers.ps1) through +[sabotage-tiers-runner.cmd](sabotage-tiers-runner.cmd): + +```powershell +.\tools\run-sabotage.ps1 -Manifest tools\sabotage-tiers.json ` + -CargoCommand (Resolve-Path tools\sabotage-tiers-runner.cmd).Path +``` + +[sabotage-long-haul.json](sabotage-long-haul.json) is the same for [plan-long-haul.ps1](plan-long-haul.ps1), the planner +behind the long-haul workflow, judged by [test-plan-long-haul.ps1](test-plan-long-haul.ps1) through +[sabotage-long-haul-runner.cmd](sabotage-long-haul-runner.cmd). It carries one declared equivalent mutant, an entry +that is expected to survive and says why. + +```powershell +.\tools\run-sabotage.ps1 -Manifest tools\sabotage-long-haul.json ` + -CargoCommand (Resolve-Path tools\sabotage-long-haul-runner.cmd).Path +``` + +[sabotage-probation.json](sabotage-probation.json) is the same for the scripts that keep the probation tier's results -- +[probation-common.ps1](probation-common.ps1), [run-tier.ps1](run-tier.ps1), +[publish-probation-results.ps1](publish-probation-results.ps1) and [report-probation.ps1](report-probation.ps1) -- judged by +[test-probation.ps1](test-probation.ps1) through [sabotage-probation-runner.cmd](sabotage-probation-runner.cmd). That suite +builds real one-crate workspaces, so each entry costs close to a minute. + +```powershell +.\tools\run-sabotage.ps1 -Manifest tools\sabotage-probation.json ` + -CargoCommand (Resolve-Path tools\sabotage-probation-runner.cmd).Path +``` + Runs on **Windows PowerShell 5.1 and PowerShell 7 alike**, like the other scripts in this directory, and the full sweep is verified on both. Worth stating because the two differ in ways that bite here specifically: 5.1 rejects diff --git a/tools/check-test-tiers.ps1 b/tools/check-test-tiers.ps1 new file mode 100644 index 000000000..154b0aa49 --- /dev/null +++ b/tools/check-test-tiers.ps1 @@ -0,0 +1,328 @@ +# Copyright (c) Mike Grier. +# +# tools/check-test-tiers.ps1 -- a test's tier marker and the module it sits in agree. +# +# WHAT A TIER IS. DEVELOPMENT.md ("Test tiers") and DESIGN-NOTES.md ("long-haul-tier") say: a long-haul test is +# `#[ignore = "long-haul: "]` in a module named `long_haul`; a probation test is +# `#[ignore = "probation: "]` in a module named `probation`. The tier's own run selects by NAME, +# because libtest filters by name and cannot filter by ignore reason: `--ignored long_haul::` runs every +# ignored test whose path contains `long_haul::`. +# +# WHY A CENSUS. The marker and the path are two statements of one fact, and nothing makes them agree. A test +# marked into a tier its path does not select would be ignored everywhere and run by no one, which looks exactly +# like a test that passes; a test in the tier's module but not marked would run on every push, or, if ignored +# for another reason, be picked up by the tier's run for a reason that is not its own. So both directions are +# checked, with the rules in Get-TierViolation. +# +# THE CENSUS ASKS THE TEST BINARIES. It builds the workspace's test executables and has each one list its own +# tests, with their paths and ignore reasons, through libtest's JSON discovery. A scan of the source for +# `#[ignore]` and `mod long_haul` would be a proxy for what rustc and libtest decide -- macro-generated tests, +# `#[path]` modules and `cfg` all change the answer -- and a census of the tier's membership that disagreed +# with the tier's own run would be worse than none. Unlisted, and so unchecked: doctests, which the tiers do +# not apply to. +# +# The listing needs libtest's unstable `--format json`, which a test executable accepts under RUSTC_BOOTSTRAP=1 +# (the same arrangement as the compile_fail doctest check). That is set for the executables only. +# +# ./tools/check-test-tiers.ps1 # the workspace, all features (CI) +# A TIER NEVER RUNS ON A PUSH. A `cargo test ... -- --include-ignored` (or `--ignored`) in a workflow selects every +# ignored test it is not told to skip, and a tier test is ignored, so an unfiltered one would run the tier on every +# push and defeat the point of having one. Each such command is checked against the census for the tests it would +# select (Get-WorkflowTierViolation): its packages, its targets, its name filters and its `--skip`s. The commands +# the tiers run through are tools/run-tier.ps1, which is not a `cargo test` line in a workflow and so is not read. +# +# ./tools/check-test-tiers.ps1 # the workspace, all features (CI) +# ./tools/check-test-tiers.ps1 -ListingPath FILE # a recorded listing, for the tests +# ./tools/check-test-tiers.ps1 -RepositoryRoot DIR -CargoArgs @('--workspace') # a fixture workspace +# +# Exit: 0 consistent, 1 a test breaks a rule, 2 the census could not be taken. +# +# A listing file is one JSON object per line: {"binary":"","name":"","ignore":, +# "ignore_message":""}, with the optional "package" and "kind" (lib, bin, test, example) of the executable +# the workflow check selects by. tools/test-check-test-tiers.ps1 writes them. +[CmdletBinding()] +param( + [string] $RepositoryRoot, + [string] $ListingPath, + [string] $WorkflowDirectory, + [string[]] $CargoArgs = @('--workspace', '--all-features', '--locked') +) + +Set-StrictMode -Version Latest +$ErrorActionPreference = 'Stop' + +if (-not $RepositoryRoot) { $RepositoryRoot = Split-Path -Parent $PSScriptRoot } +if (-not $WorkflowDirectory) { $WorkflowDirectory = Join-Path $RepositoryRoot '.github/workflows' } + +# The tiers, spelled once. `Marker` is what an ignore reason starts with, `Module` the module a tier's tests sit +# in, and `Pattern` what a reason that is MEANT as the marker looks like when it is not spelled right. The +# tier's run filters on `::`, and a test's path is `::::`, so the filter selects +# exactly the tests with that module segment and no other. +$tiers = @( + [pscustomobject]@{ Name = 'long-haul'; Marker = 'long-haul:'; Module = 'long_haul'; Pattern = '(?i)long[\s_-]*haul' } + [pscustomobject]@{ Name = 'probation'; Marker = 'probation:'; Module = 'probation'; Pattern = '(?i)probation' } +) + +# libtest writes an ignore reason into its JSON without escaping a backslash, so a reason that names a path +# (`\\localhost\C$`) is not valid JSON and a strict parser refuses the whole line. The fields read here are a +# test's path, whether it is ignored, and the reason's leading text, so a line the parser refuses is read by shape. +function ConvertFrom-LibtestLine { + param([string] $Line) + $parsed = $null + try { $parsed = $Line | ConvertFrom-Json -ErrorAction Stop } catch { $parsed = $null } + if ($null -ne $parsed) { + if ($parsed.type -ne 'test' -or $parsed.event -ne 'discovered') { return $null } + return [pscustomobject]@{ name = [string]$parsed.name; ignore = [bool]$parsed.ignore; ignore_message = [string]$parsed.ignore_message } + } + $shape = [regex]::Match($Line, '^\s*\{\s*"type":\s*"test",\s*"event":\s*"discovered",\s*"name":\s*"(?[^"]*)",\s*"ignore":\s*(?true|false)(?:,\s*"ignore_message":\s*"(?.*?)")?,\s*"source_path":') + if (-not $shape.Success) { + # No test reaches this: no executable the suite can build writes a line that is neither JSON nor this + # shape. It exists so a libtest that changes its format fails the census instead of being read as empty. + throw "A test listing line is neither JSON nor the shape libtest writes: $Line" + } + [pscustomobject]@{ name = $shape.Groups['name'].Value; ignore = ($shape.Groups['ignore'].Value -eq 'true'); ignore_message = $shape.Groups['message'].Value } +} + +function Get-TierViolation { + param([object[]] $Tests) + foreach ($test in $Tests) { + $reason = if ($test.ignore) { [string]$test.ignore_message } else { '' } + $segments = @($test.name -split '::') + $modules = if ($segments.Count -gt 1) { @($segments[0..($segments.Count - 2)]) } else { @() } + foreach ($tier in $tiers) { + $marked = $reason.StartsWith($tier.Marker, [System.StringComparison]::Ordinal) + $inModule = $modules -ccontains $tier.Module + $filter = $tier.Module + '::' + $selected = $test.name.Contains($filter) + $problem = $null + if ($marked -and -not $inModule) { + $problem = "is marked $($tier.Name) but is not in a module named $($tier.Module), so `"$filter`" never selects it and nothing runs it" + } + elseif ($marked -and $reason.Substring($tier.Marker.Length).Trim().Length -eq 0) { + $problem = "is marked $($tier.Name) but says nothing after `"$($tier.Marker)`": the reason is where what it costs is written" + } + elseif ($inModule -and -not $marked) { + $problem = if ($test.ignore) { + "is in a module named $($tier.Module) but ignored for another reason, so the $($tier.Name) run would pick it up for a reason that is not its own" + } + else { "is in a module named $($tier.Module) but is not ignored, so it runs on every push and not in the $($tier.Name) tier" } + } + elseif ($selected -and -not $inModule) { + $problem = "has `"$filter`" in its path without a module of that name, so the $($tier.Name) run would select it by accident" + } + elseif ($reason -match $tier.Pattern -and -not $marked) { + $problem = "has an ignore reason that reads like a $($tier.Name) marker but does not start with `"$($tier.Marker)`"" + } + if ($problem) { + [pscustomobject]@{ Binary = $test.binary; Name = $test.name; Reason = $reason; Problem = $problem } + } + } + } +} + +# The package a cargo `package_id` names, in either of the forms cargo has written it: `path+file:///dir#name@1.0.0`, +# or `path+file:///dir/name#1.0.0` when the name is the directory's, or the older `name 1.0.0 (path+file:///dir)`. +function Get-PackageName { + param([string] $PackageId) + if ($PackageId -match '#(?[^@#/]+)@') { return $Matches['name'] } + if ($PackageId -match '/(?[^/#]+)#\d') { return $Matches['name'] } + if ($PackageId -match '^(?\S+) \d') { return $Matches['name'] } + return '' +} + +# The tier tests a workflow's `cargo test` command would run. `Command` is the text from `cargo test` on. +# Selection is cargo's and libtest's: the packages (`-p`, else all), the targets (`--lib`, `--bins`, `--bin`, +# `--examples`, `--example`, `--test`, `--tests`, `--all-targets`, else all), and then, over the names, the +# positional filters (a substring, or the whole name under `--exact`) and the `--skip`s. +function Get-CommandTierSelection { + param([string] $Command, [object[]] $Tests) + $tokens = @(($Command -replace "[`"']", '') -split '\s+' | Where-Object { $_ }) + $split = [array]::IndexOf($tokens, '--') + $cargoSide = @(if ($split -lt 0) { $tokens } else { $tokens[0..($split - 1)] }) + $harnessSide = @(if ($split -lt 0) { } else { $tokens | Select-Object -Skip ($split + 1) }) + + $packages = New-Object System.Collections.Generic.List[string] + $kinds = New-Object System.Collections.Generic.List[string] + $named = New-Object System.Collections.Generic.List[string] + $valueFlags = @('-p', '--package', '--test', '--bin', '--example', '--features', '-F', '--target', '--manifest-path', '--target-dir', '--profile', '-j', '--jobs', '--exclude') + for ($i = 0; $i -lt $cargoSide.Count; $i++) { + $token = $cargoSide[$i] + $value = if ($i + 1 -lt $cargoSide.Count) { $cargoSide[$i + 1] } else { '' } + switch -CaseSensitive ($token) { + { $_ -in '-p', '--package' } { $packages.Add($value); $i++; continue } + '--test' { $named.Add('test:' + $value); $i++; continue } + '--bin' { $named.Add('bin:' + $value); $i++; continue } + '--example' { $named.Add('example:' + $value); $i++; continue } + '--lib' { $kinds.Add('lib'); continue } + '--bins' { $kinds.Add('bin'); continue } + '--examples' { $kinds.Add('example'); continue } + { $_ -in '--tests', '--all-targets' } { $kinds.AddRange([string[]]@('lib', 'bin', 'test', 'example')); continue } + { $_ -in $valueFlags } { $i++; continue } + } + } + $filters = New-Object System.Collections.Generic.List[string] + $skips = New-Object System.Collections.Generic.List[string] + $exact = $false + for ($i = 0; $i -lt $harnessSide.Count; $i++) { + $token = $harnessSide[$i] + if ($token -eq '--skip') { if ($i + 1 -lt $harnessSide.Count) { $skips.Add($harnessSide[$i + 1]) }; $i++ } + elseif ($token -eq '--exact') { $exact = $true } + elseif ($token -in '--test-threads', '--format', '-Z', '--logfile', '--color', '--shuffle-seed') { $i++ } + elseif (-not $token.StartsWith('-')) { $filters.Add($token) } + } + + foreach ($test in $Tests) { + $reason = if ($test.ignore) { [string]$test.ignore_message } else { '' } + $tier = $tiers | Where-Object { $reason.StartsWith($_.Marker, [System.StringComparison]::Ordinal) } | Select-Object -First 1 + if (-not $tier) { continue } + if ($packages.Count -gt 0 -and $packages -notcontains $test.package) { continue } + if ($kinds.Count -gt 0 -or $named.Count -gt 0) { + $targeted = ($kinds -contains $test.kind) -or ($named -contains ($test.kind + ':' + $test.binary)) + if (-not $targeted) { continue } + } + if ($filters.Count -gt 0) { + $hit = $false + foreach ($filter in $filters) { if (($exact -and $test.name -ceq $filter) -or (-not $exact -and $test.name.Contains($filter))) { $hit = $true } } + if (-not $hit) { continue } + } + $skipped = $false + foreach ($skip in $skips) { if (($exact -and $test.name -ceq $skip) -or (-not $exact -and $test.name.Contains($skip))) { $skipped = $true } } + if ($skipped) { continue } + [pscustomobject]@{ Tier = $tier.Name; Test = $test } + } +} + +function Get-WorkflowTierViolation { + param([object[]] $Tests, [string] $Directory) + if (-not (Test-Path -LiteralPath $Directory -PathType Container)) { return } + foreach ($file in Get-ChildItem -LiteralPath $Directory -File | Where-Object { $_.Extension -in '.yml', '.yaml' }) { + $lines = [System.IO.File]::ReadAllLines($file.FullName) + for ($n = 0; $n -lt $lines.Count; $n++) { + $match = [regex]::Match($lines[$n], '\bcargo test\b.*\s(--include-ignored|--ignored)\b') + if (-not $match.Success) { continue } + $command = $lines[$n].Substring($lines[$n].IndexOf('cargo test')).Trim() + $selected = @(Get-CommandTierSelection -Command $command -Tests $Tests) + if ($selected.Count -gt 0) { + $first = $selected | Select-Object -First 3 | ForEach-Object { "$($_.Test.package)::$($_.Test.binary) $($_.Test.name) ($($_.Tier))" } + [pscustomobject]@{ + Binary = "$($file.Name):$($n + 1)" + Name = $command + Reason = '' + Problem = "runs ignored tests without skipping the tiers, so it would run $($selected.Count) tier test(s) on a push, for example: $($first -join '; '). Add `--skip long_haul:: --skip probation::`, or name the tests it is for." + } + } + } + } +} + +# The tests every executable lists, as records. Exits 2 when the census cannot be taken, because a census that +# silently saw fewer tests than exist would pass for the wrong reason. +function Get-TestListing { + # Every executable is asked for its list, and one that is not a libtest harness would instead run its own + # main with arguments it does not expect. None is today; one added later is a decision to make here, not a + # surprise to find in a CI run. + $custom = @(Get-ChildItem -LiteralPath $RepositoryRoot -Recurse -Filter Cargo.toml -File -ErrorAction SilentlyContinue | + Where-Object { $_.FullName -notmatch '[\\/](target|\.scratch|node_modules)[\\/]' } | + Where-Object { (Get-Content -LiteralPath $_.FullName -Raw) -match '(?m)^\s*harness\s*=\s*false' } | + ForEach-Object { $_.FullName }) + if ($custom.Count -gt 0) { + Write-Host "A target with harness = false is declared in: $($custom -join ', ')" + Write-Host 'This check asks each test executable for its list, which would run such a target instead; teach it about the target first.' + exit 2 + } + + # Function-local: on Windows PowerShell 5.1 cargo's progress on stderr is a terminating error under `Stop` + # even when it is discarded, and the exit code is what says whether the build worked. + $ErrorActionPreference = 'Continue' + Push-Location -LiteralPath $RepositoryRoot + try { + $built = @(& cargo test @CargoArgs --no-run --message-format=json 2>$null) + if ($LASTEXITCODE -ne 0) { + Write-Host "cargo could not build the tests (exit $LASTEXITCODE); run: cargo test $($CargoArgs -join ' ') --no-run" + exit 2 + } + } + finally { Pop-Location } + $executables = @($built | Where-Object { $_ -like '{*' } | ForEach-Object { + try { $_ | ConvertFrom-Json } catch { $null } + } | Where-Object { $null -ne $_ -and $_.reason -eq 'compiler-artifact' -and $_.executable -and $_.profile.test } | + ForEach-Object { [pscustomobject]@{ Name = $_.target.name; Path = $_.executable; Package = (Get-PackageName ([string]$_.package_id)); Kind = [string]@($_.target.kind)[0] } } | + Sort-Object Path -Unique) + if ($executables.Count -eq 0) { + Write-Host 'cargo built no test executables, so there is nothing to ask.' + exit 2 + } + + foreach ($exe in $executables) { + $info = New-Object System.Diagnostics.ProcessStartInfo + $info.FileName = $exe.Path + $info.Arguments = '-Z unstable-options --format json --list' + $info.UseShellExecute = $false + $info.CreateNoWindow = $true + $info.RedirectStandardOutput = $true + $info.RedirectStandardError = $true + # The decoder is named, not the console's: a name or a reason need not be ASCII, and the console's code + # page is not always UTF-8 (see Get-GitBlobUtf8 in common.ps1). + $info.StandardOutputEncoding = New-Object System.Text.UTF8Encoding($false) + $info.EnvironmentVariables['RUSTC_BOOTSTRAP'] = '1' + $process = [System.Diagnostics.Process]::Start($info) + try { + $stderr = $process.StandardError.ReadToEndAsync() + $stdout = $process.StandardOutput.ReadToEndAsync() + if (-not $process.WaitForExit(120000)) { + try { $process.Kill() } catch { $null = $_ } + Write-Host "$($exe.Name) did not list its tests within 120 seconds." + exit 2 + } + $process.WaitForExit() + if ($process.ExitCode -ne 0) { + Write-Host "$($exe.Name) ($($exe.Path)) exited $($process.ExitCode) when asked to list its tests: $($stderr.Result.Trim())" + exit 2 + } + foreach ($line in ($stdout.Result -split "`r?`n")) { + if (-not $line.TrimStart().StartsWith('{')) { continue } + $event = ConvertFrom-LibtestLine -Line $line + if ($null -ne $event) { + [pscustomobject]@{ binary = $exe.Name; package = $exe.Package; kind = $exe.Kind; name = $event.name; ignore = $event.ignore; ignore_message = $event.ignore_message } + } + } + } + finally { $process.Dispose() } + } +} + +$tests = @(if ($ListingPath) { + if (-not (Test-Path -LiteralPath $ListingPath -PathType Leaf)) { Write-Host "No listing at $ListingPath."; exit 2 } + foreach ($line in [System.IO.File]::ReadAllLines($ListingPath)) { + if ($line.Trim().Length -eq 0) { continue } + $record = $line | ConvertFrom-Json + [pscustomobject]@{ + binary = [string]$record.binary + package = if ($record.PSObject.Properties['package']) { [string]$record.package } else { '' } + kind = if ($record.PSObject.Properties['kind']) { [string]$record.kind } else { '' } + name = [string]$record.name + ignore = [bool]$record.ignore + ignore_message = [string]$record.ignore_message + } + } + } + else { Get-TestListing }) + +$violations = @(@(Get-TierViolation -Tests $tests) + @(Get-WorkflowTierViolation -Tests $tests -Directory $WorkflowDirectory) | Sort-Object Binary, Name, Problem) +if ($violations.Count -gt 0) { + foreach ($v in $violations) { + Write-Host "$($v.Binary): $($v.Name)" + Write-Host " $($v.Problem)" + if ($v.Reason) { Write-Host " ignore reason: $($v.Reason)" } + } + Write-Host '' + Write-Host "$($violations.Count) test tier problem(s). The convention is in DEVELOPMENT.md, `"Test tiers`"." + exit 1 +} + +$summary = @($tiers | ForEach-Object { + $tier = $_ + "$($tier.Name) $(@($tests | Where-Object { $_.ignore -and $_.ignore_message.StartsWith($tier.Marker, [System.StringComparison]::Ordinal) }).Count)" + }) -join ', ' +Write-Host "Test tiers consistent: $($tests.Count) tests across $(@($tests | ForEach-Object { $_.binary } | Sort-Object -Unique).Count) executables; $summary." +exit 0 diff --git a/tools/plan-long-haul.ps1 b/tools/plan-long-haul.ps1 new file mode 100644 index 000000000..0b0026131 --- /dev/null +++ b/tools/plan-long-haul.ps1 @@ -0,0 +1,119 @@ +# Copyright (c) Mike Grier. +<# +.SYNOPSIS + Decides whether the long-haul workflow has anything to do. + +.DESCRIPTION + `.github/workflows/long-haul.yml` runs the long-haul and probation test tiers daily, and only when `main` has + moved since the last run that completed. A run on an unchanged `main` would repeat the last one's result at + the cost of a workspace build and every long test, so the schedule asks this first. + + The rule: + + - A run the engineer asked for (`workflow_dispatch`), or any trigger but the schedule, always runs. + - A scheduled run does not run when the most recent earlier run of the workflow that completed -- succeeded, + failed or timed out -- was on the commit being run now. It runs when there is no such run, or when that + run was on another commit. + - A cancelled run did not complete, and a run that was only the gate skipping its work has the commit it + skipped on, so it counts: the schedule would otherwise run again the next day on the same commit. + - When the earlier runs cannot be listed the answer is to run, with a warning. The tier exists to run, and + a failure to ask is not evidence that nothing changed. + + The runs come from `gh run list`, or from `-RunsPath` for a test: a JSON array of objects with + `databaseId`, `headSha`, `conclusion` and `createdAt`. + +.PARAMETER EventName + The triggering event, `github.event_name`. + +.PARAMETER Sha + The commit this run is on, `github.sha`. + +.PARAMETER CurrentRunId + This run's id, `github.run_id`, so it is never counted as an earlier one. + +.PARAMETER Workflow + The workflow file to list the earlier runs of. + +.PARAMETER Branch + The branch the earlier runs are listed for. + +.PARAMETER RunsPath + A JSON file of earlier runs to use instead of asking GitHub. + +.PARAMETER GitHubOutput + The Actions step-output file. Receives `run=true|false` and `reason=`. + +.EXAMPLE + ./tools/plan-long-haul.ps1 -EventName schedule -Sha $sha -CurrentRunId 1 -RunsPath runs.json +#> +[CmdletBinding()] +param( + [Parameter(Mandatory = $true)][string] $EventName, + [Parameter(Mandatory = $true)][string] $Sha, + [string] $CurrentRunId = '', + [string] $Workflow = 'long-haul.yml', + [string] $Branch = 'main', + [string] $RunsPath, + [string] $GitHubOutput +) + +Set-StrictMode -Version Latest +$ErrorActionPreference = 'Stop' + +. (Join-Path $PSScriptRoot 'common.ps1') + +# What counts as having completed: it ran to a result. A cancelled run, a skipped one and a run that never +# started say nothing about the commit. +$completedConclusions = @('success', 'failure', 'timed_out') + +function Get-LongHaulPlan { + param([string] $EventName, [string] $Sha, [string] $CurrentRunId, [object[]] $Runs) + if ($EventName -ne 'schedule') { + return [pscustomobject]@{ Run = $true; Reason = "a $EventName run is always taken" } + } + $earlier = @($Runs | + Where-Object { "$($_.databaseId)" -ne $CurrentRunId -and $completedConclusions -contains [string]$_.conclusion } | + Sort-Object { [datetime]$_.createdAt } -Descending) + if ($earlier.Count -eq 0) { + return [pscustomobject]@{ Run = $true; Reason = 'no earlier run completed' } + } + $last = $earlier[0] + if ([string]$last.headSha -eq $Sha) { + return [pscustomobject]@{ Run = $false; Reason = "main has not moved since run $($last.databaseId), which completed ($($last.conclusion)) on $Sha" } + } + return [pscustomobject]@{ Run = $true; Reason = "main moved from $($last.headSha) (run $($last.databaseId)) to $Sha" } +} + +$runs = @() +$plan = $null +if ($EventName -eq 'schedule') { + $json = $null + if ($RunsPath) { + if (-not (Test-Path -LiteralPath $RunsPath -PathType Leaf)) { Write-Host "No runs file at $RunsPath."; exit 2 } + $json = [System.IO.File]::ReadAllText($RunsPath) + } + else { + $asked = Invoke-NativeSplit { gh run list --workflow $Workflow --branch $Branch --status completed --limit 30 --json databaseId,headSha,conclusion,createdAt } + if ($asked.ExitCode -ne 0) { + Write-Host "::warning::could not list earlier runs of $Workflow (gh exited $($asked.ExitCode): $($asked.Stderr)); running" + $plan = [pscustomobject]@{ Run = $true; Reason = 'the earlier runs could not be listed' } + } + else { $json = ($asked.Stdout -join "`n") } + } + # Windows PowerShell 5.1 hands back a parsed array as ONE object, so it is enumerated to get the runs. + if ($null -ne $json -and $json.Trim().Length -gt 0) { + $parsed = $json | ConvertFrom-Json + $runs = @($parsed | ForEach-Object { $_ } | Where-Object { $null -ne $_ }) + } +} + +if ($null -eq $plan) { + $plan = Get-LongHaulPlan -EventName $EventName -Sha $Sha -CurrentRunId $CurrentRunId -Runs $runs +} + +$verdict = if ($plan.Run) { 'run' } else { 'skip' } +Write-Host "long-haul: $verdict -- $($plan.Reason)" +if ($GitHubOutput) { + [System.IO.File]::AppendAllText($GitHubOutput, "run=$($plan.Run.ToString().ToLowerInvariant())`nreason=$($plan.Reason)`n") +} +exit 0 diff --git a/tools/probation-common.ps1 b/tools/probation-common.ps1 new file mode 100644 index 000000000..3ecad40e7 --- /dev/null +++ b/tools/probation-common.ps1 @@ -0,0 +1,318 @@ +# Copyright (c) Mike Grier. +<# + Shared support for the probation tier's results, dot-sourced by + run-tier.ps1, publish-probation-results.ps1 and report-probation.ps1. Not a script. + + A probation test is one that has never run anywhere, so it starts on probation and is + promoted to the long-haul tier once it has passed enough runs (DESIGN-NOTES.md, + "long-haul-tier"). These functions turn a tier run's libtest output into outcomes, keep + a record of each test's runs across runs, and report that record. The record is derived + data and is published to a branch of its own, `probation-results`; the decision is in + DESIGN-NOTES.md, "probation-results". + + The record, `results.json`: + + { "version": 1, "latestRun": "", "latestAt": "