Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
15 commits
Select commit Hold shift + click to select a range
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,77 @@
using System;
using System.Threading.Tasks;
using FluentAssertions;
using Microsoft.VisualStudio.TestTools.UnitTesting;

namespace TaskMaster.Test.Ribbon
{
/// <summary>
/// Regression for issue #942: the prime-fault report must precede the in-flight marker's
/// removal, so any caller that observes the marker absent observes a report that has already
/// completed. A third partial of the coordinator fixture, so the private <c>Harness</c> and
/// <c>LoggedError</c> types are reused; the primary file is close to the 500-line ceiling.
/// </summary>
public partial class EngineToggleStateCoordinatorTests
{
#region Issue #942 — prime fault report precedes marker removal

/// <summary>
/// Regression for issue #942. Invariant: for a key whose prime did not run to completion,
/// the in-flight marker is present until the fault report has returned. The discriminator
/// is the prime handle observed from inside the error-log sink: it is the still-registered
/// continuation under the fixed order and <see cref="Task.CompletedTask"/> under the
/// defective one, on the same thread, so the outcome is a function of program order
/// rather than of scheduling. No sleep, delay, gate, timer or parallelism attribute.
/// </summary>
[TestMethod]
public async Task GetPressed_WhenPrimeFaults_PrimeHandleStaysRegisteredUntilFaultIsLogged()
{
// Arrange
var harness = new Harness();
var probe = new TaskCompletionSource<bool>();
var failure = new InvalidOperationException("configuration load failed");
harness.Engines.Setup(x => x.EngineActiveAsync(SpamEngine)).Returns(probe.Task);
harness.Coordinator.GetPressed(SpamEngine);
var prime = harness.Coordinator.GetPrimeTask(SpamEngine);
Task handleSeenBySink = null;
harness.OnLogError = (_, _) =>
handleSeenBySink = harness.Coordinator.GetPrimeTask(SpamEngine);

// Act
probe.SetException(failure);
await prime;

// Assert
// If this test passes without the production reorder in CompletePrime, the negative
// control has lost isolation: investigate the run rather than accepting it.
handleSeenBySink
.Should()
.BeSameAs(
prime,
"while the fault is being reported the prime handle "
+ "must still be registered, so a caller that fetches it "
+ "after the trigger awaits the report"
);
harness.Errors.Should().ContainSingle("a prime fault is reported exactly once");
harness
.Errors[0]
.Message.Should()
.Contain(SpamEngine, "the message names the engine whose prime failed");
harness
.Errors[0]
.Exception.Should()
.BeSameAs(failure, "the sink receives the injected exception unchanged");
harness.Invalidations.Should().BeEmpty("a failed prime leaves nothing to display");
harness
.Coordinator.GetPrimeTask(SpamEngine)
.Should()
.BeSameAs(
Task.CompletedTask,
"once the handle has completed the marker has been cleared "
+ "so a later read may re-prime"
);
}

#endregion Issue #942 — prime fault report precedes marker removal
}
}
13 changes: 12 additions & 1 deletion TaskMaster.Test/Ribbon/EngineToggleStateCoordinatorTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -412,7 +412,11 @@ internal Harness()
OnInvalidate?.Invoke(controlId);
},
message => Notifications.Add(message),
(message, exception) => Errors.Add(new LoggedError(message, exception))
(message, exception) =>
{
Errors.Add(new LoggedError(message, exception));
OnLogError?.Invoke(message, exception);
}
);
}

Expand All @@ -433,6 +437,13 @@ internal Harness()
/// </summary>
internal Action<string> OnInvalidate { get; set; }

/// <summary>
/// An optional extra observer invoked from inside the error-log sink, immediately after
/// the error has been appended to <see cref="Errors"/>, so a test can probe coordinator
/// state at the exact moment a fault is reported.
/// </summary>
internal Action<string, Exception> OnLogError { get; set; }

internal List<string> Invalidations { get; } = new List<string>();

