From 0640999b2aeacb410044c064150ff5a022105d5f Mon Sep 17 00:00:00 2001 From: Ankit Jain Date: Wed, 29 Jun 2022 00:54:08 -0400 Subject: [PATCH 1/7] [wasm][nodejs] Ensure that stdout/stderr have been flushed out before exiting When the results xml is large, and we are writing the base64 representation in one line, `node` can exit before all the output gets flushed out. This results in xharness getting an incomplete `STARTRESULTXML ... ` with missing `ENDRESULTXML`, thus no `testResults.xml` is generated. This can be seen in the case of `Microsoft.Extensions.Primitives.Tests` which has xml ~140KB, and `System.Memory.Tests` which has a xml ~13MB. So, wait for the two streams to be flushed out, with a timeout of 3secs. --- .../templates/console/app-support.mjs | 19 ++++++++++-- src/mono/wasm/test-main.js | 29 +++++++++---------- 2 files changed, 30 insertions(+), 18 deletions(-) diff --git a/src/mono/wasm/templates/templates/console/app-support.mjs b/src/mono/wasm/templates/templates/console/app-support.mjs index 63059780d8a2eb..a2fb6787134b69 100644 --- a/src/mono/wasm/templates/templates/console/app-support.mjs +++ b/src/mono/wasm/templates/templates/console/app-support.mjs @@ -47,11 +47,26 @@ function set_exit_code(exit_code, reason) { } if (App && App.INTERNAL) { - App.INTERNAL.mono_wasm_exit(exit_code); + let _flush = function(_stream) { + return new Promise((resolve, reject) => { + setTimeout(reject, 30000); + _stream.write('', function() { resolve () }); + _stream.on('error', (error) => reject(error)); + }); + }; + let stderrFlushed = _flush(process.stderr); + let stdoutFlushed = _flush(process.stdout); + + Promise.all([ stdoutFlushed, stderrFlushed ]) + .then( + () => App.INTERNAL.mono_wasm_exit(exit_code), + reason => { + console.error(`flushing std* streams failed: ${reason}`); + App.INTERNAL.mono_wasm_exit(123456); + }); } } - let runArgs = {}; let is_debugging = false; diff --git a/src/mono/wasm/test-main.js b/src/mono/wasm/test-main.js index 1651d13d311549..dbf4e46dd93a0d 100644 --- a/src/mono/wasm/test-main.js +++ b/src/mono/wasm/test-main.js @@ -105,26 +105,23 @@ function set_exit_code(exit_code, reason) { } else if (App && App.INTERNAL) { if (is_node) { - let _flush = function (_stream) { - return new Promise((resolve, reject) => { - if (!_stream.write('')) { - _stream.on('drain', () => resolve()); - setTimeout(reject, 3000); - } else { - resolve(); - } - }); + let _flush = function(_stream) { + return new Promise((resolve, reject) => { + setTimeout(reject, 30000); + _stream.write('', function() { resolve () }); + _stream.on('error', (error) => reject(error)); + }); }; let stderrFlushed = _flush(process.stderr); let stdoutFlushed = _flush(process.stdout); - Promise.all([stdoutFlushed, stderrFlushed]) - .then( - () => App.INTERNAL.mono_wasm_exit(exit_code), - reason => { - console.error(`flushing std* streams failed: ${reason}`); - App.INTERNAL.mono_wasm_exit(123); - }); + Promise.all([ stdoutFlushed, stderrFlushed ]) + .then( + () => App.INTERNAL.mono_wasm_exit(exit_code), + reason => { + console.error(`flushing std* streams failed: ${reason}`); + App.INTERNAL.mono_wasm_exit(123456); + }); } else { App.INTERNAL.mono_wasm_exit(exit_code); } From ddc89afe1aa6f0b822153678eaf121401c5e1594 Mon Sep 17 00:00:00 2001 From: Ankit Jain Date: Wed, 29 Jun 2022 00:58:12 -0400 Subject: [PATCH 2/7] [wasm] Wasm.Build.Tests: improve reading output from processes - Fix to call `WaitForExit()` once `WaitForExit(int)` returns, which ensures that all the async handlers have been run. - Also, for non-browser xharness runs use the emitted `wasm-console.log` as the output, so we don't depend on xharness' stdout. --- .../Wasm.Build.Tests/BuildTestBase.cs | 43 ++++++++++++------- 1 file changed, 27 insertions(+), 16 deletions(-) diff --git a/src/tests/BuildWasmApps/Wasm.Build.Tests/BuildTestBase.cs b/src/tests/BuildWasmApps/Wasm.Build.Tests/BuildTestBase.cs index 6c11e076aba594..f9b0b5a4f19cc8 100644 --- a/src/tests/BuildWasmApps/Wasm.Build.Tests/BuildTestBase.cs +++ b/src/tests/BuildWasmApps/Wasm.Build.Tests/BuildTestBase.cs @@ -152,11 +152,13 @@ protected string RunAndTestWasmApp(BuildArgs buildArgs, } string bundleDir = Path.Combine(GetBinDir(baseDir: buildDir, config: buildArgs.Config, targetFramework: targetFramework), "AppBundle"); - (string testCommand, string extraXHarnessArgs) = host switch + + // Use wasm-console.log to get the xharness output for non-browser cases + (string testCommand, string extraXHarnessArgs, bool useWasmConsoleOutput) = host switch { - RunHost.V8 => ("wasm test", "--js-file=test-main.js --engine=V8 -v trace"), - RunHost.NodeJS => ("wasm test", "--js-file=test-main.js --engine=NodeJS -v trace"), - _ => ("wasm test-browser", $"-v trace -b {host} --web-server-use-cop") + RunHost.V8 => ("wasm test", "--js-file=test-main.js --engine=V8 -v trace", true), + RunHost.NodeJS => ("wasm test", "--js-file=test-main.js --engine=NodeJS -v trace", true), + _ => ("wasm test-browser", $"-v trace -b {host} --web-server-use-cop", false) }; string testLogPath = Path.Combine(_logPath, host.ToString()); @@ -170,7 +172,8 @@ protected string RunAndTestWasmApp(BuildArgs buildArgs, expectedAppExitCode: expectedExitCode, extraXHarnessArgs: extraXHarnessArgs, appArgs: args, - extraXHarnessMonoArgs: extraXHarnessMonoArgs + extraXHarnessMonoArgs: extraXHarnessMonoArgs, + useWasmConsoleOutput: useWasmConsoleOutput ); if (buildArgs.AOT) @@ -192,7 +195,8 @@ protected string RunAndTestWasmApp(BuildArgs buildArgs, protected static string RunWithXHarness(string testCommand, string testLogPath, string projectName, string bundleDir, ITestOutputHelper _testOutput, IDictionary? envVars=null, - int expectedAppExitCode=0, int xharnessExitCode=0, string? extraXHarnessArgs=null, string? appArgs=null, string? extraXHarnessMonoArgs = null) + int expectedAppExitCode=0, int xharnessExitCode=0, string? extraXHarnessArgs=null, + string? appArgs=null, string? extraXHarnessMonoArgs = null, bool useWasmConsoleOutput = false) { _testOutput.WriteLine($"============== {testCommand} ============="); Directory.CreateDirectory(testLogPath); @@ -230,6 +234,12 @@ protected static string RunWithXHarness(string testCommand, string testLogPath, timeoutMs: s_defaultPerTestTimeoutMs); File.WriteAllText(Path.Combine(testLogPath, $"xharness.log"), output); + if (useWasmConsoleOutput) + { + string wasmConsolePath = Path.Combine(testLogPath, "wasm-console.log"); + if (File.Exists(wasmConsolePath)) + output = File.ReadAllText(wasmConsolePath); + } if (exitCode != xharnessExitCode) { @@ -746,9 +756,12 @@ public static (int exitCode, string buildOutput) RunProcess(string path, process.BeginOutputReadLine(); process.BeginErrorReadLine(); - // process.WaitForExit doesn't work if the process exits too quickly? - // resetEvent.WaitOne(); - if (!process.WaitForExit(timeoutMs ?? s_defaultPerTestTimeoutMs)) + using CancellationTokenSource cts = new(); + cts.CancelAfter(timeoutMs ?? s_defaultPerTestTimeoutMs); + + await process.WaitForExitAsync(cts.Token); + + if (cts.IsCancellationRequested) { // process didn't exit process.Kill(entireProcessTree: true); @@ -758,13 +771,11 @@ public static (int exitCode, string buildOutput) RunProcess(string path, throw new XunitException($"Process timed out. Last 20 lines of output:{Environment.NewLine}{string.Join(Environment.NewLine, lastLines)}"); } } - else - { - // this will ensure that all the async event handling - // has completed - // https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.process.waitforexit?view=net-5.0#System_Diagnostics_Process_WaitForExit_System_Int32_ - await process.WaitForExitAsync(); - } + + // this will ensure that all the async event handling has completed + // and should be called after process.WaitForExit(int) + // https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.process.waitforexit?view=net-5.0#System_Diagnostics_Process_WaitForExit_System_Int32_ + process.WaitForExit(); process.ErrorDataReceived -= logStdErr; process.OutputDataReceived -= logStdOut; From 6dee11e2e963e311067e682b30bd1a461fc5eaa4 Mon Sep 17 00:00:00 2001 From: Ankit Jain Date: Wed, 29 Jun 2022 01:00:26 -0400 Subject: [PATCH 3/7] Wasm.Build.Tests: Run the crypto test only with browser. Other cases are covered in library tests --- .../Wasm.Build.Tests/NativeLibraryTests.cs | 13 +++---------- 1 file changed, 3 insertions(+), 10 deletions(-) diff --git a/src/tests/BuildWasmApps/Wasm.Build.Tests/NativeLibraryTests.cs b/src/tests/BuildWasmApps/Wasm.Build.Tests/NativeLibraryTests.cs index 809ccee6d6b994..d5f0d0f59755a7 100644 --- a/src/tests/BuildWasmApps/Wasm.Build.Tests/NativeLibraryTests.cs +++ b/src/tests/BuildWasmApps/Wasm.Build.Tests/NativeLibraryTests.cs @@ -98,8 +98,8 @@ public static int Main() } [ConditionalTheory(typeof(BuildTestBase), nameof(IsUsingWorkloads))] - [BuildAndRun(aot: false)] - [BuildAndRun(aot: true)] + [BuildAndRun(aot: false, host: RunHost.Chrome)] + [BuildAndRun(aot: true, host: RunHost.Chrome)] public void ProjectUsingBrowserNativeCrypto(BuildArgs buildArgs, RunHost host, string id) { string projectName = $"AppUsingBrowserNativeCrypto"; @@ -140,14 +140,7 @@ public static int Main() output); string cryptoInitMsg = "MONO_WASM: Initializing Crypto WebWorker"; - if (host == RunHost.V8 || host == RunHost.NodeJS) - { - Assert.DoesNotContain(cryptoInitMsg, output); - } - else - { - Assert.Contains(cryptoInitMsg, output); - } + Assert.Contains(cryptoInitMsg, output); } } } From 43d6be785ba1cd8edccfb50520e083684203afdf Mon Sep 17 00:00:00 2001 From: Ankit Jain Date: Wed, 29 Jun 2022 01:04:54 -0400 Subject: [PATCH 4/7] Enable WasmTemplateTests.ConsolePublishAndRun Fixes https://github.com/dotnet/runtime/issues/70675 --- src/tests/BuildWasmApps/Wasm.Build.Tests/WasmTemplateTests.cs | 1 - 1 file changed, 1 deletion(-) diff --git a/src/tests/BuildWasmApps/Wasm.Build.Tests/WasmTemplateTests.cs b/src/tests/BuildWasmApps/Wasm.Build.Tests/WasmTemplateTests.cs index fed63140faeb35..c088ca58365af0 100644 --- a/src/tests/BuildWasmApps/Wasm.Build.Tests/WasmTemplateTests.cs +++ b/src/tests/BuildWasmApps/Wasm.Build.Tests/WasmTemplateTests.cs @@ -149,7 +149,6 @@ public void ConsoleBuildAndRun(string config) } [ConditionalTheory(typeof(BuildTestBase), nameof(IsUsingWorkloads))] - [ActiveIssue("https://github.com/dotnet/runtime/issues/70675", TestPlatforms.Windows)] [InlineData("Debug", false)] [InlineData("Debug", true)] [InlineData("Release", false)] From d37afef7383d36772c1a2081450092c60fd6c3b2 Mon Sep 17 00:00:00 2001 From: Ankit Jain Date: Wed, 29 Jun 2022 01:33:31 -0400 Subject: [PATCH 5/7] Wasm.Build.Tests: avoid unncessary copy when building locally Copy sdk for testing workloads only on CI. --- .../data/RunScriptTemplate.cmd | 21 ++++++++++------- .../data/RunScriptTemplate.sh | 23 ++++++++++++------- 2 files changed, 28 insertions(+), 16 deletions(-) diff --git a/src/tests/BuildWasmApps/Wasm.Build.Tests/data/RunScriptTemplate.cmd b/src/tests/BuildWasmApps/Wasm.Build.Tests/data/RunScriptTemplate.cmd index c2523168b9009e..d3c47af35c02ff 100644 --- a/src/tests/BuildWasmApps/Wasm.Build.Tests/data/RunScriptTemplate.cmd +++ b/src/tests/BuildWasmApps/Wasm.Build.Tests/data/RunScriptTemplate.cmd @@ -94,16 +94,21 @@ exit /b %EXIT_CODE% REM Functions :SetEnvVars if [%TEST_USING_WORKLOADS%] == [true] ( + set _DIR_NAME=dotnet-workload set SDK_HAS_WORKLOAD_INSTALLED=true - robocopy /np /nfl /e %BASE_DIR%\dotnet-workload %EXECUTION_DIR%\dotnet-workload - set "SDK_FOR_WORKLOAD_TESTING_PATH=%EXECUTION_DIR%\dotnet-workload" - set "PATH=%EXECUTION_DIR%\dotnet-workload;%PATH%" - set "AppRefDir=%BASE_DIR%\microsoft.netcore.app.ref" ) else ( + set _DIR_NAME=sdk-no-workload set SDK_HAS_WORKLOAD_INSTALLED=false - robocopy /np /nfl /e %BASE_DIR%\sdk-no-workload %EXECUTION_DIR%\sdk-no-workload - set "SDK_FOR_WORKLOAD_TESTING_PATH=%EXECUTION_DIR%\sdk-no-workload" - set "PATH=%EXECUTION_DIR%\sdk-no-workload;%PATH%" - set "AppRefDir=%BASE_DIR%\microsoft.netcore.app.ref" ) + +if [%HELIX_CORRELATION_PAYLOAD%] NEQ [] ( + robocopy /np /nfl /NDL /NJH /NJS /nc /e %BASE_DIR%\%_DIR_NAME% %EXECUTION_DIR%\%_DIR_NAME% + set _SDK_DIR=%EXECUTION_DIR%\%_DIR_NAME% +) else ( + set _SDK_DIR=%BASE_DIR%\%_DIR_NAME% +) + +set "PATH=%_SDK_DIR%;%PATH%" +set "SDK_FOR_WORKLOAD_TESTING_PATH=%_SDK_DIR%" +set "AppRefDir=%BASE_DIR%\microsoft.netcore.app.ref" EXIT /b 0 diff --git a/src/tests/BuildWasmApps/Wasm.Build.Tests/data/RunScriptTemplate.sh b/src/tests/BuildWasmApps/Wasm.Build.Tests/data/RunScriptTemplate.sh index 97ed44c3606048..0c3be485422f90 100644 --- a/src/tests/BuildWasmApps/Wasm.Build.Tests/data/RunScriptTemplate.sh +++ b/src/tests/BuildWasmApps/Wasm.Build.Tests/data/RunScriptTemplate.sh @@ -66,19 +66,26 @@ echo XHARNESS_ARGS=$XHARNESS_ARGS function set_env_vars() { + local _DIR_NAME= if [ "x$TEST_USING_WORKLOADS" = "xtrue" ]; then - cp -r $BASE_DIR/dotnet-workload $EXECUTION_DIR - export PATH=$EXECUTION_DIR/dotnet-workload:$PATH + _DIR_NAME=dotnet-workload export SDK_HAS_WORKLOAD_INSTALLED=true - export SDK_FOR_WORKLOAD_TESTING_PATH=$EXECUTION_DIR/dotnet-workload - export AppRefDir=$BASE_DIR/microsoft.netcore.app.ref else - cp -r $BASE_DIR/sdk-no-workload $EXECUTION_DIR - export PATH=$EXECUTION_DIR/sdk-no-workload:$PATH + _DIR_NAME=sdk-no-workload export SDK_HAS_WORKLOAD_INSTALLED=false - export SDK_FOR_WORKLOAD_TESTING_PATH=$EXECUTION_DIR/sdk-no-workload - export AppRefDir=$BASE_DIR/microsoft.netcore.app.ref fi + + local _SDK_DIR= + if [[ -n "$HELIX_WORKITEM_UPLOAD_ROOT" ]]; then + cp -r $BASE_DIR/$_DIR_NAME $EXECUTION_DIR + _SDK_DIR=$EXECUTION_DIR/$_DIR_NAME + else + _SDK_DIR=$BASE_DIR/$_DIR_NAME + fi + + export PATH=$_SDK_DIR:$PATH + export SDK_FOR_WORKLOAD_TESTING_PATH=$_SDK_DIR + export AppRefDir=$BASE_DIR/microsoft.netcore.app.ref } export TEST_LOG_PATH=${XHARNESS_OUT}/logs From 6b40e09058f8ca796f03c07682eadc8cf373af1d Mon Sep 17 00:00:00 2001 From: Ankit Jain Date: Thu, 30 Jun 2022 00:27:05 -0400 Subject: [PATCH 6/7] Address feedback from @kg --- .../templates/templates/console/app-support.mjs | 4 ++-- src/mono/wasm/test-main.js | 4 ++-- .../BuildWasmApps/Wasm.Build.Tests/BuildTestBase.cs | 13 +++++++++++-- 3 files changed, 15 insertions(+), 6 deletions(-) diff --git a/src/mono/wasm/templates/templates/console/app-support.mjs b/src/mono/wasm/templates/templates/console/app-support.mjs index a2fb6787134b69..a4c15ac8f86eb7 100644 --- a/src/mono/wasm/templates/templates/console/app-support.mjs +++ b/src/mono/wasm/templates/templates/console/app-support.mjs @@ -49,9 +49,9 @@ function set_exit_code(exit_code, reason) { if (App && App.INTERNAL) { let _flush = function(_stream) { return new Promise((resolve, reject) => { - setTimeout(reject, 30000); - _stream.write('', function() { resolve () }); + setTimeout(() => { reject(new Error("timed out waiting for stdout/stderr streams to flush")) }, 30000); _stream.on('error', (error) => reject(error)); + _stream.write('', function() { resolve () }); }); }; let stderrFlushed = _flush(process.stderr); diff --git a/src/mono/wasm/test-main.js b/src/mono/wasm/test-main.js index dbf4e46dd93a0d..283d447d851162 100644 --- a/src/mono/wasm/test-main.js +++ b/src/mono/wasm/test-main.js @@ -107,9 +107,9 @@ function set_exit_code(exit_code, reason) { if (is_node) { let _flush = function(_stream) { return new Promise((resolve, reject) => { - setTimeout(reject, 30000); - _stream.write('', function() { resolve () }); + setTimeout(() => { reject(new Error("timed out waiting for stdout/stderr streams to flush")) }, 30000); _stream.on('error', (error) => reject(error)); + _stream.write('', function() { resolve () }); }); }; let stderrFlushed = _flush(process.stderr); diff --git a/src/tests/BuildWasmApps/Wasm.Build.Tests/BuildTestBase.cs b/src/tests/BuildWasmApps/Wasm.Build.Tests/BuildTestBase.cs index f9b0b5a4f19cc8..e8417708e65be3 100644 --- a/src/tests/BuildWasmApps/Wasm.Build.Tests/BuildTestBase.cs +++ b/src/tests/BuildWasmApps/Wasm.Build.Tests/BuildTestBase.cs @@ -237,8 +237,17 @@ protected static string RunWithXHarness(string testCommand, string testLogPath, if (useWasmConsoleOutput) { string wasmConsolePath = Path.Combine(testLogPath, "wasm-console.log"); - if (File.Exists(wasmConsolePath)) - output = File.ReadAllText(wasmConsolePath); + try + { + if (File.Exists(wasmConsolePath)) + output = File.ReadAllText(wasmConsolePath); + else + _testOutput.WriteLine($"Warning: Could not find {wasmConsolePath}. Ignoring."); + } + catch (IOException ioex) + { + _testOutput.WriteLine($"Warning: Could not read {wasmConsolePath}: {ioex}"); + } } if (exitCode != xharnessExitCode) From c5163dcaaab072fe6f7cf714114d59ef97962435 Mon Sep 17 00:00:00 2001 From: Ankit Jain Date: Thu, 30 Jun 2022 00:35:57 -0400 Subject: [PATCH 7/7] Remove timeout on flushing stdout/stderr streams, for console templates, IOW, user apps --- src/mono/wasm/templates/templates/console/app-support.mjs | 1 - 1 file changed, 1 deletion(-) diff --git a/src/mono/wasm/templates/templates/console/app-support.mjs b/src/mono/wasm/templates/templates/console/app-support.mjs index a4c15ac8f86eb7..5df6ddc8e8ba19 100644 --- a/src/mono/wasm/templates/templates/console/app-support.mjs +++ b/src/mono/wasm/templates/templates/console/app-support.mjs @@ -49,7 +49,6 @@ function set_exit_code(exit_code, reason) { if (App && App.INTERNAL) { let _flush = function(_stream) { return new Promise((resolve, reject) => { - setTimeout(() => { reject(new Error("timed out waiting for stdout/stderr streams to flush")) }, 30000); _stream.on('error', (error) => reject(error)); _stream.write('', function() { resolve () }); });