Skip to content

fix(ribbon): report a prime fault before clearing its in-flight marker - #946

Merged
drmoisan merged 15 commits into
mainfrom
bug/engine-toggle-prime-fault-logging-test-races-942
Sep 30, 2026
Merged

drmoisan merged 15 commits into
mainfrom
bug/engine-toggle-prime-fault-logging-test-races-942

Conversation

@drmoisan

Copy link
Copy Markdown
Owner

Suggested title

fix(ribbon): report a prime fault before clearing its in-flight marker

Summary

  • EngineToggleStateCoordinator.CompletePrime now calls the injected error-log delegate before it removes the engine key from the in-flight prime dictionary. Previously the marker was removed first, so a caller that fetched the prime handle after the fault could receive Task.CompletedTask while the fault report was still pending on a thread-pool thread.
  • This removes the intermittent failure of GetPressed_WhenPrimeFaults_LogsErrorAndStillReturnsFalse seen on the required MSTest-with-coverage check (first observed on PR test(931): remove scheduler and file-handle dependence from breadcrumb thread-affinity and FileInfoWrapper tests #939). That test is left unchanged, byte for byte.
  • New deterministic regression test GetPressed_WhenPrimeFaults_PrimeHandleStaysRegisteredUntilFaultIsLogged, in a new third partial of the coordinator fixture. It observes the prime handle from inside the error-log sink, so its outcome depends on program order, not on scheduling.
  • The test fixture's Harness gains an optional OnLogError observer hook, following the existing OnInvalidate pattern.
  • Documentation on CompletePrime and GetPrimeTask now states the report-then-clear order and the guarantee it provides.

Why

The research record and spec in the feature folder established that the fault observer is inside the awaited task. The defect was the order of two statements inside that observer, not a missing await. TryRemove ran before _logError. A test thread that called GetPrimeTask after probe.SetException(...) could therefore observe the marker already gone, await a completed task, and assert on an empty error list while the pool thread was still reporting.

The invariant restored is: for a key whose prime did not run to completion, the in-flight marker is present until the fault report has returned. Any caller that observes the marker absent therefore observes a completed report.

What Changed

Production

  • TaskMaster/Ribbon/EngineToggleStateCoordinator.cs (+10 / -5):
    • _primeTasks.TryRemove(engineName, out _); moved to after _logError(BuildPrimeFailedMessage(engineName), failure);, with a three-line comment explaining why the order is load-bearing.
    • The summary on CompletePrime and the returns on GetPrimeTask are updated.
    • Unchanged: the early return on ran-to-completion, the base-exception unwrap, the synthesized TaskCanceledException, StartPrimeIfNeeded and its lock. No try, catch or lock was added.

Tests

  • TaskMaster.Test/Ribbon/EngineToggleStateCoordinatorTests.PrimeFaultOrdering.cs (new, 77 lines): one MSTest test using the existing strict Moq engines mock and FluentAssertions with reason strings, laid out as Arrange, Act, Assert.
  • TaskMaster.Test/Ribbon/EngineToggleStateCoordinatorTests.cs (+12 / -1): Harness.OnLogError hook, invoked immediately after the error is appended to Errors. The diff touches only the Harness type.
  • TaskMaster.Test/TaskMaster.Test.csproj (+1): explicit Compile Include for the new partial.

Docs and evidence

  • Feature folder docs/features/active/2026-09-29-engine-toggle-prime-fault-logging-test-races-942/ contains: research, spec, plan, Phase 0 to Phase 3 evidence projections, and the policy, code and feature audits.
  • docs/features/potential/promoted/2026-09-29-engine-toggle-prime-fault-logging-test-races.md: the promotion record, inherited from the promotion commit.

Architecture / How It Fits Together

GetPressed starts a prime through StartPrimeIfNeeded, which stores the ContinueWith continuation returned by StartObservedPrime. On completion, that continuation (CompletePrime) runs on the default scheduler. On any non-success outcome it now reports first, then clears the marker. GetPrimeTask returns the stored continuation while the marker is present, and Task.CompletedTask once it is cleared. The production sink is the log4net error call wired in RibbonController.EngineCommands.cs. That call is unchanged and does not re-enter the coordinator.

Verification

Completed (recorded in the feature folder evidence):

  • Fail-before (evidence/regression-testing/prime-fault-ordering-fail-before.md):
    • Setup: hook, new test and csproj entry present; production file byte-identical to the merge base.
    • Result: the coordinator fixture exits 1; 25 tests, 1 failed.
    • The new test failed on the same-instance assertion of the sink-observed handle; the message contains to refer to and must still be registered.
  • Pass-after (evidence/regression-testing/prime-fault-ordering-pass-after.md): exit 0, 25 of 25 passed, including both prime-fault tests and both cancellation tests. Re-confirmed on the rebuilt assembly in Phase 3.
  • Final toolchain pass (evidence/qa-gates/toolchain-final-pass.md), in CLAUDE.md order:
    • dotnet tool run csharpier format ., then dotnet tool run csharpier check .: no differences.
    • Analyzer rebuild msbuild TaskMaster.sln /t:Rebuild /m /p:Configuration=Debug "/p:Platform=Any CPU" /p:EnableNETAnalyzers=true /p:EnforceCodeStyleInBuild=true: exit 0, no skipped CoreCompile.
    • Nullable rebuild msbuild TaskMaster.sln /t:Rebuild /m /p:Configuration=Debug "/p:Platform=Any CPU" /p:TreatWarningsAsErrors=true: exit 0, no skipped CoreCompile.
    • Coverage-enabled test run: exit 0.
  • Coverage (evidence/qa-gates/coverage-post-change.md):
    • First-party lines: 85.32 percent baseline, 85.31 percent final.
    • First-party branches: 79.73 percent baseline, 79.72 percent final.
    • Lines-valid is identical at both stages (65736), so the denominators are comparable.
    • Coordinator file: 143 of 143 lines and 37 of 38 branches at both stages. Every line element in CompletePrime has at least 1 hit, including the moved TryRemove.
    • Route: the local run used the runner's own collector invocation, with four shell-icon test classes excluded because one of them fails on this workstation. CI runs those classes.
  • Footprint (evidence/qa-gates/footprint-scope.md): only the four code files, the feature folder and the inherited promotion record changed. The Race partial, the ribbon controller wiring and both run-settings files are untouched.
  • Feature review: 0 blocking findings. Policy audit PASS, code review APPROVE, feature audit PASS with 14 of 14 acceptance criteria.

Recommended:

  • Watch the required MSTest-with-coverage check on this PR and subsequent PRs for any recurrence in the coordinator test class.

Backward Compatibility / Migration Notes

None. CompletePrime and Harness are private. GetPrimeTask is internal and keeps its signature. No public API, configuration or data change.

Risks and Mitigations

  • Throwing error sink. A sink that throws would now leave the marker registered, in addition to faulting the continuation. The production sink is log4net's error method, which does not throw on appender failure. Hardening with try/finally is a documented non-goal.
  • Delayed re-prime. A getPressed poll that arrives during the log call sees the marker present and does not re-prime on that poll; the next poll does. The window is bounded by one log call.
  • Rollback. Revert the single fix commit.

Review Guide

  1. TaskMaster/Ribbon/EngineToggleStateCoordinator.cs: the CompletePrime reorder and the documentation.
  2. TaskMaster.Test/Ribbon/EngineToggleStateCoordinatorTests.PrimeFaultOrdering.cs: the regression test.
  3. TaskMaster.Test/Ribbon/EngineToggleStateCoordinatorTests.cs: the Harness hook.
  4. Evidence under evidence/regression-testing/ and evidence/qa-gates/. The plan file is large and mechanical.

Follow-ups

These are listed for the coordinator; none are filed from this branch:

  • Hazard B. When a prime completes synchronously in a non-success state, the prime marker's registration can race its removal. It is recorded as a spec non-goal, and the coordinator promotes it separately.
  • Optional try/finally hardening of the log call, needed only if a throwing sink is ever introduced.
  • Two other production sites that discard fault-observing continuations: AppEvents.ReadinessHookup.cs and OutlookFolderTreeService.cs. No test asserts on their logs, so they are outside this defect.
  • Local workstation failure of one shell-icon test (an invalid Win32 icon handle), which forced the local coverage route to exclude four classes. It is pre-existing and environmental.

GitHub Auto-close

🤖 Generated with Claude Code

drmoisan and others added 15 commits September 29, 2026 23:08
…ging test race

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
…ne-toggle-prime-fault-logging-test-races-942
…on C1)

Co-Authored-By: Claude Opus 5.5 noreply@anthropic.com
…orrection C2)

Co-Authored-By: Claude Opus 5.5 noreply@anthropic.com
…light delta R2-D1)

Co-Authored-By: Claude Opus 5.5 noreply@anthropic.com
…ering fix

Co-Authored-By: Claude Opus 5.5 noreply@anthropic.com
…r (issue 942)

Co-Authored-By: Claude Opus 5.5 noreply@anthropic.com
…idence

Co-Authored-By: Claude Opus 5.5 noreply@anthropic.com
Co-Authored-By: Claude Opus 5.5 noreply@anthropic.com
Co-Authored-By: Claude Opus 5.5 noreply@anthropic.com
@drmoisan
drmoisan merged commit b305903 into main Sep 30, 2026
7 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Bug: engine-toggle-prime-fault-logging-test-races

1 participant