Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Regression] [Product bug] Test failure: System.Net.Sockets.Tests.TelemetryTest.EventSource_SocketConnectFailure_LogsConnectFailed(useDnsEndPoint: True) #43931

Closed
v-haren opened this issue Oct 28, 2020 · 18 comments · Fixed by #45170 or #54071
Assignees
Labels
area-System.Net.Sockets bug disabled-test The test is disabled in source code against the issue regression-from-last-release test-run-core Test failures in .NET Core test runs
Milestone

Comments

@v-haren
Copy link

v-haren commented Oct 28, 2020

failed in job: runtime-libraries-coreclr outerloop 20201027.2

net6.0-Linux-Release-x64-CoreCLR_release-RedHat.7.Amd64.Open

Error message

Microsoft.DotNet.RemoteExecutor.RemoteExecutionException : Remote process failed with an unhandled exception.


Stack trace

Child exception:
  Xunit.Sdk.EqualException: Assert.Equal() Failure
Expected: 1
Actual:   2
   at System.Net.Sockets.Tests.TelemetryTest.VerifyStartStopEvents(ConcurrentQueue`1 events, Boolean connect, Int32 expectedCount) in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 396
   at System.Net.Sockets.Tests.TelemetryTest.VerifyConnectFailureEvents(ConcurrentQueue`1 events) in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 324
   at System.Net.Sockets.Tests.TelemetryTest.<>c.<<EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0>d.MoveNext() in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 203
--- End of stack trace from previous location ---
   at Microsoft.DotNet.RemoteExecutor.Program.Main(String[] args) in /_/src/Microsoft.DotNet.RemoteExecutor/src/Program.cs:line 65

Child process:
  System.Net.Sockets.Tests, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 System.Net.Sockets.Tests.TelemetryTest+<>c System.Threading.Tasks.Task <EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0(System.String, System.String)

Child arguments:
  Apm, True
@ghost
Copy link

ghost commented Oct 28, 2020

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

@Dotnet-GitSync-Bot Dotnet-GitSync-Bot added the untriaged New issue has not been triaged by the area owner label Oct 28, 2020
@v-haren
Copy link
Author

v-haren commented Oct 29, 2020

failed again in job: runtime-libraries-coreclr outerloop 20201028.2

failed test: System.Net.Sockets.Tests.TelemetryTest.EventSource_ConnectAsyncCanceled_LogsConnectFailed(connectMethod: "Task", useDnsEndPoint: True)

net6.0-Linux-Release-x64-CoreCLR_release-RedHat.7.Amd64.Open

Error message

Microsoft.DotNet.RemoteExecutor.RemoteExecutionException : Remote process failed with an unhandled exception.


Stack trace

Child exception:
  Xunit.Sdk.EqualException: Assert.Equal() Failure
Expected: 1
Actual:   2
   at System.Net.Sockets.Tests.TelemetryTest.VerifyStartStopEvents(ConcurrentQueue`1 events, Boolean connect, Int32 expectedCount) in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 396
   at System.Net.Sockets.Tests.TelemetryTest.VerifyConnectFailureEvents(ConcurrentQueue`1 events) in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 324
   at System.Net.Sockets.Tests.TelemetryTest.<>c.<<EventSource_ConnectAsyncCanceled_LogsConnectFailed>b__12_0>d.MoveNext() in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 316
--- End of stack trace from previous location ---
   at Microsoft.DotNet.RemoteExecutor.Program.Main(String[] args) in /_/src/Microsoft.DotNet.RemoteExecutor/src/Program.cs:line 65

Child process:
  System.Net.Sockets.Tests, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 System.Net.Sockets.Tests.TelemetryTest+<>c System.Threading.Tasks.Task <EventSource_ConnectAsyncCanceled_LogsConnectFailed>b__12_0(System.String, System.String)

Child arguments:
  Task, True

@karelz karelz added bug and removed untriaged New issue has not been triaged by the area owner labels Oct 29, 2020
@karelz karelz added this to the 6.0.0 milestone Oct 29, 2020
@karelz
Copy link
Member

karelz commented Oct 29, 2020

Triage: Likely a regression - started to fail more often after change in the area recently.

