ConnectionClosedTokenFiresOnClientFIN fails due to timeout

[captainsafia]

ConnectionClosedTokenFiresOnClientFIN fails due to a time out.

Ref: https://dev.azure.com/dnceng/public/_build/results?buildId=691787&view=results

  √ HttpsConnectionClosedWhenResponseDoesNotSatisfyMinimumDataRate [4s 429ms]
[xUnit.net 00:00:33.17]     ConnectionClosedTokenFiresOnClientFIN(listenOptions: http://127.0.0.1:0) [FAIL]
[xUnit.net 00:00:33.17]       System.TimeoutException : The operation at /_/src/Servers/Kestrel/shared/test/TaskTimeoutExtensions.cs:27 timed out after reaching the limit of 30000ms.
[xUnit.net 00:00:33.17]       Stack Trace:
[xUnit.net 00:00:33.18]         /_/src/Testing/src/TaskExtensions.cs(57,0): at Microsoft.AspNetCore.Testing.TaskExtensions.TimeoutAfter(Task task, TimeSpan timeout, String filePath, Int32 lineNumber)
[xUnit.net 00:00:33.18]         /_/src/Servers/Kestrel/test/FunctionalTests/RequestTests.cs(527,0): at Microsoft.AspNetCore.Server.Kestrel.FunctionalTests.RequestTests.ConnectionClosedTokenFiresOnClientFIN(ListenOptions listenOptions)
[xUnit.net 00:00:33.18]         --- End of stack trace from previous location ---
  X ConnectionClosedTokenFiresOnClientFIN(listenOptions: http://127.0.0.1:0) [30s 26ms]
  Error Message:
   System.TimeoutException : The operation at /_/src/Servers/Kestrel/shared/test/TaskTimeoutExtensions.cs:27 timed out after reaching the limit of 30000ms.
  Stack Trace:
     at Microsoft.AspNetCore.Testing.TaskExtensions.TimeoutAfter(Task task, TimeSpan timeout, String filePath, Int32 lineNumber) in /_/src/Testing/src/TaskExtensions.cs:line 57
   at Microsoft.AspNetCore.Server.Kestrel.FunctionalTests.RequestTests.ConnectionClosedTokenFiresOnClientFIN(ListenOptions listenOptions) in /_/src/Servers/Kestrel/test/FunctionalTests/RequestTests.cs:line 527
--- End of stack trace from previous location ---
  √ LargeUpload(contentLength: 2147483648, checkBytes: False) [1s 761ms]
  √ LargeUpload(contentLength: 10485760, checkBytes: True) [117ms]
  √ ConnectionResetBetweenRequestsIsLoggedAsDebug [7ms]
  √ ThrowsOnReadAfterConnectionError [8ms]
  √ ServerCanAbortConnectionAfterUnobservedClose(listenOptions: http://127.0.0.1:0) [10ms]
  √ ServerCanAbortConnectionAfterUnobservedClose(listenOptions: http://127.0.0.1:0) [7ms]
  √ RemoteIPv6Address [17ms]
  √ AbortingTheConnectionSendsFIN [7ms]
  √ RemoteIPv4Address [5ms]
  √ RequestAbortedTokenFiredOnClientFIN [8ms]
  √ ConnectionClosedTokenFiresOnServerAbort(listenOptions: http://127.0.0.1:0) [8ms]
  √ ConnectionClosedTokenFiresOnServerAbort(listenOptions: http://127.0.0.1:0) [5ms]
  √ ConnectionResetPriorToRequestIsLoggedAsDebug [6ms]
  √ ConnectionResetMidRequestIsLoggedAsDebug [8ms]
  √ ConnectionClosedTokenFiresOnServerFIN(listenOptions: http://127.0.0.1:0) [8ms]
  √ ConnectionClosedTokenFiresOnServerFIN(listenOptions: http://127.0.0.1:0) [5ms]
  √ DoesNotHangOnConnectionCloseRequest [9ms]
  √ CanHandleMultipleConcurrentRequests [8ms]
  √ RequestsCanBeAbortedMidRead(listenOptions: http://127.0.0.1:0) [20ms]
  √ RequestsCanBeAbortedMidRead(listenOptions: http://127.0.0.1:0) [6ms]
  √ ClientCanReceiveFullConnectionCloseResponseWithoutErrorAtALowDataRate [15s 99ms]
  √ ThrowsOnWriteWithRequestAbortedTokenAfterRequestIsAborted(listenOptions: http://127.0.0.1:0) [9ms]
  √ ThrowsOnWriteWithRequestAbortedTokenAfterRequestIsAborted(listenOptions: http://127.0.0.1:0) [5ms]
  √ ConnectionClosedWhenBothRequestAndResponseExperienceBackPressure [4s 350ms]
  √ WriteAfterConnectionCloseNoops(listenOptions: http://127.0.0.1:0) [7ms]
  √ WriteAfterConnectionCloseNoops(listenOptions: http://127.0.0.1:0) [4ms]
  √ ConnectionNotClosedWhenClientSatisfiesMinimumDataRateGivenLargeResponseHeaders [16s 133ms]
  √ AppCanHandleClientAbortingConnectionMidResponse(listenOptions: http://127.0.0.1:0) [4s 484ms]
[xUnit.net 00:01:12.37]   Finished:    Libuv.FunctionalTests
  √ AppCanHandleClientAbortingConnectionMidResponse(listenOptions: http://127.0.0.1:0) [5s 41ms]

[BrennanConroy]

Dupe of #20163

[captainsafia]

Let's keep this one open since it's referenced in the QuarantinedTest attribute.

[BrennanConroy]

Test seems to fail only on OSX?

[0.001s] [TestLifetime] [Information] Starting test ConnectionClosedTokenFiresOnClientFIN-http_127.0.0.1_0 at 2020-06-01T22:46:27
[0.002s] [Microsoft.AspNetCore.Hosting.Diagnostics] [Debug] Hosting starting
[0.005s] [Microsoft.AspNetCore.Hosting.Diagnostics] [Debug] Hosting started
[0.005s] [Microsoft.AspNetCore.Hosting.Diagnostics] [Debug] Loaded hosting startup assembly Libuv.FunctionalTests, Version=5.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60
[0.005s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] TestServer is listening on port 63015
[0.006s] [Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv] [Debug] Connection id "0HM06FMF76B3K" received FIN.
[0.006s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HM06FMF76B3K" accepted.
[0.006s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HM06FMF76B3K" started.
[0.007s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HM06FMF76B3K" disconnecting.
[0.007s] [Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv] [Debug] Connection id "0HM06FMF76B3K" sending FIN because: "The client closed the connection."
[0.007s] [Microsoft.AspNetCore.Server.Kestrel] [Debug] Connection id "0HM06FMF76B3K" stopped.
[30.024s] [Microsoft.AspNetCore.Hosting.Diagnostics] [Debug] Hosting shutdown
[30.027s] [TestLifetime] [Information] Finished test ConnectionClosedTokenFiresOnClientFIN-http_127.0.0.1_0 in 30.0267181s

[halter73]

Is it also libuv only?

[BrennanConroy]

Idk, didn't think to check.

[davidfowl]

Hopefully we’ll have dumps soon for OS X. Also we don’t get dumps on timeouts here yet