Skip to content

Bug: timeoutafter-tests-race-real-wall-clock-deadline #516

Closed

Description

@drmoisan
  • Work Mode: full-bug

Summary

UtilitiesCS.Test/Threading/TimeOutTask_AdditionalTests.cs contains tests that race a real 100 ms wall-clock deadline against exception propagation. On a loaded CI runner the deadline can win, so the test observes TimeoutException instead of the expected InvalidOperationException and fails. This is a flaky test, not a product defect, and it fails CI on unrelated pull requests.

Environment

  • OS/version: windows-latest GitHub Actions runner (also reproducible in principle on any loaded machine)
  • Runtime: .NET Framework 4.8.1, MSTest via vstest.console.exe
  • Command/flags used: the CI job "Format, build, analyze, and test", which runs the MSTest suite with coverage
  • Data source or fixture: UtilitiesCS.Test/Threading/TimeOutTask_AdditionalTests.cs

Steps to Reproduce

  1. Open any pull request that does not touch UtilitiesCS.Test/Threading/ and let CI run the full MSTest suite.
  2. Observe the run under runner load.
  3. Compare against a local run of the same test on an idle machine.

Observed on 2026-08-08 in run 31275248280 for PR #514 (issue #438): 6350 total, 6349 passed, 1 failed.

Expected Behavior

The test deterministically asserts that a source exception set after TimeoutAfter is attached propagates as InvalidOperationException, independent of machine load. Per .claude/rules/general-unit-test.md, tests must be deterministic and real wall-clock waits are a banned API in test code.

Actual Behavior

TimeoutAfter_GenericTask_ShouldPropagateFaultedSourceException_WhenSourceFaultsLater failed on the CI runner with:

System.TimeoutException: The operation has timed out.

The same test passes locally on an idle machine on the same commit, confirming a load-dependent race rather than a functional regression.

The test attaches a 100 ms timeout and then sets the exception:

var source = new TaskCompletionSource<int>();
var proxy = source.Task.TimeoutAfter(100);
source.SetException(new InvalidOperationException("boom"));
Func<Task> act = async () => await proxy;
await act.Should().ThrowAsync<InvalidOperationException>().WithMessage("boom");

If the runner does not schedule the continuation within 100 ms, the timeout path completes first and the assertion sees the wrong exception type.

Logs / Screenshots

Note the reported duration of 174 ms against a 100 ms deadline, which is the race made visible.

Impact / Severity

  • Blocker
  • High
  • Medium
  • Low

This fails CI on pull requests that have nothing to do with the code under test, and the only available remedy today is to re-run the job. That is corrosive in two ways: it blocks unrelated work, and it normalizes re-running a red suite until it turns green - the exact habit that allows a genuine regression to be waved through. The sibling test TimeoutAfter_NonGenericTask_ShouldPropagateFaultedSourceException_WhenSourceFaultsLater has the identical structure and the same latent failure mode.

Source

From: docs/features/potential/2026-08-08-timeoutafter-tests-race-real-wall-clock-deadline.md

Activity

  1. drmoisan commented on Sep 2, 2026

    @drmoisan
    OwnerAuthor

    Closing as completed. Delivered by commits 2b8ff3ef ("fix(tests): remove wall-clock race in TimeOutTask proxy-propagation tests") and d208fa68 ("fix(tests): drive TimeoutAfter timeout from an injectable TimeProvider seam"), merged into main via PR #552.

    Confirmed directly against origin/main:UtilitiesCS.Test/Threading/TimeOutTask_AdditionalTests.cs: TimeoutAfter_GenericTask_ShouldPropagateFaultedSourceException_WhenSourceFaultsLater and its three sibling tests now call source.Task.TimeoutAfter(100, FrozenClock()), where FrozenClock() returns a Microsoft.Extensions.Time.Testing.FakeTimeProvider that is never advanced. UtilitiesCS/Threading/TimeOutTask.cs now exposes TimeoutAfter overloads that take an optional TimeProvider (defaulting to TimeProvider.System) and arm the timeout via TimeProvider.CreateTimer instead of a raw System.Threading.Timer. There is no longer a real 100 ms wall-clock wait racing exception propagation; the timer cannot fire because the injected clock is frozen, so the test result no longer depends on runner load. Two positive-control tests were also added that advance the fake clock past the deadline to prove the seam is wired correctly.

    Verified during a full-repo bug sweep (2026-09-02). No branch or PR remains to ship; this was left open only as bookkeeping.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions