ProcessThreadTests.TestStartTimeProperty failure in CI

[jkotas]

    System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty [FAIL]
      Assert.Single() Failure: The collection did not contain any matching items
      Expected:   (predicate expression)
      Collection: [System.Diagnostics.ProcessThread, System.Diagnostics.ProcessThread, System.Diagnostics.ProcessThread, System.Diagnostics.ProcessThread, System.Diagnostics.ProcessThread, ···]
      Stack Trace:
        /_/src/libraries/System.Diagnostics.Process/tests/ProcessThreadTests.cs(156,0): at System.Diagnostics.Tests.ProcessThreadTests.<>c__DisplayClass4_2.<TestStartTimeProperty>b__0()
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs(2396,0): at System.Threading.Tasks.Task.InnerInvoke()
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs(2384,0): at System.Threading.Tasks.Task.<>c.<.cctor>b__292_0(Object obj)
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs(179,0): at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
        --- End of stack trace from previous location ---
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs(203,0): at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs(2342,0): at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)
        --- End of stack trace from previous location ---
        /_/src/libraries/System.Diagnostics.Process/tests/ProcessThreadTests.cs(149,0): at System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty()
        --- End of stack trace from previous location ---

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=755830
Build error leg or test failing: System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty
Pull request: #105519

Error Message

Fill the error message using step by step known issues guidance.

{
  "ErrorMessage": ["System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty [FAIL]","The collection did not contain any matching items"],
  "ErrorPattern": "",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: 🔎 https://dev.azure.com/dnceng-public/public/_build/results?buildId=755830
Error message validated: [System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty [FAIL] The collection did not contain any matching items]
Result validation: ✅ Known issue matched with the provided build.
Validation performed at: 7/26/2024 12:06:54 AM UTC

Report

Build	Definition	Test	Pull Request
1342756	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#115996
1332497	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#125022
1326378	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#124923
1315488	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#124834
1313486	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#124834
1308905	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#124203
1306012	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#124740

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
1	1	7

[dotnet-policy-service]

Tagging subscribers to this area: @dotnet/area-system-diagnostics-process
See info in area-owners.md if you want to be subscribed.

[jozkee]

#104972 was an attempt to fix it but looks like ProcessInfo.Threads is not being Refresh()'d properly.

[adamsitnik]

I wonder why it fails only on Mono?

[kuba1]

I've looked into this test but couldn't find anything obvious. That's not surprising since the test fails only occasionally.
So my guess is that there is either something wrong with the runners or there is some race condition in the code.

The fact that it seems to fail only on Mono would suggest that it might be a race condition that is more likely (or only possible) to occur on Mono (might also be a problem with Mono, I suppose).

My usual approach to an issue like this is to add as much logging into the test as possible and wait till it fails (preferably a couple times). The goal would be to find out exactly why it fails (is the new thread's id missing from the list of process threads, or something else), whether the reason is always the same or different etc. Hope is that with this additional data, it's going to be possible to figure out what's wrong.

I proposed that for TimeInQueue_RecordedForNewConnectionsOnly in #124740 and I could do that for this test also. I would modify the PR to only print out this additional logging if the test fails.

I'm on Fedora 42.

[danmoseley]

Analysis

The test's second half starts a LongRunning task (dedicated OS thread), then immediately does p.Refresh() followed by Assert.Single(p.Threads, t => t.Id == newThreadId). On Linux, p.Threads enumerates /proc/self/task/ — there's a known small window after thread creation where the new thread's /proc entry isn't visible yet.

PR #104972 (which fixed #103448) improved correctness by matching the exact thread ID instead of picking the newest-by-StartTime, but this made the test stricter: the /proc visibility race now causes a hard Assert.Single failure instead of silently matching a wrong thread.

The Mono-only pattern is consistent with Mono's thread startup having different timing that widens this window.

Suggested fix

Replace the single-shot Assert.Single with a retry loop that re-calls Refresh(), giving /proc time to reflect the new thread:

await Task.Factory.StartNew(() =>
{
    int newThreadId = GetCurrentThreadId();

    ProcessThread newThread = null;
    for (int i = 0; i < 10 && newThread is null; i++)
    {
        if (i > 0) Thread.Sleep(100);
        p.Refresh();
        newThread = p.Threads.Cast<ProcessThread>()
            .FirstOrDefault(t => t.Id == newThreadId);
    }

    Assert.NotNull(newThread);
    Assert.InRange(newThread.StartTime.ToUniversalTime(),
        curTime - allowedWindow,
        DateTime.Now.ToUniversalTime() + allowedWindow);
}, CancellationToken.None, TaskCreationOptions.LongRunning,
   TaskScheduler.Default);

This is low-risk — it preserves the exact-ID matching from #104972 while tolerating the /proc propagation delay. If the root cause is something deeper (e.g., Mono returning incorrect thread IDs), the retry would still fail and surface that.

Happy to put up a PR for this.

[danmoseley]

@copilot prepare PR with fix as suggested in my comment immediately above. run relevant tests in a loop (ideally on Mono) before returning.