Test failure: EventSource_UnsuccessfulRequest_LogsStartFailedStop

[karelz]

Types:

• System.Net.Http.Functional.Tests.TelemetryTest_Http20
• System.Net.Http.Functional.Tests.TelemetryTest_Http11

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

Day	Run	Type	OS
6/11	Official run	Http20	Ubuntu.1804.Amd64.Open
6/12	Official run	Http11	Ubuntu.1604.Amd64.Open
6/14	Official run	Http11	SLES.12.Amd64.Open
6/15	Official run	Http11	Debian.9.Amd64.Open
6/17	Official run	Http11	Debian.9.Amd64.Open
6/20	Official run	Http11	SLES.15.Amd64.Open
6/21	Official run	Http20	Debian.10.Amd64.Open
6/23	PR #54562	Http11	Debian.10.Amd64.Open
6/27	Official run	Http20	Alpine.312.Arm64.Open
6/28	Official run	Http11	Debian.9.Amd64.Open
6/30	Official run	Http11	Fedora.30.Amd64.Open
7/4	Official run	Http20	Ubuntu.1804.ArmArch.Open
7/6	Official run	Http11	Ubuntu.1804.Amd64.Open
7/7	Official run	Http11	Debian.9.Amd64.Open
7/11	Official run	Http11	Ubuntu.1910.Amd64.Open
7/12	Official run	Http11	Debian.10.Amd64.Open

Failure Http11:

Child exception:
  Xunit.Sdk.EqualException: Assert.Equal() Failure
Expected: 1
Actual:   0
   at System.Net.Http.Functional.Tests.TelemetryTest.ValidateConnectionEstablishedClosed(ConcurrentQueue`1 events, Version version, Int32 count) in /_/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs:line 431
   at System.Net.Http.Functional.Tests.TelemetryTest.<>c.<<EventSource_UnsuccessfulRequest_LogsStartFailedStop>b__4_0>d.MoveNext() in /_/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs:line 288
--- 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.Http.Functional.Tests, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 System.Net.Http.Functional.Tests.TelemetryTest+<>c System.Threading.Tasks.Task <EventSource_UnsuccessfulRequest_LogsStartFailedStop>b__4_0(System.String, System.String)

Child arguments:
  1.1, GetStreamAsync

Failure Http20 (reversed Expected / Actual):

Child exception:
  Xunit.Sdk.EqualException: Assert.Equal() Failure
Expected: 0
Actual:   1
   at System.Net.Http.Functional.Tests.TelemetryTest.ValidateEventCounters(ConcurrentQueue`1 events, Int32 requestCount, Boolean shouldHaveFailures, Int32 requestsLeftQueueVersion) in /_/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs:line 546
   at System.Net.Http.Functional.Tests.TelemetryTest.<>c.<<EventSource_UnsuccessfulRequest_LogsStartFailedStop>b__4_0>d.MoveNext() in /_/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs:line 290
--- 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.Http.Functional.Tests, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 System.Net.Http.Functional.Tests.TelemetryTest+<>c System.Threading.Tasks.Task <EventSource_UnsuccessfulRequest_LogsStartFailedStop>b__4_0(System.String, System.String)

Child arguments:
  2.0, SendAsync

@MihaZupan perhaps another similar problem in Telemetry test? No failure in last week ...

[ghost]

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

Issue Details

---

Types:

• System.Net.Http.Functional.Tests.TelemetryTest_Http20
• System.Net.Http.Functional.Tests.TelemetryTest_Http11

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

Day | Run | Type | OS
-- | -- | --
6/11 | Official run | Http20 | Ubuntu.1804.Amd64.Open
6/12 | Official run | Http11 | Ubuntu.1604.Amd64.Open
6/14 | Official run | Http11 | SLES.12.Amd64.Open
6/15 | Official run | Http11 | Debian.9.Amd64.Open
6/17 | Official run | Http11 | Debian.9.Amd64.Open
6/20 | Official run | Http11 | SLES.15.Amd64.Open
6/21 | Official run | Http20 | Debian.10.Amd64.Open
6/23 | PR #54562 | Http11 | Debian.10.Amd64.Open
6/27 | Official run | Http11 |
6/28 | Official run | Http11 |
6/30 | Official run | Http11 |
| Official run | Http11 |
| Official run | Http11 |

Author:	karelz
Assignees:	-
Labels:	area-System.Net.Http, os-linux
Milestone:	-

[MihaZupan]

For HTTP/2, the assert is here:

runtime/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs

Line 546 in f7e4c26

Assert.Equal(0, http20ConnectionsTotal[^1]);

Likely the same underlying test issue as in #46073 (potentially fixed by #55729).
We should check failures again in a week or two to confirm.

For HTTP/1.1 there seems to be a slight race condition that could be hit in the test.
We may cancel the request between establishing the transport (TCP) and constructing the HttpConnection object.
The server should wait to receive the request line instead of just the connection before cancelling the request.