[wasm] interpreter timeouts when WebSocket closes unexpectedly

[lewing]

Error Blob

{
  "ErrorMessage": "WebSockets",
  "BuildRetry": false,
  "ErrorPattern": "timed out after",
  "ExcludeConsoleLog": false
}

Report

Build	Definition	Step Name	Console log	Pull Request
250074	dotnet/runtime	EnterpriseLinuxTests	Log	#85244
248095	dotnet/runtime	Build tvOS arm64 Release AllSubsets_Mono	Log
247826	dotnet/runtime	EnterpriseLinuxTests	Log	#84886
247278	dotnet/runtime	windows-x64 Release AllSubsets_Mono	Log
247262	dotnet/runtime	Build managed test components	Log	#85150
247245	dotnet/runtime	EnterpriseLinuxTests	Log	#85149
246700	dotnet/runtime	EnterpriseLinuxTests	Log	#82832
247117	dotnet/runtime	Build managed test components	Log
247097	dotnet/runtime	Build product	Log	#85107
246782	dotnet/runtime	Build Browser wasm Linux Release AllSubsets_Mono_RuntimeTests	Log	#85074
245670	dotnet/runtime	EnterpriseLinuxTests	Log	#84793
245608	dotnet/runtime	Restore and Build Product	Log
245486	dotnet/runtime	coreclr Pri1 Runtime Tests Run R2R_Composite windows x64 checked	Log
244298	dotnet/runtime	linux-x64 Debug NativeAOT	Log	#85017
244227	dotnet/runtime	coreclr Pri1 Runtime Tests Run linux x64 checked	Log	#85040
244251	dotnet/runtime	Libraries Build windows x86 Release	Log
244240	dotnet/runtime	Libraries Build Linux_musl x64 Release	Log
244156	dotnet/runtime	coreclr Pri1 Runtime Tests Run R2R_CG2 windows arm64 checked	Log

Build	Definition	Test	Pull Request
251128	dotnet/runtime	System.Net.Quic.Functional.Tests.WorkItemExecution
251095	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85281
251104	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85289
250758	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#84580
251030	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#74623
251034	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85000
251007	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85288
250766	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85275
250966	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85286
250923	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85114
250561	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#84494
250728	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85277
250888	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85284
250875	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#84804
250677	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#84864
250855	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85281
250307	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#84891
250824	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85282
250754	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85273
250690	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85106
250681	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#84325
250570	dotnet/runtime	Microsoft.Extensions.Hosting.Unit.Tests.WorkItemExecution	#84191
250551	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85174
250536	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85191
250524	dotnet/runtime	normal-System.Text.Json.Tests.WorkItemExecution	#85127
250509	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85182
250534	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution
250518	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85109
250493	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85189
250434	dotnet/runtime	chrome-DebuggerTests.WorkItemExecution	#85270
250407	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85268
250395	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85267
250379	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85266
250361	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#83669
250298	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85109
250289	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85000
250102	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85228
250209	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#84976
250184	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85255
250208	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution	#84976
250095	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85254
249965	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85248
249824	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249871	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85246
249844	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249843	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249838	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249839	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249836	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249806	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#84062
249811	dotnet/runtime	WasmTestOnNodeJS-System.Transactions.Local.Tests.WorkItemExecution	#80267
249760	dotnet/runtime	Workloads-Webcil-Wasm.Build.Tests.WasmTemplateTests.WorkItemExecution	#83411
248007	dotnet/runtime	normal-System.Collections.Immutable.Tests.WorkItemExecution	#85065
248214	dotnet/runtime	chrome-DebuggerTests.EvaluateOnCallFrameTests.WorkItemExecution	#85177
249647	dotnet/runtime	System.Net.Quic.Functional.Tests.WorkItemExecution
249621	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85239
249570	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#84580
249563	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85228
249339	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution
249314	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#84580
249123	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85017
249141	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249146	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249150	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85127
249137	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249142	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249145	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249136	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
249081	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution
249037	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85215
248971	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85017
248919	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution
248924	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85203
248920	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85202
248494	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85112
248856	dotnet/runtime	System.Net.Quic.Functional.Tests.WorkItemExecution
248860	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85200
248535	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85120
248659	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
248673	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
248665	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
248666	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
248664	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
248661	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution
248629	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution
248625	dotnet/runtime	System.Formats.Tar.Tests.WorkItemExecution	#84976
248589	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85190
248574	dotnet/runtime	Microsoft.Extensions.Hosting.Unit.Tests.WorkItemExecution	#84191
248550	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#84519
248395	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#85127
246224	dotnet/runtime	chrome-DebuggerTests.EvaluateOnCallFrameTests.WorkItemExecution	#82146
248243	dotnet/runtime	chrome-DebuggerTests.EvaluateOnCallFrameTests.WorkItemExecution	#85178
244064	dotnet/runtime	WasmTestOnBrowser-System.Net.WebSockets.Client.Tests.WorkItemExecution	#84977
248202	dotnet/runtime	chrome-DebuggerTests.EvaluateOnCallFrameTests.WorkItemExecution
248104	dotnet/runtime	chrome-DebuggerTests.EvaluateOnCallFrameTests.WorkItemExecution	#84867
248061	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#74623
248075	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85000
248057	dotnet/runtime	WasmTestOnBrowser-System.Text.Json.Tests.WorkItemExecution	#85114
247737	dotnet/runtime	chrome-DebuggerTests.EvaluateOnCallFrameTests.WorkItemExecution	#85093
247875	dotnet/runtime	chrome-DebuggerTests.EvaluateOnCallFrameTests.WorkItemExecution	#84494
Displaying 100 of 325 results

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
57	238	343

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