@MihaZupan
Copy link
Member

Kusto query I mentioned.

Initial failures on #43661

@MihaZupan MihaZupan assigned stephentoub and unassigned MihaZupan Nov 10, 2020
@stephentoub
Copy link
Member

@MihaZupan, I've been unsuccessful in reproing this locally on either Windows or Ubuntu. Were you able to repro it?

@wfurt
Copy link
Member

wfurt commented Nov 13, 2020

I see only 9 (2 debug, 9 release) failures in last 10 day. Only one failure with Task, 7 failures with APM.

Aside from the one above I see two other variants:

Child exception:
  Xunit.Sdk.ThrowsException: Assert.Throws() Failure
Expected: typeof(System.Exception)
Actual:   (No exception was thrown)
   at System.Net.Sockets.Tests.TelemetryTest.<>c__DisplayClass10_0.<<EventSource_SocketConnectFailure_LogsConnectFailed>b__2>d.MoveNext() in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 185
--- End of stack trace from previous location ---
   at System.Diagnostics.Tracing.TestEventListener.RunWithCallbackAsync(Action`1 handler, Func`1 body) in /_/src/libraries/Common/tests/System/Diagnostics/Tracing/TestEventListener.cs:line 109
   at System.Net.Sockets.Tests.TelemetryTest.<>c.<<EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0>d.MoveNext() in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 179
--- End of stack trace from previous location ---
   at Microsoft.DotNet.RemoteExecutor.Program.Main(String[] args) in /_/src/Microsoft.DotNet.RemoteExecutor/src/Program.cs:line 65

Child process:
  System.Net.Sockets.Tests, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 System.Net.Sockets.Tests.TelemetryTest+<>c System.Threading.Tasks.Task <EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0(System.String, System.String)

Child arguments:
  Sync, False

and