internal List<string> Notifications { get; } = new List<string>();
Expand Down
1 change: 1 addition & 0 deletions TaskMaster.Test/TaskMaster.Test.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -357,6 +357,7 @@
<Compile Include="Ribbon\RibbonExplorerXmlTests.cs" />
<Compile Include="Ribbon\SpamManagerResetGateTests.cs" />
<Compile Include="Ribbon\EngineToggleStateCoordinatorTests.Race.cs" />
<Compile Include="Ribbon\EngineToggleStateCoordinatorTests.PrimeFaultOrdering.cs" />
<Compile Include="Ribbon\EngineTogglePressedStateCacheTests.cs" />
<Compile Include="Properties\AssemblyInfo.cs" />
</ItemGroup>
Expand Down
15 changes: 10 additions & 5 deletions TaskMaster/Ribbon/EngineToggleStateCoordinator.cs
Original file line number Diff line number Diff line change
Expand Up @@ -242,7 +242,9 @@ internal async Task ExecuteToggleAsync(string engineName)
/// <returns>
/// The prime task, or <see cref="Task.CompletedTask"/> when no prime has been started for
/// the key. The returned task never faults: a prime fault is observed inside the prime
/// itself and reported through <c>logError</c>.
/// itself and reported through <c>logError</c>. For a key whose prime did not run to
/// completion, the marker is cleared only after that report has returned, so a caller that
/// receives <see cref="Task.CompletedTask"/> can rely on the fault having been reported.
/// </returns>
internal Task GetPrimeTask(string engineName)
{
Expand Down Expand Up @@ -326,8 +328,9 @@ string controlId

/// <summary>
/// Observes the outcome of a prime. On any outcome other than ran-to-completion the cache
/// is left unset — so the key still reports unchecked — the in-flight marker is cleared so
/// a later read may re-prime, and the failure is reported through <c>logError</c>.
/// is left unset — so the key still reports unchecked — the failure is reported through
/// <c>logError</c>, and only then is the in-flight marker cleared so a later read may
/// re-prime.
/// </summary>
/// <remarks>
/// The status is tested rather than the exception. A CANCELED task carries a null
Expand All @@ -345,13 +348,15 @@ private void CompletePrime(Task completed, string engineName)
return;
}

_primeTasks.TryRemove(engineName, out _);

var failure =
(Exception)completed.Exception?.GetBaseException()
?? new TaskCanceledException(completed);

// Report-then-clear is load-bearing: the marker stays registered until the report has
// returned, so a caller that observes the marker absent — including one that fetched the
// prime handle after the fault — is guaranteed the fault has already been reported.
_logError(BuildPrimeFailedMessage(engineName), failure);
_primeTasks.TryRemove(engineName, out _);
}

/// <summary>
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,50 @@
# Code Review — engine-toggle-prime-fault-logging-test-races (Issue #942)

- Branch: `bug/engine-toggle-prime-fault-logging-test-races-942` against base `231e1c0b55105aeb626bf5a6e8d0266a567cacad`
- Review date label: 2026-09-30T08-30 (assigned without a clock; later than every executor evidence label)
- Files reviewed in full: `TaskMaster/Ribbon/EngineToggleStateCoordinator.cs`, `TaskMaster.Test/Ribbon/EngineToggleStateCoordinatorTests.cs`, `TaskMaster.Test/Ribbon/EngineToggleStateCoordinatorTests.PrimeFaultOrdering.cs`, `TaskMaster.Test/TaskMaster.Test.csproj` (the three coordinator `Compile Include` lines), plus the unchanged `EngineToggleStateCoordinatorTests.Race.cs` for context.
- Companion artifacts: `policy-audit.2026-09-30T08-30.md`, `feature-audit.2026-09-30T08-30.md`.

## Executive Summary

Verdict: **APPROVE**. 0 blocking findings. Five non-blocking entries (CR-1 to CR-5); none requires a change on this branch.

The fix is the smallest correct one for the defect the research record established. `CompletePrime` runs as a `ContinueWith` continuation on the default scheduler; before the change it removed the in-flight marker and then reported the fault, so a `GetPrimeTask` call issued after the trigger could observe `Task.CompletedTask` while the report was still pending on a pool thread. The change moves `_primeTasks.TryRemove` after `_logError`, which makes the marker's absence imply a completed report. That is sufficient for the flaky test's observation path because `ConcurrentDictionary.TryRemove` publishes under a lock and `TryGetValue` reads with a volatile read, so a caller that observes the removal acquires the `Errors.Add` the sink performed before it. The regression test discriminates on the marker state at the moment the sink runs, on the same thread that will perform the removal, so its outcome depends on program order and not on scheduling; the fail-before evidence shows it failing deterministically on the `BeSameAs` assertion against the byte-identical base production file.

The success path is untouched (early return before any marker or sink access), the cancellation path still synthesizes `TaskCanceledException`, the type keeps exactly one `catch` and one `lock`, and no seam, constructor parameter or public surface was added.

## Findings Table

