[wasm][aot] Uncaught errors in System.Runtime.Tests

[radical]

Build, and log:

info: Discovering: System.Runtime.Tests.dll (method display = ClassAndMethod, method display options = None)
info: Discovered:  System.Runtime.Tests.dll (found 8909 of 9059 test cases)
info: Using random seed for test cases: 867690635
info: Using random seed for collections: 867690635
info: Starting:    System.Runtime.Tests.dll
fail: 143503392
fail: 143503392
fail: 143503392
fail: 143503392
info: WASM EXIT 1
info: Waiting to flush log messages with a timeout of 120 secs ..
fail: Application has finished with exit code TESTS_FAILED but 0 was expected
fail: [out of order message from the browser]: http://127.0.0.1:49190/test-main.js 342:0 Uncaught (in promise)
fail: [out of order message from the browser]: http://127.0.0.1:49190/dotnet.js 1882:6 Uncaught
XHarness exit code: 71 (GENERAL_FAILURE)

This is when building [wasm] Unwrap exception when calling entrypoint (#74235) on main.
/cc @maraf @pavelsavara

[ghost]

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

Issue Details

---

Build, and log:

info: Discovering: System.Runtime.Tests.dll (method display = ClassAndMethod, method display options = None)
info: Discovered:  System.Runtime.Tests.dll (found 8909 of 9059 test cases)
info: Using random seed for test cases: 867690635
info: Using random seed for collections: 867690635
info: Starting:    System.Runtime.Tests.dll
fail: 143503392
fail: 143503392
fail: 143503392
fail: 143503392
info: WASM EXIT 1
info: Waiting to flush log messages with a timeout of 120 secs ..
fail: Application has finished with exit code TESTS_FAILED but 0 was expected
fail: [out of order message from the browser]: http://127.0.0.1:49190/test-main.js 342:0 Uncaught (in promise)
fail: [out of order message from the browser]: http://127.0.0.1:49190/dotnet.js 1882:6 Uncaught
XHarness exit code: 71 (GENERAL_FAILURE)

This is when building [wasm] Unwrap exception when calling entrypoint (#74235) on main.
/cc @maraf @pavelsavara

Author:	radical
Assignees:	-
Labels:	arch-wasm, blocking-clean-ci, area-VM-meta-mono, wasm-aot-test
Milestone:	-

[pavelsavara]

This seems that there is throw 143503392 which is probably pointer ? Do we know what could throw like this ?

[pavelsavara]

Could this be

function ___cxa_throw(ptr, type, destructor) {
      ...
      throw ptr;

[pavelsavara]

@vargaz do you have any ideas ? Thanks!

[carlossanlop]

@pavelsavara @radical @vargaz I am seeing this failure in this 7.0 backport PR: #74971

Can you please determine if this is something that needs a fix to get backported to 7.0?

• Pipeline results: https://dev.azure.com/dnceng-public/public/_build/results?buildId=2240&view=logs&j=7f41eb05-1c5f-5922-38da-d308f495fb31&t=142a4cb7-24ad-543f-6942-1fea62d34e98&l=58
• Queue: Build Browser wasm Linux Release LibraryTests_AOT
• Artifacts: https://dev.azure.com/dnceng-public/public/_build/results?buildId=2240&view=ms.vss-test-web.build-test-results-tab&runId=31826&resultId=100001&paneView=dotnet-dnceng.dnceng-anon-build-release-tasks.helix-anon-test-information-tab

From console.f9376408.log in the artifacts:

[02:06:01] info: Starting:    System.Runtime.Tests.dll
[02:06:57] info: /datadisks/disk1/work/BAC30A50/w/AD8509D5/e/wasm_build/AppBundle/dotnet.js:1883: 138656096
[02:06:57] info:       throw ptr;

The wasm-console.log file in the artifacts seems to tell that the execution suddenly crashed (I would've expected a summary at the end, not an abrupt stop):

[PASS] System.Tests.RealFormatterTests.TestFormatterDouble_P20(value: 65747.125, expectedResult: "6,574,712.50000000000000000000 %")
[PASS] System.Tests.RealFormatterTests.TestFormatterDouble_P20(value: 1844674407370955.2, expectedResult: "184,467,440,737,095,525.00000000000000000000 %")
/datadisks/disk1/work/BAC30A50/w/AD8509D5/e/wasm_build/AppBundle/dotnet.js:1883: 138656096
      throw ptr;
      ^

[radical]

It happens on main too, and it's not fixed yet.

[radical]

Rolling build for 7.0, and log:

[20:25:44] info: Using random seed for test cases: 2136378125
[20:25:44] info: Using random seed for collections: 2136378125
[20:25:44] info: Starting:    System.Collections.Tests.dll
[20:27:01] fail: 737314736
[20:27:01] fail: 737314736
[20:27:01] fail: 737314736
[20:27:01] fail: 737314736
[20:27:01] info: WASM EXIT 1
[20:27:01] info: Waiting to flush log messages with a timeout of 120 secs ..
[20:27:02] fail: Application has finished with exit code TESTS_FAILED but 0 was expected
[20:27:02] fail: [out of order message from the browser]: http://127.0.0.1:49189/test-main.js 342:0 Uncaught (in promise)
[20:27:02] fail: [out of order message from the browser]: http://127.0.0.1:49189/dotnet.js 1882:6 Uncaught
XHarness exit code: 71 (GENERAL_FAILURE)

[pavelsavara]

I can reproduce it on my machine. It takes ~60 attempts to get one failure. I'm trying to capture better trace now.

[pavelsavara]

This is example when throw ptr worked just fine. I guess because wasm-function mono_llvm_cpp_catch_exception was on the stack.

exceptionLastInfo 210474704 19896236 0 Error
___cxa_throw (dotnet.js:1978:74)
mono_llvm_cpp_throw_exception (wasm://wasm/204a75de:wasm-function[291239]:0x43c4680)
mini_llvmonly_throw_exception (wasm://wasm/204a75de:wasm-function[308473]:0x459effe)
corlib_System_RuntimeType_get_GenericParameterPosition (wasm://wasm/204a75de:wasm-function[114673]:0x18774bb)
System_Runtime_Tests_System_Tests_Types_TypePropertyTestBase__GenericParameterPosition_Get_ReturnsExpectedb__83_0 (wasm://wasm/204a75de:wasm-function[222795]:0x324c2fd)
corlib_wrapper_delegate_invoke_System_Func_1_TResult_REF_invoke_TResult (wasm://wasm/204a75de:wasm-function[147115]:0x1da087c)
invoke_iii (dotnet.js:9495:42)
xunit_assert_Xunit_Assert_RecordException_System_Func_1_object (wasm://wasm/204a75de:wasm-function[281013]:0x41871b4)
xunit_assert_Xunit_Assert_Throws_T_REF_System_Func_1_object (wasm://wasm/204a75de:wasm-function[281012]:0x4187066)
System_Runtime_Tests_System_Tests_Types_TypePropertyTestBase_GenericParameterPosition_Get_ReturnsExpected (wasm://wasm/204a75de:wasm-function[222762]:0x324a3a9)
corlib_aot_wrapper_gsharedvt_out_sig_pinvoke_void_this_ (wasm://wasm/204a75de:wasm-function[152905]:0x1ec6053)
jit_call_cb (wasm://wasm/204a75de:wasm-function[290739]:0x43a3fc1)
invoke_vi (dotnet.js:9572:35)
mono_llvm_cpp_catch_exception (wasm://wasm/204a75de:wasm-function[291240]:0x43c469f)
do_jit_call (wasm://wasm/204a75de:wasm-function[290686]:0x43a2d95)
interp_exec_method (wasm://wasm/204a75de:wasm-function[290612]:0x4395262)
interp_runtime_invoke (wasm://wasm/204a75de:wasm-function[290611]:0x4393db1)
mono_jit_runtime_invoke (wasm://wasm/204a75de:wasm-function[308057]:0x458e20f)
do_runtime_invoke (wasm://wasm/204a75de:wasm-function[295834]:0x443b2a5)
mono_runtime_invoke_checked (wasm://wasm/204a75de:wasm-function[295832]:0x443b24d)
mono_runtime_try_invoke_span (wasm://wasm/204a75de:wasm-function[295995]:0x443f92d)
mono_runtime_invoke_span_checked (wasm://wasm/204a75de:wasm-function[295996]:0x443fb86)
ves_icall_InternalInvoke (wasm://wasm/204a75de:wasm-function[294509]:0x4415680)
ves_icall_InternalInvoke_raw (wasm://wasm/204a75de:wasm-function[294724]:0x441c3ed)
aot_wrapper_corlib_System_dot_Reflection_System_dot_Reflection_dot_RuntimeMethodInfo__InternalInvoke_pinvoke_obj_this_objbcls17_Span_601_3cobject_3e_26__attrs_1bclsc_Exception_26__attrs_2obj_cls1d_Reflection_dRuntimeMethodInfo_objbcls17_Span_601_3cobject_3e_26__attrs_1bclsc_Exception_26__attrs_2 (wasm://wasm/204a75de:wasm-function[134575]:0x1b3c8f1)
invoke_iiiiii (dotnet.js:9561:42)
corlib_System_Reflection_MethodInvoker_InterpretedInvoke_object_System_Span_1_object_System_Reflection_BindingFlags (wasm://wasm/204a75de:wasm-function[136506]:0x1b7929a)

...

[vargaz]

Does it only fail when run from the browser ?

[pavelsavara]

This one is V8 @vargaz

[pavelsavara]

This is stack trace when the mono_llvm_cpp_catch_exception is missing on V8 Windows

Using random seed for test cases: 1151537649
Using random seed for collections: 1151537649
Starting:    System.Runtime.Tests.dll
WASM EXIT 1
quit3_
exceptionLast 130410104
exceptionLastInfo 130410104 19896236 0 Error
    at ___cxa_throw (C:/Dev/runtime2/artifacts/bin/System.Runtime.Tests/Release/net7.0-browser/browser-wasm/AppBundle/dotnet.js:1988:74)
    at mono_llvm_cpp_throw_exception (wasm://wasm/204a75de:wasm-function[291239]:0x43c4680)
    at interp_runtime_invoke (wasm://wasm/204a75de:wasm-function[290611]:0x4393dd6)
    at mono_jit_runtime_invoke (wasm://wasm/204a75de:wasm-function[308057]:0x458e20f)
    at do_runtime_invoke (wasm://wasm/204a75de:wasm-function[295834]:0x443b2a5)
    at mono_runtime_try_invoke (wasm://wasm/204a75de:wasm-function[295845]:0x443b9c5)
    at mono_runtime_invoke (wasm://wasm/204a75de:wasm-function[295924]:0x443da8c)
    at mono_wasm_invoke_method_bound (wasm://wasm/204a75de:wasm-function[310012]:0x45d2fd9)
    at Module._mono_wasm_invoke_method_bound [as mono_wasm_invoke_method_bound] (C:/Dev/runtime2/artifacts/bin/System.Runtime.Tests/Release/net7.0-browser/browser-wasm/AppBundle/dotnet.js:8153:141)
    at ei (C:/Dev/runtime2/artifacts/bin/System.Runtime.Tests/Release/net7.0-browser/browser-wasm/AppBundle/dotnet.js:9:61953)
    at y.javaScriptExports.call_entry_point (C:/Dev/runtime2/artifacts/bin/System.Runtime.Tests/Release/net7.0-browser/browser-wasm/AppBundle/dotnet.js:9:64998)
    at Object.Me [as runMain] (C:/Dev/runtime2/artifacts/bin/System.Runtime.Tests/Release/net7.0-browser/browser-wasm/AppBundle/dotnet.js:9:3132)
    at run (test-main.js:331:50)
130410104
exiting due to exception: 130410104
Process v8.cmd exited with 1

[pavelsavara]

@vargaz is it actionable now ?

[lewing]

@vargaz this is showing up regularly and we need to resolve it, it looks like some mixed paths aren't handling the unmanaged exception?

cc @marek-safar @lambdageek

[lambdageek]

Looking at this one, #74302 (comment), I think mono_wasm_invoke_method_bound or maybe mono_runtime_invoke (on wasm?) needs a C++ catch clause. because our LLVM code assumes it can throw and unwind until we get back to the interpreter (to do_jit_call), but in this case we have JS->C->C# and there's no C# code to get back to. it's happening with call_entry_point but it could probalby happen with other JS export entrypoints.

Actually I wonder if we're missing a do_jit_call (or really mono_llvm_cpp_catch_exception) for some opcode?

Another thought: do we load/register AOT images asynchronously? is it possible we executed main before all the AOT images were loaded? So the interp thought it was doing a normal call, but by the time the exception is thrown we registered AOT images and they throw a C++ exception?

[vargaz]

Disabling random testcase ordering for this assembly would probably work around the problem.

[vargaz]

Does this still happen ?

[vargaz]

-> Fixed