Read acceptance-test binlogs behind a lock - #10658
Conversation
Serialization.Read from MSBuild.StructuredLogger is not safe to call concurrently in a cold process, and both acceptance suites parallelize at method level, so the first overlapping reads race on the library's lazy static initialization. A read that loses the race does not throw, it returns a Build whose only children are an error reading "Error when opening the log file." and a warning, with no build content underneath. Positive assertions over that tree then fail for no product reason, and Assert.DoesNotContain passes vacuously. Add BinlogReader next to AcceptanceAssert, take a process-wide lock around the read, and route all 15 call sites through it. When the tree still looks unusable the helper fails with the binlog path, its size on disk and the swallowed error text, instead of handing back an empty Build. Reading twelve real binlogs from 25 cold processes gives 10 empty reads out of 300 without the lock and 0 out of 300 with it. The lock costs about 270ms across twelve reads. 🤖
There was a problem hiding this comment.
Pull request overview
Serializes StructuredLogger binlog reads to prevent flaky acceptance-test results caused by concurrent initialization.
Changes:
- Adds
BinlogReaderwith locking, retries, and diagnostic validation. - Routes all 15 binlog reads through the helper.
- Shares the helper with both acceptance-test suites.
Reviewed changes
Copilot reviewed 7 out of 7 changed files in this pull request and generated no comments.
Show a summary per file
| File | Description |
|---|---|
SdkTests.cs |
Uses synchronized binlog reading. |
RunnerTests.cs |
Uses synchronized binlog reading. |
MSTest.Acceptance.IntegrationTests.csproj |
Links the shared helper. |
PackagedApp.MSBuildRegistration.cs |
Uses synchronized binlog reading. |
MSBuildTests.GenerateEntryPoint.cs |
Migrates all binlog reads to the helper. |
MSBuild.KnownExtensionRegistration.cs |
Uses synchronized binlog reading. |
Helpers/BinlogReader.cs |
Implements locked reads and invalid-tree diagnostics. |
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
This comment has been minimized.
This comment has been minimized.
![github-actions[bot]](https://avatars.githubusercontent.com/in/15368?s=60&v=4){kind=small}
This comment has been minimized.
This comment has been minimized.
With the lock held a retry can only re-read the same file and get the same answer, so the loop never did anything. On a binlog that is genuinely unreadable it read a large file three times while holding the lock, and every other test waited for it. The corruption check stays and now throws on the first read. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 7 out of 7 changed files in this pull request and generated no new comments.
Suppressed comments (1)
test/IntegrationTests/Microsoft.Testing.Platform.Acceptance.IntegrationTests/Helpers/BinlogReader.cs:72
AddItemis not a validity marker for a binlog: a readable project can legitimately perform no item additions (for example, a minimal project or a build that fails before item evaluation). This check would therefore turn a successful parse into an infrastructure failure. Check for the project hierarchy, or only the documented error-tree shape, instead.
: build.FindFirstDescendant<SL.AddItem>() is null
? "The tree holds no AddItem nodes at all, which no real build produces."
🧵 Parallel-safety audit — PR #10658Parallelization — one row per test assembly touched by this PR:
Findings: A (global-state) Top actions (by expected value):
Info
No Critical/High/Warning findings. This PR eliminates a real cross-test race under Advisory only — heuristic, non-blocking. Re-run with
|
🧪 Expert test review — PR #10658This PR is a mechanical reliability fix, not new test authorship: it adds a
No inline suggestions were posted: every touched test line is a like-for-like replacement of This advisory comment was generated automatically. Grades are heuristic and informational — they do not block merging. Re-run with
|
Serialization.Readfrom MSBuild.StructuredLogger is not safe to call concurrently in a cold process, and both acceptance suites parallelize at method level, so the first overlapping reads race on the library's lazy static initialization. A read that loses the race does not throw, it returns aBuildwhose only children are an error reading "Error when opening the log file." and a warning, with no build content underneath.This turned an official main build red on
EnableMSTestRunner_True_Will_Run_Standalone. The binlog on disk was fine, the read was not, reading the same file serially finds exactly theProjectCapabilitynode the assertion was looking for. The same race also letsAssert.DoesNotContainover a binlog pass on an empty tree, so it has been silently weakening those assertions as well.Adds
BinlogReadernext toAcceptanceAssert, takes a process-wide lock around the read, and routes all 15 call sites through it. If the tree still looks unusable the helper now fails with the binlog path, its size on disk and the swallowed error text, instead of leaving the test to reportnotExpected: 0 / actual: 0.Reading twelve real binlogs from 25 cold processes gives 10 empty reads out of 300 without the lock and 0 out of 300 with it. The lock costs about 270ms across twelve reads.
Verified:
build.cmd -pack -c Releasepasses, and both acceptance suites pass apart from net462, NativeAOT and vstest.console failures that reproduce the same way on unmodified main.🤖