[wasm] Failure in System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable

[elinor-fung]

System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable failed in the runtime-extra-platforms build 20220207.1:
https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-heads-main-f4f1585b13aa4f5f8d/WasmTestOnBrowser-System.Net.WebSockets.Client.Tests/1/console.40167f2b.log?sv=2019-07-07&se=2022-02-27T09%3A53%3A39Z&sr=c&sp=rl&sig=xgEDf%2FOAKGGUQQX6hWwJAqg5DkXD0aQWlTheUwX7ZmY%3D

[10:16:02] fail: [FAIL] System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable(server: wss://127.0.0.1:37129/WebSocket/EchoWebSocket.ashx)
[10:16:02] info: System.OperationCanceledException : The operation was canceled.
[10:16:02] info:    at System.Net.WebSockets.BrowserWebSocket.CancelationHelper(Task`1 jsTask, Int32 promiseJSHandle, CancellationToken cancellationToken, WebSocketState previousState)
[10:16:02] info:    at System.Net.WebSockets.BrowserWebSocket.ConnectAsyncCore(Uri uri, List`1 requestedSubProtocols, CancellationToken cancellationToken)
[10:16:02] info:    at System.Net.WebSockets.ClientWebSocket.ConnectAsyncCore(Uri uri, CancellationToken cancellationToken)
[10:16:02] info:    at System.Net.WebSockets.Client.Tests.WebSocketHelper.<>c__DisplayClass4_0.<<GetConnectedWebSocket>b__0>d.MoveNext()
[10:16:02] info: --- End of stack trace from previous location ---
[10:16:02] info:    at System.Net.WebSockets.Client.Tests.WebSocketHelper.<Retry>d__5`1[[System.Net.WebSockets.ClientWebSocket, System.Net.WebSockets.Client, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext()
[10:16:02] info:    at System.Net.WebSockets.Client.Tests.SendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable(Uri server)
[10:16:02] info: --- End of stack trace from previous location ---
[10:16:02] fail: [out of order message from the browser]: http://127.0.0.1:43513/dotnet.js 2 WebSocket connection to 'wss://127.0.0.1:37129/WebSocket/EchoWebSocket.ashx' failed: WebSocket opening handshake timed out

Build	Kind	Start Time
1596337	Rolling	2022-07-02

[ghost]

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

Issue Details

---

System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable failed in the runtime-extra-platforms build 20220207.1:
https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-heads-main-f4f1585b13aa4f5f8d/WasmTestOnBrowser-System.Net.WebSockets.Client.Tests/1/console.40167f2b.log?sv=2019-07-07&se=2022-02-27T09%3A53%3A39Z&sr=c&sp=rl&sig=xgEDf%2FOAKGGUQQX6hWwJAqg5DkXD0aQWlTheUwX7ZmY%3D

[10:16:02] fail: [FAIL] System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable(server: wss://127.0.0.1:37129/WebSocket/EchoWebSocket.ashx)
[10:16:02] info: System.OperationCanceledException : The operation was canceled.
[10:16:02] info:    at System.Net.WebSockets.BrowserWebSocket.CancelationHelper(Task`1 jsTask, Int32 promiseJSHandle, CancellationToken cancellationToken, WebSocketState previousState)
[10:16:02] info:    at System.Net.WebSockets.BrowserWebSocket.ConnectAsyncCore(Uri uri, List`1 requestedSubProtocols, CancellationToken cancellationToken)
[10:16:02] info:    at System.Net.WebSockets.ClientWebSocket.ConnectAsyncCore(Uri uri, CancellationToken cancellationToken)
[10:16:02] info:    at System.Net.WebSockets.Client.Tests.WebSocketHelper.<>c__DisplayClass4_0.<<GetConnectedWebSocket>b__0>d.MoveNext()
[10:16:02] info: --- End of stack trace from previous location ---
[10:16:02] info:    at System.Net.WebSockets.Client.Tests.WebSocketHelper.<Retry>d__5`1[[System.Net.WebSockets.ClientWebSocket, System.Net.WebSockets.Client, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext()
[10:16:02] info:    at System.Net.WebSockets.Client.Tests.SendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable(Uri server)
[10:16:02] info: --- End of stack trace from previous location ---
[10:16:02] fail: [out of order message from the browser]: http://127.0.0.1:43513/dotnet.js 2 WebSocket connection to 'wss://127.0.0.1:37129/WebSocket/EchoWebSocket.ashx' failed: WebSocket opening handshake timed out

Author:	elinor-fung
Assignees:	-
Labels:	arch-wasm
Milestone:	-

[ghost]

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

Issue Details

---

System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable failed in the runtime-extra-platforms build 20220207.1:
https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-heads-main-f4f1585b13aa4f5f8d/WasmTestOnBrowser-System.Net.WebSockets.Client.Tests/1/console.40167f2b.log?sv=2019-07-07&se=2022-02-27T09%3A53%3A39Z&sr=c&sp=rl&sig=xgEDf%2FOAKGGUQQX6hWwJAqg5DkXD0aQWlTheUwX7ZmY%3D

[10:16:02] fail: [FAIL] System.Net.WebSockets.Client.Tests.MemorySendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable(server: wss://127.0.0.1:37129/WebSocket/EchoWebSocket.ashx)
[10:16:02] info: System.OperationCanceledException : The operation was canceled.
[10:16:02] info:    at System.Net.WebSockets.BrowserWebSocket.CancelationHelper(Task`1 jsTask, Int32 promiseJSHandle, CancellationToken cancellationToken, WebSocketState previousState)
[10:16:02] info:    at System.Net.WebSockets.BrowserWebSocket.ConnectAsyncCore(Uri uri, List`1 requestedSubProtocols, CancellationToken cancellationToken)
[10:16:02] info:    at System.Net.WebSockets.ClientWebSocket.ConnectAsyncCore(Uri uri, CancellationToken cancellationToken)
[10:16:02] info:    at System.Net.WebSockets.Client.Tests.WebSocketHelper.<>c__DisplayClass4_0.<<GetConnectedWebSocket>b__0>d.MoveNext()
[10:16:02] info: --- End of stack trace from previous location ---
[10:16:02] info:    at System.Net.WebSockets.Client.Tests.WebSocketHelper.<Retry>d__5`1[[System.Net.WebSockets.ClientWebSocket, System.Net.WebSockets.Client, Version=7.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].MoveNext()
[10:16:02] info:    at System.Net.WebSockets.Client.Tests.SendReceiveTest.ZeroByteReceive_CompletesWhenDataAvailable(Uri server)
[10:16:02] info: --- End of stack trace from previous location ---
[10:16:02] fail: [out of order message from the browser]: http://127.0.0.1:43513/dotnet.js 2 WebSocket connection to 'wss://127.0.0.1:37129/WebSocket/EchoWebSocket.ashx' failed: WebSocket opening handshake timed out

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

[elinor-fung]

Not sure if this is related to #53957 and #57519? cc @pavelsavara

[pavelsavara]

I suspect that the helix agent was too slow to open that connection and browser's WS is not very patient with it.
In the log above, the browser complained [10:16:02] fail: [out of order message from the browser]: http://127.0.0.1:43513/dotnet.js 2 WebSocket connection to 'wss://127.0.0.1:37129/WebSocket/EchoWebSocket.ashx' failed: WebSocket opening handshake timed out.
Note that the server is running also on the same Helix agent.

[lewing]

Do we think this is still reproducible with the latest code?

[pavelsavara]

Not on my local machine. Please re-open if it happens again.