Child exception:
  System.Net.Internals.SocketExceptionFactory+ExtendedSocketException (00000001, 11): Resource temporarily unavailable
   at System.Net.Dns.GetHostEntryOrAddressesCore(String hostName, Boolean justAddresses, AddressFamily addressFamily) in /_/src/libraries/System.Net.NameResolution/src/System/Net/Dns.cs:line 385
   at System.Net.Dns.GetHostAddressesCore(String hostName, AddressFamily addressFamily) in /_/src/libraries/System.Net.NameResolution/src/System/Net/Dns.cs:line 369
   at System.Net.Dns.<>c.<GetHostEntryOrAddressesCoreAsync>b__33_0(Object s) in /_/src/libraries/System.Net.NameResolution/src/System/Net/Dns.cs:line 556
   at System.Threading.Tasks.Task`1.InnerInvoke() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Future.cs:line 506
   at System.Threading.Tasks.Task.<>c.<.cctor>b__278_0(Object obj) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 2359
   at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs:line 275
--- End of stack trace from previous location ---
   at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs:line 300
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 2321
--- End of stack trace from previous location ---
   at System.Net.Sockets.Tests.TelemetryTest.GetRemoteEndPointAsync(String useDnsEndPointString, Int32 port) in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 70
   at System.Net.Sockets.Tests.TelemetryTest.<>c.<<EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0>d.MoveNext() in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 173
--- End of stack trace from previous location ---
   at Microsoft.DotNet.RemoteExecutor.Program.Main(String[] args) in /_/src/Microsoft.DotNet.RemoteExecutor/src/Program.cs:line 65

Child process:
  System.Net.Sockets.Tests, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 System.Net.Sockets.Tests.TelemetryTest+<>c System.Threading.Tasks.Task <EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0(System.String, System.String)

Child arguments:
  Sync, False

@stephentoub
Copy link
Member

Thanks. Yeah, I just ran 8000 iterations on both Windows and Linux over the course of a few hours and couldn't get it to happen. Obviously it can, of course, or it wouldn't be happening sporadically in CI.

@v-haren
Copy link
Author

v-haren commented Nov 23, 2020

failed again in job: runtime-libraries-coreclr outerloop 20201122.2

failed test: System.Net.Sockets.Tests.TelemetryTest.EventSource_SocketConnectFailure_LogsConnectFailed(connectMethod: "Apm", useDnsEndPoint: True)

net6.0-Linux-Release-x64-CoreCLR_release-RedHat.7.Amd64.Open

Error message

Microsoft.DotNet.RemoteExecutor.RemoteExecutionException : Remote process failed with an unhandled exception.


Stack trace

Child exception:
  Xunit.Sdk.EqualException: Assert.Equal() Failure
Expected: 1
Actual:   2
   at System.Net.Sockets.Tests.TelemetryTest.VerifyStartStopEvents(ConcurrentQueue`1 events, Boolean connect, Int32 expectedCount) in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 396
   at System.Net.Sockets.Tests.TelemetryTest.VerifyConnectFailureEvents(ConcurrentQueue`1 events) in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 324
   at System.Net.Sockets.Tests.TelemetryTest.<>c.<<EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0>d.MoveNext() in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 203
--- End of stack trace from previous location ---
   at Microsoft.DotNet.RemoteExecutor.Program.Main(String[] args) in /_/src/Microsoft.DotNet.RemoteExecutor/src/Program.cs:line 65

Child process:
  System.Net.Sockets.Tests, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 System.Net.Sockets.Tests.TelemetryTest+<>c System.Threading.Tasks.Task <EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0(System.String, System.String)

Child arguments:
  Apm, True

@ManickaP
Copy link
Member

ManickaP commented Dec 4, 2020

It's still happening kusto for the last 10 days has 14 occurrences, including from yesterday (3.12.).

@MihaZupan could you give it another look please?

@ManickaP ManickaP reopened this Dec 4, 2020
@v-haren
Copy link
Author

v-haren commented Dec 8, 2020

failed again in job: runtime-libraries-coreclr outerloop 20201207.1

failed test: System.Net.Sockets.Tests.TelemetryTest.EventSource_ConnectAsyncCanceled_LogsConnectFailed(connectMethod: "Task", useDnsEndPoint: True)

net6.0-Linux-Release-x64-CoreCLR_release-RedHat.7.Amd64.Open

Error message

Microsoft.DotNet.RemoteExecutor.RemoteExecutionException : Remote process failed with an unhandled exception.


Stack trace

Child exception:
  Xunit.Sdk.EqualException: Assert.Equal() Failure
Expected: 1
Actual:   2
   at System.Net.Sockets.Tests.TelemetryTest.VerifyStartStopEvents(ConcurrentQueue`1 events, Boolean connect, Int32 expectedCount) in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 396
   at System.Net.Sockets.Tests.TelemetryTest.VerifyConnectFailureEvents(ConcurrentQueue`1 events) in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 324
   at System.Net.Sockets.Tests.TelemetryTest.<>c.<<EventSource_ConnectAsyncCanceled_LogsConnectFailed>b__12_0>d.MoveNext() in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 316
--- End of stack trace from previous location ---
   at Microsoft.DotNet.RemoteExecutor.Program.Main(String[] args) in /_/src/Microsoft.DotNet.RemoteExecutor/src/Program.cs:line 65

Child process:
  System.Net.Sockets.Tests, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 System.Net.Sockets.Tests.TelemetryTest+<>c System.Threading.Tasks.Task <EventSource_ConnectAsyncCanceled_LogsConnectFailed>b__12_0(System.String, System.String)

Child arguments:
  Task, True

@MihaZupan
Copy link
Member

MihaZupan commented Dec 14, 2020

Linking #44015 as caused by the same underlying issue.

That particular issue has been addressed by #45170.

@MihaZupan
Copy link
Member

MihaZupan commented Dec 14, 2020

Note that this issue is mentioning test failures for:

@ManickaP
Copy link
Member

@MihaZupan if there's another test reported under this issue feel free to extract it to its own issue and delete the comment. I've been doing that quite a bit lately.
Especially if we might disable the test.

@MihaZupan MihaZupan changed the title Test failure: System.Net.Sockets.Tests.TelemetryTest.EventSource_SocketConnectFailure_LogsConnectFailed(connectMethod: \"Apm\", useDnsEndPoint: True) Test failure: System.Net.Sockets.Tests.TelemetryTest.EventSource_SocketConnectFailure_LogsConnectFailed(useDnsEndPoint: True) Dec 14, 2020
@MihaZupan
Copy link
Member

Test disabled by #46031.

@MihaZupan MihaZupan added the disabled-test The test is disabled in source code against the issue label Dec 14, 2020
@karelz karelz changed the title Test failure: System.Net.Sockets.Tests.TelemetryTest.EventSource_SocketConnectFailure_LogsConnectFailed(useDnsEndPoint: True) [Regression] [Product bug] Test failure: System.Net.Sockets.Tests.TelemetryTest.EventSource_SocketConnectFailure_LogsConnectFailed(useDnsEndPoint: True) Dec 14, 2020
@karelz karelz added the os-linux Linux OS (any supported distro) label Dec 14, 2020
@stephentoub stephentoub removed their assignment Jan 5, 2021
@karelz karelz added the test-run-core Test failures in .NET Core test runs label Jun 8, 2021
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Jun 11, 2021
@MihaZupan MihaZupan added regression-from-last-release and removed os-linux Linux OS (any supported distro) labels Jun 18, 2021
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Jun 24, 2021
@mateoatr
Copy link
Contributor

mateoatr commented Jul 8, 2021

The test failed again in runtime-libraries-coreclr outerloop 20210707.3.

@antonfirsov
Copy link
Member

@karelz
Copy link
Member

karelz commented Jul 22, 2021

Test failures 5/22-7/22 (incl. PRs):

Day Run OS
7/7 Official run 5x failed -- Debian.9.Arm32.Open, Centos.8.Amd64.Open, Ubuntu.1804.Amd64.Open, Windows.10.Amd64.Server19H1.Open, Windows.7.Amd64.Open
7/8 Official run 2x failed -- Alpine.312.Amd64.Open, Ubuntu.1804.ArmArch.Open
7/21 PR #56102 3x failed -- RedHat.7.Amd64.Open, Fedora.32.Amd64.Open, Ubuntu.1604.Amd64.Open

@MihaZupan any ideas why there are these spikes in runs? Does the test depend on external server? Or is it sign that DNS was not working or something like that?

All 3 spikes above are the variant:

Child exception:
  Xunit.Sdk.ThrowsException: Assert.Throws() Failure
Expected: typeof(System.Exception)
Actual:   (No exception was thrown)
   at System.Net.Sockets.Tests.TelemetryTest.<>c__DisplayClass10_0.<<EventSource_SocketConnectFailure_LogsConnectFailed>b__2>d.MoveNext() in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 176
--- End of stack trace from previous location ---
   at System.Diagnostics.Tracing.TestEventListener.RunWithCallbackAsync(Action`1 handler, Func`1 body) in /_/src/libraries/Common/tests/System/Diagnostics/Tracing/TestEventListener.cs:line 118
   at System.Net.Sockets.Tests.TelemetryTest.<>c.<<EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0>d.MoveNext() in /_/src/libraries/System.Net.Sockets/tests/FunctionalTests/TelemetryTest.cs:line 170
--- End of stack trace from previous location ---
   at Microsoft.DotNet.RemoteExecutor.Program.Main(String[] args) in /_/src/Microsoft.DotNet.RemoteExecutor/src/Program.cs:line 65

Child process:
  System.Net.Sockets.Tests, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 System.Net.Sockets.Tests.TelemetryTest+<>c System.Threading.Tasks.Task <EventSource_SocketConnectFailure_LogsConnectFailed>b__10_0(System.String, System.String)

Child arguments:
  Sync, True

@MihaZupan
Copy link
Member

This test tries connecting to microsoft.com:12345, expecting that to fail and throw. If microsoft.com actually started accepting connections on that port, we would start seeing this test failing across all argument variants.

The failure here is that socket.Connect(EndPoint) did not throw (while all other async variants apparently did).
@antonfirsov do you know of any recent-ish Socket changes that would affect sync connects?

@ghost ghost locked as resolved and limited conversation to collaborators Aug 21, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-System.Net.Sockets bug disabled-test The test is disabled in source code against the issue regression-from-last-release test-run-core Test failures in .NET Core test runs
Projects
None yet
9 participants