`System.Net.NameResolution.Functional.Tests` - crashed with `Process terminated. Assertion failed.`

[radical]

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=421754
Build error leg or test failing: System.Net.NameResolution.Functional.Tests.WorkItemExecution
Pull request: #92703

Error Message

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

{
  "ErrorMessage": "",
  "ErrorPattern": "System.Net.NameResolution.Functional.Tests.*\n.*Process terminated. Assertion failed.",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: 🔎
Result validation: ⚠️ Provided build not found. Provide a valid build in the "Build: 🔎" line.
Validation performed at: 11/10/2023 10:50:38 PM UTC

Report

Summary

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

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

Issue Details

---

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=421754
Build error leg or test failing: System.Net.NameResolution.Functional.Tests.WorkItemExecution
Pull request: #92703

Error Message

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

{
  "ErrorMessage": "",
  "ErrorPattern": "System.Net.NameResolution.Functional.Tests.*Process terminated. Assertion failed.",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: 🔎 https://dev.azure.com/dnceng-public/public/_build/results?buildId=421754
Error message validated: System.Net.NameResolution.Functional.Tests.*Process terminated. Assertion failed.
Result validation: ❌ Known issue did not match with the provided build.
Validation performed at: 9/28/2023 9:28:38 PM UTC

Author:	radical
Assignees:	-
Labels:	area-System.Net, blocking-clean-ci, untriaged, Known Build Error, needs-area-label
Milestone:	-

[danmoseley]

Process terminated. Assertion failed.
   at System.Net.NetEventSource.Info(String thisOrContextObject, String memberName, String message) in /_/src/libraries/Common/src/System/Net/Logging/NetEventSource.Common.cs:line 80
   at System.Net.NetEventSource.Info(Object thisOrContextObject, FormattableString formattableString, String memberName) in /_/src/libraries/Common/src/System/Net/Logging/NetEventSource.Common.cs:line 67
   at System.Net.Dns.<>c.<GetHostEntryAsync>b__6_0(Task`1 t, Object s) in /_/src/libraries/System.Net.NameResolution/src/System/Net/Dns.cs:line 126
   at System.Threading.Tasks.ContinuationTaskFromResultTask`1.InnerInvoke() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/TaskContinuation.cs:line 140

There is a dump

[danmoseley]

        [Event(InfoEventId, Level = EventLevel.Informational, Keywords = Keywords.Default)]
        private void Info(string thisOrContextObject, string? memberName, string? message)
        {
            Debug.Assert(IsEnabled()); //<<<<<

This is on a Threadpool thread - some race here?

@MihaZupan

[MihaZupan]

This could happen if one thread was disabling the specific EventSource as another is executing the above Info call.
The place that hit the assert just has a particularly large window between checking IsEnabled and the call to log.

The only tests using this EventSource are these:

runtime/src/libraries/System.Net.NameResolution/tests/FunctionalTests/LoggingTest.cs

Lines 31 to 97 in 7d9b92d

	[ConditionalFact]
	public void GetHostEntry_InvalidHost_LogsError()
	{
	using (var listener = new TestEventListener("Private.InternalDiagnostics.System.Net.NameResolution", EventLevel.Error))
	{
	var events = new ConcurrentQueue<EventWrittenEventArgs>();
	listener.RunWithCallback(ev => events.Enqueue(ev), () =>
	{
	try
	{
	Dns.GetHostEntry(Configuration.Sockets.InvalidHost);
	throw new SkipTestException("GetHostEntry should fail but it did not.");
	}
	catch (SocketException e) when (e.SocketErrorCode == SocketError.HostNotFound)
	{
	}
	catch (Exception e)
	{
	throw new SkipTestException($"GetHostEntry failed unexpectedly: {e.Message}");
	}
	});
	Assert.True(events.Count > 0, "events.Count should be > 0");
	foreach (EventWrittenEventArgs ev in events)
	{
	Assert.True(ev.Payload.Count >= 3);
	Assert.NotNull(ev.Payload[0]);
	Assert.NotNull(ev.Payload[1]);
	Assert.NotNull(ev.Payload[2]);
	}
	}
	}
	[ConditionalFact]
	public async Task GetHostEntryAsync_InvalidHost_LogsError()
	{
	using (var listener = new TestEventListener("Private.InternalDiagnostics.System.Net.NameResolution", EventLevel.Error))
	{
	var events = new ConcurrentQueue<EventWrittenEventArgs>();
	await listener.RunWithCallbackAsync(ev => events.Enqueue(ev), async () =>
	{
	try
	{
	await Dns.GetHostEntryAsync(Configuration.Sockets.InvalidHost).ConfigureAwait(false);
	throw new SkipTestException("GetHostEntryAsync should fail but it did not.");
	}
	catch (SocketException e) when (e.SocketErrorCode == SocketError.HostNotFound)
	{
	await WaitForErrorEventAsync(events);
	}
	catch (Exception e)
	{
	throw new SkipTestException($"GetHostEntryAsync failed unexpectedly: {e.Message}");
	}
	}).ConfigureAwait(false);
	Assert.True(events.Count > 0, "events.Count should be > 0");
	foreach (EventWrittenEventArgs ev in events)
	{
	Assert.True(ev.Payload.Count >= 3);
	Assert.NotNull(ev.Payload[0]);
	Assert.NotNull(ev.Payload[1]);
	Assert.NotNull(ev.Payload[2]);
	}
	}

They should be using RemoteExecutor instead.