WasmTestOnBrowser-System.Private.Xml.Tests - GENERAL_FAILURE

[karelz]

Runfo failures in last 30 days

• Platform: net7.0-Browser-Release-wasm-Mono_Release-WasmTestOnBrowser-(Windows.Amd64.Server2022.Open)windows.amd64.server2022.open

Day	Run	Details
9/23	Rolling run 28100	Console - InvalidOperationException
9/21	Rolling run 24630	Console - InvalidOperationException
9/20	2x Rolling run 24096	Console & Console - InvalidOperationException
9/20	Rolling run 23279	Console - InvalidOperationException
9/19	Rolling run 22721	Console - InvalidOperationException
9/18	Rolling run 21535	Console - ChannelClosedException
9/17	Rolling run 21283	Console - ChannelClosedException
9/16	Rolling run 20550	Console - ChannelClosedException
9/16	Rolling run 19690	Console - ChannelClosedException
9/15	Rolling run 18995	Console - ChannelClosedException

Failure examples:

InvalidOperationException - Console on 9/23:

[23:37:33] info: Starting: System.Private.Xml.Tests.dll
[23:38:40] fail: 224964280
[23:38:40] fail: 224964280
[23:38:40] fail: 224964280
[23:38:40] fail: 225333728
[23:38:40] info: WASM EXIT 1
[23:38:40] info: Waiting to flush log messages with a timeout of 120 secs ..
[23:38:40] info: WASM EXIT 1
[23:38:40] fail: Application has finished with exit code TESTS_FAILED but 0 was expected
fail: Microsoft.AspNetCore.Server.Kestrel[13]
 Connection id "0HMKTNI0N1333", Request id "0HMKTNI0N1333:00000001": An unhandled exception was thrown by the application.
 System.InvalidOperationException: Message processor is not running. Make sure to call RunAsync first
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.InvokeAsync(String message, Boolean isError) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 94
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmBrowserTestRunner.RunConsoleMessagesPump(WebSocket socket, CancellationToken token) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/Browser/WasmBrowserTestRunner.cs:line 196
 at Microsoft.DotNet.XHarness.CLI.Commands.WebServer.TestWebServerStartup.<>c__DisplayClass3_0.<<Configure>b__2>d.MoveNext() in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WebServer.cs:line 163
 --- End of stack trace from previous location ---
 at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
XHarness exit code: 71 (GENERAL_FAILURE)

C:\helix\work\workitem\e\wasm_build\AppBundle>set EXIT_CODE=71 
----- end Fri 09/23/2022 23:38:44.97 ----- exit code 71 ----------------------------------------------------------

ChannelClosedException - Console on

