ProcessThreadTests.TestStartTimeProperty failed in CI

[stephentoub]

Build Information

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

Error Message

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

{
  "ErrorMessage": "ProcessThreadTests.TestStartTimeProperty",
  "ErrorPattern": "",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Exception Message
Assert.InRange() Failure: Value not in range
Range:  (2024-06-13T19:52:03.7272386Z - 2024-06-13T19:52:07.7320077Z)
Actual: 2024-06-13T19:51:56.0017534Z
CallStack
   at System.Diagnostics.Tests.ProcessThreadTests.<>c__DisplayClass4_2.<TestStartTimeProperty>b__0() in /_/src/libraries/System.Diagnostics.Process/tests/ProcessThreadTests.cs:line 154
   at System.Threading.Tasks.Task.InnerInvoke() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 2396
   at System.Threading.Tasks.Task.<>c.<.cctor>b__292_0(Object obj) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 2384
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs:line 179
--- End of stack trace from previous location ---
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs:line 203
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 2342
--- End of stack trace from previous location ---
   at System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty() in /_/src/libraries/System.Diagnostics.Process/tests/ProcessThreadTests.cs:line 148
--- End of stack trace from previous location ---

Known issue validation

Build: 🔎 https://dev.azure.com/dnceng-public/public/_build/results?buildId=707064
Error message validated: [ProcessThreadTests.TestStartTimeProperty]
Result validation: ✅ Known issue matched with the provided build.
Validation performed at: 6/13/2024 10:08:56 PM UTC

Report

Build	Definition	Test	Pull Request
749496	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#105209
744740	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#104972
737065	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#104437
735640	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty
733347	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#104562
731358	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#104437
730106	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#104328
728232	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#103444
724651	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#104173
722132	dotnet/runtime	System.Diagnostics.Tests.ProcessThreadTests.TestStartTimeProperty	#103915

Summary

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

[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]

Marking as runtime-mono as all failing legs are
net9.0-linux-Debug-x64-Mono_Interpreter_Debug or
net9.0-linux-Release-x64-Mono_Minijit_Release.

[danmoseley]

Increasing the tolerance for just those configurations is probably reasonable.

[jozkee]

@danmoseley this may be an actual bug in Process.Threads in mono. Looking at the failing code:
It is spawning a new thread with StartNew.
It is then taking the last thread in p.Threads
then checking that the thread's StartTime is close to a timestamp form when the test started (curTime).

runtime/src/libraries/System.Diagnostics.Process/tests/ProcessThreadTests.cs

Lines 148 to 160 in 8e6df8d

	await Task.Factory.StartNew(() =>
	{
	p.Refresh();
	try
	{
	var newest = p.Threads.Cast<ProcessThread>().OrderBy(t => t.StartTime.ToUniversalTime()).Last();
	Assert.InRange(newest.StartTime.ToUniversalTime(), curTime - allowedWindow, DateTime.Now.ToUniversalTime() + allowedWindow);
	}
	catch (InvalidOperationException)
	{
	// A thread may have gone away between our getting its info and attempting to access its StartTime
	}
	}, CancellationToken.None, TaskCreationOptions.LongRunning, TaskScheduler.Default);

As per the error:

Assert.InRange() Failure: Value not in range
Range:  (2024-06-13T19:52:03.7272386Z - 2024-06-13T19:52:07.7320077Z)
Actual: 2024-06-13T19:51:56.0017534Z

the Actual value is way off in the past (9 secs.), I would expect the tolerance to be there for when the new thread is way long in the future. I think this may be taking a wrong thread instead.

[adamsitnik]

I think this may be taking a wrong thread instead.

I've changed #104972 to get the current thread by matching the ID. PTAL @jozkee