Issue Details

---

Error Blob

{
  "ErrorMessage": " WARNING: Web browsers do not support closing the output side of a WebSocket. CloseOutputAsync has closed the socket and discarded any incoming messages.",
  "BuildRetry": false,
  "ErrorPattern": "",
  "ExcludeConsoleLog": true
}

Reproduction Steps

No response

Author:	lewing
Assignees:	-
Labels:	arch-wasm, blocking-clean-ci, Known Build Error
Milestone:	8.0.0

[lewing]

These are the WebSocket only failures getting caught up in #83655 which are different from the general aot timeout in compilation

[lewing]

this might have stopped when I rolled back the chrome installer :|

[pavelsavara]

That message WARNING: Web browsers do not support closing the output side of a WebSocket. is correct/expected side effect of specific unit test in that suite. So I think it tell us nothing about the timeout here.

[pavelsavara]

This is timeout on NodeJS, which is strange.
It will run full suite in under a minute and then hang until xharness timeout.

Log

[16:15:26] info: Using js engine NodeJS from path /home/helixbot/node-v16.19.0-linux-x64/bin/node
...
[16:16:15] info: Finished:    System.Net.WebSockets.Client.Tests.dll
[16:16:15] info: 
[16:16:15] info: === TEST EXECUTION SUMMARY ===
[16:16:15] info: Total: 258, Errors: 0, Failed: 0, Skipped: 0, Time: 46.2105388s
[16:16:15] info: 
[16:16:15] info: Received expected 122093 of /root/helix/work/workitem/uploads/xharness-output/testResults.xml
[16:16:15] info: Finished writing 122093 bytes of RESULTXML
[16:16:15] info: Xml file was written to the provided writer.
[16:16:15] info: Tests run: 258 Passed: 258 Inconclusive: 0 Failed: 0 Ignored: 0 Skipped: 0
[16:16:15] info: WASM EXIT 0
[16:45:26] fail: Tests timed out after 1800secs
[16:45:26] info: Process 76 didn't exit within 00:30:00 and will be killed

[pavelsavara]

I updated the pattern.

[pavelsavara]

This is browser log

going fine until [05:34:49] and then nothing at all until timeout.
Note message at [05:33:11] as well as other messages here are expected part of the test.

[05:32:57] Starting ChromeDriver 109.0.5414.0
[05:33:10] info: Starting:    System.Net.WebSockets.Client.Tests.dll
[05:33:11] warn: WARNING: Web browsers do not support closing the output side of a WebSocket. CloseOutputAsync has closed the socket and discarded any incoming messages.
[05:34:47] info: http://127.0.0.1:49168/dotnet.js 2 WebSocket connection to 'ws://127.0.0.1:49168/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[05:34:47] info: http://127.0.0.1:49168/dotnet.js 2 WebSocket connection to 'wss://127.0.0.1:49169/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[05:34:47] info: http://127.0.0.1:49168/dotnet.js 2 WebSocket connection to 'ws://127.0.0.1:49168/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[05:34:47] info: http://127.0.0.1:49168/dotnet.js 2 WebSocket connection to 'wss://127.0.0.1:49169/WebSocket/EchoWebSocket.ashx?delay10sec' failed: WebSocket is closed before the connection is established.
[05:34:47] fail: [out of order message from the browser]: http://127.0.0.1:49168/dotnet.js 2 WebSocket connection to 'ws://127.0.0.1:49168/WebSocket/EchoWebSocket.ashx?subprotocol=CustomProtocol' failed: Error during WebSocket handshake: Response must not include 'Sec-WebSocket-Protocol' header if not present in request: CustomProtocol
[05:34:47] fail: [out of order message from the browser]: http://127.0.0.1:49168/dotnet.js 2 WebSocket connection to 'wss://127.0.0.1:49169/WebSocket/EchoWebSocket.ashx?subprotocol=CustomProtocol' failed: Error during WebSocket handshake: Response must not include 'Sec-WebSocket-Protocol' header if not present in request: CustomProtocol
[05:34:47] fail: [out of order message from the browser]: http://127.0.0.1:49168/dotnet.js 2 WebSocket connection to 'ws://127.0.0.1:49294/' failed: Connection closed before receiving a handshake response
[05:34:49] fail: [out of order message from the browser]: http://127.0.0.1:49168/dotnet.js 2 WebSocket connection to 'ws://0bd7e6fd642a453ebfaf64d54d37f4cc/' failed: Error in connection establishment: net::ERR_NAME_NOT_RESOLVED

...
[EXECUTION TIMED OUT]
Exit Code:-3Executor timed out after 1800 seconds and was killed