[23:13:04] info: Starting: System.Private.Xml.Tests.dll
[23:14:16] fail: 245597000
[23:14:16] fail: 245597000
[23:14:16] fail: 245597000
[23:14:16] fail: 245597120
[23:14:16] info: WASM EXIT 1
[23:14:16] info: Waiting to flush log messages with a timeout of 120 secs ..
[23:14:16] info: WASM EXIT 1
[23:14:16] fail: Flushing log messages failed with: System.InvalidOperationException: An attempt was made to transition a task to a final state when it had already completed.
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.ProcessMessage(String message, Boolean isError) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 200
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.RunAsync(CancellationToken token) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 82
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.RunAsync(CancellationToken token) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 82
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.CompleteAndFlushAsync(Nullable`1 timeout) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 106. Ignoring.
fail: Microsoft.AspNetCore.Server.Kestrel[13]
 Connection id "0HMKPPD0JB2H6", Request id "0HMKPPD0JB2H6:00000001": An unhandled exception was thrown by the application.
 System.Threading.Channels.ChannelClosedException: The channel has been closed.
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmBrowserTestRunner.RunConsoleMessagesPump(WebSocket socket, CancellationToken token) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/Browser/WasmBrowserTestRunner.cs:line 196
 at Microsoft.DotNet.XHarness.CLI.Commands.WebServer.TestWebServerStartup.<>c__DisplayClass3_0.<<Configure>b__2>d.MoveNext() in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WebServer.cs:line 163
 --- End of stack trace from previous location ---
 at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
[23:14:16] fail: [out of order message from the browser]: http://127.0.0.1:49195/dotnet.js 4:1872 "[main] websocket closed: [object CloseEvent]" CloseEvent
[23:14:16] info: Could not process message: {"method":"console.log","payload":"WASM EXIT 1","arguments":["WASM EXIT 1"]}
[23:14:16] info: Application has finished with exit code TESTS_FAILED. But the log processor failed with GENERAL_FAILURE.
[23:14:16] fail: Application has finished with exit code GENERAL_FAILURE but 0 was expected
XHarness exit code: 71 (GENERAL_FAILURE)

C:\helix\work\workitem\e\wasm_build\AppBundle>set EXIT_CODE=71 
----- end Sun 09/18/2022 23:14:20.41 ----- exit code 71 ----------------------------------------------------------

Report

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
0	0	0

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

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

Issue Details

---

Runfo failures in last 30 days

• Platform: net7.0-Browser-Release-wasm-Mono_Release-WasmTestOnBrowser-(Windows.Amd64.Server2022.Open)windows.amd64.server2022.open

Day	Run	Details
9/23	Rolling run 28100	Console - InvalidOperationException
9/21	Rolling run 24630	Console - InvalidOperationException
9/20	2x Rolling run 24096	Console & Console - InvalidOperationException
9/20	Rolling run 23279	Console - InvalidOperationException
9/19	Rolling run 22721	Console - InvalidOperationException
9/18	Rolling run 21535	Console - ChannelClosedException
9/17	Rolling run 21283	Console - ChannelClosedException
9/16	Rolling run 20550	Console - ChannelClosedException
9/16	Rolling run 19690	Console - ChannelClosedException
9/15	Rolling run 18995	Console - ChannelClosedException

Failure examples:

InvalidOperationException - Console on 9/23:

[23:37:33] info: Starting: System.Private.Xml.Tests.dll
[23:38:40] fail: 224964280
[23:38:40] fail: 224964280
[23:38:40] fail: 224964280
[23:38:40] fail: 225333728
[23:38:40] info: WASM EXIT 1
[23:38:40] info: Waiting to flush log messages with a timeout of 120 secs ..
[23:38:40] info: WASM EXIT 1
[23:38:40] fail: Application has finished with exit code TESTS_FAILED but 0 was expected
fail: Microsoft.AspNetCore.Server.Kestrel[13]
 Connection id "0HMKTNI0N1333", Request id "0HMKTNI0N1333:00000001": An unhandled exception was thrown by the application.
 System.InvalidOperationException: Message processor is not running. Make sure to call RunAsync first
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.InvokeAsync(String message, Boolean isError) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 94
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmBrowserTestRunner.RunConsoleMessagesPump(WebSocket socket, CancellationToken token) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/Browser/WasmBrowserTestRunner.cs:line 196
 at Microsoft.DotNet.XHarness.CLI.Commands.WebServer.TestWebServerStartup.<>c__DisplayClass3_0.<<Configure>b__2>d.MoveNext() in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WebServer.cs:line 163
 --- End of stack trace from previous location ---
 at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
XHarness exit code: 71 (GENERAL_FAILURE)

C:\helix\work\workitem\e\wasm_build\AppBundle>set EXIT_CODE=71 
----- end Fri 09/23/2022 23:38:44.97 ----- exit code 71 ----------------------------------------------------------

ChannelClosedException - Console on

[23:13:04] info: Starting: System.Private.Xml.Tests.dll
[23:14:16] fail: 245597000
[23:14:16] fail: 245597000
[23:14:16] fail: 245597000
[23:14:16] fail: 245597120
[23:14:16] info: WASM EXIT 1
[23:14:16] info: Waiting to flush log messages with a timeout of 120 secs ..
[23:14:16] info: WASM EXIT 1
[23:14:16] fail: Flushing log messages failed with: System.InvalidOperationException: An attempt was made to transition a task to a final state when it had already completed.
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.ProcessMessage(String message, Boolean isError) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 200
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.RunAsync(CancellationToken token) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 82
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.RunAsync(CancellationToken token) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 82
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmTestMessagesProcessor.CompleteAndFlushAsync(Nullable`1 timeout) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/WasmTestMessagesProcessor.cs:line 106. Ignoring.
fail: Microsoft.AspNetCore.Server.Kestrel[13]
 Connection id "0HMKPPD0JB2H6", Request id "0HMKPPD0JB2H6:00000001": An unhandled exception was thrown by the application.
 System.Threading.Channels.ChannelClosedException: The channel has been closed.
 at Microsoft.DotNet.XHarness.CLI.Commands.Wasm.WasmBrowserTestRunner.RunConsoleMessagesPump(WebSocket socket, CancellationToken token) in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WASM/Browser/WasmBrowserTestRunner.cs:line 196
 at Microsoft.DotNet.XHarness.CLI.Commands.WebServer.TestWebServerStartup.<>c__DisplayClass3_0.<<Configure>b__2>d.MoveNext() in /_/src/Microsoft.DotNet.XHarness.CLI/Commands/WebServer.cs:line 163
 --- End of stack trace from previous location ---
 at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
 at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
