[wasm] SendReceive_VaryingLengthBuffers_Success failing in CI

[ViktorHofer]

[20:06:15] info: Discovering: System.Net.WebSockets.Client.Tests.dll (method display = ClassAndMethod, method display options = None)
[20:06:15] info: Discovered:  System.Net.WebSockets.Client.Tests.dll (found 53 of 87 test cases)
[20:06:15] info: Starting:    System.Net.WebSockets.Client.Tests.dll
[20:07:51] info: http://127.0.0.1:34693/dotnet.js 0 WebSocket connection to 'ws://074bf40fe279493f8fb2a570a8bfbea8/' failed: WebSocket is closed before the connection is established.
[20:10:00] fail: [FAIL] System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.SendReceive_VaryingLengthBuffers_Success(server: ws://127.0.0.1:34693/WebSocket/EchoWebSocket.ashx)
[20:10:00] info: System.OperationCanceledException : The operation was canceled.
[20:10:00] info:    at System.Threading.Channels.AsyncOperation`1[[System.Net.WebSockets.ReceivePayload, System.Net.WebSockets.Client, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].GetResult(Int16 token)
[20:10:00] info:    at System.Net.WebSockets.BrowserWebSocket.ReceiveAsync(ArraySegment`1 buffer, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.BrowserWebSocket.ReceiveAsync(ArraySegment`1 buffer, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.WebSocket.ReceiveAsync(Memory`1 buffer, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ReceiveAsync(WebSocket ws, ArraySegment`1 arraySegment, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.Client.Tests.SendReceiveTest.SendReceive_VaryingLengthBuffers_Success(Uri server)
[20:10:00] info: --- End of stack trace from previous location ---
[20:11:11] info: http://127.0.0.1:34693/dotnet.js 0 WebSocket connection to 'ws://127.0.0.1:34693/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[20:11:12] info: http://127.0.0.1:34693/dotnet.js 0 WebSocket connection to 'wss://127.0.0.1:41047/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[20:11:42] info: Finished:    System.Net.WebSockets.Client.Tests.dll
[20:11:42] info: 
[20:11:42] info: === TEST EXECUTION SUMMARY ===
[20:11:42] info: Total: 89, Errors: 0, Failed: 1, Skipped: 0, Time: 327.6009649s

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-53905-merge-5a8d9815e63046a192/System.Net.WebSockets.Client.Tests/console.608b53e4.log?sv=2019-07-07&se=2021-06-29T19%3A48%3A07Z&sr=c&sp=rl&sig=pEysk8NCg3vGVdQFHK7K1Q12bdrdQ83pA6K9hLXcrb0%3D

Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1179573&view=logs&j=108d2c4a-8a62-5a58-8dad-8e1042acc93c&t=568f884b-cc12-5fd3-e7fe-790b5ac403f4

Configuration: Build Browser wasm Release AllSubsets_Mono

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

Issue Details

---

[20:06:15] info: Discovering: System.Net.WebSockets.Client.Tests.dll (method display = ClassAndMethod, method display options = None)
[20:06:15] info: Discovered:  System.Net.WebSockets.Client.Tests.dll (found 53 of 87 test cases)
[20:06:15] info: Starting:    System.Net.WebSockets.Client.Tests.dll
[20:07:51] info: http://127.0.0.1:34693/dotnet.js 0 WebSocket connection to 'ws://074bf40fe279493f8fb2a570a8bfbea8/' failed: WebSocket is closed before the connection is established.
[20:10:00] fail: [FAIL] System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.SendReceive_VaryingLengthBuffers_Success(server: ws://127.0.0.1:34693/WebSocket/EchoWebSocket.ashx)
[20:10:00] info: System.OperationCanceledException : The operation was canceled.
[20:10:00] info:    at System.Threading.Channels.AsyncOperation`1[[System.Net.WebSockets.ReceivePayload, System.Net.WebSockets.Client, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].GetResult(Int16 token)
[20:10:00] info:    at System.Net.WebSockets.BrowserWebSocket.ReceiveAsync(ArraySegment`1 buffer, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.BrowserWebSocket.ReceiveAsync(ArraySegment`1 buffer, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.WebSocket.ReceiveAsync(Memory`1 buffer, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ReceiveAsync(WebSocket ws, ArraySegment`1 arraySegment, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.Client.Tests.SendReceiveTest.SendReceive_VaryingLengthBuffers_Success(Uri server)
[20:10:00] info: --- End of stack trace from previous location ---
[20:11:11] info: http://127.0.0.1:34693/dotnet.js 0 WebSocket connection to 'ws://127.0.0.1:34693/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[20:11:12] info: http://127.0.0.1:34693/dotnet.js 0 WebSocket connection to 'wss://127.0.0.1:41047/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[20:11:42] info: Finished:    System.Net.WebSockets.Client.Tests.dll
[20:11:42] info: 
[20:11:42] info: === TEST EXECUTION SUMMARY ===
[20:11:42] info: Total: 89, Errors: 0, Failed: 1, Skipped: 0, Time: 327.6009649s

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-53905-merge-5a8d9815e63046a192/System.Net.WebSockets.Client.Tests/console.608b53e4.log?sv=2019-07-07&se=2021-06-29T19%3A48%3A07Z&sr=c&sp=rl&sig=pEysk8NCg3vGVdQFHK7K1Q12bdrdQ83pA6K9hLXcrb0%3D

Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1179573&view=logs&j=108d2c4a-8a62-5a58-8dad-8e1042acc93c&t=568f884b-cc12-5fd3-e7fe-790b5ac403f4

Configuration: Build Browser wasm Release AllSubsets_Mono

Author:	ViktorHofer
Assignees:	-
Labels:	area-System.Net
Milestone:	-

Tagging subscribers to 'arch-wasm': @lewing
See info in area-owners.md if you want to be subscribed.

Issue Details

---

[20:06:15] info: Discovering: System.Net.WebSockets.Client.Tests.dll (method display = ClassAndMethod, method display options = None)
[20:06:15] info: Discovered:  System.Net.WebSockets.Client.Tests.dll (found 53 of 87 test cases)
[20:06:15] info: Starting:    System.Net.WebSockets.Client.Tests.dll
[20:07:51] info: http://127.0.0.1:34693/dotnet.js 0 WebSocket connection to 'ws://074bf40fe279493f8fb2a570a8bfbea8/' failed: WebSocket is closed before the connection is established.
[20:10:00] fail: [FAIL] System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.SendReceive_VaryingLengthBuffers_Success(server: ws://127.0.0.1:34693/WebSocket/EchoWebSocket.ashx)
[20:10:00] info: System.OperationCanceledException : The operation was canceled.
[20:10:00] info:    at System.Threading.Channels.AsyncOperation`1[[System.Net.WebSockets.ReceivePayload, System.Net.WebSockets.Client, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].GetResult(Int16 token)
[20:10:00] info:    at System.Net.WebSockets.BrowserWebSocket.ReceiveAsync(ArraySegment`1 buffer, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.BrowserWebSocket.ReceiveAsync(ArraySegment`1 buffer, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.WebSocket.ReceiveAsync(Memory`1 buffer, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ReceiveAsync(WebSocket ws, ArraySegment`1 arraySegment, CancellationToken cancellationToken)
[20:10:00] info:    at System.Net.WebSockets.Client.Tests.SendReceiveTest.SendReceive_VaryingLengthBuffers_Success(Uri server)
[20:10:00] info: --- End of stack trace from previous location ---
[20:11:11] info: http://127.0.0.1:34693/dotnet.js 0 WebSocket connection to 'ws://127.0.0.1:34693/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[20:11:12] info: http://127.0.0.1:34693/dotnet.js 0 WebSocket connection to 'wss://127.0.0.1:41047/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[20:11:42] info: Finished:    System.Net.WebSockets.Client.Tests.dll
[20:11:42] info: 
[20:11:42] info: === TEST EXECUTION SUMMARY ===
[20:11:42] info: Total: 89, Errors: 0, Failed: 1, Skipped: 0, Time: 327.6009649s

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-53905-merge-5a8d9815e63046a192/System.Net.WebSockets.Client.Tests/console.608b53e4.log?sv=2019-07-07&se=2021-06-29T19%3A48%3A07Z&sr=c&sp=rl&sig=pEysk8NCg3vGVdQFHK7K1Q12bdrdQ83pA6K9hLXcrb0%3D

Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1179573&view=logs&j=108d2c4a-8a62-5a58-8dad-8e1042acc93c&t=568f884b-cc12-5fd3-e7fe-790b5ac403f4

Configuration: Build Browser wasm Release AllSubsets_Mono

Author:	ViktorHofer
Assignees:	-
Labels:	arch-wasm, area-System.Net, untriaged
Milestone:	-

[lewing]

Not sure what is going on here @pavelsavara can you take a look?

[karelz]

Note: There is also bunch of similar failures of this test, but perhaps that has been already addressed?

System.Net.WebSockets.WebSocketException : Unable to connect to the remote server
---- System.Net.Http.HttpRequestException : Unknown error (0xffffffff) (corefx-net-http11.azurewebsites.net:443)
-------- System.Net.Sockets.SocketException : Unknown error (0xffffffff)

Data from 4/18-6/17 (incl. PRs) -- Mono failures all, mostly wasm:

Date	Build	Notes
5/18	PR #52923	System.OperationCanceledException : The operation was canceled.
5/19	official test run	16x - WebSocketException : Unable to connect to the remote server (Mono, not wasm)
5/20-6/2	PR #53027	143x - mix of failures (100x Mono, not wasm), incl. 5x State immediately after ConnectAsync incorrect: Closed
5/26	official test run	29x - WebSocketException : Unable to connect to the remote server (Mono, not wasm)
5/26	PR #53277	15x - WebSocketException : Unable to connect to the remote server 1x State immediately after ConnectAsync incorrect: Closed (Mono, not wasm)
5/26-5/27	PR #53280	48x - WebSocketException : Unable to connect to the remote server (Mono, not wasm)
6/9	official test run	System.OperationCanceledException : The operation was canceled.
6/9	PR #53905	System.OperationCanceledException : The operation was canceled.
6/9	PR #53023	System.OperationCanceledException : The operation was canceled.
6/0	PR #49876	System.OperationCanceledException : The operation was canceled.
6/11	PR #53644	System.OperationCanceledException : The operation was canceled.
6/12	PR #54089	System.Net.WebSockets.WebSocketException : The WebSocket is in an invalid state ('Aborted') for this operation. Valid states are: 'Connecting, Open, CloseReceived, CloseSent'
6/13	PR #54124	System.OperationCanceledException : The operation was canceled.
6/14	PR #54136	System.OperationCanceledException : The operation was canceled.
6/14	PR #52510	System.OperationCanceledException : The operation was canceled.
6/15	PR #53294	System.OperationCanceledException : The operation was canceled.
6/15	PR #54053	System.OperationCanceledException : The operation was canceled.
6/16	PR #54286	System.OperationCanceledException : The operation was canceled.

[pavelsavara]

error 0xffffffff is already captured here #53281

[pavelsavara]

Running this locally in tight loop I was able to only reproduce

Retry after attempt #1 failed with System.Net.WebSockets.WebSocketException (0x80004005): Unable to connect to the remote server
 ---> System.Net.WebSockets.WebSocketException (0x80004005): An internal WebSocket error occurred. Please see the innerException, if present, for more details.
   at System.Net.WebSockets.BrowserWebSocket.ConnectAsyncJavaScript(Uri uri, CancellationToken cancellationToken, List`1 requestedSubProtocols)
   at System.Net.WebSockets.BrowserWebSocket.ConnectAsyncJavaScript(Uri uri, CancellationToken cancellationToken, List`1 requestedSubProtocols)
   at System.Net.WebSockets.WebSocketHandle.ConnectAsync(Uri uri, CancellationToken cancellationToken, ClientWebSocketOptions options)
   at System.Net.WebSockets.ClientWebSocket.ConnectAsyncCore(Uri uri, CancellationToken cancellationToken)
   at System.Net.WebSockets.Client.Tests.WebSocketHelper.<>c__DisplayClass4_0.<<GetConnectedWebSocket>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.Net.WebSockets.Client.Tests.WebSocketHelper.<Retry>d__5`1[[System.Net.WebSockets.ClientWebSocket, System.Net.WebSockets.Client, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext()

[pavelsavara]

With timeout down to 3000ms

  info: http://127.0.0.1:49635/dotnet.js 0 WebSocket connection to 'wss://127.0.0.1:49636/WebSocket/EchoWebSocket.ashx' failed: WebSocket is closed before the connection is established.
  fail: [FAIL] System.Net.WebSockets.Client.Tests.ArraySegmentSendReceiveTest.SendReceive_VaryingLengthBuffers_Success(server: wss://127.0.0.1:49636/WebSocket/EchoWebSocket.ashx)
  info: System.Threading.Tasks.TaskCanceledException : A task was canceled.
  info:    at System.Net.WebSockets.BrowserWebSocket.ConnectAsyncJavaScript(Uri uri, CancellationToken cancellationToken, List`1 requestedSubProtocols)
  info:    at System.Net.WebSockets.WebSocketHandle.ConnectAsync(Uri uri, CancellationToken cancellationToken, ClientWebSocketOptions options)
  info:    at System.Net.WebSockets.ClientWebSocket.ConnectAsyncCore(Uri uri, CancellationToken cancellationToken)
  info:    at System.Net.WebSockets.Client.Tests.WebSocketHelper.<>c__DisplayClass4_0.<<GetConnectedWebSocket>b__0>d.MoveNext()
  info: --- End of stack trace from previous location ---
  info:    at System.Net.WebSockets.Client.Tests.WebSocketHelper.<Retry>d__5`1[[System.Net.WebSockets.ClientWebSocket, System.Net.WebSockets.Client, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext()
  info:    at System.Net.WebSockets.Client.Tests.SendReceiveTest.SendReceive_VaryingLengthBuffers_Success(Uri server)
  info: --- End of stack trace from previous location ---