| Severity | File | Location | Finding | Recommendation | Rationale | Evidence |
|---|---|---|---|---|---|---|
| Low (non-blocking, follow-up) | `TaskMaster/Ribbon/EngineToggleStateCoordinator.cs` | `StartPrimeIfNeeded` lines 271–279 and `CompletePrime` line 359 | Hazard B (NB-2 of the #735 review) remains: `_primeTasks[engineName] = StartObservedPrime(...)` stores the continuation after `StartObservedPrime` returns, and the continuation is queued to the pool with `TaskContinuationOptions.None`. If the prime completes synchronously in a non-success state, `CompletePrime` can execute `TryRemove` before the assignment lands, leaving a completed handle registered for the rest of the session. The reorder neither widens nor narrows the window. | Track under the separately promoted issue (the spec records it as promoted by the coordinator; the session checkout's branch name indicates #944). A fix would take `_primeGate` inside `CompletePrime` or register before starting; both are explicitly out of scope here. | Declared non-goal in `spec.md` "Scope & Non-Goals" and plan D-1; the caller instructed it be listed, not blocked. | Direct read of lines 263–305 and 344–360; research record section 6 "Rejected alternatives". |
| Low (non-blocking, latent) | `TaskMaster/Ribbon/EngineToggleStateCoordinator.cs` | `CompletePrime` lines 358–359 | A throwing error sink now leaves the in-flight marker registered as well as faulting the continuation (before the change it only faulted the continuation, which `StartObservedPrime`'s remarks say "always completes successfully"). The production sink is `logger.Error(message, exception)` (log4net), which does not throw on appender failure, so the path is unreachable today. | No change on this branch. If a sink that can throw is ever injected, wrap the report in `try { _logError(...) } finally { _primeTasks.TryRemove(...) }` so the marker is always cleared; the spec records this as an optional hardening and a non-goal. | The trade is documented in `spec.md` "Error handling and logging updates" and "Risks & Mitigations"; adding `try`/`finally` now would violate AC1's "no `try` … is added" clause. | Direct read; `RibbonController.EngineCommands.cs` wiring per plan fact 5 (unchanged on this branch). |
| Informational | `TaskMaster/Ribbon/EngineToggleStateCoordinator.cs` | `CompletePrime` lines 355–359 | A `getPressed` poll that arrives between the report and the removal now sees the marker present and does not re-prime on that poll; the next poll re-primes. Before the change the opposite window existed (a re-prime could start, and log, before the first fault's report), which could invert log order. The new window is bounded by one log call and nothing asserts on either. | None. | Behavior-preserving in every observable the tests and the ribbon depend on; the documented ordering guarantee is the stronger property. | `spec.md` "Data flow and validation changes"; direct read. |
| Informational | `TaskMaster.Test/Ribbon/EngineToggleStateCoordinatorTests.PrimeFaultOrdering.cs` | line 36 `Task handleSeenBySink = null;` | The local is initialised to `null` and written from the sink on a pool thread; the read after `await prime` is ordered by task completion. In a nullable-annotated file this would be `Task?`; none of the three partials carries `#nullable enable`, consistent with the sibling files and with the repository's per-file opt-in rule. | None; a nullable adoption of the fixture is outside this bug's scope. | Matches existing style (CLAUDE.md General 7.1). | Direct read; no `#nullable` in any touched file. |
| Informational | `TaskMaster.Test/Ribbon/EngineToggleStateCoordinatorTests.cs` | `Harness` line 445 | `OnLogError` is a settable, unguarded observer invoked from inside the sink. An observer that throws would fault the continuation the test awaits and surface as a test failure with the thrown exception, which is the correct failure mode for a test-only hook; it mirrors the pre-existing `OnInvalidate` hook exactly. | None. | Test-only surface, private nested type. | Direct read of lines 403–452. |

## Design and Correctness Review

- **Invariant statement.** The comment above `_logError` states the invariant in one sentence ("the marker stays registered until the report has returned, so a caller that observes the marker absent … is guaranteed the fault has already been reported"), and the `summary` of `CompletePrime` and the `returns` of `GetPrimeTask` both restate it. Comment explains why, not what (CLAUDE.md General 5.3).
- **Memory-model argument.** The spec's happens-before reasoning was checked against the code: the pool thread executes `Errors.Add` (inside `_logError`) then `TryRemove`; `TryRemove` acquires the bucket lock and writes with volatile semantics; the test thread's `TryGetValue` performs a volatile read. A test thread that sees the key absent therefore sees the appended error. The original reproduction test needs no change and now cannot observe an empty list.
- **Regression test discriminator.** `handleSeenBySink` is written from the sink, i.e. on the thread executing `CompletePrime`, at the moment `_logError` runs. Under the old order the sink runs after `TryRemove` and reads `Task.CompletedTask`; under the new order it reads the registered continuation. This is a function of statement order alone, which is what makes the fail-before result deterministic (24/1 every time, not intermittently) and the in-file comment about "loss of isolation" meaningful.
- **Cleanup discipline.** The new test ends with the marker cleared and no re-prime triggered (no `GetPressed` after the await), so the strict mock has exactly one expected call and no work is left in flight. The final `BeSameAs(Task.CompletedTask)` assertion doubles as the cleanup check.
- **Partial-class shape.** The new partial mirrors the Race partial: no `[TestClass]`, one region, the minimal `using` set (no `using Moq;` because Moq is not named directly, avoiding an unnecessary-using diagnostic). The csproj entry is required because the test project uses explicit compile items; the evidence proves the test executed (RESULT line), which is the only way to know a partial is compiled.
- **File sizes.** 420 / 470 / 77 lines, all under the 500-line ceiling; the primary fixture has 30 lines of headroom, which is why the third partial exists.
- **Unchanged neighbours confirmed.** `Race.cs` is untouched (diff-clean per `determinism-tokens.md` `NONGOAL_FILES_DIFF_EXIT=0`; the file read is consistent with the plan's fact 3). `GetPrimeTask` has no production caller (Grep over `TaskMaster/`).

## Test Quality Review

| Property | Assessment |
|---|---|
| Independence / isolation | Own harness, own mock, own completion source; no shared static state. |
| Determinism | No sleep, delay, retry, timeout, wall-clock, `[DoNotParallelize]`, blocking wait, temp file or scheduler seam (20-token census at 0 plus direct read). The outcome is program-order dependent only. |
| Failure diagnostics | Every assertion carries a reason; the `BeSameAs` failure text seen at fail-before names both the expected continuation type and the found `Task`, which is directly actionable. |
| Scenario coverage | Faulted path (new + original), canceled path (two Race tests), success early return (prime-success tests), key validation (existing). Complete for the changed method. |
| Original reproduction preserved | `GetPressed_WhenPrimeFaults_LogsErrorAndStillReturnsFalse` is byte-for-byte unchanged (method SHA equal at base and head) and passes in every post-fix run. |

## Non-Blocking Follow-ups

1. Hazard B (registration racing removal on a synchronous non-success prime) — separately promoted; not addressed here by design.
2. Optional `try`/`finally` hardening of the report-then-clear pair if a throwing error sink is ever injected — documented non-goal.
3. The two other production sites that discard fault-observing continuations (`AppEvents.ReadinessHookup.cs`, `OutlookFolderTreeService.cs`) noted in the spec — no test asserts on their logs; outside this defect.
Original file line number Diff line number Diff line change
@@ -0,0 +1,11 @@
# Bootstrap: dotnet-coverage global tool (issue 942)

Timestamp: 2026-09-30T07-26
Task: P0-T7
Command: pwsh -NoProfile -Command 'if (-not (Get-Command dotnet-coverage -ErrorAction SilentlyContinue)) { dotnet tool install --global dotnet-coverage }; "DOTNET_COVERAGE_RESOLVED=$($null -ne (Get-Command dotnet-coverage -ErrorAction SilentlyContinue))"; dotnet-coverage --version'
EXIT_CODE: 0

Output Summary:
- The tool was already resolvable; the guarded install did not run.
- DOTNET_COVERAGE_RESOLVED=True
- Version line: 18.10.0+f4cc39224845ffa74bf246c9da2399d50e5d6342
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
# Bootstrap: NuGet restore (issue 942)

Timestamp: 2026-09-30T07-25
Task: P0-T6
Command: pwsh -NoProfile -Command 'Set-Location -LiteralPath "WORKTREE"; $env:MSBUILDDISABLENODEREUSE = "1"; & .\scripts\vscode\Invoke-Restore.ps1; "RESTORE_EXIT=$LASTEXITCODE"; "PACKAGE_DIRS=..."; foreach ($proj in @("TaskMaster\TaskMaster.csproj", "TaskMaster.Test\TaskMaster.Test.csproj")) { ... "ANALYZER_MISSING $proj = $missing" }'
EXIT_CODE: 0

Output Summary:
- RESTORE_EXIT=0
- PACKAGE_DIRS=172
- ANALYZER_MISSING TaskMaster\TaskMaster.csproj = 0
- ANALYZER_MISSING TaskMaster.Test\TaskMaster.Test.csproj = 0
- Every analyzer Include of the two Write Set projects resolves relative to its own project directory; no ANALYZER PATH SKEW.
- Execution note: the restore script's console output was redirected to an ignored log under the repository coverage directory (it carries absolute host paths); the payload's gate lines above are unchanged.
Loading
Loading