[23:14:16] fail: [out of order message from the browser]: http://127.0.0.1:49195/dotnet.js 4:1872 "[main] websocket closed: [object CloseEvent]" CloseEvent
[23:14:16] info: Could not process message: {"method":"console.log","payload":"WASM EXIT 1","arguments":["WASM EXIT 1"]}
[23:14:16] info: Application has finished with exit code TESTS_FAILED. But the log processor failed with GENERAL_FAILURE.
[23:14:16] fail: Application has finished with exit code GENERAL_FAILURE but 0 was expected
XHarness exit code: 71 (GENERAL_FAILURE)

C:\helix\work\workitem\e\wasm_build\AppBundle>set EXIT_CODE=71 
----- end Sun 09/18/2022 23:14:20.41 ----- exit code 71 ----------------------------------------------------------

Author:	karelz
Assignees:	-
Labels:	arch-wasm
Milestone:	-

[radical]

The xharness exception can be ignored. The real issue is #74302 .

[lewing]

looks like a manifestation of #74302

[carlossanlop]

It's affecting various System.Xml tests. They all show this error message:

[21:36:12] warn: Blocking on the main thread is very dangerous, see https://emscripten.org/docs/porting/pthreads.html#blocking-on-the-main-browser-thread
[21:51:05] fail: Tests timed out. Killing driver service pid 4661
[21:51:06] fail: Application has finished with exit code TIMED_OUT but 0 was expected
XHarness exit code: 71 (GENERAL_FAILURE)

• Found in unrelated release/7.0 PR: [release/7.0][Android] Backport fix NetworkInterface.GetAllNetworkInterfaces #76565

• Pipeline: runtime-extra-platforms

• Queues:

  • Build Browser wasm Linux Release LibraryTests_Threading
  • Build Browser wasm Linux Release LibraryTests_Threading_PerfTracing

• Job results:

  • Threading: https://dev.azure.com/dnceng-public/public/_build/results?buildId=38971&view=logs&j=5e0663a6-779c-5be5-6d4c-61295b043a58&t=a6da8bfe-2e5e-5d0c-f321-5907e9da992a
  • Threading_PerfTracing: https://dev.azure.com/dnceng-public/public/_build/results?buildId=38971&view=logs&j=92c81310-cb26-5923-f96e-b7c73963fa3d&t=0aa9a844-8701-5b62-3bc4-3a39f7c23650

• Log files:

  • System.Xml.RW.XmlSystemPathResolver
    https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-76565-merge-ca460d6a395347bab6/WasmTestOnBrowser-System.Xml.RW.XmlSystemPathResolver.Tests/1/console.37cb0c0c.log?helixlogtype=result

  • System.Xml.XmlSchema.XmlSchemaValidatorApi https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-76565-merge-ca460d6a395347bab6/WasmTestOnBrowser-System.Xml.XmlSchema.XmlSchemaValidatorApi.Tests/1/console.17381658.log?helixlogtype=result

  • System.Xml.XmlSchemaSet https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-76565-merge-ca460d6a395347bab6/WasmTestOnBrowser-System.Xml.XmlSchemaSet.Tests/1/console.e1c804c4.log?helixlogtype=result